integration_tests: bound two timing cases on what they can actually prove

[bburda]

Pull Request

Summary

test_peer_recovery case 7 reads the peer-owned topic through the merged Function after the peer gateway comes back, and it polls until that read answers 200. A 200 is not the answer here. When the peer returns, the member re-subscribes, and until its first sample arrives the read is a well-formed body with "status": "metadata_only" and no payload. The case checked the payload after the poll had already stopped, so the first 200 had to carry data or the case failed.

That is a race with the publisher, and it lost on a sanitizer build: AssertionError: 'metadata_only' != 'data', with subscriber_count: 0 in the reported body.

Case 1 in the same file already waits for the payload, and says why in its own comment. Case 7 now does the same. A read that never carries the sample within the recovery budget still fails the case, with a message that says the sample never came.

Waiting for the payload would on its own accept a gateway that stopped waiting for a first sample at all, because a later poll would find the sample anyway. The gateway does wait today, up to topic_sample_timeout_sec (1 s by default), on a condition variable in the subscription pool. One more read after the poll pins that: once the member's subscription is warm the gateway holds the latest sample, so a read has to carry it on the spot.

---

Issue

• none: a test-side timing fix, no change to the gateway

---

Type

• Bug fix
• New feature or tests
• Breaking change
• Documentation only

---

Testing

The demo publisher on the peer-owned topic runs at 500 ms, which is fast enough that the first read after recovery usually already carries a sample. To make the window real, the publisher period was raised locally and the case was run in four configurations:

test version	publisher period	result
before	500 ms	passes, case 7 takes 0.41 s
before	15 s	fails, 'metadata_only' != 'data', same body as CI
after	15 s	passes, case 7 takes 10.0 s
after, expected value mutated to one the gateway never reports	500 ms	fails after the full 90 s budget, only case 7, on the new message

The last row is the check that the new poll can still fail: with the expectation mutated, case 7 spends its whole budget and reports that the sample never came, while the other eight cases stay green.

Full package run with all three changes: colcon test --packages-select ros2_medkit_integration_tests, 1244 tests, 0 errors, 0 failures.

Second case: the graph-event spawn bound

The same package had a second case measuring a quantity it did not control. test_graph_event_discovery timed spawn detection from subprocess.Popen and required it under 2.0 s. The gateway coalesces graph events behind discovery.refresh_debounce_ms, 1000 ms by default and not set by that test, so a spawn arriving mid-window waits for the next one and detection lands on a multiple of the debounce.

Measured by setting the bound to 0 so every run prints its time, eight runs with the default settings:

3.616  3.619  3.415  3.634  3.523  1.148  1.043  3.623  [s]

Two clusters, and the 2.0 s bound sits in the empty gap between them, so the case passed on which side of the debounce the spawn happened to land. Locally that was 2 passes in 8. With the debounce lowered to 50 ms, six runs gave 1.247 1.244 1.244 1.248 0.210 3.005, which is what identifies the debounce as the cause.

For reference, spawn to node-visible-in-the-ROS-graph, measured by an independent rclpy node with no gateway involved and a fresh domain per iteration, is 0.43 s to 0.59 s over eight samples. So most of the old 2.0 s budget was never the gateway's to spend.

A bound on elapsed time cannot separate the two mechanisms on its own, whatever value it takes. The backstop timer is created during gateway initialisation, so its phase relative to a mid-run spawn is arbitrary: a sweep landing inside the bound serves the detection even when the graph-event path is dead. At a 30 s backstop that is a 10/30 chance for a 10 s bound and 2/30 for the old 2 s one, so raising the bound alone would have made the case weaker.

So the case now establishes what it measured before bounding it. The backstop runs at 60 s, the longest interval the gateway accepts, and the case checks that it finished measuring within 30 s of the gateway answering /health. No sweep can have run inside that window, so the refresh it saw came from a graph event. The bound is 10 s, above the measured spread, and the poll gives up at 15 s so a late detection reports the time it took.

Verified: three runs pass with the default settings, the case taking 4.9 s to 7.5 s, well inside its 30 s window. Falsification: with the graph-event path disabled by a 60 s debounce, this case fails at its 15 s poll and the startup-discovery case fails at its 30 s poll. That second failure is new coverage - the 30 s backstop used to serve startup discovery.

Not identified: with the debounce at 50 ms four runs clustered at 1.244-1.248 s, too tight to be chance, so there is a second quantisation in there; and one run still took 3.005 s. Neither is explained, and neither changes what the bound can prove.

---

Checklist

• Breaking changes are clearly described (and announced in docs / changelog if needed)
• Tests were added or updated if needed
• Docs were updated if behavior or public API changed