Skip to content

test(bus-rabbitmq): no_ack_shutdown_drains_in_flight_handlers is timing dependent #525

Description

@pierrick-fonquerne

Symptom

no_ack_shutdown_drains_in_flight_handlers (crates/hexeract-bus-rabbitmq/tests/integration.rs:1667) fails intermittently in the Docker integration job:

assertion `left == right` failed: every in-flight no_ack handler must finish before shutdown (#338)
  left: 2
 right: 4

The observed value of left varies between runs (3, then 2) while the tested code is unchanged.

Evidence that the failure is non deterministic

The same commit failed twice and then passed on a plain rerun, with no code change in between. Observed on PR #524:

Target Runs Result
main 17 all green
PR branch 3 2 failures, 1 success (same commit)

The branch under test only touched crates/hexeract-bus-rabbitmq/src/request_client.rs. None of the functions it changed (supervise_reply_inbox, reconnect_reply_inbox, retry_reply_inbox_after_failures) has any caller outside that file, so no execution path of the integration test binary can reach them. The failure is unrelated to that change.

Root cause

The test synchronises on an absolute delay rather than on a signal:

// Let all deliveries enter their (slow) handlers, then cancel mid-flight.
tokio::time::sleep(Duration::from_millis(100)).await;
cancel.cancel();

It assumes that within 100 ms the broker has delivered all four messages and that each one has entered its handler. Two facts make that assumption fragile:

  • every test in the suite starts its own RabbitMQ container (start_rabbit), and the job runs cargo test --workspace --all-features -- --ignored on ubuntu-latest with no --test-threads limit, so many brokers start concurrently on a 2 vCPU runner
  • the measured duration of the integration binary ranges from 99.87 s to 113.27 s across runs, which is the same load variance expressed on the wall clock

When a delivery lands after cancel(), the worker drains the handlers that did start, which is the correct behaviour, but the counter never reaches batch. The assertion therefore conflates two properties: that shutdown drains in-flight handlers (the intent, #338) and that delivery happened before cancellation (a race).

This is the only test in the suite that waits on a clock instead of an explicit signal.

Proposed fix

Replace the calibrated sleep with an explicit rendezvous, so the test cancels only once all four handlers have provably started:

  • give SlowCountingHandler a Barrier (or a Notify plus a started counter) sized to batch
  • have each handler signal on entry, before its simulated work
  • await that signal in the test body, then call cancel()

The assertion on done == batch then measures the drain alone, and the test stops depending on runner load. A bounded tokio::time::timeout around the rendezvous keeps a genuine delivery failure from hanging the suite.

Impact

Low severity, real cost: unrelated pull requests go red at random and need a rerun. The habit of rerunning without reading is what eventually hides a genuine regression.

Activity

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