Adding --time-phases to forc build (#2091)

* make items under [project] ordered alphabetically in forc.toml

* issue #1893store/show bytecode hash

* formatted

* added cargo lock file

* cargo toml dependencies in alphabetical order

* hash bin of script or predicate only

* format

* generating bytecode hash only on scripts and predicates

* removed option from Compiled::tree_type

* ran clippy

* added to forc_build documentation

* made filename suffix containing bin hash a constant

* get root of predicate bytecode

* Apply suggestions from code review

Co-authored-by: Mohammad Fawaz <mohammadfawaz89@gmail.com>

* if let to match on program type

* Update forc/src/cli/commands/build.rs

updating bin-root filename

Co-authored-by: mitchmindtree <mail@mitchellnordine.com>

* added benchmarks for compilation process

* use macro instead of closure for wrapping parts of compilation process

Co-authored-by: Waseem G <contact@waseem-g.com>
Co-authored-by: Mohammad Fawaz <mohammadfawaz89@gmail.com>
Co-authored-by: mitchmindtree <mail@mitchellnordine.com>
Co-authored-by: Toby Hutton <toby@grusly.com>

Author: 5 people

forc-pkg/src/manifest.rs

@@ -81,6 +81,7 @@ pub struct BuildProfile {
     pub print_finalized_asm: bool,
     pub print_intermediate_asm: bool,
     pub silent: bool,
+    pub time_phases: bool,
 }
 
 impl Dependency {
@@ -347,6 +348,7 @@ impl BuildProfile {
             print_finalized_asm: false,
             print_intermediate_asm: false,
             silent: false,
+            time_phases: false,
         }
     }
 
@@ -356,6 +358,7 @@ impl BuildProfile {
             print_finalized_asm: false,
             print_intermediate_asm: false,
             silent: false,
+            time_phases: false,
         }
     }
 }

forc-pkg/src/pkg.rs

@@ -1409,12 +1409,36 @@ pub fn compile(
     namespace: namespace::Module,
     source_map: &mut SourceMap,
 ) -> Result<(Compiled, Option<namespace::Root>)> {
+    // Time the given expression and print the result if `build_config.time_phases` is true.
+    macro_rules! time_expr {
+        ($description:expr, $expression:expr) => {{
+            if build_profile.time_phases {
+                let expr_start = std::time::Instant::now();
+                let output = { $expression };
+                println!(
+                    "  Time elapsed to {}: {:?}",
+                    $description,
+                    expr_start.elapsed()
+                );
+                output
+            } else {
+                $expression
+            }
+        }};
+    }
+
     let entry_path = manifest.entry_path();
-    let sway_build_config = sway_build_config(manifest.dir(), &entry_path, build_profile)?;
+    let sway_build_config = time_expr!(
+        "produce `sway_core::BuildConfig`",
+        sway_build_config(manifest.dir(), &entry_path, build_profile)?
+    );
     let silent_mode = build_profile.silent;
 
     // First, compile to an AST. We'll update the namespace and check for JSON ABI output.
-    let ast_res = compile_ast(manifest, build_profile, namespace)?;
+    let ast_res = time_expr!(
+        "compile to ast",
+        compile_ast(manifest, build_profile, namespace)?
+    );
     match &ast_res {
         CompileAstResult::Failure { warnings, errors } => {
             print_on_failure(silent_mode, warnings, errors);
@@ -1424,7 +1448,7 @@ pub fn compile(
             typed_program,
             warnings,
         } => {
-            let json_abi = typed_program.kind.generate_json_abi();
+            let json_abi = time_expr!("generate JSON ABI", typed_program.kind.generate_json_abi());
             let tree_type = typed_program.kind.tree_type();
             match tree_type {
                 // If we're compiling a library, we don't need to compile any further.
@@ -1443,8 +1467,14 @@ pub fn compile(
 
                 // For all other program types, we'll compile the bytecode.
                 TreeType::Contract | TreeType::Predicate | TreeType::Script => {
-                    let asm_res = sway_core::ast_to_asm(ast_res, &sway_build_config);
-                    let bc_res = sway_core::asm_to_bytecode(asm_res, source_map);
+                    let asm_res = time_expr!(
+                        "compile ast to asm",
+                        sway_core::ast_to_asm(ast_res, &sway_build_config)
+                    );
+                    let bc_res = time_expr!(
+                        "compile asm to bytecode",
+                        sway_core::asm_to_bytecode(asm_res, source_map)
+                    );
                     match bc_res {
                         BytecodeCompilationResult::Success { bytes, warnings } => {
                             print_on_success(silent_mode, &pkg.name, &warnings, &tree_type);

forc/src/cli/commands/build.rs

@@ -70,6 +70,9 @@ pub struct Command {
     ///  If --build-profile is also provided, forc omits this flag and uses provided build-profile.
     #[clap(long)]
     pub release: bool,
+    /// Output the time elapsed over each part of the compilation process.
+    #[clap(long)]
+    pub time_phases: bool,
 }
 
 pub(crate) fn exec(command: Command) -> Result<()> {

forc/src/cli/commands/deploy.rs

@@ -62,6 +62,9 @@ pub struct Command {
     /// If --build-profile is also provided, forc omits this flag and uses provided build-profile.
     #[clap(long)]
     pub release: bool,
+    /// Output the time elapsed over each part of the compilation process.
+    #[clap(long)]
+    pub time_phases: bool,
 }
 
 pub(crate) async fn exec(command: Command) -> Result<()> {

forc/src/cli/commands/run.rs

@@ -60,6 +60,10 @@ pub struct Command {
     #[clap(long = "silent", short = 's')]
     pub silent_mode: bool,
 
+    /// Output the time elapsed over each part of the compilation process.
+    #[clap(long)]
+    pub time_phases: bool,
+
     /// Pretty-print the outputs from the node.
     #[clap(long = "pretty-print", short = 'r')]
     pub pretty_print: bool,

forc/src/ops/forc_build.rs

@@ -28,6 +28,7 @@ pub fn build(command: BuildCommand) -> Result<pkg::Compiled> {
         locked,
         build_profile,
         release,
+        time_phases,
     } = command;
 
     let key_debug: String = "debug".to_string();
@@ -74,6 +75,7 @@ pub fn build(command: BuildCommand) -> Result<pkg::Compiled> {
     profile.print_finalized_asm |= print_finalized_asm;
     profile.print_intermediate_asm |= print_intermediate_asm;
     profile.silent |= silent_mode;
+    profile.time_phases |= time_phases;
 
     // Build it!
     let (compiled, source_map) = pkg::build(&plan, &profile, SWAY_GIT_TAG)?;

forc/src/ops/forc_deploy.rs

@@ -37,6 +37,7 @@ pub async fn deploy(command: DeployCommand) -> Result<fuel_tx::ContractId> {
         url,
         build_profile,
         release,
+        time_phases,
     } = command;
 
     let build_command = BuildCommand {
@@ -53,6 +54,7 @@ pub async fn deploy(command: DeployCommand) -> Result<fuel_tx::ContractId> {
         locked,
         build_profile,
         release,
+        time_phases,
     };
 
     let compiled = forc_build::build(build_command)?;

forc/src/ops/forc_run.rs

@@ -40,6 +40,7 @@ pub async fn run(command: RunCommand) -> Result<Vec<fuel_tx::Receipt>> {
         locked: command.locked,
         build_profile: None,
         release: false,
+        time_phases: command.time_phases,
     };
 
     let compiled = forc_build::build(build_command)?;