example/wallet: a rollout of the ledger can end a watch with LEDGER_UNAVAILABLE, when the wallet opens the ledger's watch again on the pod that's shutting down

[Zaba505]

What happens

The shared ARolloutOfTheLedger case of the gRPC walkthrough fails intermittently under Wallet walkthrough (testcontainers), on main, in the merge queue and on PRs, e.g. run 39689285771 on main:

--- FAIL: TestInit_passes_the_shared_cases_against_PostgreSQL/ARolloutOfTheLedger (10.24s)
    cases.go:378:
        Error Trace:  example/wallet/cases/cases.go:556
                      example/wallet/cases/cases.go:368
                      example/wallet/cases/cases.go:378
                      example/wallet/app/app_testcontainers_test.go:135
        Error:        Received unexpected error:
                      rpc error: code = Unavailable desc = the ledger can't be reached
        Messages:     receiving from a watch

It has failed this way 8 times since the case landed in #1242 on 2026-10-21, out of about 33 CI runs, about 1 in 4:

Run	Where
39614373989	Renovate PR (#1235)
39621096106	Renovate PR (#1235)
39629611323	Renovate PR (#1235)
39631851410	Renovate PR (#1235)
39632755932	PR #1248
39636981340	merge queue (#1249)
39674901660	Renovate PR (#1235)
39689285771	main

A watch on the wallet ended during a rollout of the ledger with LEDGER_UNAVAILABLE. #1200 has every watch stay open through a rollout of the ledger. The same case against the in-memory ledger, TestInit_passes_the_shared_cases, hasn't failed.

Why

This hasn't been triaged. What follows comes from the code and a reproduction.

1. grpcserver's Shutdown cancels the context of every stream, and of every stream that starts after, before GracefulStop sends the GOAWAY (Server.Shutdown, Streams at shutdown). So the ledger pod being replaced ends each watch with Unavailable "server is shutting down" while the wallet's connection to it is still open.
2. The wallet's WatchAccount opens the ledger's watch again at once. Until the wallet's client has read the GOAWAY, the new stream goes on the same connection, to the same pod, and gets a context that is already cancelled.
3. The ledger's WatchAccount reads the account before it sends its first message. pgx fails the query on the cancelled context, so the stream ends with Unavailable before any message.
4. The wallet opens the ledger's watch again only when the one that ended had received a message (received && ...). This one received none, so the wallet ends its client's watch with "the ledger can't be reached".

The in-memory store (memoryStore.Account) and the fake ledger of the wallet's "relays the watch through the ledger's shutdown" test ignore a cancelled context and send the first message, so neither sees this.

grpcserver's doc tells a client that gets Unavailable to reconnect, since "the new stream lands on another pod", and grpcclient's says the streams the end user's code opens again "land on the next pod". Before the GOAWAY reaches the client, they land on the same pod.

Reproduction. At 6351c86, this change to grpc/internal/server/server.go widens the window between the cancel and the GOAWAY:

 	s.streams.stop()
+	time.Sleep(200 * time.Millisecond)

With it, the case fails every time (-count=3), with the error CI sees:

$ go -C example/wallet test -race -tags testcontainers -count=3 \
    -run 'TestInit_passes_the_shared_cases_against_PostgreSQL/ARolloutOfTheLedger$' ./app/
--- FAIL: TestInit_passes_the_shared_cases_against_PostgreSQL/ARolloutOfTheLedger (5.10s)
        Error:      Received unexpected error:
                    rpc error: code = Unavailable desc = the ledger can't be reached
        Messages:   receiving from a watch

Without the change, it failed this way 10 times out of 15 locally (-count=15, with another test suite running alongside).

Expected

Every watch on the wallet stays open through a rollout of the ledger, as #1200 has it, whenever the wallet's watch of the ledger is opened again. The ARolloutOfTheLedger case passes whenever the wallet works.

References

• run 39689285771, the run that prompted this
• the ARolloutOfTheLedger case, from story(example): keep every watch open through a rollout of the ledger #1200
• grpcclient: a rollout of a dependency served by grpcserver opens the breaker of a Client with five streams open to the pod #1176, the rollout bug before this one, fixed by story(grpcclient): a dependency's rollout or connection age leaves the Client's breaker closed #1180

[Zaba505]

Triage

Verdict: A reproducible bug in grpcserver, which the wallet shows. Shutdown cancels every stream before GracefulStop sends the GOAWAY, so a stream that a client opens again at once can land on the pod that is shutting down, where it ends before any message. It is worse than reported: any client of grpcserver that opens streams again can hit it, without the wallet. And a connection still in its TLS handshake holds the GOAWAY back for as long as the handshake lasts. Every stream opened again in that time lands on the old pod. #1258 is filed to fix it.

Is this a misuse of humus?

No. The order of the cancel and the GOAWAY is grpcserver's. Server.Shutdown calls s.streams.stop(), then GracefulStop. Which connection a new stream goes on is up to grpc-go's client, and the end user doesn't control it. The wallet's relay is the end user's code. It opens the ledger's watch again on Unavailable once the watch has sent a message (server.go#L143), as grpcserver's doc tells a client to.

The docs promise where that stream goes: "Reconnect: the new stream lands on another pod." The end user can't defend against the window. Nothing tells them when their client has read the GOAWAY, and a stream opened again too soon ends with the same status as the one before, "server is shutting down". On a handler that sends before it looks at its context, the new stream even hears from the old pod first, and then ends again. Opening it again at once only lands on the old pod again, until the GOAWAY arrives.

The strongest argument for misuse is that the wallet treats a watch that ends before its first message as a ledger that is down. grpcserver doesn't ask that of a client. The argument doesn't hold. #1177 chose that bound because of grpcserver's promise: "A watch outlives a rollout of either service: the wallet opens the ledger's watch again on another pod." And a plain grpcserver pod and a grpcclient Client fail the same way without the wallet (below).

Is it a feature request?

No. It contradicts these promises:

• grpcserver's doc, doc.go#L188-L191, and the docs site's Streams at shutdown: "The server is going away. Reconnect: the new stream lands on another pod."
• grpcclient's doc, doc.go#L112-L117: "The circuit breaker ignores a stream that ends with Unavailable, however many end at once (see Streams, below), so the end user's code opens them again, and they land on the next pod."
• #681's revision, answer 2: "The client reconnects, and lands on another pod."
• Proposal: gRPC walkthrough #1177: "So a rollout of the ledger keeps every app's watch open, and a ledger that is down ends it". And story(example): keep every watch open through a rollout of the ledger #1200's criterion: "No watch ends."

A fix restores promised behaviour, and changes no exported name, signature, Settings field or default. doc.go's L172-L174 says "A stream that starts after that gets a context that is already cancelled". That sentence describes the window the bug lives in, and correcting it isn't an API change.

Is it reproducible?

Yes. It reproduced at 6351c86 with Go 1.27.0, grpc-go v1.84.0, pgx v5.11.0, testcontainers-go v0.44.0 and postgres:18.0 on Podman 5.8.9. Every test ran under -race, 4 runs each.

There are two kinds of reproduction. The first kind extends grpcclient's rollout tests from #1176. Pods ledger-a and ledger-b run on grpcserver's defaults behind a dialer that does what a ClusterIP Service does. An end user's App opens streams on ledger-a through a Client. The test routes the Service to ledger-b and sends ledger-a SIGTERM. Each stream opens again once, as soon as it ends. The second kind is the wallet's own case, against PostgreSQL. To widen the window without changing humus, some tests open a TCP connection to the pod that never starts its TLS handshake, as a client does that dials just before the listener closes.

scenario	runs failed	what the streams opened again did
one server stream, synctest	0 of 4	heard from ledger-b
one bidirectional stream, synctest	0 of 4	heard from ledger-b
8 server streams, synctest	2 of 4	3, then 6, of 8 ended "server is shutting down" on ledger-a before any message
8 server streams on pods that send first, synctest	0 of 4	heard from ledger-b
a server stream, a connection to ledger-a in its handshake, synctest	4 of 4	ended "server is shutting down" on ledger-a before any message
a bidirectional stream, the same	4 of 4	the same
a server stream on pods that send first, the same	4 of 4	heard from ledger-a
one server stream, loopback TCP	0 of 4	heard from ledger-b
8 server streams, loopback TCP	2 of 4	1 of 8 ended on ledger-a, each time
8 server streams on pods that send first, loopback TCP	0 of 4	heard from ledger-b
a server stream, a connection in its handshake, loopback TCP	4 of 4	ended on ledger-a
the case as it is, TestInit_passes_the_shared_cases_against_PostgreSQL/ARolloutOfTheLedger	3 of 4	Unavailable desc = the ledger can't be reached, "receiving from a watch"
the case with each service's telemetry recorded	0 of 4	16 watches opened again, all on the next replica
the case with a connection to each ledger replica in its handshake	4 of 4	8 of 8 opened again on the shutting-down replica
the case against the in-memory ledger, TestInit_passes_the_shared_cases/ARolloutOfTheLedger	0 of 4

The wallet against PostgreSQL, with a connection to each replica in its handshake: every watch ends. Each held connection closes 200ms after its replica's first watch ends. That does from a test what the report's 200ms sleep did inside Shutdown. Each ledger start gets telemetry of its own, numbered. From run 2:

1. At +0.059s, RolloutLedger begins. The first replica, start 1, leaves the endpoints and drains for 5s, with the 8 watches still open on it.
2. At +5.059s, Shutdown cancels them, and each ends: ledger start 1: WatchAccount from +000.030s to +005.059s (5.028397s): Error "server is shutting down".
3. At +5.060s, the wallet opens all 8 again, on the same replica: ledger start 1: WatchAccount from +005.060s to +005.060s (171µs): Error "server is shutting down", 8 times, each lasting 171–368µs.
4. At +5.061s, none of them has sent a message, so the wallet ends each app's watch: WARN "the wallet answered Unavailable for the ledger" wallet.v1.Wallet/WatchAccount exception.message="rpc error: code = Unavailable desc = server is shutting down", 8 times. wallet.watches.reopened is 8: every watch opened again landed on the replica that was shutting down.
5. At +5.077s, the case fails with the ledger can't be reached. At +5.260s, the held connection closes, and only then can GracefulStop send its GOAWAY.

8 server streams on one Client, with nothing held: some land on the old pod. From synctest's run 3:

1. Each stream ends: stream 0 heard from ledger-a, and ended: rpc error: code = Unavailable desc = server is shutting down.
2. Six streams open again while the Client has only its connection to ledger-a: stream 0 opened again with 1 connection(s) begun, and ended before its first message: rpc error: code = Unavailable desc = server is shutting down.
3. The other two open after the GOAWAY: stream 1 opened again with 1 connection(s) begun, and heard from ledger-b.

One stream never lost this race in synctest or over TCP. It takes several streams ending at once, as the case's 8 watches do. With each service's telemetry recorded, the case passed 4 runs of 4, while the case as it is failed 3 of 4. I didn't look into why recording changes the timing.

The report has the mechanism right. It needs these corrections and additions:

• The bug isn't the wallet's. The wallet shows it, because its ledger fails a stream on a cancelled context before the first message.
• At step 3, the ledger logged no warning for the 8 watches it ended. It warns for Unavailable and Internal only, so it answered Canceled, which it does for a context error (server.go#L270-L271). humus's interceptor then ended each stream "server is shutting down". So the wallet sees the same status the first watch ended with. I didn't log pgx's error itself.
• The in-memory ledger hides the bug, but it doesn't avoid it. On pods that send first, a stream opened again with a connection in its handshake heard from the shutting-down pod, 4 runs of 4. With the in-memory ledger, the wallet would get that message, see the watch end again, and open it again on the same pod until the GOAWAY arrives. I got that last part from the wallet's code and didn't reproduce it.

Why

1. Shutdown cancels every stream first (server.go#L204), then runs GracefulStop (L209-L214). Each handler returns, and its stream's trailers go out on the open connection. Reproduced.
2. grpc-go's GracefulStop closes the listener, then waits on serveWG (server.go#L1697), and only then drains every connection, which sends the GOAWAY (L1703). serveWG counts every accepted connection until its handshake ends (L990-L994), and the handshake may last up to ConnectionTimeout, 120s by default (L1005). So the trailers can reach the client before the GOAWAY, and a connection in its handshake holds the GOAWAY back. Reproduced by the tests with a connection in its handshake.
3. A client moves off a connection only when it reads the GOAWAY: handleGoAway tells the ClientConn, and marks the transport draining (http2_client.go#L1419-L1430). Until then, a new stream goes on the old connection, to the old pod. Reproduced.
4. The old pod accepts the stream, even after its first GOAWAY, which grpc-go sends for that reason: "During this time accept new streams since they might have originated before the GoAway reaches the client" (http2_server.go#L1426-L1429). I got that from grpc-go's code and didn't reproduce it. humus's interceptor cancels the stream's context before its handler runs (streams.go#L53-L58). Reproduced: every stream that landed on the old pod ended at once.
5. The ledger reads the account before it sends (server.go#L169-L175), the read fails on the cancelled context, and the stream ends before any message. The wallet opens a watch again only after a message, so it ends the app's watch with LEDGER_UNAVAILABLE. Reproduced.

Other ways into the same code:

• Every kind of stream. Server and bidirectional streams are reproduced. Client streams go through the same interceptor. I got that from the code and didn't test it.
• MaxConnectionAgeGrace isn't affected. The server sends its GOAWAY at MaxConnectionAge, a whole grace before it closes the connection under its streams, so a stream opened then goes on a new connection. I got that from the code and didn't test it.
• grpchealth's server is built on the same code, so a health Watch ends the same way. I got that from the code and didn't test it.
• A connection in its handshake also holds Shutdown past its grace period. Stop waits on the same serveWG. A pod on grpcserver's defaults, with no stream open and one connection held in its handshake, exited 2m0s after SIGTERM, 4 runs of 4: shutdown ran past the grace period of 15s: shutdown: grpcserver: shutting down: context deadline exceeded. Its 5s drain and 15s grace period say 20s. That is a bug of its own, and it isn't in story(grpcserver): a stream opened again when Shutdown ends one lands on another pod #1258.

#1258 is filed to fix it:

• a stream opened again as soon as Shutdown ends one lands on another pod, for server and bidirectional streams, and for 8 streams at once;
• that holds while a connection to the pod is in its TLS handshake;
• every watch on the wallet stays open through a rollout of the ledger against PostgreSQL, and a ledger that is down still ends it;
• the triage's reproductions, as tests in grpcclient's dependencies_test.go, and a container test for the wallet;
• grpcserver's and grpcclient's docs and comments corrected where they describe the order of the cancel and the GOAWAY.

[Zaba505]

Fixed by #1258, in #1272, merged as e59c40c.

Shutdown in grpc/internal/server, which grpcserver and grpchealth both use, now does three things in order. It closes every connection still in its TLS handshake, so GracefulStop sends its GOAWAY at once. It calls GracefulStop. It cancels the streams only once every open connection has written its GOAWAY. Each stream's trailers now follow the GOAWAY on its connection, so a stream the wallet opens again at once goes over a new connection, to another ledger pod.

TestInit_passes_the_shared_cases_against_PostgreSQL/ARolloutOfTheLedger passed 5 runs of 5. A new container test runs the same rollout with a connection to each ledger replica held in its handshake, and it passes too. The triage's reproductions are now tests in grpc/grpcclient/dependencies_test.go, run in synctest and over loopback TCP.

The fix also cures the triage's side finding: a connection in its handshake no longer holds Shutdown past its grace period.