From 475ab3affea4890d823a4a7421fc2d7fb25fe284 Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Wed, 9 Sep 2026 14:30:43 +0200 Subject: [PATCH 1/2] integration_tests: wait for the member's sample in the peer recovery read test_07 polled until the aggregate read of the peer-owned topic answered 200 and checked the payload after the poll had already stopped. A 200 is not the answer here. When the peer comes back the member re-subscribes, and the read waits for a first sample only as long as topic_sample_timeout_sec allows, 1 s by default, so it answers metadata_only with an empty payload when the sample lands later. The case compared that body against 'data' and failed, which is what happens under a sanitizer build. The poll now waits for the payload, the way case 1 already waits for it on the healthy peer. A read that never carries the sample within the recovery budget still fails the case, with a message that says so. 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. One more read after the poll closes that hole: once the member's subscription is warm the gateway holds the latest sample, so a read has to carry it on the spot. --- .../test/features/test_peer_recovery.test.py | 34 +++++++++++++++++-- 1 file changed, 31 insertions(+), 3 deletions(-) diff --git a/src/ros2_medkit_integration_tests/test/features/test_peer_recovery.test.py b/src/ros2_medkit_integration_tests/test/features/test_peer_recovery.test.py index 7aedd42e2..4afcd7e4b 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_peer_recovery.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_peer_recovery.test.py @@ -825,15 +825,26 @@ def test_07_a_peer_owned_read_succeeds_again_and_the_peer_answered_it(self): 'test_04 must watch this URL fail before test_07 can claim it recovered', ) + # A 200 is not yet an answer here. The member re-subscribes when its + # peer comes back, and until its first sample arrives the read is a + # well-formed 'metadata_only' body with no payload - the same state + # case 1 waits through on the healthy peer. The budget below is what + # covers the gap; reading once and calling the empty body a failure + # makes the case race the publisher. def served(): answer = self._aggregate_read_of_peer_topic() - return answer if answer.status_code == 200 else None + if answer.status_code != 200: + return None + payload = answer.json() + if payload.get('x-medkit', {}).get('status') != 'data' or not payload.get('data'): + return None + return answer response = _poll(served, timeout=RECOVERY_TIMEOUT) self.assertIsNotNone( response, - f'a read of {PEER_DECLARED_APP} never recovered after its peer came back; ' - f'last answer was {self._aggregate_read_of_peer_topic().text}', + f"a read of {PEER_DECLARED_APP} never carried the member's sample after " + f'its peer came back; last answer was {self._aggregate_read_of_peer_topic().text}', ) body = response.json() @@ -869,6 +880,23 @@ def served(): f'returned before the outage: {body}', ) + # The poll above waits the member's subscription warm, which is what a + # first read after recovery has to do. Once it is warm a read carries + # the sample on the spot: the gateway holds the latest one and answers + # from it. A read that comes back empty here is not a cold-start + # transient, it is a member that serves nothing until asked twice. + warm = self._aggregate_read_of_peer_topic() + self.assertEqual(warm.status_code, 200, warm.text) + warm_body = warm.json() + self.assertEqual( + warm_body.get('x-medkit', {}).get('status'), 'data', + f'a second read of the recovered member came back without data: {warm_body}', + ) + self.assertTrue( + warm_body.get('data'), + f'a second read of the recovered member carried an empty payload: {warm_body}', + ) + def test_08_the_retained_declaration_does_not_linger_beside_the_live_copy(self): """Recovery is a replacement, not an addition. From 32bda350a0177f5367c0ba15ed60e2a73131eef5 Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Wed, 9 Sep 2026 14:30:48 +0200 Subject: [PATCH 2/2] integration_tests: make the spawn detection bound say what triggered the refresh The graph-event case measured from process spawn and required detection inside 2 s. Two things were wrong with that bound. The gateway coalesces graph events behind discovery.refresh_debounce_ms, 1000 ms by default, so a spawn arriving mid-window waits for the next one and detection lands on a multiple of the debounce. Measured with the default settings the spread runs from about 1 s to 3.6 s, and the 2 s bound sat in the gap between those two clusters, so the case turned on which side of the debounce the spawn happened to land. The backstop timer is also 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, and an elapsed-time bound cannot tell the two apart. The backstop now runs at the longest interval the gateway accepts, 60 s, and the case checks that it finished measuring within 30 s of the gateway answering /health. Inside that window no sweep has run, so the refresh it observed came from a graph event. The latency 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. With the graph-event path disabled by a 60 s debounce, this case fails at its poll and so does the startup-discovery case, which the 30 s backstop used to serve. --- .../test_graph_event_discovery.test.py | 64 ++++++++++++++----- 1 file changed, 47 insertions(+), 17 deletions(-) diff --git a/src/ros2_medkit_integration_tests/test/features/test_graph_event_discovery.test.py b/src/ros2_medkit_integration_tests/test/features/test_graph_event_discovery.test.py index 57cb66c0c..ea8793cee 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_graph_event_discovery.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_graph_event_discovery.test.py @@ -65,8 +65,14 @@ ) -# Long backstop so any sub-backstop detection must come from graph events. -BACKSTOP_INTERVAL_MS = 30000 +# The gateway's maximum accepted backstop interval, and it has to be the +# maximum. The backstop timer is created during gateway initialisation and its +# phase relative to a mid-run spawn is arbitrary, so a case that only measures +# elapsed time cannot tell a graph-event refresh from a backstop sweep that +# happened to land nearby. Pushing the FIRST sweep as far out as the parameter +# allows lets the spawn case finish inside a window where no sweep has run yet; +# PRE_BACKSTOP_BUDGET_SEC below is what keeps it inside that window. +BACKSTOP_INTERVAL_MS = 60000 # Demo nodes launched at startup. INITIAL_NODES = ['temp_sensor', 'rpm_sensor'] @@ -78,16 +84,24 @@ # # Spawn detection is bounded by: # process exec + rclcpp init + DDS announce + 100 ms poll + refresh_cache. -# 5 s is comfortable; well under the 30 s backstop, so a pass proves the -# graph-event poll fired the refresh. -SPAWN_DETECTION_TIMEOUT = 5.0 - -# Graph-event-driven detection should land in under a second; allow -# generous CI jitter headroom but still well below the backstop. A -# detection above this bound proves the backstop, not the graph event, -# triggered the refresh - which is the regression this test exists to -# catch. -GRAPH_EVENT_MAX_LATENCY_SEC = 2.0 +# The poll sits above the latency bound below, so a detection that arrives late +# reports the time it took instead of a bare timeout. +SPAWN_DETECTION_TIMEOUT = 15.0 + +# How long after the gateway first answered /health the spawn case may still +# measure. The first backstop sweep runs BACKSTOP_INTERVAL_MS after gateway +# initialisation, which precedes that first answer by well under a second, so a +# measurement inside this budget is one no sweep could have served. That is what +# makes the bound below a statement about the graph-event path. +PRE_BACKSTOP_BUDGET_SEC = 30.0 + +# The latency of the graph-event path itself, measured from process spawn. It +# cannot be sub-second: the gateway coalesces graph events behind +# discovery.refresh_debounce_ms, 1000 ms by default, and a spawn that arrives +# mid-window waits for the next one, so detection lands on a multiple of the +# debounce. Measured on a developer machine with the default settings, the +# spread is roughly 1 s to 3.6 s. +GRAPH_EVENT_MAX_LATENCY_SEC = 10.0 # Initial discovery shares the budget with full gateway startup. INITIAL_DETECTION_TIMEOUT = 30.0 @@ -153,6 +167,10 @@ class TestGraphEventDiscovery(GatewayTestCase): @classmethod def setUpClass(cls): super().setUpClass() + # Reference point for PRE_BACKSTOP_BUDGET_SEC: the gateway has answered + # /health by the time the base class returns, so initialisation - and + # with it the backstop timer - started a moment earlier. + cls._health_at = time.monotonic() cls._extra_proc = None @classmethod @@ -207,9 +225,10 @@ def test_initial_discovery_picks_up_startup_nodes(self): def test_new_node_detected_via_graph_event(self): """Spawning a node mid-run must propagate within the spawn budget. - ``BACKSTOP_INTERVAL_MS`` is 30 s; detection within - ``SPAWN_DETECTION_TIMEOUT`` (5 s) therefore proves the refresh - was triggered by a graph event, not the safety-backstop sweep. + The case runs before the first backstop sweep and checks that it did, + so the refresh it observes can only have come from a graph event. The + measured time starts at process spawn, so it also carries the node's + own startup and the gateway's event debounce. """ # Make sure the initial graph is fully settled before spawning. for key in INITIAL_NODES: @@ -240,10 +259,21 @@ def test_new_node_detected_via_graph_event(self): interval=0.1, ) elapsed = time.monotonic() - spawn_time + # Establish what was measured before bounding it. Past this budget + # a backstop sweep could have served the detection, and then the + # bound below would be reporting on the wrong mechanism. + since_health = time.monotonic() - type(self)._health_at + self.assertLess( + since_health, PRE_BACKSTOP_BUDGET_SEC, + f'detection landed {since_health:.3f}s after the gateway came up, ' + f'past the {PRE_BACKSTOP_BUDGET_SEC}s window in which no backstop ' + f'sweep can have run ({BACKSTOP_INTERVAL_MS}ms backstop), so this ' + f'run cannot say what triggered the refresh', + ) self.assertLess( elapsed, GRAPH_EVENT_MAX_LATENCY_SEC, - f'Spawn detection took {elapsed:.3f}s - expected sub-second ' - f'via graph-event poll, not backstop-driven ' + f'Spawn detection took {elapsed:.3f}s - expected the ' + f'graph-event poll to serve it, not the backstop sweep ' f'({BACKSTOP_INTERVAL_MS}ms backstop configured)', ) app_ids = [app.get('id', '') for app in data.get('items', [])]