Skip to content

Flake: CrossProcessNotifyPgTests times out because the LISTEN readiness gate goes green BEFORE LISTEN runs — and StartAsync lies in production too #2281

Closed

Description

@rbuergi

MeshWeaver.Hosting.PostgreSql.Test.CrossProcessNotifyPgTests.AWriteByAnotherProcess_ArrivesOnThisProcessesPartitionFeed
fails as a 30 s TimeoutException — the pg_notify never reaches process B's feed at all. No
issue existed for it (searched --state all), so filing one; it is a sibling of #2008 by area
(the cross-process change feed) but a different failure mode: #2008 asserts a wrong value,
this one never receives anything.

Occurrences — both on diffs that cannot reach PostgreSQL notify

System.TimeoutException : The operation has timed out.
  at CrossProcessNotifyPgTests.AWriteByAnotherProcess_ArrivesOnThisProcessesPartitionFeed()
     CrossProcessNotifyPgTests.cs(104)

Line 104 is the wait for the notification, which is armed before the write and polls a list a
subscription fills — so this is not the "subscribed after the event" shape on the Rx side. It is
that shape one layer down, in Postgres.

Root cause: the readiness gate is satisfied strictly BEFORE LISTEN runs

PostgreSqlChangeListener.StartAsync reports "started" without the listener listening:

public Task StartAsync(CancellationToken ct = default)
{
    _cts = CancellationTokenSource.CreateLinkedTokenSource(ct);
    _listenTask = ListenLoopAsync(_cts.Token);   // fire-and-forget
    return Task.CompletedTask;                   // ← returns before the connection is even open
}

and ListenLoopAsync opens the connection first and executes LISTEN mesh_node_changes
after:

await using var conn = await _dataSource.OpenConnectionAsync(ct);
conn.Notification += OnNotification;
await using (var listenCmd = new NpgsqlCommand("LISTEN mesh_node_changes", conn))
    await listenCmd.ExecuteNonQueryAsync(ct);

The test knows the hazard and guards it — but with a probe that cannot detect it
(CrossProcessNotifyPgTests.WaitForListenSession):

"SELECT count(*) FROM pg_stat_activity WHERE application_name = 'meshweaver-change-listener'"

A backend appears in pg_stat_activity the moment the connection is opened. The LISTEN
statement has not run yet. So the gate goes green in the window between OpenConnectionAsync and
ExecuteNonQueryAsync, the test writes, NOTIFY is delivered to zero listeners — and Postgres
never replays a notification
. The subscriber then waits out its full 30 s for an announcement that
was made once, to nobody.

That is exactly the class PR #2259 established (something subscribes AFTER the event it waits for,
to a source that announces exactly once
), and the gate is exactly the "green signal measuring the
wrong thing" shape: its own comment says "The LISTEN session has to be OPEN before the write, or the
NOTIFY has no subscriber — Postgres does not replay"
, and then it measures the connection
instead of the subscription.

Neither file has been touched on main since a16942810, so this is live today. It is also why the
occurrence on a 68-commits-behind branch is not explained by staleness: there is nothing on main that
would have fixed it.

Not only a test problem

StartAsync returning Task.CompletedTask before LISTEN is registered is a production API
telling its caller a lie: after await listener.StartAsync() the process is not listening, and every
NOTIFY fired in that window is lost with no recovery path (the change feed has no replay, and the
reconnect branch has the same hole, widened by its 5 s backoff). Any consumer that starts a listener
and then depends on a write being announced — the partition provider's own bring-up — is exposed to
the same window on a cold pod.

Suggested fix (root, not the gate)

Make StartAsync mean what it says: complete only once LISTEN mesh_node_changes has actually been
executed on the dedicated connection (first successful registration), surfacing a registration
failure to the caller instead of swallowing it into the reconnect loop. Reactive shape, not a
hand-woven gate: an AsyncSubject<Unit> the loop completes right after ExecuteNonQueryAsync, with
StartAsync returning its first emission.

The test's WaitForListenSession can then be deleted outright rather than made cleverer — with a
truthful StartAsync there is nothing left to poll for. (If a probe is ever wanted again, the
minimum that discriminates is AND query = 'LISTEN mesh_node_changes' AND state = 'idle', i.e. the
statement having completed on that backend — never the mere existence of the connection.)

Found while working the flake population (#1384) — attribution only, not fixing it here.

🤖 Generated with Claude Code

Activity

  1. rbuergi commented on Aug 25, 2026

    @rbuergi
    ContributorAuthor

    Reproduced deterministically and fixed in #2286 — the issue body above said "not fixing it here", which is now out of date.

    Widening the window with a temporary 3 s delay between OpenConnectionAsync and the LISTEN statement turns the analysis into a red/green:

    gate window outcome
    pg_stat_activity poll (main) +3 s FAIL — System.TimeoutException at [30 s], the CI signature verbatim
    listener.Listening (#2286) +3 s PASS in 3 s
    listener.Listening shipped (no delay) PASS in 153 ms

    The production window is narrowed in visibility, not closed — a NOTIFY fired between a pod's StartAsync and its LISTEN is still lost. Closing it means either blocking host startup on the database (rejected: an IHostedService must not) or treating the feed as non-authoritative until Listening fires. That is a design call for whoever owns the change feed; the signal to make it on now exists.

  2. added a commit that references this issue on Aug 25, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions