Logging, runtime tracing, and the obs performance profiler for OCaml
0

Configure Feed

Select the types of activity you want to include in your feed.

obs: name the report model after its library

memtrace_eio dates from `eiotrace', the tool that merged a memtrace .ctf with Eio runtime_events. The module no longer mentions Memtrace at all -- the .ctf reader is Ctf_input -- and it reports fine on traces carrying no Eio scheduler events. Its library was already observer_model, so naming the module after it drops a redundant level: callers write Observer_model.Model.t, not Observer_model.Memtrace_eio.Model.t.

The four file renames reached HEAD in 31a64e002, which swept a staged `git mv' from a concurrent session; this commit carries the call sites that go with them, so the tree compiles again.

+58 -58
+10 -10
bin/obs/cmd_common.ml
··· 1 - module Report = Observer_model.Memtrace_eio.Report 2 - module Render = Observer_model.Memtrace_eio.Render 1 + module Report = Observer_model.Report 2 + module Render = Observer_model.Render 3 3 4 4 let current_json = ref false 5 5 let json_enabled () = !current_json ··· 136 136 137 137 let sort_conv = 138 138 let parse = function 139 - | "self" -> Ok Observer_model.Memtrace_eio.Render.Self 140 - | "total" -> Ok Observer_model.Memtrace_eio.Render.Total 141 - | "count" -> Ok Observer_model.Memtrace_eio.Render.Count 142 - | "p99" -> Ok Observer_model.Memtrace_eio.Render.P99 143 - | "alloc" -> Ok Observer_model.Memtrace_eio.Render.Alloc 139 + | "self" -> Ok Observer_model.Render.Self 140 + | "total" -> Ok Observer_model.Render.Total 141 + | "count" -> Ok Observer_model.Render.Count 142 + | "p99" -> Ok Observer_model.Render.P99 143 + | "alloc" -> Ok Observer_model.Render.Alloc 144 144 | s -> err_usage "unknown sort %S" s 145 145 in 146 146 let pp ppf s = 147 147 Fmt.string ppf 148 148 (match s with 149 - | Observer_model.Memtrace_eio.Render.Self -> "self" 149 + | Observer_model.Render.Self -> "self" 150 150 | Total -> "total" 151 151 | Count -> "count" 152 152 | P99 -> "p99" ··· 172 172 let sort = 173 173 Arg.( 174 174 value 175 - & opt sort_conv Observer_model.Memtrace_eio.Render.Self 175 + & opt sort_conv Observer_model.Render.Self 176 176 & info [ "sort" ] ~docv:"KEY" 177 177 ~doc:"Sort spans by self|total|count|p99|alloc.") 178 178 in 179 179 let mk top min_share all sort = 180 180 { 181 - Observer_model.Memtrace_eio.Render.top; 181 + Observer_model.Render.top; 182 182 min_share = min_share /. 100.; 183 183 all; 184 184 sort;
+5 -5
bin/obs/cmd_common.mli
··· 10 10 (** [err_usage fmt] formats a usage error into [Error (`Msg _)]. *) 11 11 12 12 val render_report : 13 - Observer_model.Memtrace_eio.Render.opts -> 14 - Observer_model.Memtrace_eio.Report.t -> 13 + Observer_model.Render.opts -> 14 + Observer_model.Report.t -> 15 15 unit 16 16 (** [render_report opts report] prints the full [report] to stdout: JSON under 17 17 [--json], otherwise the text report coloured when stdout is a tty. *) 18 18 19 19 val render_summary : 20 - Observer_model.Memtrace_eio.Render.opts -> 21 - Observer_model.Memtrace_eio.Report.t -> 20 + Observer_model.Render.opts -> 21 + Observer_model.Report.t -> 22 22 unit 23 23 (** [render_summary opts report] prints only the triage (budget, verdict, 24 24 findings) to stdout: JSON under [--json], otherwise the short text report 25 25 coloured when stdout is a tty. Used by [obs run]; [obs report] prints the 26 26 full {!render_report}. *) 27 27 28 - val opts_term : Observer_model.Memtrace_eio.Render.opts Cmdliner.Term.t 28 + val opts_term : Observer_model.Render.opts Cmdliner.Term.t 29 29 (** [opts_term] parses [--top], [--min], [--all] and [--sort] into render 30 30 options. *) 31 31
+4 -4
bin/obs/cmd_report.ml
··· 138 138 if missing <> [] then 139 139 Cmd_common.err_usage "no such trace: %s" (String.concat ", " missing) 140 140 else begin 141 - let model = Observer_model.Memtrace_eio.Model.v () in 141 + let model = Observer_model.Model.v () in 142 142 (* Each fxt record is routed to the (process, ring) carried by its 143 143 thread, so multiple producers in one trace stay isolated. *) 144 144 List.iter ··· 153 153 traces; 154 154 Option.iter 155 155 (fun (start, stop) -> 156 - Observer_model.Memtrace_eio.Model.set_wall_clock model ~start ~stop) 156 + Observer_model.Model.set_wall_clock model ~start ~stop) 157 157 meta.wall; 158 158 List.iter 159 159 (fun (process, parent_span) -> 160 - Observer_model.Memtrace_eio.Model.set_process_context model ~process 160 + Observer_model.Model.set_process_context model ~process 161 161 ~parent_span) 162 162 meta.ctx; 163 163 Cmd_common.render_report opts 164 - (Observer_model.Memtrace_eio.Model.report model); 164 + (Observer_model.Model.report model); 165 165 Ok () 166 166 end 167 167
+1 -1
bin/obs/cmd_run.ml
··· 5 5 module Ctf_input = Observer_offline.Ctf_input 6 6 module Collector_server = Observer_offline.Collector_server 7 7 module Collector = Observer_offline.Collector 8 - module Model = Observer_model.Memtrace_eio.Model 8 + module Model = Observer_model.Model 9 9 10 10 let src = Logs.Src.create "obs.run" ~doc:"obs live run" 11 11
+1 -1
lib/obs/observer_model.mli
··· 1 1 (** Unified scheduler, GC and allocation hotspots for OCaml 5 / Eio programs. 2 2 3 - [Memtrace_eio] merges three event sources into one plain-text report: 3 + The model merges three event sources into one plain-text report: 4 4 5 5 - Eio scheduler events (fibers, cancellation contexts, spans, suspends), 6 6 decoded from a [runtime_events] ring via {!Eio_runtime_events};
+2 -2
lib/obs/offline/ctf_input.ml
··· 1 1 module R = Observe_memtrace.Memtrace.Trace.Reader 2 2 module E = Observe_memtrace.Memtrace.Trace.Event 3 3 module L = Observe_memtrace.Memtrace.Trace.Location 4 - module Model = Observer_model.Memtrace_eio.Model 4 + module Model = Observer_model.Model 5 5 6 6 let pp_site (l : L.t) = 7 7 Fmt.str "%s (%s:%d)" l.L.defname (Filename.basename l.L.filename) l.L.line ··· 31 31 in 32 32 Model.alloc_sample model 33 33 { 34 - Observer_model.Memtrace_eio.Model.words = length; 34 + Observer_model.Model.words = length; 35 35 nsamples; 36 36 site; 37 37 wall_us;
+2 -2
lib/obs/offline/ctf_input.mli
··· 1 1 (** Read a memtrace [.ctf] allocation trace into the shared 2 - {!Observer_model.Memtrace_eio.Model}. *) 2 + {!Observer_model.Model}. *) 3 3 4 - val feed : Observer_model.Memtrace_eio.Model.t -> string -> unit 4 + val feed : Observer_model.Model.t -> string -> unit 5 5 (** [feed model ctf] opens the memtrace [.ctf] at [ctf], records its sample rate 6 6 and start time, and feeds each allocation sample to [model], attributing it 7 7 to its innermost backtrace site.
+2 -2
lib/obs/offline/fxt_adapter.ml
··· 1 1 (* Translate between Eio [runtime_events] and the Fuchsia trace format, both 2 - directions, against the shared {!Observer_model.Memtrace_eio.Model}. 2 + directions, against the shared {!Observer_model.Model}. 3 3 4 4 The writer ({!Sink}) is driven by the same callbacks that feed the live 5 5 model: each runtime_events record is emitted as one fxt record, yielding a ··· 21 21 22 22 module W = Observer_fxt.Write 23 23 module Rd = Observer_fxt.Read 24 - module Model = Observer_model.Memtrace_eio.Model 24 + module Model = Observer_model.Model 25 25 module Rt = Observe_rt 26 26 module Frame = Observe_protocol.Frame 27 27
+4 -4
lib/obs/offline/fxt_adapter.mli
··· 1 1 (** Translate between Eio [runtime_events] and the Fuchsia trace format against 2 - the shared {!Observer_model.Memtrace_eio.Model}. 2 + the shared {!Observer_model.Model}. 3 3 4 4 The writer ({!Sink}) emits one fxt record per runtime_events record, so a 5 5 live capture and the reader below agree byte-for-byte and the result opens ··· 81 81 end 82 82 83 83 val feed_records : 84 - Observer_model.Memtrace_eio.Model.t -> Observer_fxt.Read.record Seq.t -> unit 84 + Observer_model.Model.t -> Observer_fxt.Read.record Seq.t -> unit 85 85 (** [feed_records model records] replays parsed fxt [records] into [model], 86 86 routing each record to the (process, ring) carried by its thread ([pid] is 87 87 the process, [tid] the ring), so distinct producers never merge. *) 88 88 89 - val feed_string : Observer_model.Memtrace_eio.Model.t -> string -> unit 89 + val feed_string : Observer_model.Model.t -> string -> unit 90 90 (** [feed_string model data] parses [data] as a Fuchsia trace and replays it 91 91 into [model], routing each record by its thread's (process, ring). 92 92 @raise Failure if [data] is not a valid Fuchsia trace. *) 93 93 94 - val feed_file : Observer_model.Memtrace_eio.Model.t -> string -> unit 94 + val feed_file : Observer_model.Model.t -> string -> unit 95 95 (** [feed_file model path] reads the [.fxt] at [path] and replays it into 96 96 [model], routing each record by its thread's (process, ring). 97 97 @raise Failure if the file is not a valid Fuchsia trace. *)
+1 -1
test/obs_eio/test.ml
··· 1 - let () = Alcotest.run "memtrace_eio" [ Test_memtrace_eio.suite ] 1 + let () = Alcotest.run "observer_model" [ Test_observer_model.suite ]
+22 -22
test/obs_eio/test_observer_model.ml
··· 1 - module Q = Observer_model.Memtrace_eio.Quantile 2 - module M = Observer_model.Memtrace_eio.Model 3 - module Rep = Observer_model.Memtrace_eio.Report 1 + module Q = Observer_model.Quantile 2 + module M = Observer_model.Model 3 + module Rep = Observer_model.Report 4 4 5 5 let close ?(eps = 1e-9) name a b = 6 6 Alcotest.(check bool) name true (Float.abs (a -. b) < eps) ··· 348 348 M.eio_event m ~ring:0 ~ts_ns:(ms 7.) `Exit_span; 349 349 let r = M.report m in 350 350 let text = 351 - Observer_model.Memtrace_eio.Render.to_string 352 - Observer_model.Memtrace_eio.Render.default_opts r 351 + Observer_model.Render.to_string 352 + Observer_model.Render.default_opts r 353 353 in 354 354 (* Isolate the Contention block so the span name from the hotspots table above 355 355 does not leak into the assertion. *) ··· 460 460 M.eio_event m ~ring:0 ~ts_ns:(ms (t0 +. 5.)) (`Fiber 1) 461 461 done; 462 462 let r = M.report m in 463 - let s = Observer_model.Memtrace_eio.Render.to_json r in 463 + let s = Observer_model.Render.to_json r in 464 464 let json = Json.Value.of_string_exn s in 465 465 let obj = function 466 466 | Json.Value.Object (m, _) -> m ··· 587 587 M.eio_event m ~ring:0 ~ts_ns:(ms 50.) `Exit_span; 588 588 let r = M.report m in 589 589 let s = 590 - Observer_model.Memtrace_eio.Render.to_string 591 - Observer_model.Memtrace_eio.Render.default_opts r 590 + Observer_model.Render.to_string 591 + Observer_model.Render.default_opts r 592 592 in 593 593 let has sub = 594 594 let n = String.length sub and m = String.length s in ··· 815 815 M.eio_event m ~ring:0 ~ts_ns:(ms 50.) (`Suspend_fiber "io"); 816 816 M.eio_event m ~ring:0 ~ts_ns:(ms 50.) `Exit_span; 817 817 let r = M.report m in 818 - let opts = Observer_model.Memtrace_eio.Render.default_opts in 819 - let summary = Observer_model.Memtrace_eio.Render.to_summary opts r in 820 - let full = Observer_model.Memtrace_eio.Render.to_string opts r in 818 + let opts = Observer_model.Render.default_opts in 819 + let summary = Observer_model.Render.to_summary opts r in 820 + let full = Observer_model.Render.to_string opts r in 821 821 Alcotest.(check bool) "summary budget" true (contains summary "== BUDGET =="); 822 822 Alcotest.(check bool) 823 823 "summary verdict" true ··· 909 909 [ 970; 988 ]; 910 910 let r = M.report m in 911 911 let s = 912 - Observer_model.Memtrace_eio.Render.to_string 913 - Observer_model.Memtrace_eio.Render.default_opts r 912 + Observer_model.Render.to_string 913 + Observer_model.Render.default_opts r 914 914 in 915 915 (* Isolate the "waiting by cause" block of the budget (the lines between the 916 916 "waiting by cause:" header and the following "events:" confidence line), so ··· 1399 1399 "verdict not CPU-bound" false 1400 1400 (contains r.Rep.verdict "CPU-bound"); 1401 1401 let text = 1402 - Observer_model.Memtrace_eio.Render.to_string 1403 - Observer_model.Memtrace_eio.Render.default_opts r 1402 + Observer_model.Render.to_string 1403 + Observer_model.Render.default_opts r 1404 1404 in 1405 1405 Alcotest.(check bool) 1406 1406 "alloc top sites header" true ··· 1431 1431 (* memtrace and runtime_events now share the monotonic clock, so the rendered 1432 1432 join reports no wall-vs-monotonic drift rather than an approximate label *) 1433 1433 let text = 1434 - Observer_model.Memtrace_eio.Render.to_string 1435 - Observer_model.Memtrace_eio.Render.default_opts r 1434 + Observer_model.Render.to_string 1435 + Observer_model.Render.default_opts r 1436 1436 in 1437 1437 Alcotest.(check bool) 1438 1438 "monotonic clock note" true ··· 1492 1492 "verdict denies CPU-bound" true 1493 1493 (contains r.Rep.verdict "not CPU-bound"); 1494 1494 let text = 1495 - Observer_model.Memtrace_eio.Render.to_string 1496 - Observer_model.Memtrace_eio.Render.default_opts r 1495 + Observer_model.Render.to_string 1496 + Observer_model.Render.default_opts r 1497 1497 in 1498 1498 Alcotest.(check bool) 1499 1499 "budget marks wall unattributed" true ··· 1516 1516 "verdict names the empty case" true 1517 1517 (contains r.Rep.verdict "Empty capture"); 1518 1518 let text = 1519 - Observer_model.Memtrace_eio.Render.to_string 1520 - Observer_model.Memtrace_eio.Render.default_opts r 1519 + Observer_model.Render.to_string 1520 + Observer_model.Render.default_opts r 1521 1521 in 1522 1522 Alcotest.(check bool) 1523 1523 "budget marks wall unattributed" true ··· 1527 1527 (contains text "run looks balanced") 1528 1528 1529 1529 let suite = 1530 - ( "memtrace_eio", 1530 + ( "observer_model", 1531 1531 [ 1532 1532 Alcotest.test_case "probe span surfaces" `Quick test_probe_span_surfaces; 1533 1533 Alcotest.test_case "hot span finding" `Quick test_hot_span;
+1 -1
test/obs_eio/test_observer_model.mli
··· 1 - (** Tests for the Observer_model.Memtrace_eio module. *) 1 + (** Tests for the Observer_model module. *) 2 2 3 3 val suite : string * unit Alcotest.test_case list 4 4 (** Test suite. *)
+2 -2
test/producer/test_forwarder.ml
··· 4 4 module Collector_server = Observer_offline.Collector_server 5 5 module Ctf_input = Observer_offline.Ctf_input 6 6 module Fxt_adapter = Observer_offline.Fxt_adapter 7 - module Model = Observer_model.Memtrace_eio.Model 8 - module Rep = Observer_model.Memtrace_eio.Report 7 + module Model = Observer_model.Model 8 + module Rep = Observer_model.Report 9 9 module Observe_rt = Observe_rt 10 10 11 11 let hello os_pid =
+1 -1
test/producer/test_forwarder_eio.ml
··· 1 1 module Forwarder_eio = Observe_producer_eio.Forwarder_eio 2 2 module Collector_server = Observer_offline.Collector_server 3 3 module Fxt_adapter = Observer_offline.Fxt_adapter 4 - module Model = Observer_model.Memtrace_eio.Model 4 + module Model = Observer_model.Model 5 5 6 6 (* The Eio forwarder runs the drain in a fiber of the program's own loop -- no 7 7 Domain -- and writes over an Eio flow. Started inside Eio_main.run, it streams