fix(fault_manager): give the fault at a recording-window boundary its own bag - #594
Open
bburda wants to merge 7 commits into
Open
fix(fault_manager): give the fault at a recording-window boundary its own bag#594bburda wants to merge 7 commits into
bburda wants to merge 7 commits into
Conversation
A fault confirming right after a post-fault recording window finalised found the ring buffer empty by construction - the flush that opened the previous bag moved the whole deque out, and every message published during that window went straight into that bag instead of the buffer. on_fault_confirmed() then warned and returned, so the fault got no bag, no metadata row and no retry: every later GetRosbag for it failed forever. Typically that fault is the second one of a burst, whose post-failure data is exactly what an analysis needs. When the buffer is empty and duration_after_sec > 0, open a writer anyway and enter the normal post-roll state machine. The recording holds the post-fault window only, and because it is the ordinary state machine a further fault of the burst attaches to it as usual. With duration_after_sec == 0 there is no window to record into, so the fault still gets no bag (now logged as such). flush_to_bag() used to return one empty string for both "nothing was buffered" and "the bag could not be written"; those need opposite reactions, so it now reports OK / EMPTY_BUFFER / IO_ERROR and the writer-open block moves into open_bag_writer(), usable with no buffered messages. A post-roll is never opened on top of an I/O failure. duration_sec is computed from the recording's real span instead of the configured windows, which both paths hardcoded. A post-fault-only bag reports roughly duration_after_sec rather than pre+post, and a bag flushed from a partly-filled buffer reports what it holds. The span can exceed pre+post: the ring buffer is pruned only when a message arrives, so a topic that goes quiet keeps its last window buffered and that data is still flushed - deliberate for a black box, and now reported truthfully. test_06 waits for a full buffer accordingly.
The single-writer recording model decides what each fault of a burst gets, and none of it was written down: neither that nothing is buffered while a post-fault window is open, nor what happens to a fault confirming just after one closes, nor what the stored duration_sec actually measures. - config/fault-manager.rst: new "Recording Lifecycle and the Window Boundary" subsection covering the three cases (no recording open, inside a window, right after one closed), the post-fault-only bag and the log line that names it, the duration_after_sec: 0 and I/O-failure cases, zero-message bags, and what duration_sec reports. - tutorials/snapshots.rst: a burst-shaped walkthrough of the same three cases with the practical consequences and how to tell a post-fault-only bag from a full one. - fault_manager README: the capture paragraph now describes the boundary instead of stopping at "single-writer". - fault_manager design doc: a section on the ring buffer and post-roll state machine, with a state diagram, why the buffer is empty at the boundary, the flush outcomes, and how the recording span is tracked.
…appers SqliteStatement and Stmt own a prepared statement and declare a destructor plus deleted copy operations, but not the move ones, which clang-tidy's cppcoreguidelines-special-member-functions reports and which fails the package's lint gate. Both are non-movable by intent (the deleted copy constructor already suppresses the implicit moves), so spelling the move operations out as deleted states that and changes no behaviour.
The writer changed hands outside the lock that clears the recording guard: finalize dropped the guard, released post_fault_timer_mutex_, and only then took writer_mutex_ to reset active_writer_. Clearing that guard is exactly what lets the next confirmation in, so a boundary confirmation could open ITS writer into active_writer_ in the gap and have it destroyed by the finalise still in flight. Its window then recorded through a null pointer with every message silently dropped, and its finalise still stored a row - the failure this branch exists to fix, back as a race and with a row that lies about it. The guard, the start time and the writer now change hands in one critical section; the writer is only closed afterwards, outside both locks, since flushing a bag is real I/O. The resulting lock order is documented at the mutex. Recording spans are measured on the monotonic clock. They were taken from the wall clock that timestamps messages, which is not monotonic: a 220ms backwards step inside a 0.5s post-fault window made a finalise report a completion 220ms before the confirmation that opened the recording, and the duration came out negative and was clamped to zero. The pre-fault history a full bag holds is still a wall-clock quantity, so it is converted to a monotonic start once, at flush time. A metadata-storage failure at finalize no longer leaves the bag behind. Retrieval is keyed by fault code and quota accounting enumerates rows, so a bag with no row occupies disk that nothing can find and nothing can evict; it is discarded instead, as the all-cleared branch already does. Tests cover the race with both threads the production code has (the capture pool confirming, the executor finalising), the storage failure, the attachment cap and a clear arriving inside a post-fault-only window.
Every assertion about the boundary fault's bag was satisfied by a bag with no messages in it. A metadata row, a distinct path, size_bytes > 0 and a non-empty download are all true of a zero-message recording, and this same suite proves one is produced and served, so the claim the work exists for - the bag holds the post-fault window - had nothing pinning it. The integration test now reads the bag back and asserts the captured topic and a non-zero message count; the zero-message case asserts a count of zero, so the first assertion is known to discriminate rather than to be trivially true. The e2e's synchronisation point could not fail. It waited for a sentence the demo node's own fault logs before the burst even starts - guaranteed by the precondition that waits for that fault's recording - and assertWaitFor scans everything received so far, so it matched a stale line. The pattern now carries the fault code. Under a mutation that logs the sentence from the wrong branch, the old pattern stays green and the new one fails. The demo node's own recording is a zero-message post-fault-only bag, so the e2e downloads it and checks the mcap magic bytes, which pins the documented claim that such a bag is still servable, and compares its size against the boundary fault's bag as a content check over HTTP. Also: the deadlines are brought back under a budget the test can meet and the test gets its own, larger one; the @verifies tags move to where the traceability generator can see them.
duration_sec is the span the recording was open, not a span of its content, and the difference is visible: a post-fault-only window during which nothing was published still reports its window rather than zero. The code said one thing and a helper comment said another; all four documentation locations now state the same rule, with the reason. The README was missing the note that the span can exceed the configured pre plus post windows, and the tutorial's "how to tell the bags apart" snippet asserted the very bound the paragraph below it withdraws. Both corrected. The design doc gains the recording hand-off: why the guard, the start time and the writer move together, the resulting lock order and why it is acyclic, what happens to a bag whose row cannot be stored, and the interval during which a writer is being opened and arriving messages still take the buffering path.
Contributor
There was a problem hiding this comment.
Pull request overview
This PR fixes a rosbag snapshot gap in ros2_medkit_fault_manager where a fault confirmed immediately after a post-fault recording window closed could end up with no bag and no metadata row. It also tightens recording finalization ownership to eliminate a boundary race and updates duration reporting to reflect the actual recording span.
Changes:
- Distinguish “empty ring buffer” vs “I/O failure” during flush, and create a post-fault-only bag when
duration_after_sec > 0and the buffer is empty (#574). - Make recording ownership transfer (guard/start-time/writer) atomic with respect to finalize vs new confirmations, and compute/store honest
duration_secfrom a monotonic clock span. - Add unit + integration + end-to-end tests for boundary behavior (sqlite3 + mcap) and update docs to describe the recording lifecycle and window-boundary semantics.
Reviewed changes
Copilot reviewed 14 out of 14 changed files in this pull request and generated no comments.
Show a summary per file
| File | Description |
|---|---|
| src/ros2_medkit_integration_tests/test/features/test_rosbag_boundary_download.test.py | New end-to-end gateway HTTP regression test covering boundary bag listing/detail/download behavior. |
| src/ros2_medkit_integration_tests/CMakeLists.txt | Extends timeout for the new boundary download feature test to avoid slow-runner timeouts. |
| src/ros2_medkit_fault_manager/test/test_rosbag_integration.test.py | Updates duration semantics assertions and strengthens the buffer-refill guard for reliable duration validation. |
| src/ros2_medkit_fault_manager/test/test_rosbag_capture.cpp | Adds extensive boundary-focused integration coverage (post-only bags, duration honesty, I/O failure recovery, finalize race). |
| src/ros2_medkit_fault_manager/test/test_rosbag_boundary.test.py | New parametrized integration tests (sqlite3 + mcap) for boundary behavior and zero-message post-only bags. |
| src/ros2_medkit_fault_manager/src/sqlite_fault_storage.cpp | Makes SQLite statement RAII wrapper explicitly non-movable (clarifying intent). |
| src/ros2_medkit_fault_manager/src/rosbag_capture.cpp | Implements boundary post-only recording, flush status differentiation, monotonic duration tracking, and race-safe finalize ownership transfer. |
| src/ros2_medkit_fault_manager/src/fault_audit_log.cpp | Makes audit-log statement RAII wrapper explicitly non-movable (clarifying intent). |
| src/ros2_medkit_fault_manager/README.md | Documents the single-writer lifecycle, boundary post-only bags, and the updated meaning of duration_sec. |
| src/ros2_medkit_fault_manager/include/ros2_medkit_fault_manager/rosbag_capture.hpp | Adds flush outcome types and documents lock ordering and boundary recording semantics; introduces monotonic start tracking field. |
| src/ros2_medkit_fault_manager/design/index.rst | Adds a detailed design section for the rosbag black-box state machine, boundary case, ownership transfer, and duration semantics. |
| src/ros2_medkit_fault_manager/CMakeLists.txt | Increases rosbag capture GTest timeout and adds/labels the new boundary launch test with an appropriate timeout. |
| docs/tutorials/snapshots.rst | Adds user-facing explanation of burst behavior at the window boundary and clarifies duration_sec semantics. |
| docs/config/fault-manager.rst | Expands configuration docs with a full “recording lifecycle and boundary” section including post-only bags and duration meaning. |
TSan on CI reported a data race between rclcpp::CallbackGroup::add_timer on the thread confirming a fault and ~WallTimer on the thread running the executor. Both sides are production shapes: on_fault_confirmed runs on a CaptureThreadPool worker and created a wall timer there, while the executor thread ran the previous window's callback and dropped that timer. Creating and destroying a timer both mutate rcl's clock jump-callback list, and the two coincide precisely when one fault confirms as the previous window closes - the burst-at-the-boundary case this code exists to serve. post_fault_timer_mutex_ cannot close it. It guards our member, not rclcpp's internals, and the destruction is not ours to lock: the executor holds the last reference in AnyExecutable::timer and releases it after the callback returns, outside any mutex we could take. So the timer is no longer replaced per recording. It is created once and re-armed with rcl_timer_reset, which restarts the period and clears the cancelled flag, and finalize only cancels it. One recording or a hundred now perform a single create_wall_timer and no destroy. The node-mutating calls that remain - that one creation, the discovery timer, the capture subscriptions and their teardown - are serialised under node_ops_mutex_, the same remedy SnapshotCapture already uses for this class of race. It is innermost in the lock order documented at post_fault_timer_mutex_ and is never held across bag I/O. The discovery timer still releases its own shared_ptr from inside its callback, so the executor can hold the last reference there too. That is pre-existing, far rarer, and left alone here.
mfaferek93
reviewed
Aug 6, 2026
| // be able to evict it. Discard it for the same reason the all-cleared branch | ||
| // above does. | ||
| std::error_code ec; | ||
| std::filesystem::remove_all(bag_path, ec); |
Collaborator
There was a problem hiding this comment.
This catch assumes nothing can reference the bag yet, but enforce_storage_limits() on line 1255 runs after store_rosbag_files() has already committed and can still throw (SQLITE_FULL, a failed DELETE, a prepare error). Then remove_all deletes a directory that committed fault rows point at, and those rows keep counting toward the quota until GetRosbag notices the files are gone - before this change the path just warned and kept the bag. Moving enforce_storage_limits() below the try, or only discarding when the store itself threw, restores the invariant this comment states.
mfaferek93
reviewed
Aug 6, 2026
| "Failed to store rosbag metadata for '%s' (%s); discarded the bag, nothing could reference it", | ||
| bag_path.c_str(), e.what()); | ||
| } | ||
| } |
Collaborator
There was a problem hiding this comment.
L1273-1276 clears active_capture_topics_ after post_fault_timer_mutex_ was already released, so a capture armed in that gap loses its entity filter and records every topic instead of the scoped set. Clear it while the finalize lock is still held, or skip the clear when a new recording has started.
| // path, and safe for a different reason: no post-roll state was published for | ||
| // this recording, so no finalise can be running for it, and confirmations are | ||
| // serialised against each other by the node-level rosbag mutex. | ||
| info.duration_sec = span_sec_since(recording_started_at_ns_.exchange(0)); |
Collaborator
There was a problem hiding this comment.
The duration_after_sec == 0 path calls store_rosbag_file() at L435 without the try/catch + remove_all you just added to the finalize path, so a throwing store still leaves an orphan bag dir here - same failure the PR closes. Probably cleanest as one small store-or-discard helper both paths call.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Pull Request
Summary
A fault confirmed right after a post-fault recording window closed got no bag and no record.
During a post-fault window the capture writes messages directly to the bag and stops filling the ring buffer. The flush that started the window already emptied that buffer. So a fault confirmed a few milliseconds after the window closes finds an empty buffer.
flush_to_bagreturned an empty path, the caller only logged a warning, no row was written, and nothing tried again.GetRosbagthen reported failure forever.This is the case the feature exists for. Faults often arrive in bursts from one root cause, and the second fault of a burst is the one that landed in this gap.
Now, when the buffer is empty and
duration_after_sec > 0, the capture opens a writer anyway and records only the post-fault window. The second fault of a burst gets its own bag with the data from after the failure. An empty buffer and a real I/O error are now two different results, so a post-fault recording never starts after a failed open. There is no database schema change and no service definition change.Two related fixes:
The stored
duration_secwas the configured window. It is now the real length of the recording, measured with the steady clock. A post-fault-only bag reports aboutduration_after_sec. A bag flushed from a partly filled buffer reports what it really holds. The value can be larger thanduration_sec + duration_after_sec. The ring buffer is pruned when new messages arrive, so a topic that stops publishing keeps its last window, and that data is still written to the bag. This is intended. The last messages before a topic stopped are the ones that matter most after a failure. It is now described in the documentation.Handing a recording from a closing window to a new one was split across two locks. A fault confirmed in that gap installed its own writer. The finalisation that was still running then took that writer away. The new recording wrote through a null pointer, every message was dropped, and a row was still stored for the empty bag. The result is the same bug as above, this time as a race, and with a database row that says a bag exists. The guard, the start time and the writer now change owner in one critical section. The bag is closed after that, outside both locks.
Issue
Type
Testing
Every new test was first run against the old code, to check that it fails, and that it fails for the right reason.
Unit and integration tests cover the boundary case: the second fault gets a bag and a row, on both the sqlite3 and the mcap backend. A fault confirmed inside a window still joins the running recording, as before.
The content of the bag is now checked, not only that a file exists. The bag is read back with
rosbag2_py, the metadata is checked in the unit test, and the download size is compared over HTTP. This matters because a bag with zero messages still has a file size above zero. A test that only checks for a non-empty download cannot see the difference.An end to end test runs the burst against a running gateway and downloads the bag of the second fault over HTTP.
The race is covered by making the gap wider with a sleep in the test only. Without the fix, the log shows the second recording taking the writer, the finalisation removing it, and the bag closing with zero messages while a row is stored. With the fix the same test passes.
Degenerate configuration is covered:
duration_after_sec: 0, a storage path that cannot be written, a recording that receives no messages at all, and the defaulttopics: entitymode.Build, linters, unit tests, integration tests, clang-tidy and the documentation build pass. One integration test fails,
test_opcua_secured. It fails the same way on branches that contain none of this work.Checklist
The fault manager configuration page, the snapshots tutorial, the package README and the design document now describe the recording lifecycle and the behaviour at the window boundary. The design document had no section about the ring buffer and the post-fault state machine before.
Known, not fixed here
A fault cleared while its bag is still opening keeps its row. The clear finds no active recording and no row yet, and the finalisation inserts the row after that. With
auto_cleanup: truethe cleanup is then missed. This is not new and not limited to the boundary case. The existing full-bag path has the same problem. The fix means changing the order of confirm and clear handling in the fault manager node, which is larger than this change. It needs its own issue.