Skip to content

DLPX-94668 a signal that stops stbtrace can interrupt its probe detach - #136

Merged
prakashsurya merged 1 commit into
developfrom
projects/dlpx-94668-fix
Oct 31, 2026
Merged

prakashsurya merged 1 commit into
developfrom
projects/dlpx-94668-fix

Conversation

@delphix-devops-bot

Copy link
Copy Markdown
Contributor

Jira: DLPX-94668 stbtrace tests fail on stderr from a command that exited 0

Problem

A few percent of the time, stbtrace writes a Python traceback to stderr
after a trace that worked. The command exits 0 with a complete set of JSON
datapoints and leaves no probe attached, but stderr carries ten lines of an
interrupted BCC cleanup:

Exception ignored in atexit callback: <bound method BPF.cleanup of <bcc.BPF object at 0x74eb70f1a150>>
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/bcc/__init__.py", line 1853, in cleanup
    self.detach_kprobe_event(k)
  ...
KeyboardInterrupt:

BCC detaches the probes from an atexit callback, so the detach runs once the
interpreter has started shutting down and with signal delivery still enabled.
The signal that stops the trace can land inside it, which aborts the detach
and prints the traceback.

That makes the os_tests test_stbtrace_* tests flaky: they stop the command
with timeout --preserve-status --signal=SIGINT and fail on any stderr from a
command that exited 0. On an image carrying
performance-diagnostics@1c2cf9a,
which fixed the kernel 7.0 compile break, all four subcommands fail this way
at about 4% a run.

Solution

Ignore SIGINT as soon as the first one is taken, so bcc's detach always runs
to completion. The detach stays where bcc puts it; only the window in which a
signal can interrupt it closes. BCCHelper's SIGTERM handler exits the same
way and is exposed the same way, so it disarms SIGTERM for the same reason.

Each handler disarms only the signal it handles. Disarming both would make
stbtrace and every estat script unstoppable by SIGTERM for the duration
of a detach, which nothing here needs.

The except KeyboardInterrupt that used to be the stop path goes with it:
once SIGINT has a handler of its own no KeyboardInterrupt is raised, and a
second, dead stop path only obscures which one runs. The templates keep theirs
— a template run directly, or generated with stbtrace --bcc, still gets the
default handler.

The alternative was to detach explicitly before exiting rather than leaving it
to the atexit callback. cmd/stbtrace.py has no reference to the BPF object
— the templates construct it inside the code exec'd from the template — and
bcc's own callback would still run afterwards, so that is a larger change for
the same effect.

The harness side of this is a companion PR, the dlpx-qa-gate branch projects/dlpx-94668-fix. Either change
alone turns the four tests green; both are worth having, because the harness
change also covers the compiler warnings this one does not, and this one
removes a traceback that should not be printed whether or not a test reads it.

Testing Done

Test Before the fix After the fix
stbtrace vfs stopped as the test stops it, with the interrupt forced into the detach writes the traceback 15 of 15 0 of 15
stbtrace vfs stopped as the test stops it, left to race writes the traceback 5 of 70 0 of 70

Every run on the fix exited 0 with 27-43 JSON datapoints and zero bytes on
stderr, so no other signature replaced the one that went away. A third run,
30 per arm with the arms in the opposite order, saw the race on neither side
and so discriminates nothing; it is below for completeness.

PASSED, as expected · fix · forced-interrupt control on dlpx-94668-fix-repro · local 2026-10-28T19:13Z · base 15/15 traceback, fix 0/15

Waiting for the race gives a weak comparison at a 4%-7% rate, so the control
makes it deterministic: send SIGINT to the stbtrace process in a tight
loop for eight seconds from just before the trace is due to stop, so one
always lands during the detach.

  • Script: evidence/forced-race.sh, results in evidence/forced-race-results.txt
  • Engine: dlpx-94668-fix-repro, DCoA group dlpx-qa-develop, AMI ami-0bcab2c271642a6c0 (appliance-build develop post-push 4880), kernel 7.0.0-1014-dx2026100516-af96b8512-aws, performance-diagnostics 1.0.0-1delphix.2026.10.27.14.13, bpfcc 0.36.1-1+delphix.2026.06.22.15.45
  • Arms: cmd/stbtrace.py and lib/bcchelper.py copied onto the engine from develop or from this branch, with the installed file's md5 checked against the staged one before each arm
  • Command under test: sudo -- timeout --preserve-status --signal=SIGINT --kill-after 30 15 stbtrace vfs
  • Result: base 15/15 runs wrote the traceback; fix 0/15, every run 0 bytes on stderr. Fisher exact one-sided p = 6.5e-09
PASSED, as expected · fix · interleaved A/B, 70 runs per arm, on dlpx-94668-fix-repro · local 2026-10-28T18:15Z · base 5/70 traceback, fix 0/70

The rate as the tests see it, with no forcing. Arms alternate run by run so
both see the same engine and the same load.

  • Script: evidence/ab-harness.py, results in evidence/ab-vfs-interleaved.txt
  • Same engine and command as above
  • Result: base traceback 5/70; fix traceback 0/70, and 0 bytes of stderr on all 70. Fisher exact one-sided p = 0.029
  • The fix arm here ran cmd/stbtrace.py at the revision before review, which also disarmed SIGTERM. SIGTERM is never sent by this command, so the behaviour measured is the behaviour of this branch; the forced-interrupt control above and the reversed-arm run below both ran this branch's head.
PASSED, no occurrences either side · fix · interleaved A/B, arms reversed, 30 runs per arm · local 2026-10-28T19:29Z · base 0/30 traceback, fix 0/30

The 70-run A/B always ran the base arm first within a pair, so this one runs
the fix arm first and logs the md5 of the installed stbtrace on every row.
At the measured 5-7% rate, 30 runs miss the race about one time in nine, and
that is what happened: 0/30 on both arms. It rules out a mis-staged build
on the fix arm and leaves the ordering question answered only by the forced
control above, which is deterministic and therefore order-independent.

  • Results in evidence/ab-vfs-reversed.txt; both arms ran this branch's head
  • Result: base traceback 0/30, fix traceback 0/30; every fix-arm run 0 bytes on stderr
PASSED · fix · how many interrupts the command actually gets · local 2026-10-28T19:26Z

strace on the stbtrace process through one unforced run: exactly one
SIGINT, from timeout, followed by its SIGCONT. So the unforced case is
not a second signal from sudo or the process group, and why one delivery can
surface inside the atexit callback is not established here. The fix does not
depend on knowing: it closes the window for any delivery, and the finally
disarms the interrupt before shutdown begins so a delivery already pending is
taken there rather than inside the detach.

  • Script: evidence/count-sigint.sh, results in evidence/sigint-count.txt
PASSED, as expected · fix · flake8 . and flake8_stbtrace.sh · local 2026-10-28T19:21Z

The repo's PR CI (.github/workflows/flake8.yml), run locally:

flake8 . --show-source --statistics        # clean
./.github/scripts/flake8_stbtrace.sh       # clean, all six templates

Notes to Reviewers

evidence/ above is this run's archived artifacts, not files in the repo.

Only vfs was measured on an engine. The signal handling is in
cmd/stbtrace.py, which every subcommand goes through, and the six templates
are identical in the code the fix touches; the subcommands differ only in how
many probes the detach has to walk.

stbtrace runs until it is signalled, and bcc detaches the probes from an
atexit callback. That callback runs once the interpreter has started
shutting down and with signal delivery still enabled, so a signal can
land inside the detach: the command still exits 0 with a complete set of
datapoints, but Python writes the interrupted callback's traceback to
stderr. The os_tests stbtrace tests run the command under
`timeout --signal=SIGINT` and fail on any stderr from a command that
exited 0, so they go red a few percent of the time.

Ignore SIGINT as soon as the first one is taken. The detach then always
runs to completion, and it stays where bcc puts it rather than being
reimplemented here. Each handler disarms only the signal it handles, so
nothing becomes harder to stop than it is today: BCCHelper's SIGTERM
handler exits the same way and is exposed the same way, and takes the
same guard for SIGTERM.

The `except KeyboardInterrupt` that used to be the stop path goes with
it. No KeyboardInterrupt is raised once SIGINT has a handler of its own,
and leaving a second, dead stop path in the file only obscures which one
runs.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@delphix-devops-bot delphix-devops-bot added the platform-claude PR opened by the Claude implement automation label Oct 28, 2026

@dbjwhs-perforce dbjwhs-perforce left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@prakashsurya
prakashsurya merged commit 9c0f31c into develop Oct 31, 2026
9 checks passed
@prakashsurya
prakashsurya deleted the projects/dlpx-94668-fix branch October 31, 2026 16:33
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

platform-claude PR opened by the Claude implement automation

Development

Successfully merging this pull request may close these issues.

4 participants