Skip to content

Retry ledger: record the failing attempt's stack, not just its message (GH-3763) - #3811

Merged
jeremydmiller merged 1 commit into
mainfrom
gh-3763/ledger-flaky-stack-trace
Aug 3, 2026
Merged

Retry ledger: record the failing attempt's stack, not just its message (GH-3763)#3811
jeremydmiller merged 1 commit into
mainfrom
gh-3763/ledger-flaky-stack-trace

Conversation

@jeremydmiller

Copy link
Copy Markdown
Member

Follow-up to #3810, prompted by trying to use it.

#3810 made the MQTT Broken pipe flake legible for the first time:

MQTTnet.Exceptions.MqttCommunicationException : Broken pipe
  ---- System.Net.Sockets.SocketException : Broken pipe

That is a real lead — and it is not enough. The message alone is equally consistent with three different bugs, and it took three local experiments to start telling them apart:

candidate outcome
Teardown ordering — both flaky classes stop the broker before the hosts still connected to it, and 7 of 12 classes share that shape Refuted. 10 runs of a faithful reproduction, including one with real tracked traffic through the broker, throw nothing either way
Port collision between worker processes, via PortFinder handing the same port to two of them Refuted. MQTTnet throws SocketException: Address already in use, which fails the class outright rather than producing a broken pipe
Keep-alive drop under CI load Still standing — and needs a call site to confirm

Six concurrent full-suite local runs did not reproduce it, so the next real occurrence will be on CI. The one thing that would separate the remaining candidates is the field the ledger throws away, and WorkerOutcome already carries it.

The change

The failing attempt's stack, capped at 12 frames, into the ledger JSON only:

"Stack": [
  "at SqliteTests.TempFlakyProbe.fails_once_then_passes() in .../TempFlakyProbe.cs:line 16",
  "at System.RuntimeMethodHandle.InvokeMethod(...)"
]

Deliberately not on the step summary, the annotation or the roll-up. Those three are glanceable surfaces and a stack would drown them. The JSON is already a downloadable artifact, which is the right place for something you go looking for on purpose.

Verification

With a test rigged to fail its first attempt and pass on the retry: the ledger records frames down to file and line, the step summary renders exactly as before, and the roll-up jq ignores the new field. Aggregation re-checked against a mixed set including a pre-change ledger.

🤖 Generated with Claude Code

https://claude.ai/code/session_01WHAuhdWS3XeAk16swV9G8m

GH-3763)

Follow-up to #3810, prompted by trying to use it.

#3810 made the MQTT `Broken pipe` flake legible for the first time:

    MQTTnet.Exceptions.MqttCommunicationException : Broken pipe
      ---- System.Net.Sockets.SocketException : Broken pipe

That is a real lead, and it is not enough. The message alone is equally
consistent with three different bugs, and three local experiments were needed
to start telling them apart:

  - teardown ordering, since both flaky classes stop the broker before the
    hosts still connected to it -- refuted, 10 runs of a faithful reproduction
    including one with real tracked traffic, no exception either way;
  - a port collision between worker processes, via PortFinder handing the same
    port to two of them -- refuted, MQTTnet throws SocketException "Address
    already in use", which would fail the class outright rather than produce a
    broken pipe;
  - a keep-alive drop under CI load, which is what is left, and which needs a
    call site to confirm.

Six concurrent full-suite local runs did not reproduce it, so the next real
occurrence is on CI, and the thing that would separate the remaining candidates
is the one field the ledger throws away. WorkerOutcome already carries it.

The stack goes to the ledger JSON only, capped at 12 frames. The step summary,
the annotation and the roll-up are all glanceable surfaces and a stack would
drown them; the JSON is already a downloadable artifact, which is the right
place for something you go looking for on purpose.

Verified with a test rigged to fail its first attempt: the ledger records the
frames down to file and line, the step summary is unchanged, and the roll-up jq
ignores the new field.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WHAuhdWS3XeAk16swV9G8m
@jeremydmiller
jeremydmiller merged commit 5cfe998 into main Aug 3, 2026
34 checks passed
erdtsieck pushed a commit to erdtsieck/wolverine that referenced this pull request Aug 4, 2026
…3763)

Comments only; no behaviour change.

listen_with_topic_wildcards.broadcast and
broadcast_to_topic_by_user_logic.route_by_derived_topics_2 each cost one retry
in CIMQTT5, failing with the same

    MQTTnet.Exceptions.MqttCommunicationException : Broken pipe
      ---- System.Net.Sockets.SocketException : Broken pipe

Neither is tagged Category=Flaky, deliberately. A tag would stop them running,
and the trade this repository has been making all along is that a test which
runs and occasionally retries is worth more than a test that runs nowhere. This
is visible debt in the retry ledger rather than hidden debt in an exclusion
list, which is the same trade already recorded on
multi_tenancy_through_virtual_hosts.

What the note buys is the search that has already been done. Three candidates
were tested and eliminated:

  - teardown ordering, which both classes get wrong in the same way and which
    7 of 12 broker-using classes share -- a faithful reproduction throws
    nothing in 10 runs, either ordering;
  - a port collision between worker processes via PortFinder's TOCTOU -- ruled
    out because MQTTnet throws "Address already in use", which fails the class
    at InitializeAsync rather than breaking a pipe mid-test;
  - local reproduction under concurrency -- six concurrent full-suite runs, no
    occurrence.

Left standing is a keep-alive drop under CI load, which needs a call site. PR
JasperFx#3811 makes the ledger record one, so the next occurrence writes its stack into
the test-ledger-CIMQTT5 artifact.

Also amends the note on multi_tenancy_through_virtual_hosts, which asked for a
next step -- "dump the tracked session on the FIRST attempt" -- that has since
been built and now happens on its own. Its first captured failure shows the
request never produced its response, which is consistent with the fixed queue
names already under suspicion there without yet proving them.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WHAuhdWS3XeAk16swV9G8m
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