Most OCaml command-line tools want the same logging options: a verbosity level, a level per log source, JSON output, and a way to switch on the noisy *.tracing sources only when needed. The Observe library gives them all as a single Cmdliner term. It also reads MEMTRACE to capture allocations.

The obs command is for when a tool is slow. It records the scheduler and GC events that OCaml's runtime emits, the allocations memtrace samples, and the spans of ocaml-probe. From these it prints a wall-clock budget and a verdict on where the time went. To look closer at the largest cost, it can rank allocation sites or sample CPU stacks. It can also write the trace to a SQL database laid out like Perfetto's.

An executable built with Observe.setup sends its trace to the socket named in OBS_COLLECTOR. Because of that, obs run collects in the same way from a child it started, from a subprocess of that child, or from a VM guest. Probe capture inside the process is in a separate library, observe.capture, which a tool links only if it wants it.

Installation #

Install with opam:

$ opam install observe obs

The packages may not be in the public opam-repository yet. In that case, add the overlay first:

$ opam repo add samoht https://tangled.org/gazagnaire.org/opam-overlay.git
$ opam update
$ opam install observe obs

Usage #

A single term adds all the logging flags:

open Cmdliner

let run () =
  Logs.info (fun m -> m "Starting...");
  Ok ()

let cmd =
  let info = Cmd.info "myapp" in
  Cmd.v info Term.(const run $ Observe.setup "myapp")

let main () = exit (Cmd.eval_result cmd)

Flag	Level	`*.tracing` sources
`-q`	Error	Silenced
(none)	Warning	Silenced
`-v`	Info	Silenced
`-vv`	Debug	Silenced
`-vvv`	Debug	Enabled

With -vv you get the application's debug output but still none of the *.tracing sources. For a full protocol trace, use -vvv, or --log-trace FILE to send those sources to a file. --log takes a specification in the style of RUST_LOG, and the <APP>_LOG environment variable does the same:

$ myapp --log=info,http:debug         # global info, http at debug
$ myapp --log=warn,tls.tracing:debug  # enable one tracing source
$ MYAPP_LOG=debug myapp               # the same, from the environment

--json turns on structured output, written by Json_logs.reporter unless Observe.setup gets another reporter through ~json_reporter. Passing ~json_reporter:None removes the --json flag altogether. Log reports go to stderr, which keeps stdout free for the program's own JSON document.

Observe.setup also reads MEMTRACE, so the application needs no memtrace flag of its own. obs run -- myapp sets the variable to make the child write a .ctf file per process into the run bundle. A program that does not use Cmdliner calls Observe.Memtrace.trace_if_requested () when it starts. A %p in MEMTRACE becomes the process id, and OCaml children inherit the variable, so every process in a tree writes its own file. MEMTRACE_RATE sets the share of allocated words sampled, 1e-5 by default. A short run then yields only tens of samples, and its totals swing from one run to the next; 1e-4 gives a count worth ranking, and a higher rate slows the program.

A program whose command line declares its own verbosity, colour or JSON flags calls Observe.capture "myapp" when it starts, in place of the term: it starts the same capture, so obs run observes it, and adds no flag.

An executable that emits ocaml-probe events links observe.capture and uses Observe_capture.probe_config next to Observe.setup. The default term stays as it is, which suits the many tools that only log.

The obs CLI #

$ obs run -- ./bench.exe                        # capture, then report
$ obs report latest                             # re-report a saved bundle
$ obs hotspots .obs/latest/memtrace/<pid>.ctf   # rank allocation sites
$ obs query BASE.db operations                  # SQL over the timeline
$ obs pprof app.ctf                             # export to pprof

Each obs run keeps a capture bundle: the timeline in .obs/<id>/trace.fxt and .obs/<id>/trace.pb, and one .obs/<id>/memtrace/<pid>.ctf for each process it observed. It points .obs/latest at the new bundle; --out BASE picks the base name instead, and the allocation traces then go to BASE.memtrace/. The text or JSON report comes from the .fxt file (scheduler, waiting, GC, fibers, contention and probe spans) and from each process's .ctf file (the top allocation sites). The .pb file is the timeline for Perfetto, and obs report does not read it.

obs hotspots ranks allocation sites by their share of the sampled bytes. --tree shows the call tree, and --baseline OLD.ctf NEW.ctf compares two runs, to check that a fix made a site smaller.

obs pprof writes the same stacks as a profile.proto profile, which go tool pprof, Perfetto, speedscope and pyroscope can open. It uses Go's heap sample types (alloc_objects/count and alloc_space/bytes), so those tools need no setup. memtrace samples each allocated word with a fixed probability r (the sampling rate, 1e-5 by default). The gaps between samples are therefore geometric, and each sample stands for 1/r words. The export scales the counts back to estimated totals: a site with s samples gets s / r x 8 bytes on a 64-bit host and, for blocks of l words, s / (r l) objects. The period field holds the mean number of bytes between two samples, 8 / r, which is 800,000 bytes at the default rate. The command only reads the trace and leaves the file on disk as it was.

obs run --sqlite BASE.db also writes the trace using the schema of Perfetto's trace_processor (process, thread, track, slice, counter, args). The file opens in sqlite3, Datasette or DuckDB, and a query written for trace_processor runs on it unchanged. obs query BASE.db lists the standard queries, and --sql runs one of your own.

obs run also samples native stacks, for up to six seconds by default (--sample SECONDS, with --sample 0 to turn it off), and saves them to BASE.cpu.xml. On Linux, perf records samples while the process is on a CPU. On macOS, the Time Profiler of xctrace, which ships with full Xcode and not with the Command Line Tools, takes a scheduled sample every millisecond. Both tools run outside the child. This matters because OCaml runs a signal handler only at a poll point (an allocation or a loop back-edge): a SIGPROF profiler inside the process would charge each sample to the next poll point and miss the instruction that was running, while perf and xctrace interrupt the process from outside and record its stack as it was. --sample-trigger PATH waits until that path exists before sampling, so the window covers the measured phase of a benchmark and misses the guest boot.

Run without a command, obs run does not spawn anything. It binds the collector socket and waits for producers to connect. A trace can arrive this way from a subprocess, from another host or from a VM guest (--vsock PORT accepts AF_VSOCK guests on Linux). It stops once every producer has been gone for --grace seconds, on SIGINT, or after --max seconds. The base observe library does not depend on Eio, and its blocking forwarder runs in a background domain. Executables with a single domain, unikernels for instance, use the Eio forwarder from observe.producer.eio.

API #

Most tools need only Observe.setup. It is built from Observe.quiet, Observe.verbosity, Observe.log, Observe.json, Observe.log_tags and Observe.log_trace, which are exported too, as are Observe.capture, Observe.reporter, Observe.Memtrace and the helpers parse_log_spec, apply_source_overrides and configure_tracing_sources. Observe_capture (library observe.capture) adds the --probe and --probe-format terms. The .mli files document each of them.

Trace formats #

A run writes four formats, and different tools read each one:

Format	Holds	Read by
`.fxt` (Fuchsia)	the timeline: scheduler, GC, spans	`obs report`, the unified model
`.pb` (Perfetto/Catapult)	the same timeline, for a UI	ui.perfetto.dev
`.ctf` (memtrace)	sampled allocation stacks	`obs hotspots`, `obs pprof`, upstream memtrace tools
`.db` (SQLite)	the timeline as relations	`obs query`, any SQLite tool

The sampled allocation stacks stay in memtrace's CTF format and are not merged into the timeline. Go keeps runtime/trace and pprof apart in the same way, and so does Rust with tracing and pprof; Perfetto itself imports heap profiles as pprof and does not turn allocation samples into timeline slices. A sample has no duration, so a timeline has no place for it, and profile viewers already read the format. Keeping CTF also means the tools of janestreet/memtrace still work, since lib/memtrace is a fork of that library.

logs.cli is the Cmdliner integration that comes with Logs, with --verbosity and -v flags. Observe adds RUST_LOG-style levels per source, JSON output, a trace log file and, for the tools that link it, probe capture.
env_logger (Rust) is where the --log syntax and the <APP>_LOG variable come from.
debug (Node.js) gives the same control per namespace in JavaScript.

Licence #

ISC. See LICENSE.md. The memtrace fork in lib/memtrace keeps its upstream MIT licence, in lib/memtrace/LICENSE.md.

Clone this repository

ocaml-observe #