diff --git a/src/ros2_medkit_integration_tests/CMakeLists.txt b/src/ros2_medkit_integration_tests/CMakeLists.txt index dab635448..d0c44b9c0 100644 --- a/src/ros2_medkit_integration_tests/CMakeLists.txt +++ b/src/ros2_medkit_integration_tests/CMakeLists.txt @@ -321,6 +321,13 @@ if(BUILD_TESTING) # round trip on the patient aggregator, twice, and then polls after killing # the peer. Two of those plus three gateway startups exceed the default. # + # test_relay_peer_credential launches three gateways plus a fault_manager, + # holding three extra domains for its two aggregators and the peer beside + # the launcher's own, and setUpClass waits for both aggregators to answer + # before separately holding a 60s wait, scaled, for the fault_manager node + # to appear on the peer's domain - before a single test case runs. Three + # startups plus those two sequential waits exceed the default. + # # test_aggregator_fault_stream spends most of its budget waiting rather than # working: a closed SSE connection is noticed at the peer's next keepalive, # 30s away, and the test settles the peer's occupancy before each measurement @@ -338,6 +345,7 @@ if(BUILD_TESTING) set(_MEDKIT_TEST_TIMEOUT_OVERRIDES test_aggregation_time_budgets 300 test_peer_failure_reasons 300 + test_relay_peer_credential 300 test_aggregator_fault_stream 420 test_auth_policy_contract 300 test_rosbag_boundary_download 180 diff --git a/src/ros2_medkit_integration_tests/test/features/test_aggregation_time_budgets.test.py b/src/ros2_medkit_integration_tests/test/features/test_aggregation_time_budgets.test.py index c827d9726..71362de47 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_aggregation_time_budgets.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_aggregation_time_budgets.test.py @@ -111,7 +111,9 @@ LIDAR_APP = 'remote_lidar' PEER_NAMESPACE = '/chassis/sensors' -TIMEOUT = DISCOVERY_TIMEOUT * get_time_scale() +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +TIMEOUT = DISCOVERY_TIMEOUT PEER_MANIFEST = f"""\ manifest_version: "1.0" @@ -288,7 +290,7 @@ def test_b1_operation_past_the_metadata_budget_returns_the_peers_result(self): response = requests.post( f'{GENEROUS_URL}/apps/{SLOW_APP}/operations/calibrate/executions', json={}, - timeout=(GENEROUS_FORWARD_MS / 1000.0 + 10) * get_time_scale(), + timeout=GENEROUS_FORWARD_MS / 1000.0 + 10 * get_time_scale(), ) elapsed = time.monotonic() - started @@ -367,7 +369,7 @@ def test_b2_large_resource_arrives_whole_through_the_aggregator(self): through = requests.get( f'{GENEROUS_URL}/apps/{LIDAR_APP}/data/{resource}', - timeout=(GENEROUS_FORWARD_MS / 1000.0 + 20) * get_time_scale(), + timeout=GENEROUS_FORWARD_MS / 1000.0 + 20 * get_time_scale(), ) self.assertEqual( through.status_code, 200, diff --git a/src/ros2_medkit_integration_tests/test/features/test_aggregator_fault_stream.test.py b/src/ros2_medkit_integration_tests/test/features/test_aggregator_fault_stream.test.py index a17e09d7f..b76389a24 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_aggregator_fault_stream.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_aggregator_fault_stream.test.py @@ -90,7 +90,9 @@ SERVICE_NAME = '/fault_manager/report_fault' FAULT_MANAGER_NODE = 'fault_manager' -TIMEOUT = DISCOVERY_TIMEOUT * get_time_scale() +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +TIMEOUT = DISCOVERY_TIMEOUT # Both gateways run with this, so a disconnect is seen in about a second rather # than thirty. The test asserts on WHETHER a slot is released, not on how fast, diff --git a/src/ros2_medkit_integration_tests/test/features/test_manifest_config_key.test.py b/src/ros2_medkit_integration_tests/test/features/test_manifest_config_key.test.py index 9aaa1db1e..04bcd78fd 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_manifest_config_key.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_manifest_config_key.test.py @@ -129,8 +129,9 @@ def _base_url(port): # seconds. The gateways refresh every 1000 ms, so this spans several passes. # Soak duration, not a budget - see the note above; left unscaled on purpose. HOLD_SEC = 4.0 -# Was a private 60.0; this is the shared discovery budget, scaled. -POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT * TIME_SCALE +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT POLL_INTERVAL_SEC = 0.5 # How long a single HTTP call has to come back. HTTP_TIMEOUT_SEC = 5.0 * TIME_SCALE diff --git a/src/ros2_medkit_integration_tests/test/features/test_manifest_malformed_config.test.py b/src/ros2_medkit_integration_tests/test/features/test_manifest_malformed_config.test.py index d3d76b7e7..28a358aec 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_manifest_malformed_config.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_manifest_malformed_config.test.py @@ -119,8 +119,9 @@ def _base_url(port): # expensive - which is load this file would be adding, not absorbing. TIME_SCALE = get_time_scale() -# Was a private 60.0; this is the shared discovery budget, scaled. -POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT * TIME_SCALE +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT POLL_INTERVAL_SEC = 0.5 # How long a single HTTP call has to come back. HTTP_TIMEOUT_SEC = 5.0 * TIME_SCALE diff --git a/src/ros2_medkit_integration_tests/test/features/test_merge_provenance.test.py b/src/ros2_medkit_integration_tests/test/features/test_merge_provenance.test.py index 9892a4e43..691052dba 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_merge_provenance.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_merge_provenance.test.py @@ -163,8 +163,9 @@ def _base_url(port): SAMPLE_COUNT = 12 SAMPLE_DEADLINE_SEC = 70.0 * TIME_SCALE -# Was a private 60.0; this is the shared discovery budget, scaled. -POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT * TIME_SCALE +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT POLL_INTERVAL_SEC = 0.5 # How long a single HTTP call has to come back. HTTP_TIMEOUT_SEC = 5.0 * TIME_SCALE diff --git a/src/ros2_medkit_integration_tests/test/features/test_peer_failure_reasons.test.py b/src/ros2_medkit_integration_tests/test/features/test_peer_failure_reasons.test.py index c57c49c90..0d2275864 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_peer_failure_reasons.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_peer_failure_reasons.test.py @@ -55,10 +55,10 @@ from ros2_medkit_test_utils.constants import ( ALLOWED_EXIT_CODES, API_BASE_PATH, + DISCOVERY_INTERVAL, DISCOVERY_TIMEOUT, get_test_domain_id, get_test_port, - get_time_scale, ) from ros2_medkit_test_utils.launch_helpers import create_gateway_node @@ -80,7 +80,9 @@ TIGHT_METADATA_MS = 800 PATIENT_METADATA_MS = 20000 -TIMEOUT = DISCOVERY_TIMEOUT * get_time_scale() +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +TIMEOUT = DISCOVERY_TIMEOUT PEER_COMPONENT = 'remote-ecu' UNRESPONSIVE_APP = 'remote_unresponsive_param' @@ -240,13 +242,40 @@ def _wait_for_healthy_peer_or_self(cls, base_url, label): raise AssertionError(f'{label} gateway never saw a healthy peer; last saw {last}') def _fan_out_failure(self, base_url, timeout): - response = requests.get(_config_url(base_url), timeout=timeout) - self.assertEqual( - response.status_code, 200, - f'a fanned-out listing whose peer failed must still answer 200: ' - f'{response.status_code} {response.text[:400]}') - ext = response.json().get('x-medkit', {}) - self.assertTrue(ext.get('partial'), f'the answer does not admit it is partial: {ext}') + # Until a discovery pass has both marked the peer healthy and published + # it as a contributor to this entity, the aggregator answers 200 with no + # `partial` - a correct answer about a peer it does not yet know + # contributes here. Health alone does not imply it: the two are set at + # opposite ends of the same background pass, and the fetch between them + # spends the aggregator's whole metadata budget. So a reason is readable + # only once the fan-out is in the answer, and this waits for that on the + # discovery budget, which is what it is waiting for. + deadline = time.time() + TIMEOUT + ext = {} + response = None + last_error = None + while time.time() < deadline: + try: + response = requests.get(_config_url(base_url), timeout=timeout) + except requests.RequestException as exc: + last_error = str(exc) + time.sleep(DISCOVERY_INTERVAL) + continue + self.assertEqual( + response.status_code, 200, + f'a fanned-out listing whose peer failed must still answer 200: ' + f'{response.status_code} {response.text[:400]}') + ext = response.json().get('x-medkit', {}) + if ext.get('partial'): + break + time.sleep(DISCOVERY_INTERVAL) + if response is None: + raise AssertionError( + f'no response arrived from {base_url} within {TIMEOUT:.0f}s: {last_error}') + self.assertTrue( + ext.get('partial'), + f'no answer admitted it was partial within {TIMEOUT:.0f}s: {ext}' + + (f' (last request error: {last_error})' if last_error else '')) # R4: the existing key keeps its existing shape. self.assertEqual( ext.get('failed_peers'), ['remote_gateway'], diff --git a/src/ros2_medkit_integration_tests/test/features/test_plugin_entity_survives_ignore.test.py b/src/ros2_medkit_integration_tests/test/features/test_plugin_entity_survives_ignore.test.py index 6ad203e85..0cfbd7da1 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_plugin_entity_survives_ignore.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_plugin_entity_survives_ignore.test.py @@ -77,8 +77,9 @@ # expensive - which is load this file would be adding, not absorbing. TIME_SCALE = get_time_scale() -# Was a private 60.0; this is the shared discovery budget, scaled. -POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT * TIME_SCALE +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +POLL_TIMEOUT_SEC = DISCOVERY_TIMEOUT # The plugin's entities appear within a pass or two when protection works. A # short budget for "is it there" keeps a genuine deletion failing fast with a # diagnostic, instead of every test burning the long timeout and the whole diff --git a/src/ros2_medkit_integration_tests/test/features/test_relay_peer_credential.test.py b/src/ros2_medkit_integration_tests/test/features/test_relay_peer_credential.test.py index 9657c8216..9d3669288 100644 --- a/src/ros2_medkit_integration_tests/test/features/test_relay_peer_credential.test.py +++ b/src/ros2_medkit_integration_tests/test/features/test_relay_peer_credential.test.py @@ -98,7 +98,9 @@ SERVICE_NAME = '/fault_manager/report_fault' FAULT_MANAGER_NODE = 'fault_manager' -TIMEOUT = DISCOVERY_TIMEOUT * get_time_scale() +# DISCOVERY_TIMEOUT already carries the sanitizer time scale; applying the +# scale again would square it. +TIMEOUT = DISCOVERY_TIMEOUT KEEPALIVE_SEC = 2 diff --git a/tsan_suppressions.txt b/tsan_suppressions.txt index 1d66c38be..44e964327 100644 --- a/tsan_suppressions.txt +++ b/tsan_suppressions.txt @@ -70,15 +70,50 @@ deadlock:rclcpp::Context* # rclcpp GenericClient: std::future shared state racing between the # executor thread that fulfils the response promise (_M_do_set -> # unique_ptr::swap) and the caller thread reading via future::get(). -# The happens-before is established by rclcpp's pthread_once around -# _State_baseV2::wait, but TSan does not see pthread_once as -# synchronisation when the wait completes after the promise was -# already satisfied. Suppress the standard-library frames that surface -# the rclcpp/glibc internal synchronisation - the race lives in the -# stdc++ future implementation, not in our handlers. +# The setter runs under libstdc++'s call_once and then release-stores +# _State_baseV2::_M_status; wait() synchronises against that with an +# acquire load on the same atomic. TSan does model call_once and atomic +# acquire/release, but for GenericClient the setter chain +# (handle_response -> promise::set_value -> _M_set_result) is compiled +# into librclcpp, so the release store is uninstrumented and that side +# of the edge is invisible to it - the race lives in the rclcpp/glibc +# internal synchronisation, not in our handlers. rclcpp::Client's own +# handle_response is a header template instantiated in our binaries, +# where the same store IS instrumented, so these reports do not arise +# there. Suppress the standard-library frames that surface the +# GenericClient case. race:std::__future_base::_State_baseV2* race:std::__uniq_ptr_impl*_Result_base* race:std::unique_ptr*_Result_base* +# Same shared state, its _Result object rather than the state itself. The +# executor thread drops the last reference to a client future's shared +# state, and the report shows the freeing frame unsymbolized inside +# librclcpp. TSan intercepts the operator delete, since that is instrumented +# in the allocator, but never saw the acquire on the shared_ptr refcount +# that would have ordered it after the caller's read, so it pairs the free +# with the caller's read of _Result_base::_M_error inside _M_get_result. +# Anchored on rclcpp::detail::FutureAndRequestId::get() (client.hpp): it is +# the read side of this report, and of any get() through the wrapper, it is +# header code compiled into our binaries so it is always symbolized, and it +# names exactly the class - a future rclcpp handed us for a client request - +# without matching any std::future the gateway builds itself (run_sync, the +# aggregation and configuration fan-outs, the topic sampler). The pattern is +# anchored on ::get() rather than left open at the end: the wrapper's other +# members (the destructor, wait_for) are deliberately not matched here - a +# report on them would be a different report and gets its own line with its +# own evidence. A module pattern such as race:librclcpp.so would also match +# the unsymbolized frame - TSan matches function, file and module name as an +# unanchored substring - but it would suppress every report with any +# librclcpp frame on either stack, ours or not. +race:rclcpp::detail::FutureAndRequestId*::get() +# On Humble, rclcpp::GenericClient does not exist (Iron+ only); the +# gateway's own compat::GenericServiceClient stands in for it +# (generic_client_compat.hpp), and its FutureAndRequestId::get() is the +# same read through the same library state as the pattern above. Named +# explicitly rather than left to the general rule above - the same +# narrow, named exception to the "never suppress our code" rule as the +# OperationManager::call_service suppression below. +race:ros2_medkit_gateway::compat::GenericServiceClient::FutureAndRequestId::get() # rclcpp GenericClient response staging: the executor thread fills the # generic response via rclcpp::GenericClient::create_response() before @@ -117,7 +152,8 @@ race:rclcpp::GenericClient::create_response* # racing WRITES live in rclcpp/libstdc++ (create_response, std::string mutate); # our OperationManager::call_service frame is only the consumer of a value the # std::future contract hands us once the promise is satisfied - the -# happens-before that rclcpp establishes via pthread_once is invisible to TSan. +# release-store side of that handoff runs inside uninstrumented librclcpp, +# so TSan never sees it and pairs the write with our read instead. # We must match on this frame because the adjacent librclcpp create_response # frame is frequently UNSYMBOLIZED ( at librclcpp.so+0x14xxxx), so the # create_response symbol line above does not catch those reports. A library