Compiler: more timing in wasmoo

Author: hhugo

compiler/bin-wasm_of_ocaml/compile.ml

@@ -164,19 +164,23 @@ let link_and_optimize
   @@ fun opt_temp_sourcemap ->
   (with_runtime_files ~runtime_wasm_files
   @@ fun runtime_inputs ->
+  let t = Timer.make ~get_time:Unix.time () in
   Binaryen.link
     ~inputs:
       (({ Binaryen.module_name = "env"; file = runtime_file } :: runtime_inputs)
       @ List.map ~f:(fun file -> { Binaryen.module_name = "OCaml"; file }) wat_files)
     ~opt_output_sourcemap:opt_temp_sourcemap
     ~output_file:temp_file
-    ());
+    ();
+  if times () then Format.eprintf "  binaryen link: %a@." Timer.print t);
+
   Fs.with_intermediate_file (Filename.temp_file "wasm-dce" ".wasm")
   @@ fun temp_file' ->
   opt_with
     Fs.with_intermediate_file
     (if enable_source_maps then Some (Filename.temp_file "wasm-dce" ".wasm.map") else None)
   @@ fun opt_temp_sourcemap' ->
+  let t = Timer.make ~get_time:Unix.time () in
   let primitives =
     Binaryen.dead_code_elimination
       ~dependencies:Runtime_files.dependencies
@@ -185,13 +189,16 @@ let link_and_optimize
       ~input_file:temp_file
       ~output_file:temp_file'
   in
+  if times () then Format.eprintf "  binaryen dce: %a@." Timer.print t;
+  let t = Timer.make ~get_time:Unix.time () in
   Binaryen.optimize
     ~profile
     ~opt_input_sourcemap:opt_temp_sourcemap'
     ~opt_output_sourcemap:opt_sourcemap
     ~input_file:temp_file'
     ~output_file
     ();
+  if times () then Format.eprintf "  binaryen opt: %a@." Timer.print t;
   Option.iter
     ~f:(update_sourcemap ~sourcemap_root ~sourcemap_don't_inline_content)
     opt_sourcemap_file;
@@ -523,6 +530,7 @@ let run
          in
          let generated_js = output_gen wat_file (output code ~unit_name:None) in
          let tmp_wasm_file = Filename.concat tmp_dir "code.wasm" in
+         let t2 = Timer.make ~get_time:Unix.time () in
          let primitives =
            link_and_optimize
              ~profile
@@ -533,6 +541,7 @@ let run
              [ wat_file ]
              tmp_wasm_file
          in
+         if times () then Format.eprintf " link_and_optimize: %a@." Timer.print t2;
          let wasm_name =
            Printf.sprintf
              "code-%s"
@@ -546,6 +555,7 @@ let run
            Link.Wasm_binary.append_source_map_section
              ~file:tmp_wasm_file'
              ~url:(wasm_name ^ ".wasm.map"));
+         if times () then Format.eprintf "Start building js runtime@.";
          let js_runtime =
            let missing_primitives =
              let l = Link.Wasm_binary.read_imports ~file:tmp_wasm_file' in

compiler/bin-wasm_of_ocaml/dune

@@ -9,6 +9,7 @@
   compiler-libs.common
   js_of_ocaml-compiler.runtime-files
   yojson
+  unix
   (select
    findlib_support.ml
    from

compiler/lib-wasm/generate.ml

@@ -1318,11 +1318,13 @@ let add_init_function = G.add_init_function
 let output ch ~context =
   let t = Timer.make () in
   let fields = G.output ~context in
+  if times () then Format.eprintf "    fields: %a@." Timer.print t;
   Wat_output.f ch fields;
-  if times () then Format.eprintf "  output: %a@." Timer.print t
+  if times () then Format.eprintf "  output-wat: %a@." Timer.print t
 
 let wasm_output ch ~context =
   let t = Timer.make () in
   let fields = G.output ~context in
+  if times () then Format.eprintf "    fields: %a@." Timer.print t;
   Wasm_output.f ch fields;
-  if times () then Format.eprintf "  output: %a@." Timer.print t
+  if times () then Format.eprintf "  output-wasm: %a@." Timer.print t

compiler/lib-wasm/wat_output.ml

@@ -666,10 +666,13 @@ let field ctx st f =
   | Type [ t ] -> [ type_field st t ]
   | Type l -> [ List (Atom "rec" :: List.map ~f:(type_field st) l) ]
 
+let times = Debug.find "times"
+
 let f ch fields =
+  let t = Timer.make () in
   let st = build_name_tables fields in
   let ctx = { function_refs = Code.Var.Set.empty } in
-  let other_fields = List.concat (List.map ~f:(fun f -> field ctx st f) fields) in
+  let other_fields = List.concat_map ~f:(fun f -> field ctx st f) fields in
   let funct_decl =
     let functions = Code.Var.Set.elements ctx.function_refs in
     if List.is_empty functions
@@ -682,12 +685,9 @@ let f ch fields =
           :: List.map ~f:(index st.func_names) functions)
       ]
   in
-  Format.fprintf
-    (Format.formatter_of_out_channel ch)
-    "%a@."
-    format_sexp
-    (List
-       (Atom "module"
-       :: (List.concat (List.map ~f:(fun i -> import st i) fields)
-          @ funct_decl
-          @ other_fields)))
+  let imports = List.concat_map ~f:(fun i -> import st i) fields in
+  let sexp = List (Atom "module" :: List.concat [ imports; funct_decl; other_fields ]) in
+  if times () then Format.eprintf "    prepare: %a@." Timer.print t;
+  let t = Timer.make () in
+  Format.fprintf (Format.formatter_of_out_channel ch) "%a@." format_sexp sexp;
+  if times () then Format.eprintf "    format: %a@." Timer.print t

compiler/lib/timer.ml

@@ -18,12 +18,13 @@
 
 open! Stdlib
 
-type t = float
+type t =
+  { get_time : unit -> float
+  ; start : float
+  }
 
-let timer = Sys.time
+let make ?(get_time = Sys.time) () = { get_time; start = get_time () }
 
-let make () = timer ()
-
-let get t = timer () -. t
+let get t = t.get_time () -. t.start
 
 let print f t = Format.fprintf f "%.2f" (get t)

compiler/lib/timer.mli

@@ -18,7 +18,7 @@
 
 type t
 
-val make : unit -> t
+val make : ?get_time:(unit -> float) -> unit -> t
 
 val get : t -> float