bench and tests for fuchsia

bench/bench_fuchsia_write.ml

@@ -0,0 +1,58 @@
+open Trace_fuchsia_write
+module B = Benchmark
+
+let pf = Printf.printf
+
+let encode_1_span (out : Output.t) () =
+  Event.Duration_complete.encode out ~name:"span" ~t_ref:(Thread_ref.Ref 5)
+    ~time_ns:100_000L ~end_time_ns:5_000_000L ~args:[] ()
+
+let encode_3_span (out : Output.t) () =
+  Event.Duration_complete.encode out ~name:"outer" ~t_ref:(Thread_ref.Ref 5)
+    ~time_ns:100_000L ~end_time_ns:5_000_000L ~args:[] ();
+  Event.Duration_complete.encode out ~name:"inner" ~t_ref:(Thread_ref.Ref 5)
+    ~time_ns:180_000L ~end_time_ns:4_500_000L ~args:[] ();
+  Event.Instant.encode out ~name:"hello" ~time_ns:1_234_567L
+    ~t_ref:(Thread_ref.Ref 5)
+    ~args:[ "x", `Int 42 ]
+    ()
+
+let time_per_iter_ns (samples : B.t list) : float =
+  let n_iters = ref 0L in
+  let time = ref 0. in
+  List.iter
+    (fun (s : B.t) ->
+      n_iters := Int64.add !n_iters s.iters;
+      time := !time +. s.stime +. s.utime)
+    samples;
+  !time *. 1e9 /. Int64.to_float !n_iters
+
+let () =
+  let buf_pool = Buf_pool.create () in
+  let out =
+    Output.create ~buf_pool
+      ~send_buf:(fun buf -> Buf_pool.recycle buf_pool buf)
+      ()
+  in
+
+  let samples = B.throughput1 4 ~name:"encode_1_span" (encode_1_span out) () in
+  B.print_gc samples;
+
+  let [ (_, samples) ] = samples [@@warning "-8"] in
+
+  let iter_per_ns = time_per_iter_ns samples in
+  pf "%.3f ns/iter\n" iter_per_ns;
+
+  ()
+
+let () =
+  let buf_pool = Buf_pool.create () in
+  let out =
+    Output.create ~buf_pool
+      ~send_buf:(fun buf -> Buf_pool.recycle buf_pool buf)
+      ()
+  in
+
+  let samples = B.throughput1 4 ~name:"encode_3_span" (encode_3_span out) () in
+  B.print_gc samples;
+  ()

bench/dune

@@ -1,4 +1,16 @@
 
 (executable
   (name trace1)
+  (modules trace1)
   (libraries trace.core trace-tef))
+
+(executable
+  (name trace_fx)
+  (modules trace_fx)
+  (preprocess (pps ppx_trace))
+  (libraries trace.core trace-fuchsia))
+
+(executable
+  (name bench_fuchsia_write)
+  (modules bench_fuchsia_write)
+  (libraries benchmark trace-fuchsia.write))

bench/trace_fx.ml

@@ -0,0 +1,42 @@
+module Trace = Trace_core
+
+let ( let@ ) = ( @@ )
+
+let work ~dom_idx ~n () : unit =
+  for _i = 1 to n do
+    let%trace _sp = "outer" in
+    Trace_core.add_data_to_span _sp [ "i", `Int _i ];
+    for _k = 1 to 10 do
+      let%trace _sp = "inner" in
+      ()
+    done;
+
+    (* Thread.delay 1e-6 *)
+    if dom_idx = 0 && _i mod 4096 = 0 then (
+      let stat = Gc.quick_stat () in
+      Trace_core.counter_float "gc.minor" (8. *. stat.minor_words);
+      Trace_core.counter_float "gc.major" (8. *. stat.major_words)
+    )
+  done
+
+let main ~n ~j () : unit =
+  let domains =
+    Array.init j (fun dom_idx -> Domain.spawn (fun () -> work ~dom_idx ~n ()))
+  in
+  Array.iter Domain.join domains
+
+let () =
+  let@ () = Trace_fuchsia.with_setup () in
+
+  let n = ref 10_000 in
+  let j = ref 4 in
+
+  let args =
+    [
+      "-n", Arg.Set_int n, " number of iterations";
+      "-j", Arg.Set_int j, " set number of workers";
+    ]
+    |> Arg.align
+  in
+  Arg.parse args ignore "bench1";
+  main ~n:!n ~j:!j ()

bench_fx.sh

@@ -0,0 +1,3 @@
+#!/bin/sh
+DUNE_OPTS="--profile=release --display=quiet"
+exec dune exec $DUNE_OPTS bench/trace_fx.exe -- $@

dune

@@ -1,4 +1,4 @@
 
 (env
-  (_ (flags :standard -strict-sequence -warn-error -a+8+26+27 -w +a-4-40-44-70)))
+  (_ (flags :standard -strict-sequence -warn-error -a+8+26+27 -w +a-4-40-42-44-70)))
 

test/fuchsia/write/t2.ml

@@ -40,36 +40,50 @@ module Str_ = struct
     Bytes.unsafe_to_string res
 end
 
+let with_buf_output (f : Output.t -> unit) : string =
+  let buf_pool = Buf_pool.create () in
+  let buffer = Buffer.create 32 in
+  let out = Output.into_buffer ~buf_pool buffer in
+  f out;
+  Output.flush out;
+  Buffer.contents buffer
+
 let () = pf "first trace\n"
 
 let () =
-  let buf = Buf.create 128 in
+  let str =
-  Metadata.Magic_record.encode buf;
+    with_buf_output (fun out ->
-  Thread_record.encode buf ~as_ref:5 ~pid:1 ~tid:86 ();
+        Metadata.Magic_record.encode out;
-  Event.Instant.encode buf ~name:"hello" ~time_ns:1234_5678L
+        Thread_record.encode out ~as_ref:5 ~pid:1 ~tid:86 ();
+        Event.Instant.encode out ~name:"hello" ~time_ns:1234_5678L
           ~t_ref:(Thread_ref.Ref 5)
           ~args:[ "x", `Int 42 ]
-    ();
+          ())
-  pf "%s\n" (Buf.to_string buf |> Str_.to_hex)
+  in
+  pf "%s\n" (Str_.to_hex str)
 
 let () = pf "second trace\n"
 
 let () =
-  let buf = Buf.create 512 in
+  let str =
-  Metadata.Magic_record.encode buf;
+    with_buf_output (fun out ->
+        Metadata.Magic_record.encode out;
         Metadata.Initialization_record.(
-    encode buf ~ticks_per_secs:default_ticks_per_sec ());
+          encode out ~ticks_per_secs:default_ticks_per_sec ());
-  Thread_record.encode buf ~as_ref:5 ~pid:1 ~tid:86 ();
+        Thread_record.encode out ~as_ref:5 ~pid:1 ~tid:86 ();
-  Metadata.Provider_info.encode buf ~id:1 ~name:"ocaml-trace" ();
+        Metadata.Provider_info.encode out ~id:1 ~name:"ocaml-trace" ();
-  Event.Duration_complete.encode buf ~name:"outer" ~t_ref:(Thread_ref.Ref 5)
+        Event.Duration_complete.encode out ~name:"outer"
-    ~time_ns:100_000L ~end_time_ns:5_000_000L ~args:[] ();
+          ~t_ref:(Thread_ref.Ref 5) ~time_ns:100_000L ~end_time_ns:5_000_000L
-  Event.Duration_complete.encode buf ~name:"inner" ~t_ref:(Thread_ref.Ref 5)
+          ~args:[] ();
-    ~time_ns:180_000L ~end_time_ns:4_500_000L ~args:[] ();
+        Event.Duration_complete.encode out ~name:"inner"
-  Event.Instant.encode buf ~name:"hello" ~time_ns:1_234_567L
+          ~t_ref:(Thread_ref.Ref 5) ~time_ns:180_000L ~end_time_ns:4_500_000L
+          ~args:[] ();
+        Event.Instant.encode out ~name:"hello" ~time_ns:1_234_567L
           ~t_ref:(Thread_ref.Ref 5)
           ~args:[ "x", `Int 42 ]
-    ();
+          ())
+  in
   (let oc = open_out "foo.fxt" in
-   output_string oc (Buf.to_string buf);
+   output_string oc str;
    close_out oc);
-  pf "%s\n" (Buf.to_string buf |> Str_.to_hex)
+  pf "%s\n" (Str_.to_hex str)