Worktree traces prometheus scraper - #13
Merged
Merged
Conversation
Adds an opt-in TRACES_ENABLED stream that polls a co-located OM1 process's GET /traces/metrics endpoint (see OM1's internal/tracer/traceexport) using the real Prometheus exposition-format parser, and appends any new records to the current session's traces.jsonl. No new upload-path logic is needed: openmind-api assigns the S3 prefix per session directory, so this file rides the existing jsonl-to-json conversion and upload pipeline like every other stream. It's a persistent stream (like the DDS/RTSP ones): one poll loop and one in-memory dedup cursor (the newest trace timestamp written) live for the process's lifetime, with Rotate() only swapping the output file -- so OM1 re-serving its whole buffer on every poll never produces duplicate lines across a session rotation. Verified end-to-end against a real OM1 build (this repo's committed tracer/metrics/traceexport code) driving the compiled om1-telemetry binary through several rotations with no duplicate or missing records. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
jsonlToJSONArray packed the whole array onto a single line, making traces.json (and every other converted stream) unreadable and undiffable once uploaded. Insert a newline after the opening bracket and between elements so each record keeps its own line, matching the source .jsonl's readability -- still a plain JSON array, whitespace between tokens doesn't change parsing. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Found by cross-referencing a real session against what actually landed in the bucket: only ~6 tiny files (meta.json, network_status.csv, a couple-KB lidar/pointcloud fragment) made it, all timestamped 2 seconds after the session opened -- not the session's real ~5 minute run. Root cause: session.ListClosed doesn't verify a directory is actually closed, despite the name -- it lists every dated directory, including one session.OpenNext just created. The only thing excluding the live session from the retention sweep is comparing it against cmd/main's in-memory "current" pointer, which isn't updated atomically with the directory's creation on disk (a handful of statements run in between). A sweep tick landing in that gap sees a brand-new, virtually-empty directory as neither current nor uploaded, uploads it, and marks it complete -- after which the server reports the session already complete, so the real end-of-session upload silently no-ops and the rest of the session's files are never sent, with no error anywhere. Fix: protected() (shared by catch-up uploads and cap enforcement) now also excludes any directory younger than minSessionAge (30s, by its own recorded start time) regardless of the current-dir check -- a generous margin around a race window that's really microseconds wide. Also corrected ListClosed's doc comment, which claimed a guarantee the implementation never provided. Verified the new test reproduces the exact bug on the pre-fix protected() (temporarily disabled just that clause, confirmed the directory gets uploaded and marked complete, restored the fix). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Found by cross-referencing a fresh session's traces.json against its own recorded time window: 174 records spanning 21:25:54-22:51:42 landed in a session that only ran 22:47:39-22:52:39. The dedup cursor only ever lived in memory, so restarting om1-telemetry (as I'd just done to deploy the retention fix) reset it to zero -- OM1's exporter was still serving its ~200-record buffer regardless, and every one of those records looked new to the fresh process, so they all got written into whatever session happened to be open at that moment. Adds CursorFile to traces.Config: the newest written timestamp is persisted to RECORDINGS_DIR/.traces_cursor (outside the rotating session directories, since it must survive more than one session) and reloaded on Start. Rotate's existing in-memory cursor still handles session-to-session continuity within one process; this closes the gap across a full restart. Verified the new test reproduces the exact bug with loadCursor's call site commented out, then confirmed the fix. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
…anual container restart Root cause of the pointcloud gap found while cross-checking Iris's uploaded data: the Livox mid360 was genuinely publishing (confirmed independently via `ros2 topic hz`/`ros2 topic info -v`), and a fresh process's reader matched it immediately, but the long-lived reader already running in om1-telemetry never received a single message the entire time it was up. Plain DDS discovery isn't fully self-healing here: a writer announces itself with a burst of discovery packets right after it (re)starts, then falls back to a slow steady-state interval. A reader that's already been idle for a while doesn't keep re-broadcasting its own interest, so if that initial burst is lost -- and the container's own CycloneDDS trace logs show real `ddsi_udp_conn_write ... failed` errors, i.e. genuine packet loss on this link -- the reader can miss a restarted writer indefinitely. Only a brand-new reader (this rebuild, or an ad hoc `ros2` subscriber) reliably gets a clean handshake. heartbeat.Monitor already detects this exact condition (the "recorder NOT WORKING ... never received any message" warning) but previously only logged it. Added RegisterRecoverable: an optional reconnect callback invoked once per check interval for as long as a stream stays broken (guarded against overlapping in-flight calls). Wired the five DDS-backed streams (lidar, pointcloud, depth, odom, lowstate) to it via a new Reconnect() method that tears down and recreates just that stream's DDS participant/reader -- forcing a fresh discovery burst -- without touching output files or rotation state. main.go's registerHeartbeats now needs the current persistentStreams to bind each reconnect callback, but stream objects don't exist yet at the first call site (before startRecorders runs). Resolved with a lazily-evaluated closure over `rs` (declared before its first assignment) rather than reordering every call site -- reconnect callbacks are only ever invoked later, from the heartbeat monitor's own goroutine, by which point `rs` is always set. Verified: internal/lidar/reconnect_test.go publishes real samples over a loopback CycloneDDS domain, calls Reconnect() mid-stream, and confirms a sample published afterward is still received -- proving the teardown/recreate cycle doesn't break reception. New heartbeat tests confirm RegisterRecoverable calls reconnect only while broken, not while healthy, and never overlaps two in-flight reconnects. Full suite and lint pass. Deployed to the live robot and confirmed empirically: after rebuilding and restarting om1-telemetry, the fresh pointcloud reader matched the already-running Livox mid360 writer immediately and has been recording steadily since (order of thousands of records, no further "NOT WORKING" warnings). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Cleanup pass over this session's changes: removed comments inside function bodies and trimmed doc comments above functions/methods down to 1-2 lines. No behavior change. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Follow-up to the earlier comment cleanup: that pass only trimmed comments before functions/methods and missed several large ones attached to consts, types, fields, and a package doc. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Matches the corresponding OM1-side change: om1_trace_info moved off its own separate registry onto the default one, so it's now served at /metrics rather than /traces/metrics. Updated TRACES_URL's default and the surrounding docs/comments accordingly -- no change to the poller's own parsing logic, which already just looks up the om1_trace_info family by name regardless of what else is on the page. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
…k drift Root cause of the audio/video-in-wrong-session bug flagged earlier this session: finishSegment reconstructed a segment's real-world start as processStart + startSeconds, where processStart is fixed at the ffmpeg process's launch (hours ago, for these persistent streams) and startSeconds is ffmpeg's own segment-relative offset. ffmpeg's segment muxer times cuts off the incoming RTSP stream's own presentation timestamps, which can drift from wall-clock at a slightly different rate than Go's real-wall-clock rotation ticker. That per-rotation drift accumulates over the whole process's uptime, so on a long-running process a segment cut right at a rotation boundary can compute to the wrong side of it -- observed live on the robot: an audio segment for session N+1's window landed in session N's directory. Fixed by no longer trusting the accumulated processStart offset at all: watchSegments now reads both start_seconds and end_seconds from ffmpeg's segment_list CSV, and finishSegment reconstructs each segment's start by taking a fresh wall-clock/mono reading at the moment the segment is reported closed and subtracting just that one segment's own (end - start) duration. Each segment's timestamp is now anchored independently to an up-to-date clock reading, so error is bounded to one segment's own span instead of compounding over the process's entire uptime. Applied identically to internal/audio and internal/video (same structure, same bug). New regression tests in both packages (TestFinishSegment_notMisledByAccumulatedProcessDrift) construct a segment that truly starts 1s after a rotation boundary and runs a full 5-minute span before closing, and assert it lands in the new session -- the scenario a long-running process's accumulated drift used to get wrong. Updated existing finishSegment/watchSegments/ parseSegmentListLine call sites for the new signatures. Full suite and lint pass. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Root cause of the S3 data-loss another Claude session found by comparing robot-local files against S3 directly: sessions marked .uploaded locally, with files still present on the robot, that had video/audio (and sometimes everything but metadata) genuinely missing from S3 -- ~33% of all 830 sessions surveyed, spiking to 99-100% on Aug 28-29, still 40% on Sep 1. UploadSession called createSession, and if the server's response reported the session as already "complete", returned immediately without uploading anything. Retention only calls UploadSession for a session lacking a local .uploaded marker -- so the client's own view is always "not done yet" whenever this runs. The only time the server's "complete" status could disagree with that is exactly the failure case: a prior attempt uploaded some files (e.g. small metadata) before failing on something larger (a multipart video/audio file, a transient network error, anything), got marked failed server-side, and left no local .uploaded marker so retention retried it later. On that retry, if the server's account of the session looked "complete" for any reason, this shortcut skipped uploading the still-missing files entirely and returned success -- writing the local .uploaded marker as if nothing were missing, permanently. Fixed by removing the shortcut: UploadSession now always uploads every currently-present local file and only writes .uploaded after that upload actually completes from the client's own perspective, regardless of what the server reports up front. Re-uploading an already-complete session's files is a harmless, cheap no-op (S3 PUTs and presigned-POST/multipart flows are all safe to repeat) -- skipping a re-upload was never worth the risk of silently dropping data when client and server state disagree. Also dropped the now- unused Status field this decision was the only reader of. Verified with git stash on client.go alone: the new regression test (TestUploadSession_uploadsEvenWhenServerReportsAlreadyComplete) fails against the old code with the exact missing-file signature, and passes with the fix restored. Full suite and lint pass. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o
Ported from worktree-upload-S3-bucket (commit 6be805c). ffmpeg only reports a segment closed (and relocatable into its session directory) a full segment_time after it began -- the same duration as the session rotate interval -- so that close notification lands at roughly the same instant as the *next* rotation, not this one. Upload was triggered immediately on "session rotated" and took a one-shot os.ReadDir snapshot of the directory, so it consistently raced ahead of the session's own video/audio and shipped without them. This is a different bug from da78810's server-status-skip fix: that one stops a *retry* from silently accepting a stale "complete" status with files still missing; this one stops the *first* upload attempt from missing them in the first place. Both are needed. Give video/audio streams a per-target ready signal, closed once finishSegment relocates that session's first segment (or determines it never will, on a relocation error, so a permanent failure doesn't cost a full timeout on every future upload). Add WaitSegment so a caller can block on it, and thread an optional awaitReady callback through UploadFinishedSessionAsync/UploadSession, invoked before the directory is listed. main.go wires it at both call sites that upload a just-finished session (rotation and schedule-driven pause) to wait on the persistent video/audio streams; catch-up sweeps and the final shutdown upload (already preceded by a synchronous Stop() that drains the last segment) pass nil, since neither needs it. Adapted to this branch's finishSegment(scratchFile, duration, observedNow, observedMonoNs) signature from e50c56c (upload-S3-bucket still used the older processStart/startSeconds form) -- the wait logic itself is unchanged, since it only needs the resulting target, not how its timestamp was derived. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016o2Qem6WxyDBJpKotKFkKS
…ilds
Without this, `docker build` picks up whatever .cyclonedds/.draco a dev
worktree happens to have on disk (built for the host's glibc) via COPY . .,
and the Makefile's already-installed check reuses it instead of rebuilding
for the image's musl/Alpine builder stage -- idlc then fails to exec
("idlc: not found", actually an incompatible-binary error). Also excludes
.env and other .gitignore'd paths that have no business in a build context.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HcFEZMmK9xhXsKjtFyiqRi
Trims the oversized doc comments this branch introduced (UploadSession, UploadFinishedSessionAsync, awaitSegments, WaitSegment x2, its regression test) down to the project's usual 1-2 line convention. No logic changes. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
CatchUpUploads treated any directory holding the live boot clock journal as fully protected, same as EnforceRetentionCap. That's correct for deletion, but for uploads it means a single failed upload-on-rotation attempt for the very first session of a boot (e.g. a timeout talking to the API) is never retried for the rest of the process's uptime -- UploadOptions already excludes the live journal itself via PreserveJSONL, so there was never a reason to skip the rest of that directory's files too. Observed on a live device: the first session after a boot lost its one upload attempt to a transient API timeout and sat unswept for 4+ days, quietly eating into the retention cap and contributing to retention deleting other, never-uploaded sessions to stay under it. Split the single `protected` predicate into `uploadProtected` (just the currently-open directory, plus the too-young-to-sweep guard) and `deleteProtected` (that, plus the boot session directory) in both Sweep and RunSweeps. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH
This reverts commit c665e42.
This reverts commit c6c35b6.
RegisterRecoverable's reconnect only recreates the DDS reader, which can loop forever without ever restoring data if the real fault is upstream of the reader (observed live: pointcloud reconnected every 30s for 50+ minutes straight with zero effect, while lidar/odom recovered from the same incident within one reconnect). Only a full process restart -- a fresh DDS participant -- actually cleared it. Adds Monitor.SetStuckThreshold: after N consecutive failed checks for a recoverable stream, it fires a handler once instead of retrying the same ineffective action forever. main.go wires that into the existing shutdown path (same session-close/upload sequence as SIGINT/SIGTERM) and exits non-zero so the container's restart policy brings up a genuinely fresh process. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
WaitSet.Wait returned immediately on any dds_waitset_wait error, and every caller's poll loop does "on error, continue" with no backoff of its own. For a reader whose entity errors persistently (observed: depth, which has no camera publisher on this robot) that's an unthrottled busy loop -- confirmed via profiling at ~94% of all CPU time in one process, spent re-entering CGO and re-formatting the same DDS error string as fast as the scheduler allows. Wait now sleeps for the caller's timeout before returning an error, so a permanently-broken entity is bounded to a normal retry cadence instead of spinning a core. The success/timeout path (dds_waitset_wait >= 0) is untouched, so healthy streams still wake immediately on new data. Verified live: CPU usage for the process dropped from 274% to 20% total after this change, with system-wide load average dropping accordingly. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
registerHeartbeats runs on every 5-minute session rotation, and register() replaced each stream's state wholesale, so consecutiveBad and escalated got wiped back to zero every rotation. With a 30s check interval and 60s grace period, only ~8 bad checks fit in a rotation window -- one short of the 10-check stuckStreamThreshold -- so the escalation added last commit could never actually fire, for any stream, no matter how long it stayed broken. register() now carries consecutiveBad and escalated over from any existing entry for that name, so a stream's time-to-escalate spans rotations instead of restarting every 5 minutes. That alone would create a new problem: depth has no camera on this robot and will never tick, so it would now reach the threshold and force a restart, then immediately start climbing toward another one -- an infinite restart loop over a device that will never come back no matter how many times the process restarts. Added everWorked, a latch that's only set once a stream ticks for the first time; only a stream that worked and then got stuck is eligible to escalate. A stream with no hardware ever attached just keeps logging NOT WORKING, as before. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Merged onto worktree-traces-prometheus-scraper, reconciling with awaitReady/DeleteAfterUpload/boot-session-retry changes, and dropping the reintroduced sess.Status=="complete" shortcut that da78810 (Never skip uploading based on server-reported session status) had removed as the root cause of a measured S3 data-loss incident.
A stuck-stream restart (lidar, this occurrence) calls Stop(), which cancels the reader goroutine and waits for it to exit. Its cleanup calls Participant.Close() -> dds_delete(), a cgo call Go's context cancellation cannot interrupt. On a participant whose subscription never received any data, that call hung forever (confirmed via a SIGQUIT goroutine dump: 945 minutes stuck in the cgo syscall), wedging the whole shutdown sequence -- and with it session rotation, retention sweeps, and uploads, since all run on or depend on the same main goroutine. The escalate-to-restart mechanism meant to recover a stuck stream became a silent, total, unrecoverable freeze instead, invisible because ffmpeg's own segment writers kept running independently the whole time. closeEntity now runs dds_delete in its own goroutine and gives it 5s to return, abandoning (and leaking) the goroutine on timeout instead of blocking its caller forever. Applied to both Participant.Close and WaitSet.Close, the two dds_delete call sites. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH
Measured on the robot: ~90ms RTT and ~5% packet loss to S3, which caps a single TCP stream's throughput regardless of the underlying link's real capacity (229Mbit/s WiFi PHY, ~600KB/s observed). uploadMultipart sent parts through one connection sequentially, so large files rode entirely on that one connection's loss/RTT-limited ceiling. Parts now upload up to Concurrency at a time (same knob uploadFiles already uses across files), each getting its own connection and congestion window. Reads switch from a shared cursor to ReadAt per part, since concurrent goroutines can't share one. Completed parts are sorted by part number before /files/complete, since S3 requires ascending order and concurrent parts can finish out of order. Updated the test fake to match: it reassembled multipart bytes by PUT arrival order, which happened to match part order only because uploads were sequential before. Real S3 reassembles from the ordered part list in CompleteMultipartUpload regardless of PUT order, so the fake now stores each part keyed by part number and reassembles the same way on complete. Verified: full suite passes, upload package clean under -race (x5). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH
These sat outside the zstd whole-file pipeline that already covers their sibling *_frames.bin files, uploading raw. lowstate_timestamps.csv at 400Hz was the single largest contributor after the actual frame data -- 16MB of a real session's ~27MB of small-file overhead, with odom's timestamps CSV a distant second at 7MB. Both are repetitive numeric text, a good zstd fit, and zstdName/compressWholeFile were already generic over file extension, so this only needed adding both names to wholeFileTargets. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH
UploadFinishedSessionAsync's background goroutine ran under context.Background(), so its awaitReady call (awaitSegments -> WaitSegment) could block forever waiting on a video/audio segment that a broken recorder stream would never produce -- exactly the condition that also trips the heartbeat monitor's stuck-stream restart. main's shutdown path waits on every such goroutine via uploadWG before it can os.Exit to let the container restart, so one stuck goroutine silently defeated that recovery: the process hung forever instead of restarting, with recording and uploading both dead. Give the goroutine's context a 10-minute deadline instead. A timed-out attempt is simply picked up by the next catch-up sweep, same as any other failed upload. Reproduced live: the deployed traces-prometheus-scraper build hung for over an hour after a stuck odom stream triggered this exact restart path, with the process alive but no recorder children, no new sessions, and no log output. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_015KeydH8jwQFhRpXPXTMGdD
A second occurrence of the shutdown deadlock (dds_delete fixed earlier today) showed the same "stuck forever in an uninterruptible cgo call" failure mode at a different call site: lidar's dds_create_participant, in subscribeDDS's setup path rather than teardown. Confirmed via SIGQUIT goroutine dump -- goroutine 1 blocked 4 minutes on LidarStream.Stop()'s wg.Wait(), same as before, but this time the lidar goroutine was stuck in NewParticipant, not Participant.Close(). Lidar had been reconnecting constantly all session (real upstream DDS instability), and enough create/destroy churn apparently left dds_create_participant itself wedged. Applied the same bounded-goroutine pattern (closeEntity's sibling, boundedCreate) to every dds_create_* call in ddscore: NewParticipant, CreateTopic, CreateReader, CreateWriter, and NewWaitSet's three-call sequence. CreateTopic's C string is freed inside the goroutine rather than via an outer defer, since freeing it early on a timeout could race a use-after-free if the abandoned call eventually runs. Verified: full suite and vet pass. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
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
3 participants
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.
No description provided.