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.

OCaml 94.8%
Perl 2.2%
Dune 0.3%
Shell 0.1%
Other 2.6%
137 1 0

Clone this repository

https://git.vm.fail/gazagnaire.org/ocaml-observe https://git.vm.fail/did:plc:nki7fzh75qm3w3houi7bj3qz
ssh://git@git.recoil.org:2222/gazagnaire.org/ocaml-observe ssh://git@git.recoil.org:2222/did:plc:nki7fzh75qm3w3houi7bj3qz

For self-hosted knots, clone URLs may differ based on your setup.


README.md

ocaml-observe#

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

Overview#

ocaml-observe is an observability toolkit. The Observe library provides Cmdliner terms for the logging controls most OCaml command-line tools need -- log verbosity, per-source filtering, JSON output, and *.tracing log-source files -- and honors MEMTRACE for allocation capture. The obs command is the heavier workflow: it captures a program's runtime_events scheduler/GC trace, memtrace allocations, and ocaml-probe spans, reports a wall-clock budget and verdict, and drills the dominant cost (allocation hotspots, CPU sampling, a queryable Perfetto-schema database). There is one capture path: any program built with Observe.setup forwards its trace over OBS_COLLECTOR, so obs run collects the same way whether it spawned the program, or a subprocess or VM guest streamed in. Runtime probe capture lives in the separate observe.capture library for tools that opt in.

Features#

  • Verbosity flags: -q, -v, -vv, -vvv
  • RUST_LOG-style configuration: --log=level,src:level,...
  • JSON output: --json for structured logging
  • Tracing log sources: --trace FILE to capture *.tracing log sources
  • Memory tracing API: Observe.Memtrace for MEMTRACE allocation captures
  • Optional probe capture API: Observe_capture in observe.capture
  • Trace analysis CLI: obs run (spawn or listen), obs report, obs hotspots, obs query
  • Queryable trace database: --sqlite writes Perfetto's trace_processor schema; obs query runs canonical and ad-hoc SQL over it
  • Native stack profiling: obs run drives sample/perf by default; --sample SECONDS changes the window and --sample 0 disables it
  • Environment variable: <APP>_LOG (e.g., MYAPP_LOG)

Installation#

Install with opam:

$ opam install ocaml-observe

If opam cannot find the package, it may not yet be released in the public opam-repository. Add the overlay repository, then install it:

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

Usage#

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)

Command Line#

$ myapp -q                            # errors only
$ myapp                               # warnings (default)
$ myapp -v                            # info level
$ myapp -vv                           # debug level
$ myapp -vvv                          # debug + *.tracing log sources

$ myapp --log=debug                   # set level via flag
$ myapp --log=info,http:debug         # global info, http at debug
$ myapp --log=warn,tls.tracing:debug  # enable specific tracing

$ MYAPP_LOG=debug myapp               # set level via env var

$ myapp --json                        # JSON output
$ myapp --trace protocol.log          # write *.tracing log-source output

Verbosity Levels#

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

The -vv flag gives you application-level debug output without noisy *.tracing sources. Use -vvv or --trace FILE when you need full protocol log traces.

JSON Output#

With --json, use the optional json_reporter parameter to enable JSON log output:

open Cmdliner

let run () = `Ok ()

let json_reporter ~app:_ ~base:_ () = Logs.nop_reporter

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

Requires the json-logs package.

Probe Capture#

Libraries that emit ocaml-probe events can be captured by tools that compose the probe term explicitly:

open Cmdliner

let run _setup probe =
  let close = Option.map Observe_capture.probe_capture_config probe in
  Fun.protect
    ~finally:(fun () -> Option.iter (fun close -> close ()) close)
    (fun () ->
      (* application code that emits Probe events *)
      ())

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

Link that executable with observe.capture. This keeps the default Observe.setup term suitable for the common logging-only CLI case while still allowing rare in-process capture use cases.

Memory Tracing#

Cmdliner programs using Observe.setup automatically honor MEMTRACE, without adding a tool-local memtrace flag:

open Cmdliner

let run _setup =
  let payload = Array.init 1024 string_of_int in
  Printf.printf "processed %d items\n%!" (Array.length payload)

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

Observe.setup starts tracing from MEMTRACE without exposing any memtrace flags on the application CLI, which is how obs run -- myapp asks the child to write a per-process .ctf in the run bundle. Non-Cmdliner entrypoints can call Observe.Memtrace.trace_if_requested () directly at startup. When MEMTRACE contains %p, the placeholder expands to the process id and remains inherited by spawned OCaml children, so obs run can capture a process tree without every child opening the same trace file.

obs CLI#

The installed obs command is the analysis front door:

$ obs run -- ./bench.exe
$ obs report
$ obs report latest
$ obs report 550e8400-e29b-41d4-a716-446655440000
$ obs hotspots .obs/latest/memtrace/<pid>.ctf

obs run always keeps a capture bundle. By default it writes .obs/<id>/trace.fxt, .obs/<id>/trace.pb, and .obs/<id>/memtrace/<pid>.ctf for each observed process that supports Observe.Memtrace, then updates .obs/latest. --out BASE chooses an explicit basename and writes BASE.fxt, BASE.pb, and BASE.memtrace/<pid>.ctf. obs report loads .obs/latest by default, obs report <id> loads .obs/<id>/trace.* plus its memtrace directory, and obs report BASE loads BASE.fxt plus BASE.memtrace/*.ctf. obs run prints the run UUID and replay command on stderr before the child starts.

The obs text/JSON report is built from .fxt plus the per-process .ctf files: scheduler, waiting, GC, fibers, contention, and probe spans come from .fxt; allocation top sites come from .ctf. The .pb file is the Catapult/Perfetto timeline sidecar for visual inspection or catapult summary; obs report does not read it.

obs hotspots ranks allocation sites by share of sampled bytes. --tree renders the allocation call-tree instead of a flat list, and --baseline OLD.ctf NEW.ctf diffs two runs to confirm a fix shrank a site.

Queryable SQLite database#

obs run --sqlite BASE.db also writes the trace to a SQLite database in Perfetto's trace_processor schema: process, thread, track/thread_track/counter_track, slice (begin/end paired into ts+dur, with GC, Eio, and ocaml-probe spans each on their own track so they nest independently), counter, and args. It is a plain SQLite file in a standard schema, so it opens in sqlite3, Datasette, DuckDB, or any SQLite tool, and the same SQL you would write against Perfetto's trace_processor works here. obs query ships a small library of canonical queries over it:

$ obs query BASE.db                 # list the canonical queries
$ obs query BASE.db operations      # application spans by name, by total time
$ obs query BASE.db gc              # GC phases
$ obs query BASE.db --sql 'SELECT name, dur FROM slice ORDER BY dur DESC'

For the Perfetto timeline UI, load the bundle's .pb into https://ui.perfetto.dev instead.

Native stack profiling#

obs run records up to six seconds of native stack samples by default. --sample SECONDS changes the window and --sample 0 disables it. Linux perf records scheduled, on-CPU samples. macOS sample(1) snapshots all threads every 10 ms, including blocked ones, so its percentages describe leaf-stack residence rather than CPU time. The 10 ms interval still yields 600 snapshots per thread in the default window without the severe repeated-suspend overhead of sample(1)'s 1 ms default on many-threaded targets. Both run outside the child and avoid the GC-poll-point bias of an in-process SIGPROF handler.

For a long-lived launcher whose measured work begins after startup, pass --sample-trigger PATH. obs run waits for that path to exist before starting its one sampling window, while continuing to collect runtime events and allocations from process startup. For example, a VM benchmark can create the trigger immediately before starting iperf; the six-second default then covers the transfer instead of firmware and guest boot.

$ obs run -- ./bench.exe
...
== NATIVE STACK PROFILE ==
3207 thread-stack snapshots via sample(1); top leaf functions (blocked threads included):
  100.0%  3207     camlMylib__hot_loop

The raw profile is saved to BASE.sample.txt; the top leaf functions print after the report (text mode only, so --json stdout stays a clean document).

Listening for producers#

obs run with no command listens instead of spawning: it binds the collector socket and waits for producers to stream in. Any program built with Observe.setup becomes a producer when OBS_COLLECTOR is set in its environment -- it forwards its runtime_events, ocaml-probe spans, and memtrace allocations over the producer/collector protocol (observe.protocol). This is how a trace reaches obs from a subprocess, another host, or a VM guest; obs spawning a command is just the case where it sets OBS_COLLECTOR itself.

$ obs run --out run &                   # bind a socket, wait for producers
$ OBS_COLLECTOR=unix:run.sock ./app.exe
$ # the report prints when collection ends

--vsock PORT also accepts VM guests over AF_VSOCK (OBS_COLLECTOR=vsock:2:PORT, CID 2 is the host) on Linux. Listening ends when every producer has disconnected and stayed gone for --grace seconds, on SIGINT, or after --max seconds. The base observe logging library stays Eio-free; the blocking forwarder runs on a background Domain, and the Eio-native variant (for single-domain programs such as unikernels) lives in observe.producer.eio.

API#

  • Observe.setup - Main logging cmdliner term
  • Observe.reporter - Logs reporter writing to stderr (keeps --json stdout clean)
  • Observe.quiet - Term for -q/--quiet
  • Observe.verbosity - Term for -v/--verbose
  • Observe.log - Term for --log with env var
  • Observe.json - Term for --json
  • Observe.trace_file - Term for --trace FILE
  • Observe_eio.setup - Observe.setup plus the fiber-local probe context (observe.eio)
  • Observe.Memtrace - Memory allocation capture API (Observe.setup honors MEMTRACE; analysis is in obs)
  • Observe_capture.probe_file - Term for --probe FILE (observe.capture)
  • Observe_capture.probe_format - Term for --probe-format FORMAT (observe.capture)
  • Observe_capture.probe_config - Combined optional probe capture term (observe.capture)
  • Observe_capture.probe_capture_config - Start capture from an explicit probe config (observe.capture)
  • Observe.parse_log_spec - Parse RUST_LOG-style spec
  • Observe.apply_source_overrides - Apply per-source levels
  • Observe.configure_tracing_sources - Enable/disable *.tracing sources
  • logs.cli - Basic Cmdliner integration in the Logs library. Provides --verbosity and -v flags. ocaml-observe extends this with RUST_LOG-style per-source control, JSON output, trace-log output, and opt-in runtime probe capture.
  • env_logger (Rust) - The inspiration for the --log flag syntax and <APP>_LOG environment variable pattern.
  • debug (Node.js) - Popular namespace-based debug logging. Similar concept of per-source control.

Licence#

MIT License. See LICENSE.md for details.