Capture

Capture limits

A profiler that can fill the machine it is profiling is not a profiling tool. Every mode below has a bound, the bounds have defaults, and when one is reached the report says so instead of quietly ending early.

The problem with unbounded tracing

Event tracing writes 32 bytes per function entry and 32 per exit. A call-heavy program reaches millions of events per second, so a few seconds of tracing is hundreds of megabytes and a few minutes is more disk than most embedded targets have at all. Left unbounded that is not a slow leak — it is a device that stops working, in the middle of the investigation you were running.

So capture is bounded by default. You can turn the bound off, but you have to say so.

VariableDefaultMeaning
TRACE_MAX_MB512Total on-disk budget for the process. 0 means unlimited
TRACE_FULLstopWhat happens at the budget: stop keeps the beginning, wrap keeps the end
TRACE_SEG_MB32Segment size, which is the rotation granularity. Under wrap this is an upper bound — see below
TRACE_MIN_FREE_MB64Stop if the filesystem falls below this much free space. 0 disables the check
TRACE_MAX0Global event cap, as an upper bound

Keep the start, or keep the end

The two policies answer different questions.

stop (the default) records until the budget is gone and then stops. Use it when the interesting behaviour is at the beginning — startup cost, initialization order, the first request.

TRACE_ENABLE=1 TRACE_MAX_MB=256 ./bin/app.instr

wrap turns the trace directory into a flight recorder: old segments are discarded as new ones are written, so what survives is the most recent TRACE_MAX_MB of execution. Use it for the question instrumentation answers better than anything else — what was this program doing in the moments before it hung?

TRACE_ENABLE=1 TRACE_MAX_MB=256 TRACE_FULL=wrap ./bin/app.instr
# ... reproduce the hang, then kill it and analyze what is left
Wrap discards enter events whose exits are still to come, so the report will show unmatched exits. That is expected, not corruption, and callsight analyze labels it that way rather than leaving you to wonder.

Segments

Each thread writes trace.<pid>.<tid>.<seq>.bin, rotating to a new sequence number every TRACE_SEG_MB. Segments are what make rotation possible at all — wrap works by unlinking a whole segment — and they keep any single file small enough to copy off a device.

Under wrap, TRACE_SEG_MB is an upper bound rather than the size actually used. A thread can never discard the segment it is currently writing, so the steady state holds up to two segments per thread; with a couple of dozen threads a fixed 32 MB segment would overshoot a small budget by an order of magnitude. The runtime therefore sizes segments against the budget and the number of participating threads. A floor of 64 KB per segment remains, so a very small budget spread over many threads still cannot be honoured exactly — roughly threads × 128 KB is the practical minimum.

Files are never appended to. The kernel recycles thread ids, so a long-running pool eventually hands a new thread an id that an earlier one used; appending there would put a second file header in the middle of an existing capture and shift every later record off the 32-byte grid. The sequence number makes that unrepresentable.

Budget accounting happens once per flush — every 8192 events — not once per event. A shared counter touched by every thread on every hook would serialize the whole program on one cache line exactly when tracing is heaviest.

Summary mode: runs of any length

If what you want is which functions cost the most rather than a timeline, you do not need the events at all. TRACE_MODE=summary aggregates inside the process — call counts, inclusive and self time, min, max and a latency histogram per function, over a per-thread shadow stack — and writes only totals when the thread exits.

TRACE_ENABLE=1 TRACE_MODE=summary ./bin/app.instr

Memory is proportional to the number of instrumented functions, not to the number of calls, and so is the output. On the project's own benchmark, a run that writes 244 MB of events in the default mode writes 2.8 KB in summary mode — and writes the same 2.8 KB when the run is ten times longer:

$ python3 tests/bench/run_bench.py
mode                                   total  vs plain   ns/hook   on disk
plain build (no hooks)                  0.9ms      1.00         -         -
instrumented, tracing off               5.9ms      6.73       0.6         -
TRACE_CLOCK=tsc (default here)         97.1ms    111.70      12.0   244.1MB
TRACE_CLOCK=mono                      130.6ms    150.22      16.2   244.1MB
TRACE_MODE=summary                     65.1ms     74.84       8.0     2.8KB

summary mode on disk: 2.8KB for 200,000 iterations, 2.8KB for 2,000,000 — constant

Summary mode is also the cheaper hot path: there is no event record to write and no I/O to do. What you give up is anything that needs an ordering — flame graphs, the Perfetto timeline, and hot call sites all need the call paths that only event mode records.

events (default)summarystreaming
On-disk growthbounded by TRACE_MAX_MBconstantnone on the device
Run lengthuntil the budgetunboundedunbounded
Counts & timesexactexactexact, minus ring drops
Percentilesyesyesyes
Flame graph / timelineyesnoyes
Needsdisknothinga network path to a server

The free-space floor

The budget bounds what callsight writes; the floor bounds what it leaves behind for everyone else. Every 4 MB per thread the runtime checks the filesystem holding the trace directory and stops if free space has fallen below TRACE_MIN_FREE_MB. The check is a statvfs syscall roughly once per 130,000 events, which is not measurable next to the events themselves.

Write failures are checked too. If a write fails part way — a full disk, a quota, a size limit — the partial record is trimmed off so the file stays well-formed, the capture stops, and the reason goes to stderr and into the trace. The old behaviour was to ignore the return value, which produced a report that looked clean and was simply missing everything after the failure.

Nothing ends silently

Whenever capture ends for a reason other than the program finishing, the runtime writes a marker into the trace itself, and callsight analyze prints it above the tables:

events=850059 threads=24 functions=84 span=6.6ms unmatched_exits=0 unclosed_enters=127
! capture stopped: the 512 MB on-disk budget was reached (TRACE_MAX_MB); everything
  after that point is missing
MarkerMeans
budgetTRACE_MAX_MB was reached under the stop policy
wrapSegments were discarded; the report covers the end of the run
nospaceFree space fell below TRACE_MIN_FREE_MB
write_errorA write failed; the payload is the errno
max_eventsThe TRACE_MAX event cap was reached
truncatedA segment ends mid-record: the process was killed, or a write failed part way

Markers are ordinary 32-byte records with their own event kind, so they cost nothing to carry and any reader that does not understand one skips it. They travel over the streaming protocol as well.

The server side

The same reasoning applies to the analysis host. callsight serve bounds and rotates its output per connection, because a device that streams for an hour should not fill the machine you are analyzing on either.

callsight serve --max-mb 4096 --seg-mb 256

Choosing a bound