diff --git a/bench/bench_fuchsia_write.ml b/bench/bench_fuchsia_write.ml new file mode 100644 index 0000000..a62149e --- /dev/null +++ b/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; + () diff --git a/bench/dune b/bench/dune index c6fec56..ade51c9 100644 --- a/bench/dune +++ b/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)) diff --git a/bench/trace_fx.ml b/bench/trace_fx.ml new file mode 100644 index 0000000..aea9221 --- /dev/null +++ b/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 () diff --git a/bench_fx.sh b/bench_fx.sh new file mode 100755 index 0000000..f2ba8ae --- /dev/null +++ b/bench_fx.sh @@ -0,0 +1,3 @@ +#!/bin/sh +DUNE_OPTS="--profile=release --display=quiet" +exec dune exec $DUNE_OPTS bench/trace_fx.exe -- $@ diff --git a/dune b/dune index 1b45a87..db65d82 100644 --- a/dune +++ b/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))) diff --git a/test/fuchsia/write/t2.ml b/test/fuchsia/write/t2.ml index 9f08a70..0dcc5e9 100644 --- a/test/fuchsia/write/t2.ml +++ b/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 - Metadata.Magic_record.encode buf; - Thread_record.encode buf ~as_ref:5 ~pid:1 ~tid:86 (); - Event.Instant.encode buf ~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) + let str = + with_buf_output (fun out -> + Metadata.Magic_record.encode out; + 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 ] + ()) + in + pf "%s\n" (Str_.to_hex str) let () = pf "second trace\n" let () = - let buf = Buf.create 512 in - Metadata.Magic_record.encode buf; - Metadata.Initialization_record.( - encode buf ~ticks_per_secs:default_ticks_per_sec ()); - Thread_record.encode buf ~as_ref:5 ~pid:1 ~tid:86 (); - Metadata.Provider_info.encode buf ~id:1 ~name:"ocaml-trace" (); - Event.Duration_complete.encode buf ~name:"outer" ~t_ref:(Thread_ref.Ref 5) - ~time_ns:100_000L ~end_time_ns:5_000_000L ~args:[] (); - Event.Duration_complete.encode buf ~name:"inner" ~t_ref:(Thread_ref.Ref 5) - ~time_ns:180_000L ~end_time_ns:4_500_000L ~args:[] (); - Event.Instant.encode buf ~name:"hello" ~time_ns:1_234_567L - ~t_ref:(Thread_ref.Ref 5) - ~args:[ "x", `Int 42 ] - (); + let str = + with_buf_output (fun out -> + Metadata.Magic_record.encode out; + Metadata.Initialization_record.( + encode out ~ticks_per_secs:default_ticks_per_sec ()); + Thread_record.encode out ~as_ref:5 ~pid:1 ~tid:86 (); + Metadata.Provider_info.encode out ~id:1 ~name:"ocaml-trace" (); + 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 ] + ()) + 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)