Skip to content

Classify off-CPU intervals by switch-out reason and add a stack profile - #2

Merged
lhotari merged 2 commits into
mainfrom
offcpu-reason-classification
Sep 23, 2026
Merged

lhotari merged 2 commits into
mainfrom
offcpu-reason-classification

Conversation

@lhotari

@lhotari lhotari commented Sep 22, 2026 •

Copy link
Copy Markdown
Collaborator

Why

jonoffcpu attributes every off-CPU interval to the stack where the thread was switched out, without saying whether the thread could not run or could run but had no CPU. A Netty event loop preempted inside Unsafe.getObjectVolatile then looks the same as a thread parked on a lock. This PR records why each interval began and records only blocked intervals by default. It also adds a stack profile from which any slice (reason, stack kind, weighting) can be rendered again without re-correlating.

What changes

Kernel and capture

  • The switch-out hook moves from the classic tp/sched/sched_switch to the raw tp_btf/sched_switch. It reads the scheduler's own preempt flag and the prev_state captured before the switch. Re-reading prev->__state would race with wakeups, and the trace event encodes preemption as a magic value that has changed across kernel versions. On kernels without the four-argument prototype (Linux 5.18) the verifier rejects the program and the load fails closed.
  • Each interval is classified blocked, runnable or preempted. The per-thread state gains the reason and the raw task state, and the filter runs at switch-in. Filtering at switch-out would leave a stale start time behind after an is_switch == false exit.
  • New sampling.reasons option, default [blocked], applied before the duration bounds and admission. The kernel counts every switch-out by reason before filtering (switchOutsBlocked/Runnable/Preempted), so a blocked-only capture still shows how often its threads were denied the CPU. Rejected intervals are counted with their duration.
  • Observations gain reason, prev_task_state and preempted (proto fields 18–20; 21 is reserved for the future wakeup split). The control schema moves to version 3. The correlator still reads version 2 captures, whose intervals read back as unspecified.
  • The agent and the correlator recompute each row's reason from the raw arguments and reject a row that disagrees or was not selected, just as they recompute admissionThreshold.

Correlator

  • jonoffcpu-offcpu-stacks.collapsed still contains every recorded interval. When a capture mixes reasons, each line starts with [offcpu: <reason>] and a jonoffcpu-offcpu-stacks-<reason>.collapsed file is written per reason. Single-reason and version 2 captures are written exactly as before. --collapsed-reason-frame auto|always|never overrides this.
  • New jonoffcpu-offcpu-profile.pb, defined by docs/schema/jonoffcpu-profile.proto: a string pool, a prefix-shared stack-node tree, and one entry per Java stack × reason/task state × kernel stack × user stack × thread. Each entry carries the interval count, observed nanoseconds, and an inverse-probability estimate. It is written in a canonical order, so the same analysis gives the same bytes.
    • --profile-group-by and --max-profile-entries control the grouping. Past the entry limit, the thread, user and kernel dimensions are dropped in that order; this merges entries, changes no total, and is reported.
  • New subcommands:
    • stacks: renders a slice. --reason, --stack java|kernel|user|java+kernel|java+user+kernel, --weights observed|estimated, --summary. Rendering with the defaults reproduces the collapsed file byte for byte. Native frames drop their +0x offsets, and a kernel stack stops before the profiler's own tracing frames.
    • merge: sums profiles and keeps each input's provenance. It refuses thinned profiles and different groupings.
    • export --format csv|jsonl: one row per entry, for DuckDB and similar tools.
  • stacks --include REGEX / --exclude REGEX (each repeatable) filter whole profile entries before they are merged into lines. Every stack the profile holds is matched, even ones --stack doesn't render, so --stack java --exclude 'io\.netty\.channel\.epoll\.Native\.epollWait0' or --exclude 'ep_poll_\[k\]' drops those intervals completely. jfr-converter -X on a rendered file can't do this. An exclusion wins over an inclusion. --summary records the patterns, the stacks searched, and a filtered total that adds up exactly with the kept total to the unfiltered slice.
  • The report gains offCpuReasons (selected reasons, matched intervals and nanoseconds per reason, kernel switch-out counts, rejections) and stackProfile.

Docs: README (new "Why the thread left the CPU" section and a "Slice and filter with the stack profile" step), OFFLINE.md, AGENTS.md contracts, and the module READMEs. Both d2 diagrams are updated and re-rendered.

A finding worth knowing

A user-space thread preempted by the scheduler tick is switched out on its return to user mode, at an ordinary schedule() where preempt is false and its state is TASK_RUNNING. So ordinary preemption of running Java code is classified runnable, and preempted covers only preemption inside the kernel. On a 16-CPU 7.1.5 host, oversubscribed spinners came back 2,861 runnable against 2 preempted. The docs say to read the two together as time waiting for a CPU.

Verification

  • ./gradlew spotlessCheck :jonoffcpu-agent:check :jonoffcpu-correlator:check passes. The new StackProfileTest covers:
    • default rendering reproducing the collapsed file byte for byte, unthinned and thinned;
    • canonical re-writes, merge doubling every counter, export, and dimension dropping;
    • rejection of damaged and foreign profile files;
    • mixed-reason frames and per-reason files;
    • rejection of rows with a mismatched or unselected reason, and of inconsistent version 2/3 schemas.
  • Native: cargo fmt --check and the unit tests pass.
  • Privileged kernel proofs pass on 7.1.5: the new run-offcpu-reason-proof.sh, run-sched-exit-proof.sh, collector smoke, sequence boundary, target exit, and the T07/T08 task-lifetime gate.
  • run-packaged-agent-smoke.py --libc musl passes on x86-64 with new assertions:
    • resolved reasons: ["blocked"];
    • every matched interval accounted for as blocked;
    • kernel blocked switch-outs counted;
    • the profile rendering back to the collapsed file.
  • The smoke also passes without the tracefs mount, both privileged and with --cap-add BPF --cap-add PERFMON --cap-add SYSLOG. The README's tracefs guidance for Docker Desktop is kept because that environment is unverified.
  • On the real 110 MB Apache Pulsar broker capture (version 2), compared with the pre-change build:
    • the collapsed output is byte-identical;
    • the profile is 913 KB with 12,914 entries, against a 6.3 MB collapsed file;
    • rendering a slice takes 0.33 s, against 67 s to correlate;
    • peak retention goes from 203 to 226 MiB.

Compatibility

  • Default change: captures now record only blocked intervals. sampling.reasons: [blocked, runnable, preempted] restores the old selection.
  • A 0.2.0 correlator refuses version 3 captures with a schema-version error rather than producing wrong numbers.
  • Ring-buffer records grow from 120 to 128 bytes, and the correlator's source column slot from 38 to 51 bytes. The ladder fixtures' tuned budgets were raised to match.

Not covered

  • run-known-wait-attribution.py was extended to record every reason and require the known waits to be blocked, but not run, because it depends on the legacy make-based agent build.
  • Lifetime gates T09 and T14 fail both before and after this change, for reasons unrelated to it. T09 expects an empty file after a prepare fault and finds the 12-byte capture header. T14 reads the binary capture with read_to_string. Neither runs in CI.
  • The sched_wakeup split into sleeping and run-queue time is designed in (reserved proto and profile fields) but not implemented.

Record why the scheduler took each thread off the CPU, record only blocked
intervals by default, and write a deduplicated stack profile from which any
collapsed-stack slice can be rendered without re-correlating.

Kernel and capture:
- The switch-out hook is now the raw tp_btf/sched_switch. It reads the
  scheduler's own preempt flag and the pre-switch prev_state, and classifies
  the interval as blocked, runnable or preempted. The load fails closed on
  kernels without the four-argument prototype (Linux 5.18).
- sampling.reasons selects the reasons to record, default [blocked]. The
  filter runs at switch-in, before the duration bounds and admission, and the
  kernel counts every switch-out by reason before filtering.
- Observations carry reason, prev_task_state and preempted. The capture
  control schema moves to version 3; the correlator still reads version 2.
- The agent and the correlator recompute each row's reason and reject one that
  disagrees or was not selected, as they do the admission threshold.

Correlator:
- jonoffcpu-offcpu-stacks.collapsed keeps every interval. When a capture mixes
  reasons, each line starts with an [offcpu: <reason>] frame and a file per
  reason is written.
- New jonoffcpu-offcpu-profile.pb, defined by
  docs/schema/jonoffcpu-profile.proto: a string pool, a prefix-shared stack
  tree, and counters per Java stack, reason, kernel stack, user stack and
  thread. The stacks, merge and export subcommands render slices, sum
  profiles and write CSV/JSONL for tools such as DuckDB. A default rendering
  reproduces the collapsed file byte for byte.
- The report gains offCpuReasons and stackProfile.

A user-space thread preempted by the scheduler tick is switched out on its
return to user mode, where preempt is false, so it is classified runnable;
preempted is preemption inside the kernel. The new reason proof measured 2,861
runnable against 2 preempted for oversubscribed spinners, and the docs say to
read the two together as time waiting for a CPU.
Filtering a rendered collapsed file with jfr-converter -I/-X cannot drop
every interval parked in io.netty.channel.epoll.Native.epollWait0: a
Java-only line no longer carries the kernel frames a pattern would need,
and once entries are merged into lines their counters cannot be split.

stacks now takes --include REGEX and --exclude REGEX, each repeatable.
They keep or drop whole profile entries before lines are merged and before
--reason-frame auto decides whether the slice mixes reasons. Every stack
the profile is grouped by is matched, whichever --stack renders, in the
text a collapsed line would carry; an exclusion wins, as in the converter.
The summary records the patterns, the stacks searched and the intervals
and nanoseconds removed, which add up to the unfiltered slice exactly,
thinning included.

On the Pulsar broker capture, excluding epollWait0 removes 847,474 of
1,121,418 intervals in 0.75 s.
@lhotari
lhotari merged commit 2129eaa into main Sep 23, 2026
5 checks passed
@lhotari
lhotari deleted the offcpu-reason-classification branch September 24, 2026 13:12
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant