example/mailer: in one run of the container test, Sent's outcome came on mail.send and SlowProvider's request was parked on mail.retry three times

[Zaba505]

What happens

TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock failed once in the Mailer walkthrough (testcontainers) job. Two of the cases that run in parallel failed together: Sent and SlowProvider. The job passed when it was re-run on the same commit.

Run	Where	Attempt	Result
39723250627	PR #1272, c474ae3	1, from 04:40 UTC on 2026-10-22	failed
39723250627	PR #1272, c474ae3	2	passed

The test's output:

--- FAIL: TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock (31.06s)
    --- FAIL: TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock/in_parallel (0.00s)
        --- FAIL: TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock/in_parallel/Sent (4.15s)
            cases.go:102:
                	Error Trace:	/home/runner/work/humus/humus/example/mailer/cases/cases.go:102
                	            				/home/runner/work/humus/humus/example/mailer/app/app_testcontainers_test.go:222
                	Error:      	Not equal:
                	            	expected: "mail.sent"
                	            	actual  : "mail.send"
        --- FAIL: TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock/in_parallel/SlowProvider (11.12s)
            cases.go:184:
                	Error Trace:	/home/runner/work/humus/humus/example/mailer/cases/cases.go:184
                	            				/home/runner/work/humus/humus/example/mailer/app/app_testcontainers_test.go:222
                	Error:      	Should be empty, but was [{… map[baggage:acme.fault={%22rules%22:[{%22point%22:%22http:localhost:32787%22%2C%22delay_ms%22:2000}]} x-mail-attempt:2] application/json … mail.retry mail.send …} {… x-mail-attempt:3] … mail.retry mail.send …} {… x-mail-attempt:4] … mail.retry mail.send …}]
FAIL	github.com/z5labs/humus/example/mailer/app	79.919s

The SlowProvider deliveries are shortened here. All three carry the same message ID, the same baggage and the same body, and differ only in x-mail-attempt and delivery tag.

What's known

This hasn't been triaged. What follows comes from the run and the cases' code:

• Sent got an outcome whose routing key is mail.send. Sent publishes a request with no baggage, then waits for its first outcome. outcome counts a delivery from mail.events or mail.dead as an outcome, and skips one from mail.retry. So the delivery Sent got came from mail.events or mail.dead. The output doesn't say which exchange it came from, and doesn't print its headers.
• SlowProvider's request was parked on mail.retry three times before it was sent. Its request's scenario delays the provider by 2s. The three parked copies carry x-mail-attempt 2, 3 and 4. Its mail.sent outcome came after them, and its checks at lines 182 and 183 passed. Line 184 requires that the request was never parked.
• Both failed in the same run. The four other parallel cases (SentOnce, Refused, Malformed, UntrustedScenario) and the three Alone cases passed. Whether the two failures are connected isn't known.
• The mailer's code didn't change. PR story(grpcserver): a stream opened again when Shutdown ends one lands on another pod #1272 changes nothing under example/mailer, and the mailer doesn't import humus's grpc module. example/mailer is the same on c474ae3 and on main at e59c40c. The mailer's cases and app last changed in story(example): rehearse failures in the mailer's shared cases #1078.
• It's the only failure found. The 80 most recent runs of the workflow, from 2026-10-21 00:06 UTC to 2026-10-22 05:19 UTC, have no other failed attempt of this job. One run's job list couldn't be read (a server error).

Not yet known: why Sent's request came out on mail.send, why SlowProvider's 2s delay made the mailer retry, whether it reproduces locally, and how often it happens.

Expected

Sent's first outcome is a mail.sent event. SlowProvider's request is sent without being parked on mail.retry, as the case requires. The test passes on every run.

References

• the cases: Sent and SlowProvider in example/mailer/cases/cases.go
• the helpers they wait with: watch, outcome, await and outcomes, parked
• the test that runs them: TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock
• the run: 39723250627, on PR story(grpcserver): a stream opened again when Shutdown ends one lands on another pod #1272

[Zaba505]

Triage

Verdict: A reproducible bug in the mailer walkthrough's own tests, not in queue/rabbitmq, and not a misuse. Each shared case's own queues make RabbitMQ nack the mailer's publishes as the case ends. Five nacks in a row open a Publisher's breaker for 10s. While the events Publisher's breaker is open, every request is parked at each attempt and dead-lettered gave-up, though the provider sent it. Sent and SlowProvider are two requests caught in that window. It is worse than reported: the same nacks reach the mailer's retry and dead-letter Publishers, and a park or a dead letter they fail stops the mailer with exit 1. #1279 is filed to fix it.

Is this a misuse of humus?

No. The run is the walkthrough's own test, of its own cases, against its own mailer, all in example/mailer. Nothing in it was the reporter's.

queue/rabbitmq behaves as its docs say. A nack is retried (doc.go L479-L485) and counted as a failure of the broker: "nacked by the broker, a dropped connection, a failed dial or a failed handshake: a failure" (L535-L536). The breaker "opens after 5 failed attempts in a row … stays open for 10s" (L510-L512).

The strongest argument for misuse is that the walkthrough is queue/rabbitmq's end user here: it owns its cases' queues and its Publishers' BreakerPolicy. That holds. It is why the fix belongs to the walkthrough, and why this is still a bug: the walkthrough promises what its own code doesn't do.

Is it a feature request?

No. It breaks the walkthrough's promises, from #951 and the stories that landed its cases:

• "A slow provider. Under a scenario that delays ProviderPoint by 2s, under AttemptTimeout, the request is still sent at the first attempt." (Proposal: RabbitMQ processor walkthrough #951's "Run in parallel", and story(example): rehearse failures in the mailer's shared cases #1035's criteria). Refused and UntrustedScenario promise the first attempt too.
• "Run alone, one at a time, after the rest. Each opens a breaker or cuts connections, which slows every message in flight" (Proposal: RabbitMQ processor walkthrough #951; story(example): rehearse failures in the mailer's shared cases #1035: "since each opens a breaker or cuts connections"). So the cases that run in parallel open no breaker.
• "The barrier is the request's outcome … so the cases run in parallel against one broker" (Proposal: RabbitMQ processor walkthrough #951's Testing).
• "The cases mutate the broker and the provider, so they never run against production. In staging, the alone cases are an outage of the mailer that runs them" (Proposal: RabbitMQ processor walkthrough #951). The parallel ones aren't meant to be one.

A fix needs no change to humus's API. A fix that changed how queue/rabbitmq's Publisher counts a nack would change a documented guarantee of that package, which would need a proposal.

Is it reproducible?

Yes. At e59c40c, with Go 1.27.0 and -race, RabbitMQ rabbitmq:4.3.6, WireMock wiremock/wiremock:3.13.2, amqp091-go v1.16.0 and testcontainers-go v0.44.0, on Podman 5.8.9.

Test	Failed
TestInit_passes_the_shared_cases_against_RabbitMQ_and_WireMock, the cited test, as a baseline	0 of 4 runs
TestInit_passes_the_shared_cases_when_four_runs_of_them_are_in_parallel: the same mailer and harness, with cases.Parallel run four times over at once	2 of 4 runs

The second test runs only the shared cases, as they're written. More of them at once means more queues going away while the mailer publishes. Runs 2 and 4 passed, with 8 and 6 nacked attempts that never came five in a row on one Publisher.

Run 1: the events breaker opens, requests are dead-lettered gave-up, and the mailer exits 1.

1. Cases end around +0.1s and close their connections, which deletes their queues. The broker nacks the mailer's publishes to the exchanges those queues were bound to. By the end of the run: messaging.client.sent.messages, error.type=nacked, was 4 for mail.events:mail.sent, 4 for mail.events:mail.refused, 5 for mail.retry:mail.send and 6 for mail.dead:mail.send.
2. Five nacks in a row open the events Publisher's breaker: +160ms WARN circuit breaker open … humus.circuit.consecutive_failures=5.
3. From then on, each request's provider call succeeds, its event's publish is rejected, and it is parked: mail.retry mail.send … x-mail-attempt=2, then 3, 4 and 5, one second apart (the test's retry delay). The run saw 80 parked copies.
4. At attempt 5, each is dead-lettered, 12 in all: mail.dead mail.send … x-mail-dead-reason=gave-up x-mail-dead-attempts=5 x-mail-dead-error=worker: publishing mail.sent: rabbitmq: publishing to exchange "mail.events" with routing key "mail.sent": circuit: call rejected: open for another 5.896584386s. Sent_3 and UntrustedScenario_3 got these as their first outcome, at 4.25s and 4.27s, and failed with expected: "mail.sent", actual: "mail.send". That is what Sent got in CI, at 4.15s.
5. Those cases end, and their queues on mail.dead go with them, while the next dead letters are published. A dead letter is nacked, and the mailer stops: +5.245s ERROR serve: rabbitmq: processing message … from mail.send: worker: dead-lettering the request to mail.dead: rabbitmq: publishing to exchange "mail.dead" with routing key "mail.send": the broker nacked the message, exit 1.
6. Every case still waiting, the four SlowProviders and three SentOnces, times out after 60s.

Run 3: SlowProvider is sent at the fourth attempt, as in CI.

1. The events Publisher's breaker opens: +171ms WARN circuit breaker open … humus.circuit.consecutive_failures=5.
2. UntrustedScenario_2's first outcome is a gave-up dead letter, at 4.27s: expected: "mail.sent", actual: "mail.send".
3. Each SlowProvider request is parked three times: its event's publish is rejected after each 2s call.
4. The breaker half-opens and closes: +11.138s INFO circuit breaker half-open, +11.194s INFO circuit breaker closed.
5. The fourth attempt's event is published, and three SlowProviders fail at 11.14s to 11.19s, the fourth at 14.16s, each at require.Empty(t, b.parked(r.messageID)), with x-mail-attempt 2, 3 and 4. That is CI's failure, at CI's 11.12s.
6. The four SentOnces wait for two events that never come, and time out after 60s. The mailer kept running.

The broker logged no error or warning in any run.

This corrects the report:

• Sent's mail.send outcome came from mail.dead. It is the worker's gave-up dead letter after 5 attempts. Its x-mail-dead-error names the events Publisher's breaker (reproduced).
• SlowProvider's 2s delay didn't make the mailer retry. The provider answered every attempt, and the event's publish was rejected each time. The delay only placed its publishes, at about 2s, 5s and 8s, inside the 10s the breaker stayed open. The fourth, at about 11s, came once it had half-opened. WireMock was sent the request four times. I got that last part from the worker's code, and didn't check the journal.
• The two failures are connected. They are one failure: the events Publisher's breaker, open for 10s.
• The delivery tags fit. SlowProvider's parked copies were deliveries 20, 39 and 40 on its channel: its queues got every other request's parked copies and dead letters while the breaker was open. I got that from the reproduction's pattern, not from CI.

Why

1. Each case binds queues of its own to all three of the mailer's output exchanges, and they go away when it ends. watch binds an exclusive, server-named queue (bind) to mail.events, mail.dead and mail.retry. The case's connection closes in its cleanup (L409), which deletes them.
2. RabbitMQ nacks a publish routed to a queue that goes away before confirming it. When a classic queue a message was routed to goes down for any reason but normal, such as noproc or shutdown, and it hadn't confirmed the message, the channel rejects it (rabbit_classic_queue.erl L400-L442, with IS_BENIGN_EXIT). The publisher gets a basic.nack, though the other queues have the message. I got the branch from RabbitMQ's code. The nack itself is reproduced in every counted run: on mail.events and mail.dead in all four, and on mail.retry in runs 1 and 3. In an exploratory run against the broker alone, with 8 connections binding a queue to an exchange and closing, again and again: 167 of 300 publishes to mail.events and 295 of 300 to mail.retry were nacked. With the queues coming and going on mail.events instead, 0 of 300 to mail.retry were.
3. The Publisher retries a nack and counts it against the broker. classify retries it, and classifyBreaker counts it a failure. defaultTrip opens after 5 in a row, for OpenFor's 10s. A retry that is confirmed publishes the event again: an exploratory run saw mail.sent twice for one processing, about 60ms apart.
4. The worker parks a request whose event it can't publish, and gives up at the fifth attempt. send returns the publish's error, and process parks it, or dead-letters it at MAIL_MAX_ATTEMPTS, 5. The test's retry policy waits 1s, so five attempts take about 4s, all inside the breaker's 10s.
5. A park or a dead letter that fails stops the mailer. park and deadLetter return the error, and Process returning it stops the Service, as Proposal: RabbitMQ processor walkthrough #951's revision 1 decided for "a publish to mail.retry or mail.dead that fails". The cases' queues on mail.retry and mail.dead trigger it (reproduced in run 1).

The cited test runs six cases, and the window is narrow. In 12 exploratory runs of those six cases, instrumented, on 4 CPUs, mail.events publishes were nacked in 3, never 5 in a row. CI's slower runner hit it once in the 80 runs the report searched.

The same parallel cases run in the kind job (functional_test.go L50-L57), and #951 says they run against an end user's staging. There they would do the same to the deployed mailer. I got that from the code, and didn't run it.

#1279 is filed to fix it:

• the cases in cases.Parallel pass on every run, in the container test and the kind job, with each request they expect sent at the first attempt never parked or dead-lettered;
• running them opens none of the mailer's Publishers' breakers and never stops the mailer, even as their own queues go away while the mailer publishes;
• the triage's test, with four runs of the parallel cases at once, passes 10 runs in a row, in app_testcontainers_test.go;
• the pages and comments on how a case waits for its outcome say what changed.

[Zaba505]

Fixed by #1282 (#1282), merged as 2ba208d, which closed story #1279.

What changed: a shared case now unbinds its queues on mail.events, mail.dead and mail.retry before its connection closes. RabbitMQ deletes a queue that goes away with its connection (or its last consumer) only after the queue process has exited. A publish routed to it in that gap is nacked. With the binding gone first, nothing is routed to a queue that is going away, so the mailer's Publishers see no nacks, open no breaker, and park, dead-letter or stop nothing. cases.bind declares each queue exclusive but not auto-delete, consumes it without the case's context, and unbinds it in a cleanup that runs before dial's conn.Close. watch and bind no longer take a ctx. Nothing in humus or queue/rabbitmq changed.

The test: TestInit_passes_the_shared_cases_when_four_runs_of_them_are_in_parallel, the triage's reproduction, is now in example/mailer/app/app_testcontainers_test.go. It runs cases.Parallel four times over at once against one mailer. Then it checks that the mailer is still running, that the Publishers' breakers counted calls, and that none moved to open. Locally it failed 3 of 3 runs before the fix, and passed 15 of 15 after it under -race. None of the 28 publishes per run was nacked. Both Mailer walkthrough jobs (testcontainers and kind) passed on the pull request.

Docs: the walkthrough's Testing page now quotes bind under "The barrier", with the reason it unbinds first. It also quotes the shared container-test setup and the new test's checks.