Hardware counters

Why counters

Wall-clock time is what everyone measures and it is the least repeatable thing a computer does. Here is the same function, in the same binary, on the same idle machine, five consecutive runs — instructions retired against self time:

The instruction count is identical every time. The wall time varies five-fold, because run 3 met the scheduler. A CI gate on the second column has to be set so loose it catches nothing; a gate on the first can be set at 1%.

That is the whole case for this feature. Everything below exists to keep that column trustworthy.

Quick start

Three lines in trace.config:

counter instructions
counter-func handle_request 1
counter-min auto

$ callsight run -- ./bin/app.instr

run resolves those names against the binary you just built, writes the address map the runtime reads, and reports:

== HARDWARE COUNTERS (instructions) ==
     calls   instructions/call  function
       200             4,471.3  handle_request
      1600               223.0  parse_headers

Choosing what to count

Four directives, deliberately shaped like the instrumentation ones next to them.

Events: instructions, cycles, cache-references, cache-misses, branch-instructions, branch-misses, bus-cycles, stalled-cycles-frontend, stalled-cycles-backend, ref-cycles, or a raw PMU code as rNNNN.

Only instrumented functions can be counted. A function excluded at compile time emits no hooks at all, so there is nowhere to read a counter. Naming one is reported rather than silently ignored:

warning: 1 selected function(s) carry no instrumentation hooks, so they
cannot be counted — widen the include/exclude rules first: crc32_update

Names, addresses, and no rebuild

The hooks are handed a function's address; your config names functions. callsight bridges that by reading the built binary's symbol table and writing a small text map that the runtime loads at startup:

CALLSIGHT-COUNTERS 1
build-id 3f2ae1c9...
min auto
event instructions 0 1
0000000000401b40 checksum
0000000000401c90 transform

Three things follow. static functions work, because they are in .symtab like anything else — and they are usually the internals worth counting. Changing which functions are counted needs no rebuild: rewrite the map and run again. And because it is text with hex addresses, it is the same file for a 32-bit big-endian board as for x86-64.

What a read costs

This is the number that decides what is worth counting, and it varies enormously.

Two reads per counted call, so on a device where a read is microseconds, counting a 200 ns leaf function measures the instrument and nothing else. That is not a reason to avoid counters on ARM — it is a reason to point them at the right functions, which is what the next section automates.

All events open as one group, so a single read returns every value. Where reads are syscalls — aarch64, and every 32-bit target — three events therefore cost the same as one.

The guard rail

The runtime measures its own read cost at startup, then declines to count any function whose observed duration stays below about twenty times what its reads cost. It gathers 64 samples before deciding, so nothing is demoted on a cold first call, and it reports every demotion by name:

! 2 selected function(s) were skipped as too short to measure — at ~8683 ns
  per counter read, counting them would report the instrument rather than
  the code (counter-min overrides this)

On a real device that looks like this — the short functions stop being counted after their 64 samples, the long one keeps going for every call:

probe_leaf   24000 calls  p50=  416ns   counted on 64/24000 calls
probe_mid     3000 calls  p50=10781ns   counted on 64/3000 calls
probe_top        1 calls  p50=37546614ns  counted on 1/1 calls

Set counter-min 0 if you would rather have the numbers anyway, and the Config Builder shows each function's median duration next to it so the choice is informed before the run rather than after.

Refusing to guess

perf_event_open succeeding proves nothing. Inside a container the host PMU is usually not exposed, and the kernel hands back a counter that opens, reads, and returns zero forever. A naive implementation reports zero instructions for every function and looks perfectly healthy doing it.

So the runtime runs a loop of known size at startup and checks that the counter actually moved and that time_running is not zero. If it did not, counters are switched off for the run, once, out loud:

callsight: hardware counters are not usable here (the event opens but never
reaches hardware — typical in a container); continuing without them

The report that follows is entirely ordinary: no counter columns at all, rather than columns full of zeros. Three further checks back it up — whether the PMU was time-slicing mid-run, whether any counted function totalled zero across a whole capture (real work does not), and whether the address map belongs to a different build.

A regression gate

Counter metrics are diff keys, which is where the repeatability pays off:

$ callsight run --format json --out before.json -- ./bin/app.instr
$ # ... change something ...
$ callsight run --format json --out after.json -- ./bin/app.instr
$ callsight diff before.json after.json \
      --key instructions_per_call --fail-over 1

Available keys are <event> (total), <event>_per_call and <event>_self. On the two runs used in the table at the top of this page, self_ms reports a 40% regression that is pure scheduling noise while instructions_per_call reports the real 1.2% change.

Reading the numbers

A counted value is the function's own work plus a small constant: the instrumentation between the two readings. The runtime reads as late as it can on entry and as early as it can on exit, and subtracts what it can measure of its own footprint, but the exit hook's prologue runs before the reading can be taken and cannot be removed.

That constant is the same for every call of every function in a given build, so:

• Comparing builds is exact — the constant cancels. This is the use case the feature is for.
• Comparing against a non-instrumented run is not. An instrumented binary is a profiling build, and its counts include the profiling.
• Inclusive counts contain counted callees, self counts do not — the same relationship the timing columns have.

Counted functions also pay two reads' worth of wall time per call, which is included in their times. --subtract-overhead removes it, and the report says so either way.