fix: align logger timing with webpack (#13721)

Author: hardfist

crates/rspack_core/src/compilation/build_module_graph/mod.rs

@@ -17,13 +17,10 @@ pub use self::{
   module_executor::{ExecuteModuleId, ExecutedRuntimeModule, ModuleExecutor},
 };
 pub use crate::BuildModuleGraphArtifact;
-use crate::{Compilation, ExportsInfoArtifact, logger::Logger};
+use crate::{Compilation, ExportsInfoArtifact};
 
 pub async fn build_module_graph_pass(compilation: &mut Compilation) -> Result<()> {
-  let logger = compilation.get_logger("rspack.Compiler");
-  let start = logger.time("build module graph");
   do_build_module_graph(compilation).await?;
-  logger.time_end(start);
   Ok(())
 }
 

crates/rspack_core/src/compilation/build_module_graph/pass.rs

@@ -9,6 +9,7 @@ use crate::{
     finish_make::finish_make_pass, finish_module_graph::finish_module_graph_pass,
     make::make_hook_pass, pass::PassExt,
   },
+  logger::Logger,
 };
 
 /// Composite pass for the entire Build Module Graph phase.
@@ -41,20 +42,16 @@ impl PassExt for BuildModuleGraphPhasePass {
     _cache: &mut dyn Cache,
   ) -> Result<()> {
     let plugin_driver = compilation.plugin_driver.clone();
-
-    // Sub-phase: make hook
+    let logger = compilation.get_logger("rspack.Compiler");
+    // align with webpack, make hook include build_module_graph phase in webpack
+    let start = logger.time("make hook");
     make_hook_pass(compilation, plugin_driver.clone()).await?;
-
-    // Sub-phase: build module graph
     build_module_graph_pass(compilation).await?;
+    logger.time_end(start);
 
-    // Sub-phase: finish make
-    finish_make_pass(compilation, plugin_driver.clone()).await?;
-
-    // Sub-phase: finish module graph
+    finish_make_pass(compilation, plugin_driver).await?;
     finish_module_graph_pass(compilation).await?;
 
-    // Add checkpoint if incremental build is enabled
     use crate::incremental::IncrementalPasses;
     if compilation
       .incremental

crates/rspack_core/src/compilation/finish_module_graph/mod.rs

@@ -12,7 +12,6 @@ pub async fn finish_module_graph_pass(compilation: &mut Compilation) -> Result<(
   let logger = compilation.get_logger("rspack.Compiler");
   let start = logger.time("finish compilation");
   finish_build_module_graph_pass(compilation).await?;
-
   logger.time_end(start);
 
   Ok(())

crates/rspack_core/src/compilation/make/mod.rs

@@ -1,16 +1,12 @@
 use rspack_error::Result;
 
-use crate::{Compilation, SharedPluginDriver, logger::Logger};
+use crate::{Compilation, SharedPluginDriver};
 
 pub async fn make_hook_pass(
   compilation: &mut Compilation,
   plugin_driver: SharedPluginDriver,
 ) -> Result<()> {
-  let logger = compilation.get_logger("rspack.Compiler");
-
-  let start = logger.time("make hook");
   plugin_driver.compiler_hooks.make.call(compilation).await?;
-  logger.time_end(start);
 
   Ok(())
 }

crates/rspack_core/src/compilation/run_passes.rs

@@ -50,6 +50,7 @@ impl Compilation {
     for pass in &passes {
       pass.run(self, cache).await?;
     }
+
     if !self.options.mode.is_development() {
       self.module_static_cache.disable_cache();
     }

tests/rspack-test/statsAPICases/verbose-time.js

@@ -45,7 +45,6 @@ module.exports = {
 
 			LOG from rspack.Compiler
 			<t> make hook: X ms
-			<t> build module graph: X ms
 			<t> finish make hook: X ms
 			<t> finish compilation: X ms
 			<t> seal compilation: X ms

tests/rspack-test/statsOutputCases/logging/__snapshots__/stats.txt

@@ -83,7 +83,6 @@ LOG from rspack.Compilation
 
 LOG from rspack.Compiler
 <t> make hook: xx ms
-<t> build module graph: xx ms
 <t> finish make hook: xx ms
 <t> finish compilation: xx ms
 <t> seal compilation: xx ms

tests/rspack-test/statsOutputCases/preset-verbose/__snapshots__/stats.txt

@@ -72,7 +72,6 @@ LOG from rspack.Compilation
 
 LOG from rspack.Compiler
 <t> make hook: xx ms
-<t> build module graph: xx ms
 <t> finish make hook: xx ms
 <t> finish compilation: xx ms
 <t> seal compilation: xx ms