From 475ab3affea4890d823a4a7421fc2d7fb25fe284 Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Wed, 9 Sep 2026 14:30:43 +0200 Subject: [PATCH 1/8] 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/8] 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', [])] From 29e4e03a0a8851ddc496b05998b2db7350355040 Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Thu, 10 Sep 2026 13:00:51 +0200 Subject: [PATCH 3/8] integration_tests: scale the graph-event budgets and use the full pre-backstop window PRE_BACKSTOP_BUDGET_SEC goes from 30 s to 50 s. The gateway bounds the window it names: the backstop timer is armed during gateway initialisation, ahead of start_rest_server(), whose wait for the REST server to accept connections is capped at 5 s, and the base class then polls /health every 0.5 s. Of the 60 s backstop interval that leaves roughly 54 s still ahead of the first sweep by the time /health answers, so 30 was giving away about half of the usable window. 50 keeps a margin for scheduling slack. That budget stays unscaled on purpose. MEDKIT_TEST_TIME_SCALE stretches what the test is willing to wait for; it does not stretch the gateway's backstop interval, so scaling this one would let the measurement drift past the first sweep and the assertion would no longer be about the graph-event path. SPAWN_DETECTION_TIMEOUT, GRAPH_EVENT_MAX_LATENCY_SEC and INITIAL_DETECTION_TIMEOUT do scale, the way the sibling feature tests already do. Their base values are unchanged at 15 s, 10 s and 30 s; each bounds instrumented work that an ASan or TSan build slows down, and the sanitizer jobs export the same factor they apply to the ctest timeouts. --- .../test_graph_event_discovery.test.py | 34 +++++++++++++------ 1 file changed, 23 insertions(+), 11 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 ea8793cee..0cb21d944 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 @@ -55,6 +55,7 @@ from ros2_medkit_test_utils.constants import ( ALLOWED_EXIT_CODES, DEFAULT_DOMAIN_ID, + get_time_scale, ) from ros2_medkit_test_utils.gateway_test_case import GatewayTestCase from ros2_medkit_test_utils.launch_helpers import ( @@ -85,26 +86,37 @@ # Spawn detection is bounded by: # process exec + rclcpp init + DDS announce + 100 ms poll + refresh_cache. # 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 +# reports the time it took instead of a bare timeout. Every term in that sum is +# instrumented work, so the budget scales with the sanitizer factor. +SPAWN_DETECTION_TIMEOUT = 15.0 * get_time_scale() # 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 +# measure. A measurement inside this budget is one no backstop sweep could have +# served, which is what makes the bound below a statement about the graph-event +# path. The window is derived: the backstop timer is armed during gateway +# initialisation, ahead of start_rest_server(), whose wait for the REST server +# to accept connections is bounded at 5 s, and the test base class then polls +# /health every 0.5 s. So of the 60 s backstop interval about 54 s are still +# ahead of the first sweep once /health answers, and 50 leaves a margin for +# scheduling slack. +# +# This budget deliberately does NOT scale with MEDKIT_TEST_TIME_SCALE. It is +# bounded by the gateway's own backstop interval, which the scale factor does +# not stretch; scaling the budget would let the measurement drift past the +# first sweep, and the assertion would stop being about the graph-event path. +PRE_BACKSTOP_BUDGET_SEC = 50.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 +# spread is roughly 1 s to 3.6 s. The budget scales with the sanitizer factor. +GRAPH_EVENT_MAX_LATENCY_SEC = 10.0 * get_time_scale() -# Initial discovery shares the budget with full gateway startup. -INITIAL_DETECTION_TIMEOUT = 30.0 +# Initial discovery shares the budget with full gateway startup, so it scales +# with the sanitizer factor. +INITIAL_DETECTION_TIMEOUT = 30.0 * get_time_scale() def generate_test_description(): From b83052373452f22993d691ab699dea58e61e4ee3 Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Thu, 10 Sep 2026 13:02:52 +0200 Subject: [PATCH 4/8] integration_tests: describe the 60 s backstop the graph-event test runs with --- .../test/features/test_graph_event_discovery.test.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 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 0cb21d944..bfde187d8 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 @@ -28,9 +28,10 @@ ``/apps`` quickly - the load-bearing assertion that proves the graph-event refactor is working. -The gateway runs with a long ``refresh_interval_ms`` (30 s) so any -detection well under that window must come from the graph-event poll -rather than the safety backstop. +The gateway runs with ``refresh_interval_ms`` at its maximum (60 s), and the +spawn case checks that it finished inside the window before the first sweep, +so the detection it observes must come from the graph-event poll rather than +the safety backstop. Kill-detection latency is intentionally not asserted: rclcpp's graph-event for a departing participant fires only after the executor From bca862d8ad709654c711161ba061eab05528ffda Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Thu, 10 Sep 2026 13:15:08 +0200 Subject: [PATCH 5/8] integration_tests: anchor the graph-event window on the launch description launch_testing builds the description in the test process and only then starts the launch service that forks the gateway, and the gateway arms its backstop timer during its own initialisation. A time taken in generate_test_description() therefore precedes the timer, and the first sweep cannot come earlier than the backstop interval past it. The spawn case now measures its pre-backstop window from that point. The first /health answer, the old reference, is never bounded relative to the timer by the code. --- .../test_graph_event_discovery.test.py | 34 +++++++++++-------- 1 file changed, 19 insertions(+), 15 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 bfde187d8..93639d097 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 @@ -91,15 +91,16 @@ # instrumented work, so the budget scales with the sanitizer factor. SPAWN_DETECTION_TIMEOUT = 15.0 * get_time_scale() -# How long after the gateway first answered /health the spawn case may still -# measure. A measurement inside this budget is one no backstop sweep could have +# How long after the launch description was generated the spawn case may still +# measure. launch_testing builds the description in this process and only then +# starts the launch service that forks the gateway, and the gateway arms its +# backstop timer during its own initialisation, so the timer is armed strictly +# after that anchor and its first sweep cannot come earlier than +# BACKSTOP_INTERVAL_MS past it: a wall timer fires late, never early. A +# detection measured inside this budget is therefore one no sweep could have # served, which is what makes the bound below a statement about the graph-event -# path. The window is derived: the backstop timer is armed during gateway -# initialisation, ahead of start_rest_server(), whose wait for the REST server -# to accept connections is bounded at 5 s, and the test base class then polls -# /health every 0.5 s. So of the 60 s backstop interval about 54 s are still -# ahead of the first sweep once /health answers, and 50 leaves a margin for -# scheduling slack. +# path. The gateway's own startup only widens the window; 50 keeps the +# assertion 10 s clear of the 60 s edge. # # This budget deliberately does NOT scale with MEDKIT_TEST_TIME_SCALE. It is # bounded by the gateway's own backstop interval, which the scale factor does @@ -107,6 +108,10 @@ # first sweep, and the assertion would stop being about the graph-event path. PRE_BACKSTOP_BUDGET_SEC = 50.0 +# Taken when generate_test_description() runs, before launch forks the gateway. +# See PRE_BACKSTOP_BUDGET_SEC for why this is the reference point. +_LAUNCH_DESCRIBED_AT = None + # 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 @@ -121,6 +126,9 @@ def generate_test_description(): + global _LAUNCH_DESCRIBED_AT + _LAUNCH_DESCRIBED_AT = time.monotonic() + gateway_node = create_gateway_node( extra_params={ 'refresh_interval_ms': BACKSTOP_INTERVAL_MS, @@ -180,10 +188,6 @@ 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 @@ -275,10 +279,10 @@ def test_new_node_detected_via_graph_event(self): # 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 + since_launch = time.monotonic() - _LAUNCH_DESCRIBED_AT self.assertLess( - since_health, PRE_BACKSTOP_BUDGET_SEC, - f'detection landed {since_health:.3f}s after the gateway came up, ' + since_launch, PRE_BACKSTOP_BUDGET_SEC, + f'detection landed {since_launch:.3f}s after the launch was described, ' 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', From fb1803d2fee04b1d9d09d5254e37b52fe999e33c Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Thu, 10 Sep 2026 13:15:09 +0200 Subject: [PATCH 6/8] integration_tests: read the last answer only when the recovery poll fails The failure message of the recovery poll performed one more aggregate read while being built, on success as well as on failure, so the warm read that follows was the second read after the poll. Case 4 already reads the last answer only on its failure path; case 7 now does the same. --- .../test/features/test_peer_recovery.test.py | 17 ++++++++++------- 1 file changed, 10 insertions(+), 7 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 4afcd7e4b..10ff79d74 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 @@ -841,11 +841,12 @@ def served(): return answer response = _poll(served, timeout=RECOVERY_TIMEOUT) - self.assertIsNotNone( - response, - 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}', - ) + if response is None: + last = self._aggregate_read_of_peer_topic() + self.fail( + f"a read of {PEER_DECLARED_APP} never carried the member's sample after " + f'its peer came back; last answer was {last.text}' + ) body = response.json() self.assertEqual( @@ -883,8 +884,10 @@ def served(): # 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. + # from it. This is the first read after the one the poll accepted - + # the failure path above is the only other reader, and it never runs + # here - so an empty body 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() From 164ef9b3f453e52f365d2bbf0ecf86e79440bd4e Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Thu, 10 Sep 2026 13:21:36 +0200 Subject: [PATCH 7/8] integration_tests: say what the debounce and the warm read establish The debounce services the first graph event after a quiet period at the next tick and only defers the events that follow inside the window, so the latency comment no longer claims a sub-second detection is impossible. The warm-read comment in the peer recovery case now claims only what the assertion checks: a read that follows a successful one carries the sample. --- .../features/test_graph_event_discovery.test.py | 14 ++++++++------ .../test/features/test_peer_recovery.test.py | 7 +++---- 2 files changed, 11 insertions(+), 10 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 93639d097..c6b10d61a 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 @@ -112,12 +112,14 @@ # See PRE_BACKSTOP_BUDGET_SEC for why this is the reference point. _LAUNCH_DESCRIBED_AT = None -# 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. The budget scales with the sanitizer factor. +# The latency of the graph-event path itself, measured from process spawn. The +# gateway coalesces graph events behind discovery.refresh_debounce_ms, 1000 ms +# by default: the first event after a quiet period is serviced at the next +# 100 ms tick, and every event inside the window that follows waits for the +# window to end. A node coming up raises several events in a row, so its +# detection typically lands one window after its first event. Measured on a +# developer machine with the default settings, the spread is roughly 1 s to +# 3.6 s. The budget scales with the sanitizer factor. GRAPH_EVENT_MAX_LATENCY_SEC = 10.0 * get_time_scale() # Initial discovery shares the budget with full gateway startup, so it scales 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 10ff79d74..17e22fddc 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 @@ -884,10 +884,9 @@ def served(): # 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. This is the first read after the one the poll accepted - - # the failure path above is the only other reader, and it never runs - # here - so an empty body is not a cold-start transient, it is a - # member that serves nothing until asked twice. + # from it. This read follows one that carried the sample, so an empty + # body here is not a cold-start transient, it is a member that goes + # back to serving nothing between reads. warm = self._aggregate_read_of_peer_topic() self.assertEqual(warm.status_code, 200, warm.text) warm_body = warm.json() From aedeb05f7fd0c51a93835132a9bedf37969a146b Mon Sep 17 00:00:00 2001 From: Bartosz Burda Date: Thu, 10 Sep 2026 13:31:18 +0200 Subject: [PATCH 8/8] integration_tests: check the startup discovery against the pre-backstop window too The startup nodes come up after the gateway's own initial discovery, so a refresh has to pick them up, and with the poll budget scaled for the sanitizer jobs that poll outlives the 60 s backstop. The window check the spawn case already makes now covers the startup case as well, so a detection the backstop served fails with the same message in both. --- .../test_graph_event_discovery.test.py | 36 ++++++++++++------- 1 file changed, 24 insertions(+), 12 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 c6b10d61a..31fa57cfd 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 @@ -222,8 +222,29 @@ def _spawn_demo_process(key): stderr=subprocess.DEVNULL, ) + def _assert_before_first_sweep(self, what): + """Establish what a detection measured, before anything is bounded. + + Past PRE_BACKSTOP_BUDGET_SEC a backstop sweep could have served the + detection, and a bound on it would then be reporting on the wrong + mechanism. + """ + since_launch = time.monotonic() - _LAUNCH_DESCRIBED_AT + self.assertLess( + since_launch, PRE_BACKSTOP_BUDGET_SEC, + f'{what} landed {since_launch:.3f}s after the launch was described, ' + 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', + ) + def test_initial_discovery_picks_up_startup_nodes(self): - """Both startup demo nodes must be visible in /apps.""" + """Both startup demo nodes must be visible in /apps. + + The nodes come up after the gateway's own initial discovery, so a + refresh has to pick them up. The window check is what makes this a + statement about the graph-event path. + """ for key in INITIAL_NODES: _, ros_name, _ = DEMO_NODE_REGISTRY[key] data = self.poll_endpoint_until( @@ -235,6 +256,7 @@ def test_initial_discovery_picks_up_startup_nodes(self): timeout=INITIAL_DETECTION_TIMEOUT, interval=0.1, ) + self._assert_before_first_sweep(f'startup discovery of {ros_name}') app_ids = [app.get('id', '') for app in data.get('items', [])] self.assertTrue( any(ros_name in app_id for app_id in app_ids), @@ -278,17 +300,7 @@ 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_launch = time.monotonic() - _LAUNCH_DESCRIBED_AT - self.assertLess( - since_launch, PRE_BACKSTOP_BUDGET_SEC, - f'detection landed {since_launch:.3f}s after the launch was described, ' - 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._assert_before_first_sweep('spawn detection') self.assertLess( elapsed, GRAPH_EVENT_MAX_LATENCY_SEC, f'Spawn detection took {elapsed:.3f}s - expected the '