From 0752cdc7ccdb54bce2e0b9af6040fa2ac3a513e3 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Mon, 31 Aug 2026 15:05:12 -0500 Subject: [PATCH 01/26] Poll OM1's Prometheus trace export into the session directory 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- README.md | 32 +++- cmd/main/main.go | 24 +++ config/config.go | 26 +++ go.mod | 13 +- go.sum | 26 ++- internal/traces/stream.go | 316 +++++++++++++++++++++++++++++++++ internal/traces/stream_test.go | 227 +++++++++++++++++++++++ 7 files changed, 650 insertions(+), 14 deletions(-) create mode 100644 internal/traces/stream.go create mode 100644 internal/traces/stream_test.go diff --git a/README.md b/README.md index 6c545ac..37648b2 100644 --- a/README.md +++ b/README.md @@ -10,6 +10,7 @@ A Go application that synchronously records multi-modal sensor data: - **Depth** frames from a CycloneDDS topic (RVL-compressed, lossless) - **Odometry** messages from a CycloneDDS topic - **Lowstate** (IMU/joints/battery/etc.) from a CycloneDDS topic +- **LLM traces** (prompt/response records) polled from a co-located OM1 process's Prometheus trace-export endpoint All streams are timestamped and organized into session directories for easy alignment and analysis. @@ -139,6 +140,9 @@ Any of the following override the selected profile / defaults: - `ODOM_DDS_TOPIC` - DDS topic for odometry data (default: `rt/odom`) - `LOWSTATE_DDS_DOMAIN` - CycloneDDS domain ID for lowstate (default: `0`) - `LOWSTATE_DDS_TOPIC` - DDS topic for lowstate data (default: `rt/lowstate`) +- `TRACES_ENABLED` - Poll a co-located OM1 process's Prometheus trace-export endpoint and record its LLM traces (default: `false` — most deployments have no OM1 process to poll; see "LLM trace export" below) +- `TRACES_URL` - OM1's trace-export endpoint (default: `http://localhost:9090/traces/metrics`) +- `TRACES_POLL_INTERVAL` - How often to poll `TRACES_URL` (default: `30s`) - `RECORDINGS_DIR` - Base directory for recordings (default: `recordings`) - `SESSION_ROTATE_INTERVAL` - Close the current session and open a fresh one on this cadence, so each segment can be uploaded without waiting for the whole run to end (default: `5m`; `0` disables rotation — one session for the life of the process, as before this feature existed) - `UPLOAD_ENABLED` - Upload each rotated-away session to the openmind-api (default: `true`; actual uploading additionally requires `OPENMIND_API_URL` and `OPENMIND_API_KEY` — see "Cloud upload" below) @@ -248,7 +252,8 @@ recordings/ ├── depth_frames.bin # RVL-compressed depth frames (lossless) ├── depth_timestamps.csv # unix_ns,seq,byte_offset,byte_length,method,width,height,encoding,mono_ns ├── odom_frames.bin # Raw odometry messages - └── odom_timestamps.csv # Timestamps: unix_ns,seq,byte_offset,mono_ns + ├── odom_timestamps.csv # Timestamps: unix_ns,seq,byte_offset,mono_ns + └── traces.jsonl # LLM trace records polled from OM1 (if TRACES_ENABLED set) ``` Every timestamps CSV carries a **`mono_ns`** column alongside its wall-clock @@ -474,6 +479,31 @@ its own copy of it (a snapshot taken when that segment closes), so each segment's directory stays self-contained for `align_recording.py` / `fix_session_time.py` without needing the boot session alongside it. +## LLM trace export + +Set `TRACES_ENABLED=true` to poll a co-located [OM1](https://github.com/OpenMind/OM1) +process's Prometheus trace-export endpoint (`use_tracer.prometheus_export.enabled` +in OM1's config) and record each LLM interaction trace into the current +session's `traces.jsonl` -- picked up by the normal upload pipeline like +every other stream, with no extra bucket-path configuration needed. + +This is a persistent stream: it keeps one poll loop and one dedup cursor +(the newest trace timestamp already written) running for the life of the +process, only swapping which session's `traces.jsonl` it writes to on +rotation -- so OM1 re-serving its whole buffer on every poll never produces +duplicate lines, even across a session rotation. + +OM1's exporter only buffers its most recent 200 trace records; poll more +often than that window fills at your deployment's trace rate +(`TRACES_POLL_INTERVAL`, default `30s`) or older records will be evicted on +the OM1 side before this recorder ever sees them. + +`TRACES_URL` must point at OM1's trace-export endpoint specifically +(`/traces/metrics`), **not** its main `/metrics` endpoint -- the two are +deliberately separate on the OM1 side, since trace records carry full +prompt/response text as unbounded label values that a real Prometheus +scrape target shouldn't ingest. + ## Scheduling `SCHEDULE_FILE` points at an optional YAML file describing a daily diff --git a/cmd/main/main.go b/cmd/main/main.go index 6aef31d..4a09a57 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -25,6 +25,7 @@ import ( "om1-telemetry/internal/retention" "om1-telemetry/internal/schedule" "om1-telemetry/internal/session" + "om1-telemetry/internal/traces" "om1-telemetry/internal/upload" "om1-telemetry/internal/video" ) @@ -337,6 +338,9 @@ func registerHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartbea if cfg.Features.Enabled() { mon.Register(features.HeartbeatName, 0) // 0 = liveness check only } + if cfg.Traces.Enabled { + mon.Register(traces.HeartbeatName, 0) // 0 = liveness check only -- polls are regular, new records are not + } for _, name := range videoHeartbeatNames { mon.Register(name, 0) } @@ -364,6 +368,9 @@ func unregisterHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartb if cfg.Features.Enabled() { mon.Unregister(features.HeartbeatName) } + if cfg.Traces.Enabled { + mon.Unregister(traces.HeartbeatName) + } for _, name := range videoHeartbeatNames { mon.Unregister(name) } @@ -383,6 +390,7 @@ type persistentStreams struct { lowstateStream *lowstate.LowstateStream videoStreams []*video.VideoRTSPStream audioStream *audio.AudioRTSPStream + traceStream *traces.TraceStream } func newPersistentStreams(cfg config.Config, mon *heartbeat.Monitor, recordingsDir string, sess *session.Session, videoHeartbeatNames []string) persistentStreams { @@ -415,6 +423,11 @@ func newPersistentStreams(cfg config.Config, mon *heartbeat.Monitor, recordingsD lowstateCfg.Monitor = mon p.lowstateStream = lowstate.New(lowstateCfg) } + if cfg.Traces.Enabled { + tracesCfg := cfg.Traces.TraceStreamConfig() + tracesCfg.Monitor = mon + p.traceStream = traces.New(tracesCfg) + } p.videoStreams = make([]*video.VideoRTSPStream, 0, len(cfg.Video)) for i, vc := range cfg.Video { @@ -467,6 +480,9 @@ func (p *persistentStreams) start() { if p.lowstateStream != nil { p.lowstateStream.Start() } + if p.traceStream != nil { + p.traceStream.Start() + } for _, vs := range p.videoStreams { vs.Start() } @@ -489,6 +505,9 @@ func (p *persistentStreams) stop() { if p.lowstateStream != nil { p.lowstateStream.Stop() } + if p.traceStream != nil { + p.traceStream.Stop() + } for _, vs := range p.videoStreams { vs.Stop() } @@ -525,6 +544,11 @@ func (p *persistentStreams) rotate(cfg config.Config, sess *session.Session) { slog.Error("lowstate: rotate failed", "err", err) } } + if p.traceStream != nil { + if err := p.traceStream.Rotate(cfg.Traces.OutputFile); err != nil { + slog.Error("traces: rotate failed", "err", err) + } + } for i, vs := range p.videoStreams { vc := cfg.Video[i] out := realPath(vc.OutputFile, sessionRealDir) diff --git a/config/config.go b/config/config.go index cca2e35..e6867b0 100644 --- a/config/config.go +++ b/config/config.go @@ -15,6 +15,7 @@ import ( "om1-telemetry/internal/network" "om1-telemetry/internal/odom" "om1-telemetry/internal/pointcloud" + "om1-telemetry/internal/traces" "om1-telemetry/internal/upload" "om1-telemetry/internal/video" ) @@ -37,6 +38,7 @@ type Config struct { Odom OdomConfig Lowstate LowstateConfig Network NetworkConfig + Traces TracesConfig SessionRotateInterval time.Duration Upload UploadConfig Retention RetentionConfig @@ -142,6 +144,16 @@ type NetworkConfig struct { DataFile string } +// TracesConfig configures polling a co-located OM1 process's Prometheus +// trace-export endpoint (see internal/traces). Disabled unless Enabled is set -- +// most deployments don't have an OM1 process to poll. +type TracesConfig struct { + Enabled bool + URL string + PollInterval time.Duration + OutputFile string +} + // RecordingsDir is the root under which sessions are created. The session // package needs it before Load runs, because it decides the session directory // name -- which depends on whether the clock can be trusted yet. @@ -227,6 +239,12 @@ func Load(sessionDir string) Config { PollInterval: envDuration("NET_POLL_INTERVAL", 5*time.Second), DataFile: filepath.Join(sessionDir, "network_status.csv"), }, + Traces: TracesConfig{ + Enabled: envBool("TRACES_ENABLED", false), + URL: envStr("TRACES_URL", "http://localhost:9090/traces/metrics"), + PollInterval: envDuration("TRACES_POLL_INTERVAL", 30*time.Second), + OutputFile: filepath.Join(sessionDir, "traces.jsonl"), + }, SessionRotateInterval: envDuration("SESSION_ROTATE_INTERVAL", 5*time.Minute), Upload: UploadConfig{ Enabled: envBool("UPLOAD_ENABLED", true), @@ -346,6 +364,14 @@ func (c NetworkConfig) NetworkStreamConfig() network.Config { } } +func (c TracesConfig) TraceStreamConfig() traces.Config { + return traces.Config{ + URL: c.URL, + PollInterval: c.PollInterval, + OutputFile: c.OutputFile, + } +} + func envStr(key, defaultValue string) string { if value := os.Getenv(key); value != "" { return value diff --git a/go.mod b/go.mod index 94224d9..03aa10f 100644 --- a/go.mod +++ b/go.mod @@ -1,15 +1,18 @@ module om1-telemetry -go 1.25 +go 1.25.0 require ( github.com/klauspost/compress v1.18.6 - github.com/stretchr/testify v1.11.1 - golang.org/x/sys v0.35.0 + github.com/prometheus/common v0.71.0 + github.com/stretchr/testify v1.12.1 + golang.org/x/sys v0.47.0 gopkg.in/yaml.v3 v3.0.1 ) require ( - github.com/davecgh/go-spew v1.1.1 // indirect - github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 // indirect + github.com/prometheus/client_model v0.6.2 // indirect + go.yaml.in/yaml/v3 v3.0.5 // indirect + google.golang.org/protobuf v1.36.12 // indirect ) diff --git a/go.sum b/go.sum index 2f5977f..32e644c 100644 --- a/go.sum +++ b/go.sum @@ -1,13 +1,23 @@ -github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= -github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/google/go-cmp v0.7.0 h1:wk8382ETsv4JYUZwIsn6YpYiWiBsYLSJiTsyBybVuN8= +github.com/google/go-cmp v0.7.0/go.mod h1:pXiqmnSA92OHEEa9HXL2W4E7lf9JzCmGVUdgjX3N/iU= github.com/klauspost/compress v1.18.6 h1:2jupLlAwFm95+YDR+NwD2MEfFO9d4z4Prjl1XXDjuao= github.com/klauspost/compress v1.18.6/go.mod h1:cwPg85FWrGar70rWktvGQj8/hthj3wpl0PGDogxkrSQ= -github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= -github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= -github.com/stretchr/testify v1.11.1 h1:7s2iGBzp5EwR7/aIZr8ao5+dra3wiQyKjjFuvgVKu7U= -github.com/stretchr/testify v1.11.1/go.mod h1:wZwfW3scLgRK+23gO65QZefKpKQRnfz6sD981Nm4B6U= -golang.org/x/sys v0.35.0 h1:vz1N37gP5bs89s7He8XuIYXpyY0+QlsKmzipCbUtyxI= -golang.org/x/sys v0.35.0/go.mod h1:BJP2sWEmIv4KK5OTEluFJCKSidICx8ciO85XgH3Ak8k= +github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 h1:C3w9PqII01/Oq1c1nUAm88MOHcQC9l5mIlSMApZMrHA= +github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822/go.mod h1:+n7T8mK8HuQTcFwEeznm/DIxMOiR9yIdICNftLE1DvQ= +github.com/prometheus/client_model v0.6.2 h1:oBsgwpGs7iVziMvrGhE53c/GrLUsZdHnqNwqPLxwZyk= +github.com/prometheus/client_model v0.6.2/go.mod h1:y3m2F6Gdpfy6Ut/GBsUqTWZqCUvMVzSfMLjcu6wAwpE= +github.com/prometheus/common v0.71.0 h1:9KDAKb7Mj3HEVKyFCK6Dc/HIwlBzZIN2l7/lrHl3KK8= +github.com/prometheus/common v0.71.0/go.mod h1:CLJ5H8TEsGX8bl31BdMkfhIZ+QmZ9tBPPotUxUbfcmk= +github.com/stretchr/testify v1.12.1 h1:EuwCh5fleGS7H32xRwO3wRGT7DxrDhLAT6FF8MpWDWE= +github.com/stretchr/testify v1.12.1/go.mod h1:MDEgiDPPsNp5cuIrHPPCyornHKgEVbtFUmoNlxoYthg= +go.yaml.in/yaml/v2 v2.4.4 h1:tuyd0P+2Ont/d6e2rl3be67goVK4R6deVxCUX5vyPaQ= +go.yaml.in/yaml/v2 v2.4.4/go.mod h1:gMZqIpDtDqOfM0uNfy0SkpRhvUryYH0Z6wdMYcacYXQ= +go.yaml.in/yaml/v3 v3.0.5 h1:N6y/pJk8buWs9NY5ERU2HSMfm+IuD/OtfdAnq6kESPw= +go.yaml.in/yaml/v3 v3.0.5/go.mod h1:HVTZu1O7/Vkt2N+BFy8Zza+lnLsABggaTM2ZpNIGuKg= +golang.org/x/sys v0.47.0 h1:o7XGOvZQCADBQQ4Y7VNq2dRWQR7JmOUW8Kxx4ZsNgWs= +golang.org/x/sys v0.47.0/go.mod h1:4GL1E5IUh+htKOUEOaiffhrAeqysfVGipDYzABqnCmw= +google.golang.org/protobuf v1.36.12 h1:pJOKDDOyeXErUroCihFAd5LQuwXBSpVnKGrj5o/fwxc= +google.golang.org/protobuf v1.36.12/go.mod h1:HTf+CrKn2C3g5S8VImy6tdcUvCska2kB7j23XfzDpco= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= diff --git a/internal/traces/stream.go b/internal/traces/stream.go new file mode 100644 index 0000000..d584cde --- /dev/null +++ b/internal/traces/stream.go @@ -0,0 +1,316 @@ +// Package traces polls a co-located OM1 process's Prometheus trace-export +// endpoint (see OM1's internal/tracer/traceexport) and appends any records +// not seen yet to the session directory as traces.jsonl -- picked up by the +// existing session upload pipeline like every other stream's output. +// +// OM1 broadcasts trace records as om1_trace_info, an "info" metric (value +// always 1, full record in labels) on a private registry served at +// GET /traces/metrics -- deliberately not OM1's main /metrics endpoint, +// since it carries unbounded free-text label values a real Prometheus +// shouldn't store permanently. This package is that endpoint's one intended +// consumer: it scrapes it the same way Prometheus itself would (using the +// same exposition-format parser), not by any bespoke protocol. +package traces + +import ( + "context" + "encoding/json" + "fmt" + "log/slog" + "net/http" + "os" + "sort" + "strconv" + "sync" + "sync/atomic" + "time" + + "github.com/prometheus/common/expfmt" + "github.com/prometheus/common/model" + + "om1-telemetry/internal/heartbeat" + "om1-telemetry/internal/recordutil" +) + +// HeartbeatName is the stream identifier for the heartbeat monitor. +const HeartbeatName = "traces" + +// traceMetricFamily is the Prometheus metric name OM1's exporter uses. +const traceMetricFamily = "om1_trace_info" + +// httpTimeout bounds a single poll request, so an unreachable/hung OM1 +// process can never stall the loop past one poll interval. +const httpTimeout = 10 * time.Second + +type Config struct { + // URL is OM1's trace-export endpoint, e.g. http://localhost:9090/traces/metrics. + URL string + + PollInterval time.Duration + + OutputFile string + + Monitor *heartbeat.Monitor +} + +// TraceStream polls Config.URL and appends new records to the current +// output file. It is a persistent stream: Rotate swaps the output file +// without restarting the poll loop, so the in-memory dedup cursor (which +// record timestamps have already been written) survives session rotation -- +// letting OM1's exporter re-serve its whole buffer on every poll without +// producing duplicate lines. +type TraceStream struct { + cfg Config + running atomic.Bool + cancel context.CancelFunc + wg sync.WaitGroup + hc *http.Client + + fileMu sync.Mutex + file *os.File + + lastSeenMu sync.Mutex + lastSeen time.Time +} + +func New(cfg Config) *TraceStream { + return &TraceStream{cfg: cfg, hc: &http.Client{Timeout: httpTimeout}} +} + +func (s *TraceStream) Start() { + if s.running.Swap(true) { + return + } + ctx, cancel := context.WithCancel(context.Background()) + s.cancel = cancel + s.wg.Add(1) + go s.loop(ctx) +} + +func (s *TraceStream) Stop() { + if !s.running.Swap(false) { + return + } + s.cancel() + s.wg.Wait() + s.closeFile() + slog.Info("traces stream stopped") +} + +// Rotate switches the stream's output to a new file without touching the +// poll loop or the dedup cursor. +func (s *TraceStream) Rotate(outputFile string) error { + result, err := recordutil.OpenForAppend(outputFile) + if err != nil { + return fmt.Errorf("rotate: %w", err) + } + + s.fileMu.Lock() + old := s.file + s.file = result.File + s.fileMu.Unlock() + + if old != nil { + if err := old.Sync(); err != nil { + slog.Warn("traces: output sync failed", "err", err) + } + if err := old.Close(); err != nil { + slog.Warn("traces: output close failed", "err", err) + } + } + return nil +} + +func (s *TraceStream) loop(ctx context.Context) { + defer s.wg.Done() + + if err := s.ensureFileOpen(); err != nil { + slog.Error("traces: cannot open output file; stream disabled", "err", err) + return + } + + slog.Info("traces recorder started", "url", s.cfg.URL, "interval", s.cfg.PollInterval) + + ticker := time.NewTicker(s.cfg.PollInterval) + defer ticker.Stop() + + for { + s.poll(ctx) + s.cfg.Monitor.Tick(HeartbeatName) + + select { + case <-ctx.Done(): + return + case <-ticker.C: + } + } +} + +func (s *TraceStream) ensureFileOpen() error { + s.fileMu.Lock() + defer s.fileMu.Unlock() + if s.file != nil { + return nil + } + result, err := recordutil.OpenForAppend(s.cfg.OutputFile) + if err != nil { + return err + } + s.file = result.File + return nil +} + +// poll fetches and parses one batch from OM1's trace-export endpoint and +// appends any records newer than the dedup cursor. Errors (network, parse) +// are logged and left for the next tick -- OM1's exporter buffers the last +// 200 records, so a poller that's behind by less than that window catches up +// without losing anything. +func (s *TraceStream) poll(ctx context.Context) { + records, err := s.fetch(ctx) + if err != nil { + slog.Warn("traces: poll failed", "err", err) + return + } + if len(records) == 0 { + return + } + + sort.Slice(records, func(i, j int) bool { return records[i].parsedTS.Before(records[j].parsedTS) }) + + s.lastSeenMu.Lock() + cursor := s.lastSeen + s.lastSeenMu.Unlock() + + var wrote int + newest := cursor + for _, rec := range records { + if !rec.parsedTS.After(cursor) { + continue + } + if err := s.write(rec); err != nil { + slog.Warn("traces: write failed", "err", err) + return + } + wrote++ + if rec.parsedTS.After(newest) { + newest = rec.parsedTS + } + } + if wrote == 0 { + return + } + + s.lastSeenMu.Lock() + s.lastSeen = newest + s.lastSeenMu.Unlock() +} + +// line is the JSON shape written to OutputFile, matching OM1's own +// traces/tracer_.jsonl records field-for-field. +type line struct { + Timestamp string `json:"ts"` + Generation int `json:"generation"` + LLMInput string `json:"llm_input"` + LLMOutput json.RawMessage `json:"llm_output"` +} + +type record struct { + line + parsedTS time.Time +} + +func (s *TraceStream) write(rec record) error { + buf, err := json.Marshal(rec.line) + if err != nil { + return fmt.Errorf("marshal: %w", err) + } + + s.fileMu.Lock() + defer s.fileMu.Unlock() + if _, err := s.file.Write(append(buf, '\n')); err != nil { + return fmt.Errorf("write: %w", err) + } + return s.file.Sync() +} + +// fetch requests and parses one scrape of the trace-export endpoint. +func (s *TraceStream) fetch(ctx context.Context) ([]record, error) { + req, err := http.NewRequestWithContext(ctx, http.MethodGet, s.cfg.URL, nil) + if err != nil { + return nil, fmt.Errorf("build request: %w", err) + } + resp, err := s.hc.Do(req) + if err != nil { + return nil, fmt.Errorf("request: %w", err) + } + defer func() { _ = resp.Body.Close() }() + if resp.StatusCode != http.StatusOK { + return nil, fmt.Errorf("unexpected status %s", resp.Status) + } + + // om1_trace_info is a plain ASCII, underscore-separated Prometheus name + // (client_golang's classic exposition format), not a UTF-8 name -- so + // LegacyValidation, not the module-wide default of UTF8Validation. + parser := expfmt.NewTextParser(model.LegacyValidation) + families, err := parser.TextToMetricFamilies(resp.Body) + if err != nil { + return nil, fmt.Errorf("parse: %w", err) + } + + family, ok := families[traceMetricFamily] + if !ok { + return nil, nil + } + + records := make([]record, 0, len(family.GetMetric())) + for _, m := range family.GetMetric() { + labels := make(map[string]string, len(m.GetLabel())) + for _, l := range m.GetLabel() { + labels[l.GetName()] = l.GetValue() + } + + ts := labels["ts"] + parsedTS, err := time.Parse(time.RFC3339Nano, ts) + if err != nil { + slog.Warn("traces: record with unparseable ts, skipping", "ts", ts, "err", err) + continue + } + + generation, err := strconv.Atoi(labels["generation"]) + if err != nil { + generation = 0 + } + + llmOutput := labels["llm_output"] + if !json.Valid([]byte(llmOutput)) { + llmOutput = "[]" + } + + records = append(records, record{ + line: line{ + Timestamp: ts, + Generation: generation, + LLMInput: labels["llm_input"], + LLMOutput: json.RawMessage(llmOutput), + }, + parsedTS: parsedTS, + }) + } + return records, nil +} + +func (s *TraceStream) closeFile() { + s.fileMu.Lock() + f := s.file + s.file = nil + s.fileMu.Unlock() + if f == nil { + return + } + if err := f.Sync(); err != nil { + slog.Warn("traces: output sync failed", "err", err) + } + if err := f.Close(); err != nil { + slog.Warn("traces: output close failed", "err", err) + } +} diff --git a/internal/traces/stream_test.go b/internal/traces/stream_test.go new file mode 100644 index 0000000..f3a4d7e --- /dev/null +++ b/internal/traces/stream_test.go @@ -0,0 +1,227 @@ +package traces + +import ( + "fmt" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "strings" + "sync/atomic" + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +func testConfig(t *testing.T, url string) Config { + return Config{ + URL: url, + PollInterval: 20 * time.Millisecond, + OutputFile: filepath.Join(t.TempDir(), "traces.jsonl"), + } +} + +// exposition builds a minimal om1_trace_info text-exposition-format body, +// exactly as OM1's exporter (a real prometheus client_golang GaugeVec) would +// serialize it -- escaped quotes/newlines included, to exercise the parser +// the same way it would see a real scrape. +func exposition(records ...[5]string) string { + var b strings.Builder + b.WriteString("# HELP om1_trace_info test\n# TYPE om1_trace_info gauge\n") + for _, r := range records { + fmt.Fprintf(&b, `om1_trace_info{seq="%s",ts="%s",generation="%s",llm_input="%s",llm_output="%s"} 1`+"\n", + r[0], r[1], r[2], r[3], r[4]) + } + return b.String() +} + +func serveText(t *testing.T, body func() string) *httptest.Server { + t.Helper() + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "text/plain; version=0.0.4") + _, _ = w.Write([]byte(body())) + })) + t.Cleanup(server.Close) + return server +} + +func waitFor(t *testing.T, timeout time.Duration, fn func() bool) { + t.Helper() + deadline := time.After(timeout) + for { + if fn() { + return + } + select { + case <-deadline: + t.Fatal("timed out waiting for condition") + case <-time.After(5 * time.Millisecond): + } + } +} + +func fileLines(t *testing.T, path string) []string { + t.Helper() + data, err := os.ReadFile(path) + if err != nil { + if os.IsNotExist(err) { + return nil + } + t.Fatalf("read %s: %v", path, err) + } + var lines []string + for _, l := range strings.Split(strings.TrimSpace(string(data)), "\n") { + if l != "" { + lines = append(lines, l) + } + } + return lines +} + +func TestNew_returnsNonNilStream(t *testing.T) { + require.NotNil(t, New(testConfig(t, "http://example.invalid"))) +} + +func TestStartStop_cleanLifecycle(t *testing.T) { + server := serveText(t, func() string { return exposition() }) + stream := New(testConfig(t, server.URL)) + stream.Start() + time.Sleep(50 * time.Millisecond) + + done := make(chan struct{}) + go func() { + stream.Stop() + close(done) + }() + select { + case <-done: + case <-time.After(5 * time.Second): + t.Fatal("Stop() did not return within 5s") + } +} + +func TestStart_idempotent(t *testing.T) { + server := serveText(t, func() string { return exposition() }) + stream := New(testConfig(t, server.URL)) + stream.Start() + stream.Start() + stream.Stop() +} + +func TestStop_beforeStart_isNoOp(t *testing.T) { + require.NotPanics(t, func() { New(testConfig(t, "http://example.invalid")).Stop() }) +} + +func TestStop_idempotent(t *testing.T) { + server := serveText(t, func() string { return exposition() }) + stream := New(testConfig(t, server.URL)) + stream.Start() + stream.Stop() + stream.Stop() +} + +func TestPoll_writesNewRecordsOnce(t *testing.T) { + rec := [5]string{"0", "2026-08-31T17:41:36.027193146Z", "1", "hello there", "[]"} + server := serveText(t, func() string { return exposition(rec) }) + + cfg := testConfig(t, server.URL) + stream := New(cfg) + stream.Start() + defer stream.Stop() + + waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, cfg.OutputFile)) == 1 }) + + // The same record is served on every subsequent poll (OM1 keeps it + // buffered until evicted); it must not be re-written. + time.Sleep(150 * time.Millisecond) + require.Len(t, fileLines(t, cfg.OutputFile), 1, "an already-seen record must not be duplicated across polls") + require.Contains(t, fileLines(t, cfg.OutputFile)[0], `"llm_input":"hello there"`) +} + +func TestPoll_appendsNewRecordsAcrossPolls(t *testing.T) { + rec1 := [5]string{"0", "2026-08-31T17:41:36.000000000Z", "1", "first", "[]"} + rec2 := [5]string{"1", "2026-08-31T17:41:37.000000000Z", "1", "second", "[]"} + + var showSecond atomic.Bool + server := serveText(t, func() string { + if showSecond.Load() { + return exposition(rec1, rec2) + } + return exposition(rec1) + }) + + cfg := testConfig(t, server.URL) + stream := New(cfg) + stream.Start() + defer stream.Stop() + + waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, cfg.OutputFile)) == 1 }) + + showSecond.Store(true) + waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, cfg.OutputFile)) == 2 }) + + lines := fileLines(t, cfg.OutputFile) + require.Contains(t, lines[0], `"llm_input":"first"`) + require.Contains(t, lines[1], `"llm_input":"second"`) +} + +func TestPoll_handlesEscapedQuotesAndNewlines(t *testing.T) { + // Mirrors how a real client_golang exposition encoder escapes label values. + rec := [5]string{"0", "2026-08-31T17:41:36.000000000Z", "1", `line one\nline two \"quoted\"`, "[]"} + server := serveText(t, func() string { return exposition(rec) }) + + cfg := testConfig(t, server.URL) + stream := New(cfg) + stream.Start() + defer stream.Stop() + + waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, cfg.OutputFile)) == 1 }) + + lines := fileLines(t, cfg.OutputFile) + require.Contains(t, lines[0], `line one\nline two \"quoted\"`) +} + +func TestRotate_preservesDedupCursor(t *testing.T) { + rec := [5]string{"0", "2026-08-31T17:41:36.000000000Z", "1", "hello", "[]"} + server := serveText(t, func() string { return exposition(rec) }) + + cfg := testConfig(t, server.URL) + stream := New(cfg) + stream.Start() + defer stream.Stop() + + waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, cfg.OutputFile)) == 1 }) + + secondFile := filepath.Join(t.TempDir(), "traces2.jsonl") + require.NoError(t, stream.Rotate(secondFile)) + + // OM1 keeps serving the same buffered record; it was already consumed + // before the rotation, so the new file must stay empty. + time.Sleep(150 * time.Millisecond) + require.Empty(t, fileLines(t, secondFile), "a record already written before Rotate must not reappear in the new file") +} + +func TestPoll_skipsUnparseableTimestamp(t *testing.T) { + body := "# HELP om1_trace_info test\n# TYPE om1_trace_info gauge\n" + + `om1_trace_info{seq="0",ts="not-a-timestamp",generation="1",llm_input="x",llm_output="[]"} 1` + "\n" + server := serveText(t, func() string { return body }) + + cfg := testConfig(t, server.URL) + stream := New(cfg) + stream.Start() + defer stream.Stop() + + time.Sleep(100 * time.Millisecond) + require.Empty(t, fileLines(t, cfg.OutputFile), "a record with an unparseable timestamp must be skipped, not crash the poller") +} + +func TestPoll_serverUnreachable_doesNotPanic(t *testing.T) { + cfg := testConfig(t, "http://127.0.0.1:1") // nothing listens here + stream := New(cfg) + require.NotPanics(t, func() { + stream.Start() + time.Sleep(50 * time.Millisecond) + stream.Stop() + }) +} From 34b15f9196122e2b335bf358bce438aa905ee9f0 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Mon, 31 Aug 2026 16:38:58 -0500 Subject: [PATCH 02/26] Put each record on its own line in converted .jsonl->.json uploads 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- internal/upload/preprocess.go | 13 ++++++++++--- internal/upload/preprocess_test.go | 25 +++++++++++++++++++++++++ 2 files changed, 35 insertions(+), 3 deletions(-) diff --git a/internal/upload/preprocess.go b/internal/upload/preprocess.go index 145183f..3ddce8b 100644 --- a/internal/upload/preprocess.go +++ b/internal/upload/preprocess.go @@ -83,7 +83,7 @@ func jsonlToJSONArray(src, dst string) (err error) { }() w := bufio.NewWriter(out) - if _, err := w.WriteString("["); err != nil { + if _, err := w.WriteString("[\n"); err != nil { return err } @@ -98,8 +98,10 @@ func jsonlToJSONArray(src, dst string) (err error) { if !json.Valid(line) { return fmt.Errorf("%s: invalid json line: %s", src, line) } + // Each element keeps its own line -- a record-per-line array reads and + // diffs like the source .jsonl, instead of one unbroken line. if !first { - if _, err := w.WriteString(","); err != nil { + if _, err := w.WriteString(",\n"); err != nil { return err } } @@ -111,7 +113,12 @@ func jsonlToJSONArray(src, dst string) (err error) { if err := sc.Err(); err != nil { return fmt.Errorf("%s: %w", src, err) } - if _, err := w.WriteString("]"); err != nil { + if first { + // No elements: keep the array compact rather than "[\n\n]". + if _, err := w.WriteString("]"); err != nil { + return err + } + } else if _, err := w.WriteString("\n]"); err != nil { return err } return w.Flush() diff --git a/internal/upload/preprocess_test.go b/internal/upload/preprocess_test.go index 7dbfaf8..2641b9a 100644 --- a/internal/upload/preprocess_test.go +++ b/internal/upload/preprocess_test.go @@ -4,6 +4,7 @@ import ( "encoding/json" "os" "path/filepath" + "strings" "testing" "time" @@ -30,6 +31,30 @@ func TestConvertJSONLToJSON_producesValidArrayAndRemovesSource(t *testing.T) { require.Equal(t, "sample", records[1]["kind"]) } +func TestConvertJSONLToJSON_putsEachRecordOnItsOwnLine(t *testing.T) { + dir := t.TempDir() + writeFile(t, dir, "traces.jsonl", + []byte("{\"ts\":\"a\"}\n{\"ts\":\"b\"}\n{\"ts\":\"c\"}\n")) + + require.NoError(t, convertJSONLToJSON(dir, Options{})) + + raw, err := os.ReadFile(filepath.Join(dir, "traces.json")) + require.NoError(t, err) + + lines := strings.Split(strings.TrimRight(string(raw), "\n"), "\n") + require.Equal(t, []string{ + "[", + `{"ts":"a"},`, + `{"ts":"b"},`, + `{"ts":"c"}`, + "]", + }, lines, "each record must be readable and diffable on its own line, not packed into one giant line") + + var records []map[string]any + require.NoError(t, json.Unmarshal(raw, &records)) + require.Len(t, records, 3) +} + func TestConvertJSONLToJSON_emptyFileProducesEmptyArray(t *testing.T) { dir := t.TempDir() writeFile(t, dir, "video_features.jsonl", []byte("")) From 05eb97b0692a75fcf19176cf076531bec5cf796d Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Mon, 31 Aug 2026 17:35:03 -0500 Subject: [PATCH 03/26] Protect a just-opened session from a premature catch-up upload 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- internal/retention/retention.go | 34 ++++++++++++++++-- internal/retention/retention_test.go | 54 ++++++++++++++++++++++++++++ internal/session/session.go | 6 +++- 3 files changed, 91 insertions(+), 3 deletions(-) diff --git a/internal/retention/retention.go b/internal/retention/retention.go index 25192e6..572bc10 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -25,6 +25,36 @@ const uploadMarkerName = ".uploaded" // uploadTimeout bounds one session's upload, whether kicked off by rotation, schedule, or shutdown. const uploadTimeout = 10 * time.Minute +// minSessionAge is a second, time-based line of defense protecting the +// currently-recording session, alongside the dir == currentDir check every +// sweep caller applies. session.ListClosed does not itself verify a +// directory is closed -- it lists every dated directory, including one +// just created by session.OpenNext -- so the only thing stopping the sweep +// from grabbing a session mid-recording is comparing it against the +// in-memory "current" pointer, which is not updated atomically with the +// directory's creation on disk (a handful of statements run in between). +// A sweep tick landing in that gap would see a brand-new, virtually empty +// directory as neither current nor uploaded, and upload it -- after which +// the server reports the session complete, so the real end-of-session +// upload silently no-ops and most files are never sent. Any directory +// younger than minSessionAge (by its own recorded start time) is skipped +// regardless of the current-dir check, which is a generous margin around +// a race window that's really microseconds wide. +const minSessionAge = 30 * time.Second + +// tooYoungToSweep reports whether dir's own recorded start time is within +// minSessionAge of now -- see minSessionAge's doc comment. A directory whose +// start time can't be read (missing/corrupt meta.json) is not protected by +// this check; that's an existing edge case the current-dir check alone +// already had to live with. +func tooYoungToSweep(dir string) bool { + start := ReadStartedAt(dir) + if start.IsZero() { + return false + } + return time.Since(start) < minSessionAge +} + // IsUploaded reports whether dir was already fully uploaded. func IsUploaded(dir string) bool { _, err := os.Stat(filepath.Join(dir, uploadMarkerName)) @@ -175,7 +205,7 @@ func Sweep(ctl *control.State, uploader *upload.Client, recordingsDir, bootTimeb } protected := func(dir string) bool { - return dir == currentDir || BootSessionDir(bootTimebasePath, dir) + return dir == currentDir || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) } CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) @@ -279,7 +309,7 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot } cd := currentDir() return dirs, func(dir string) bool { - return dir == cd || BootSessionDir(bootTimebasePath, dir) + return dir == cd || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) }, true } diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index 2e548ba..f723fd5 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -3,6 +3,7 @@ package retention import ( "context" "encoding/json" + "fmt" "net/http" "net/http/httptest" "os" @@ -249,6 +250,59 @@ func TestSweep_uploadsOldestUnmarkedFirstAndSkipsProtectedAndAlreadyUploaded(t * require.Zero(t, api.createCalls[APISessionDir(root, live)]) } +// Reproduces the race this protection closes: a session directory that +// exists on disk (session.OpenNext already created it and wrote meta.json) +// but that the caller hasn't yet reported as "current" -- the exact gap +// between OpenNext returning and cmd/main's current pointer being updated. +// Without the age check, ListClosed would surface it and the sweep would +// upload whatever the handful of streams had flushed in the first second, +// then mark it uploaded -- so the real end-of-session upload later silently +// no-ops against a server that already thinks the session is complete. +func TestSweep_neverUploadsAVeryYoungDirEvenIfNotReportedCurrent(t *testing.T) { + api, apiURL := newMinimalFakeAPI(t) + client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) + + root := t.TempDir() + justOpened := filepath.Join(root, "2026-08-31", "2026-08-31_21-22-33") + startedNs := time.Now().Add(-1 * time.Second).UnixNano() // opened a moment ago, well inside minSessionAge + writeFile(t, justOpened, "meta.json", []byte(fmt.Sprintf(`{"session_start_unix_ns":%d}`, startedNs))) + + bootTimebasePath := filepath.Join(root, "does-not-exist.jsonl") + + // currentDir is deliberately NOT justOpened -- simulating the moment + // before cmd/main's "current" pointer has caught up to it. + Sweep(control.New(), client, root, bootTimebasePath, "", 0) + + require.False(t, IsUploaded(justOpened), + "a directory younger than minSessionAge must never be uploaded, even when it isn't reported as the current session") + + api.mu.Lock() + defer api.mu.Unlock() + require.Zero(t, api.createCalls[APISessionDir(root, justOpened)]) +} + +// The age check must not block legitimate catch-up uploads -- only ones +// still inside the race window. +func TestSweep_uploadsADirOlderThanMinSessionAge(t *testing.T) { + api, apiURL := newMinimalFakeAPI(t) + client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) + + root := t.TempDir() + old := filepath.Join(root, "2026-08-31", "2026-08-31_21-22-33") + startedNs := time.Now().Add(-2 * minSessionAge).UnixNano() + writeFile(t, old, "meta.json", []byte(fmt.Sprintf(`{"session_start_unix_ns":%d}`, startedNs))) + + bootTimebasePath := filepath.Join(root, "does-not-exist.jsonl") + + Sweep(control.New(), client, root, bootTimebasePath, "", 0) + + require.True(t, IsUploaded(old), "a directory well past minSessionAge must upload normally") + + api.mu.Lock() + defer api.mu.Unlock() + require.Equal(t, 1, api.createCalls[APISessionDir(root, old)]) +} + // Rotation's async upload and a concurrent catch-up sweep must never both // upload the same directory at once. func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { diff --git a/internal/session/session.go b/internal/session/session.go index d54f18d..76f594e 100644 --- a/internal/session/session.go +++ b/internal/session/session.go @@ -440,7 +440,11 @@ func SortedNames(dirs []string) []string { return out } -// ListClosed returns every dated session directory under root, oldest first. +// ListClosed returns every dated session directory under root, oldest +// first -- including the one currently being recorded to. Despite the +// name, it does not check meta.json's session_end field or otherwise +// verify a directory is actually closed; callers (retention's sweep) are +// responsible for excluding the live session themselves. func ListClosed(root string) ([]string, error) { dateEntries, err := os.ReadDir(root) if err != nil { From 0138e3499d0a6a8d4690f222d0e0395fefb68aec Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Mon, 31 Aug 2026 18:24:49 -0500 Subject: [PATCH 04/26] Persist the trace poller's dedup cursor across process restarts 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- README.md | 5 ++- config/config.go | 6 ++++ internal/traces/stream.go | 62 +++++++++++++++++++++++++++++++++- internal/traces/stream_test.go | 39 +++++++++++++++++++++ 4 files changed, 110 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index 37648b2..2d1c6cc 100644 --- a/README.md +++ b/README.md @@ -491,7 +491,10 @@ This is a persistent stream: it keeps one poll loop and one dedup cursor (the newest trace timestamp already written) running for the life of the process, only swapping which session's `traces.jsonl` it writes to on rotation -- so OM1 re-serving its whole buffer on every poll never produces -duplicate lines, even across a session rotation. +duplicate lines, even across a session rotation. The cursor is also +persisted to `RECORDINGS_DIR/.traces_cursor`, so a full process restart +resumes from it too, instead of re-ingesting OM1's whole buffered backlog +into whatever session happens to be open at that moment. OM1's exporter only buffers its most recent 200 trace records; poll more often than that window fills at your deployment's trace rate diff --git a/config/config.go b/config/config.go index e6867b0..2172b49 100644 --- a/config/config.go +++ b/config/config.go @@ -152,6 +152,7 @@ type TracesConfig struct { URL string PollInterval time.Duration OutputFile string + CursorFile string } // RecordingsDir is the root under which sessions are created. The session @@ -244,6 +245,10 @@ func Load(sessionDir string) Config { URL: envStr("TRACES_URL", "http://localhost:9090/traces/metrics"), PollInterval: envDuration("TRACES_POLL_INTERVAL", 30*time.Second), OutputFile: filepath.Join(sessionDir, "traces.jsonl"), + // Outside sessionDir deliberately: this must survive both session + // rotation and a full process restart, not just live for one + // session's lifetime -- see traces.Config.CursorFile. + CursorFile: filepath.Join(RecordingsDir(), ".traces_cursor"), }, SessionRotateInterval: envDuration("SESSION_ROTATE_INTERVAL", 5*time.Minute), Upload: UploadConfig{ @@ -369,6 +374,7 @@ func (c TracesConfig) TraceStreamConfig() traces.Config { URL: c.URL, PollInterval: c.PollInterval, OutputFile: c.OutputFile, + CursorFile: c.CursorFile, } } diff --git a/internal/traces/stream.go b/internal/traces/stream.go index d584cde..662f59a 100644 --- a/internal/traces/stream.go +++ b/internal/traces/stream.go @@ -19,8 +19,10 @@ import ( "log/slog" "net/http" "os" + "path/filepath" "sort" "strconv" + "strings" "sync" "sync/atomic" "time" @@ -50,6 +52,13 @@ type Config struct { OutputFile string + // CursorFile persists the dedup cursor (the newest record timestamp + // written so far) across process restarts -- not per-session, so it + // must sit outside the rotating session directories. See loadCursor's + // doc comment for why this matters. Optional: an empty value just means + // no restart-survival, matching the stream's original behavior. + CursorFile string + Monitor *heartbeat.Monitor } @@ -58,7 +67,10 @@ type Config struct { // without restarting the poll loop, so the in-memory dedup cursor (which // record timestamps have already been written) survives session rotation -- // letting OM1's exporter re-serve its whole buffer on every poll without -// producing duplicate lines. +// producing duplicate lines. The cursor is also persisted to CursorFile, so +// a full process restart resumes from it too, instead of re-ingesting +// OM1's whole buffered backlog into whatever session happens to be open at +// that moment (see loadCursor). type TraceStream struct { cfg Config running atomic.Bool @@ -128,6 +140,7 @@ func (s *TraceStream) loop(ctx context.Context) { slog.Error("traces: cannot open output file; stream disabled", "err", err) return } + s.loadCursor() slog.Info("traces recorder started", "url", s.cfg.URL, "interval", s.cfg.PollInterval) @@ -203,6 +216,53 @@ func (s *TraceStream) poll(ctx context.Context) { s.lastSeenMu.Lock() s.lastSeen = newest s.lastSeenMu.Unlock() + s.saveCursor(newest) +} + +// loadCursor restores the dedup cursor from CursorFile, if set and present. +// +// Without this, a full process restart (not just a session rotation, which +// Rotate already handles) resets the in-memory cursor to zero. OM1's +// exporter keeps serving its whole buffer (up to 200 records) regardless of +// what already got written -- so a freshly-started process would treat +// everything still in that buffer as new and write it all into whichever +// session happens to be open at that moment, mixing in records that are +// chronologically well outside that session's own time window. +func (s *TraceStream) loadCursor() { + if s.cfg.CursorFile == "" { + return + } + raw, err := os.ReadFile(s.cfg.CursorFile) + if err != nil { + return + } + ts, err := time.Parse(time.RFC3339Nano, strings.TrimSpace(string(raw))) + if err != nil { + slog.Warn("traces: cannot parse persisted cursor; starting from empty", "err", err) + return + } + s.lastSeenMu.Lock() + s.lastSeen = ts + s.lastSeenMu.Unlock() +} + +// saveCursor persists the dedup cursor so loadCursor can restore it after a +// restart. Best-effort: a failure here just means the next restart falls +// back to re-ingesting whatever OM1 still has buffered, same as before this +// existed -- not worth aborting the poll loop over. +func (s *TraceStream) saveCursor(ts time.Time) { + if s.cfg.CursorFile == "" { + return + } + if dir := filepath.Dir(s.cfg.CursorFile); dir != "" && dir != "." { + if err := os.MkdirAll(dir, 0o755); err != nil { + slog.Warn("traces: cannot create cursor file directory", "err", err) + return + } + } + if err := os.WriteFile(s.cfg.CursorFile, []byte(ts.Format(time.RFC3339Nano)), 0o644); err != nil { + slog.Warn("traces: cannot persist cursor", "err", err) + } } // line is the JSON shape written to OutputFile, matching OM1's own diff --git a/internal/traces/stream_test.go b/internal/traces/stream_test.go index f3a4d7e..47b1fda 100644 --- a/internal/traces/stream_test.go +++ b/internal/traces/stream_test.go @@ -202,6 +202,45 @@ func TestRotate_preservesDedupCursor(t *testing.T) { require.Empty(t, fileLines(t, secondFile), "a record already written before Rotate must not reappear in the new file") } +// Reproduces the real bug: a process restart (a fresh TraceStream, not just +// Rotate on the same one) used to reset the in-memory cursor to zero, so a +// still-buffered OM1 backlog would all look new again and get dumped into +// whatever session happened to be open at that moment -- even records that +// were already written, chronologically outside that session's window, +// minutes to hours earlier. CursorFile is what closes that gap. +func TestCursorFile_survivesProcessRestart(t *testing.T) { + rec := [5]string{"0", "2026-08-31T17:41:36.000000000Z", "1", "hello", "[]"} + server := serveText(t, func() string { return exposition(rec) }) + + cursorFile := filepath.Join(t.TempDir(), "cursor") + firstOutput := filepath.Join(t.TempDir(), "traces.jsonl") + + first := New(Config{ + URL: server.URL, PollInterval: 20 * time.Millisecond, + OutputFile: firstOutput, CursorFile: cursorFile, + }) + first.Start() + waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, firstOutput)) == 1 }) + first.Stop() + + // A brand-new TraceStream, as a fresh process restart would construct -- + // no in-memory state carried over, only CursorFile on disk. + secondOutput := filepath.Join(t.TempDir(), "traces.jsonl") + second := New(Config{ + URL: server.URL, PollInterval: 20 * time.Millisecond, + OutputFile: secondOutput, CursorFile: cursorFile, + }) + second.Start() + defer second.Stop() + + // OM1 keeps serving the same record the first process already wrote; + // the second process must recognize it as already-seen via the + // persisted cursor and never write it into its own (new) session file. + time.Sleep(150 * time.Millisecond) + require.Empty(t, fileLines(t, secondOutput), + "a record already written by a prior process must not be re-written after a restart") +} + func TestPoll_skipsUnparseableTimestamp(t *testing.T) { body := "# HELP om1_trace_info test\n# TYPE om1_trace_info gauge\n" + `om1_trace_info{seq="0",ts="not-a-timestamp",generation="1",llm_input="x",llm_output="[]"} 1` + "\n" From 59105cf01469a2f35e26885ca774a723d8e4dfb9 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 1 Sep 2026 13:41:06 -0500 Subject: [PATCH 05/26] Self-heal DDS readers after a sensor restart instead of requiring a manual 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- README.md | 27 +++++++ cmd/main/main.go | 61 ++++++++++++--- internal/depth/stream.go | 22 +++++- internal/heartbeat/heartbeat.go | 34 ++++++++ internal/heartbeat/heartbeat_test.go | 69 ++++++++++++++++ internal/lidar/reconnect_test.go | 113 +++++++++++++++++++++++++++ internal/lidar/stream.go | 22 +++++- internal/lowstate/stream.go | 22 +++++- internal/odom/stream.go | 22 +++++- internal/pointcloud/stream.go | 22 +++++- 10 files changed, 399 insertions(+), 15 deletions(-) create mode 100644 internal/lidar/reconnect_test.go diff --git a/README.md b/README.md index 2d1c6cc..fd84df8 100644 --- a/README.md +++ b/README.md @@ -88,6 +88,33 @@ The profile has it enabled because this fleet's G1 has a D435i fitted (measured 14.9 Hz, 480x270 `16UC1`, RVL-compressed to ~34% of raw, lossless). On a G1 without one, set `ENABLE_DEPTH=false`. +#### DDS readers reconnect on their own after a sensor restart + +`lidar`, `pointcloud`, `depth`, `odom`, and `lowstate` each hold one +long-lived DDS reader for the life of the process -- a session rotation only +swaps their output files (see `persistentStreams` in `cmd/main/main.go`), it +never resubscribes. + +Plain DDS discovery does not always recover cleanly if the underlying sensor +or its driver process restarts (a physical power-cycle, say): a writer +announces itself with a burst of discovery packets right at startup and then +falls back to a much slower steady-state interval, so a reader that's been +sitting idle for a while can simply miss that burst and never learn the new +writer exists -- nothing retries that specific handshake afterward. A reader +created fresh (a full process restart, or a brand-new subscriber from a tool +like `ros2 topic hz`) sends its own discovery burst immediately and tends to +match right away, which is what makes this failure mode easy to miss until a +stream has been silently empty for hours. + +Each of the five streams above is registered with +`heartbeat.Monitor.RegisterRecoverable` instead of plain `Register`: once a +stream is found broken (the same "recorder NOT WORKING" condition that gets +logged), the monitor calls that stream's `Reconnect()` once per check +interval until it recovers. `Reconnect()` tears down and recreates just that +stream's DDS participant/reader -- forcing a fresh discovery burst -- without +touching output files, so no manual restart should be needed after a sensor +bounces. + #### The G1's down camera is the RealSense RGB view There is no third USB camera on a G1 -- only `OM1FRONTCAM` and `OM1REARCAM`. diff --git a/cmd/main/main.go b/cmd/main/main.go index 4a09a57..fc5bf8e 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -64,7 +64,20 @@ func main() { } mon := heartbeat.NewMonitor(30 * time.Second) - registerHeartbeats(mon, cfg, videoHeartbeatNames) + + // rs is assigned below (and reassigned on every rotation/schedule + // resume); streamsFn is only ever called later, from the heartbeat + // monitor's own goroutine, by which point rs is always set -- so it's + // safe to close over it here, before its first assignment. + var rs *recorderSet + streamsFn := func() *persistentStreams { + if rs == nil { + return nil + } + return &rs.persistent + } + + registerHeartbeats(mon, cfg, videoHeartbeatNames, streamsFn) hbCtx, hbCancel := context.WithCancel(context.Background()) go mon.Run(hbCtx) @@ -121,7 +134,7 @@ func main() { sweepCtx, sweepCancel := context.WithCancel(context.Background()) go retention.RunSweeps(sweepCtx, uploader, recordingsDir, bootTimebasePath, currentDirFn, cfg.Retention, ctl) - rs := startRecorders(cfg, mon, recordingsDir, sess, videoHeartbeatNames) + rs = startRecorders(cfg, mon, recordingsDir, sess, videoHeartbeatNames) videoURLs := make([]string, 0, len(cfg.Video)) for _, vc := range cfg.Video { @@ -209,7 +222,7 @@ func main() { currentMu.Unlock() sess, cfg = next, nextCfg - registerHeartbeats(mon, cfg, videoHeartbeatNames) + registerHeartbeats(mon, cfg, videoHeartbeatNames, streamsFn) rs = startRecorders(cfg, mon, recordingsDir, sess, videoHeartbeatNames) ctl.SetRecording(true) slog.Info("recording resumed by schedule", "session", sess.RealDir()) @@ -277,7 +290,7 @@ loop: currentMu.Unlock() sess, cfg = next, nextCfg - registerHeartbeats(mon, cfg, videoHeartbeatNames) + registerHeartbeats(mon, cfg, videoHeartbeatNames, streamsFn) persistent := rs.persistent rs = startEphemeral(cfg, mon) @@ -317,21 +330,49 @@ loop: } } -func registerHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartbeatNames []string) { +// registerHeartbeats registers every stream's heartbeat check. streams +// resolves to the persistent-stream set currently in use -- called lazily by +// the heartbeat monitor, never at registration time, so it's safe to pass a +// closure over a variable that isn't assigned yet (see main's rs). The five +// DDS-backed streams register with a reconnect callback: plain DDS discovery +// does not always recover on its own after the publisher restarts, so the +// heartbeat monitor recreates the subscription itself once it notices the +// stream has gone quiet (see heartbeat.Monitor.RegisterRecoverable). +func registerHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartbeatNames []string, streams func() *persistentStreams) { if cfg.EnableLidar { - mon.Register(lidar.HeartbeatName, 10) // ~10 Hz nominal + mon.RegisterRecoverable(lidar.HeartbeatName, 10, func() { // ~10 Hz nominal + if p := streams(); p != nil && p.lidarStream != nil { + p.lidarStream.Reconnect() + } + }) } if cfg.EnablePointCloud { - mon.Register(pointcloud.HeartbeatName, 10) // ~10 Hz nominal + mon.RegisterRecoverable(pointcloud.HeartbeatName, 10, func() { // ~10 Hz nominal + if p := streams(); p != nil && p.pointCloudStream != nil { + p.pointCloudStream.Reconnect() + } + }) } if cfg.EnableDepth { - mon.Register(depth.HeartbeatName, 10) // measured 14.9 Hz on a G1; floor at 10 + mon.RegisterRecoverable(depth.HeartbeatName, 10, func() { // measured 14.9 Hz on a G1; floor at 10 + if p := streams(); p != nil && p.depthStream != nil { + p.depthStream.Reconnect() + } + }) } if cfg.EnableOdom { - mon.Register(odom.HeartbeatName, 30) // Go2 ~150, G1 ~495; 30 = safe floor + mon.RegisterRecoverable(odom.HeartbeatName, 30, func() { // Go2 ~150, G1 ~495; 30 = safe floor + if p := streams(); p != nil && p.odomStream != nil { + p.odomStream.Reconnect() + } + }) } if cfg.EnableLowstate { - mon.Register(lowstate.HeartbeatName, 400) // Go2 ~500, G1 ~1053; 400 = safe floor + mon.RegisterRecoverable(lowstate.HeartbeatName, 400, func() { // Go2 ~500, G1 ~1053; 400 = safe floor + if p := streams(); p != nil && p.lowstateStream != nil { + p.lowstateStream.Reconnect() + } + }) } mon.Register(network.HeartbeatName, 0) // 0 = liveness check only mon.Register(audio.HeartbeatName, 0) // 0 = liveness check only diff --git a/internal/depth/stream.go b/internal/depth/stream.go index 5a91d24..e960419 100644 --- a/internal/depth/stream.go +++ b/internal/depth/stream.go @@ -35,6 +35,10 @@ type DepthStream struct { cancel context.CancelFunc wg sync.WaitGroup + // reconnect asks a running record() to tear down and recreate its DDS + // subscription. Buffered so a request never blocks; see Reconnect. + reconnect chan struct{} + filesMu sync.Mutex files *outputFiles } @@ -49,7 +53,7 @@ type outputFiles struct { } func New(cfg Config) *DepthStream { - return &DepthStream{cfg: cfg} + return &DepthStream{cfg: cfg, reconnect: make(chan struct{}, 1)} } func (d *DepthStream) Start() { @@ -92,6 +96,19 @@ func (d *DepthStream) Rotate(dataFile, timestampsFile string) error { return nil } +// Reconnect tears down and recreates the DDS subscription without touching +// output files. Plain DDS discovery does not always self-heal after the +// publisher restarts (see heartbeat.Monitor's RegisterRecoverable doc +// comment for why); this forces a fresh discovery attempt on demand. +// Non-blocking -- a request that arrives while one is already pending is +// dropped, since it would have the same effect. +func (d *DepthStream) Reconnect() { + select { + case d.reconnect <- struct{}{}: + default: + } +} + func (d *DepthStream) loop(ctx context.Context) { defer d.wg.Done() for ctx.Err() == nil { @@ -146,6 +163,9 @@ func (d *DepthStream) record(ctx context.Context) error { case <-ctx.Done(): d.flush() return nil + case <-d.reconnect: + d.flush() + return fmt.Errorf("reconnect requested") case <-syncTicker.C: d.flush() case sample, ok := <-receiver: diff --git a/internal/heartbeat/heartbeat.go b/internal/heartbeat/heartbeat.go index 3d577ab..b2be5b2 100644 --- a/internal/heartbeat/heartbeat.go +++ b/internal/heartbeat/heartbeat.go @@ -22,6 +22,11 @@ type state struct { lastTime time.Time registered time.Time warned bool + + // reconnect, if set, is called (in its own goroutine) every time a check + // finds the stream still broken -- see RegisterRecoverable. + reconnect func() + reconnecting atomic.Bool } func NewMonitor(checkInterval time.Duration) *Monitor { @@ -29,11 +34,32 @@ func NewMonitor(checkInterval time.Duration) *Monitor { } func (m *Monitor) Register(name string, expectedHz float64) { + m.register(name, expectedHz, nil) +} + +// RegisterRecoverable is like Register, but reconnect is called once per +// check interval for as long as the stream stays broken. +// +// Plain DDS discovery is not self-healing in every case: a writer that +// restarts (e.g. a sensor power-cycling) announces itself with a burst of +// discovery packets and then falls back to a slow steady-state interval: if +// that initial burst is lost, a reader that has been sitting idle for a +// while -- rather than actively rebroadcasting its own interest -- can miss +// it and never match, indefinitely. reconnect should tear down and recreate +// the stream's DDS subscription so it sends a fresh discovery burst of its +// own, giving the handshake another chance. A reconnect already in flight is +// never duplicated. +func (m *Monitor) RegisterRecoverable(name string, expectedHz float64, reconnect func()) { + m.register(name, expectedHz, reconnect) +} + +func (m *Monitor) register(name string, expectedHz float64, reconnect func()) { now := time.Now() m.streams.Store(name, &state{ expectedHz: expectedHz, lastTime: now, registered: now, + reconnect: reconnect, }) } @@ -117,6 +143,14 @@ func (m *Monitor) check() { s.warned = false } + if bad && s.reconnect != nil && s.reconnecting.CompareAndSwap(false, true) { + reconnect := s.reconnect + go func() { + defer s.reconnecting.Store(false) + reconnect() + }() + } + s.lastTicks = current s.lastTime = now return true diff --git a/internal/heartbeat/heartbeat_test.go b/internal/heartbeat/heartbeat_test.go index 77d086a..7449515 100644 --- a/internal/heartbeat/heartbeat_test.go +++ b/internal/heartbeat/heartbeat_test.go @@ -2,6 +2,7 @@ package heartbeat import ( "context" + "sync/atomic" "testing" "time" @@ -142,3 +143,71 @@ func TestCheck_noWarnWhenTicksArrive(t *testing.T) { v, _ := mon.streams.Load("lidar") require.False(t, v.(*state).warned, "should not warn when stream is ticking at expected rate") } + +// Reproduces the real gap this closes: a DDS reader that never received the +// writer's post-restart discovery burst just sits there silently forever -- +// nothing in plain DDS retries that handshake. RegisterRecoverable's +// reconnect callback is what has to notice and force a retry. +func TestRegisterRecoverable_callsReconnectWhenBroken(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + called := make(chan struct{}, 1) + mon.RegisterRecoverable("pointcloud", 10, func() { + select { + case called <- struct{}{}: + default: + } + }) + + time.Sleep(20 * time.Millisecond) // past the 2x-interval grace period + mon.check() + + select { + case <-called: + case <-time.After(2 * time.Second): + t.Fatal("reconnect was not called for a stream that never received a message") + } +} + +func TestRegisterRecoverable_doesNotCallReconnectWhileHealthy(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + called := make(chan struct{}, 1) + mon.RegisterRecoverable("lidar", 10, func() { + select { + case called <- struct{}{}: + default: + } + }) + + for range 100 { + mon.Tick("lidar") + } + time.Sleep(20 * time.Millisecond) + mon.check() + + select { + case <-called: + t.Fatal("reconnect must not be called for a healthy stream") + case <-time.After(50 * time.Millisecond): + } +} + +// A reconnect can legitimately take longer than one check interval (it tears +// down and recreates a real DDS participant); check() must not pile up a new +// goroutine calling reconnect again on top of one still running. +func TestRegisterRecoverable_doesNotOverlapReconnects(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + var calls atomic.Int32 + release := make(chan struct{}) + mon.RegisterRecoverable("odom", 30, func() { + calls.Add(1) + <-release + }) + + time.Sleep(20 * time.Millisecond) + mon.check() // starts a reconnect that blocks on release + mon.check() // must see one already in flight and skip + + time.Sleep(20 * time.Millisecond) + require.Equal(t, int32(1), calls.Load(), "a reconnect already in flight must not be duplicated") + close(release) +} diff --git a/internal/lidar/reconnect_test.go b/internal/lidar/reconnect_test.go new file mode 100644 index 0000000..6fc6ce0 --- /dev/null +++ b/internal/lidar/reconnect_test.go @@ -0,0 +1,113 @@ +package lidar + +import ( + "os" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/stretchr/testify/require" + + "om1-telemetry/internal/ddscore" + "om1-telemetry/internal/lidar/ddstest" +) + +func countDataLines(t *testing.T, path string) int { + t.Helper() + data, err := os.ReadFile(path) + if err != nil { + if os.IsNotExist(err) { + return 0 + } + t.Fatalf("read %s: %v", path, err) + } + n := 0 + for _, l := range strings.Split(strings.TrimSpace(string(data)), "\n") { + if l != "" { + n++ + } + } + return n +} + +func waitForLines(t *testing.T, path string, want int, timeout time.Duration, msgAndArgs ...any) { + t.Helper() + deadline := time.After(timeout) + for { + if countDataLines(t, path) >= want { + return + } + select { + case <-deadline: + t.Fatalf("timed out waiting for %d line(s) in %s (have %d): %v", + want, path, countDataLines(t, path), msgAndArgs) + case <-time.After(10 * time.Millisecond): + } + } +} + +// Reconnect exists for exactly one real-world scenario: the physical sensor +// (or its driver process) restarts, the reader that was already running +// misses the writer's post-restart discovery burst, and -- unlike a brand +// new reader, which would match immediately -- it never recovers on its +// own. This test doesn't reproduce a lost discovery packet (not practical +// over real loopback DDS), but it does prove the mechanical half of the +// fix: Reconnect() tears the subscription down and rebuilds it without +// losing the stream's ability to receive -- so whatever heartbeat.Monitor +// decides to call it on gets a working reader back. +func TestReconnect_stillReceivesAfterRecreatingSubscription(t *testing.T) { + if testing.Short() { + t.Skip("skipping DDS loopback test in short mode") + } + + t.Setenv("CYCLONEDDS_URI", ``) + + const ( + domainID = 79 + topicName = "reconnect_test_scan" + ) + + wp, err := ddscore.NewParticipant(domainID) + require.NoError(t, err) + defer func() { _ = wp.Close() }() + + writer, err := ddstest.SetupWriter(wp, topicName) + require.NoError(t, err) + + dir := t.TempDir() + tsFile := filepath.Join(dir, "timestamps.csv") + stream := New(Config{ + DDSDomainID: domainID, + DDSTopic: topicName, + TimestampsFile: tsFile, + DataFile: filepath.Join(dir, "data.bin"), + }) + stream.Start() + defer stream.Stop() + + require.NoError(t, ddstest.PublishScan(writer, 8, 0)) + waitForLines(t, tsFile, 1, 2*time.Second) // +1 for the CSV header + + stream.Reconnect() + // Give record() time to observe the request and tear down the old + // participant/reader before the recreated one starts discovery. + time.Sleep(300 * time.Millisecond) + + // The recreated reader still has to complete DDS discovery with the + // (already-running) writer before a sample lands, and a single publish + // racing that handshake could be missed entirely (VOLATILE durability + // delivers only to readers already matched at publish time) -- so + // publish repeatedly, like the real writer's continuous stream would, + // until the new subscription has clearly caught up. + deadline := time.After(5 * time.Second) + for countDataLines(t, tsFile) < 2 { + require.NoError(t, ddstest.PublishScan(writer, 8, 1)) + select { + case <-deadline: + t.Fatalf("a sample published after Reconnect was never received by the recreated subscription (have %d line(s))", + countDataLines(t, tsFile)) + case <-time.After(100 * time.Millisecond): + } + } +} diff --git a/internal/lidar/stream.go b/internal/lidar/stream.go index 5a6a06c..ab274fc 100644 --- a/internal/lidar/stream.go +++ b/internal/lidar/stream.go @@ -35,6 +35,10 @@ type LidarStream struct { cancel context.CancelFunc wg sync.WaitGroup + // reconnect asks a running record() to tear down and recreate its DDS + // subscription. Buffered so a request never blocks; see Reconnect. + reconnect chan struct{} + filesMu sync.Mutex files *outputFiles } @@ -49,7 +53,7 @@ type outputFiles struct { } func New(cfg Config) *LidarStream { - return &LidarStream{cfg: cfg} + return &LidarStream{cfg: cfg, reconnect: make(chan struct{}, 1)} } func (l *LidarStream) Start() { @@ -92,6 +96,19 @@ func (l *LidarStream) Rotate(dataFile, timestampsFile string) error { return nil } +// Reconnect tears down and recreates the DDS subscription without touching +// output files or the dedup/rotation state. Plain DDS discovery does not +// always self-heal after the publisher restarts (see heartbeat.Monitor's +// RegisterRecoverable doc comment for why); this forces a fresh discovery +// attempt on demand. Non-blocking -- a request that arrives while one is +// already pending is dropped, since it would have the same effect. +func (l *LidarStream) Reconnect() { + select { + case l.reconnect <- struct{}{}: + default: + } +} + func (l *LidarStream) loop(ctx context.Context) { defer l.wg.Done() for ctx.Err() == nil { @@ -146,6 +163,9 @@ func (l *LidarStream) record(ctx context.Context) error { case <-ctx.Done(): l.flush() return nil + case <-l.reconnect: + l.flush() + return fmt.Errorf("reconnect requested") case <-syncTicker.C: l.flush() case sample, ok := <-receiver: diff --git a/internal/lowstate/stream.go b/internal/lowstate/stream.go index 7ac104b..d1415fd 100644 --- a/internal/lowstate/stream.go +++ b/internal/lowstate/stream.go @@ -34,6 +34,10 @@ type LowstateStream struct { cancel context.CancelFunc wg sync.WaitGroup + // reconnect asks a running record() to tear down and recreate its DDS + // subscription. Buffered so a request never blocks; see Reconnect. + reconnect chan struct{} + filesMu sync.Mutex files *outputFiles } @@ -48,7 +52,7 @@ type outputFiles struct { } func New(cfg Config) *LowstateStream { - return &LowstateStream{cfg: cfg} + return &LowstateStream{cfg: cfg, reconnect: make(chan struct{}, 1)} } func (l *LowstateStream) Start() { @@ -91,6 +95,19 @@ func (l *LowstateStream) Rotate(dataFile, timestampsFile string) error { return nil } +// Reconnect tears down and recreates the DDS subscription without touching +// output files. Plain DDS discovery does not always self-heal after the +// publisher restarts (see heartbeat.Monitor's RegisterRecoverable doc +// comment for why); this forces a fresh discovery attempt on demand. +// Non-blocking -- a request that arrives while one is already pending is +// dropped, since it would have the same effect. +func (l *LowstateStream) Reconnect() { + select { + case l.reconnect <- struct{}{}: + default: + } +} + func (l *LowstateStream) loop(ctx context.Context) { defer l.wg.Done() for ctx.Err() == nil { @@ -145,6 +162,9 @@ func (l *LowstateStream) record(ctx context.Context) error { case <-ctx.Done(): l.flush() return nil + case <-l.reconnect: + l.flush() + return fmt.Errorf("reconnect requested") case <-syncTicker.C: l.flush() case sample, ok := <-receiver: diff --git a/internal/odom/stream.go b/internal/odom/stream.go index 45b4f00..fa436d3 100644 --- a/internal/odom/stream.go +++ b/internal/odom/stream.go @@ -33,6 +33,10 @@ type OdomStream struct { cancel context.CancelFunc wg sync.WaitGroup + // reconnect asks a running record() to tear down and recreate its DDS + // subscription. Buffered so a request never blocks; see Reconnect. + reconnect chan struct{} + filesMu sync.Mutex files *outputFiles } @@ -47,7 +51,7 @@ type outputFiles struct { } func New(cfg Config) *OdomStream { - return &OdomStream{cfg: cfg} + return &OdomStream{cfg: cfg, reconnect: make(chan struct{}, 1)} } func (o *OdomStream) Start() { @@ -90,6 +94,19 @@ func (o *OdomStream) Rotate(dataFile, timestampsFile string) error { return nil } +// Reconnect tears down and recreates the DDS subscription without touching +// output files. Plain DDS discovery does not always self-heal after the +// publisher restarts (see heartbeat.Monitor's RegisterRecoverable doc +// comment for why); this forces a fresh discovery attempt on demand. +// Non-blocking -- a request that arrives while one is already pending is +// dropped, since it would have the same effect. +func (o *OdomStream) Reconnect() { + select { + case o.reconnect <- struct{}{}: + default: + } +} + func (o *OdomStream) loop(ctx context.Context) { defer o.wg.Done() for ctx.Err() == nil { @@ -144,6 +161,9 @@ func (o *OdomStream) record(ctx context.Context) error { case <-ctx.Done(): o.flush() return nil + case <-o.reconnect: + o.flush() + return fmt.Errorf("reconnect requested") case <-syncTicker.C: o.flush() case sample, ok := <-receiver: diff --git a/internal/pointcloud/stream.go b/internal/pointcloud/stream.go index 09af1f6..8ad0c9c 100644 --- a/internal/pointcloud/stream.go +++ b/internal/pointcloud/stream.go @@ -41,6 +41,10 @@ type PointCloudStream struct { // needs no lock of its own. encoder *zstd.Encoder + // reconnect asks a running record() to tear down and recreate its DDS + // subscription. Buffered so a request never blocks; see Reconnect. + reconnect chan struct{} + filesMu sync.Mutex files *outputFiles } @@ -55,7 +59,7 @@ type outputFiles struct { } func New(cfg Config) *PointCloudStream { - return &PointCloudStream{cfg: cfg} + return &PointCloudStream{cfg: cfg, reconnect: make(chan struct{}, 1)} } func (c *PointCloudStream) Start() { @@ -104,6 +108,19 @@ func (c *PointCloudStream) Rotate(dataFile, timestampsFile string) error { return nil } +// Reconnect tears down and recreates the DDS subscription without touching +// output files or the encoder. Plain DDS discovery does not always self-heal +// after the publisher restarts (see heartbeat.Monitor's RegisterRecoverable +// doc comment for why); this forces a fresh discovery attempt on demand. +// Non-blocking -- a request that arrives while one is already pending is +// dropped, since it would have the same effect. +func (c *PointCloudStream) Reconnect() { + select { + case c.reconnect <- struct{}{}: + default: + } +} + func (c *PointCloudStream) loop(ctx context.Context) { defer c.wg.Done() for ctx.Err() == nil { @@ -172,6 +189,9 @@ func (c *PointCloudStream) record(ctx context.Context) error { case <-ctx.Done(): c.flush() return nil + case <-c.reconnect: + c.flush() + return fmt.Errorf("reconnect requested") case <-syncTicker.C: c.flush() case sample, ok := <-receiver: From 94b9d965ea374f876f13b32852e4819b531aae22 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 1 Sep 2026 14:23:44 -0500 Subject: [PATCH 06/26] Trim inline comments and pare doc comments to 1-2 lines 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- cmd/main/main.go | 27 +++++++++------------------ config/config.go | 3 --- internal/depth/stream.go | 6 +----- internal/heartbeat/heartbeat.go | 10 ---------- internal/heartbeat/heartbeat_test.go | 14 +++++--------- internal/lidar/reconnect_test.go | 21 +++------------------ internal/lidar/stream.go | 6 +----- internal/lowstate/stream.go | 6 +----- internal/odom/stream.go | 6 +----- internal/pointcloud/stream.go | 6 +----- internal/retention/retention.go | 5 +---- internal/retention/retention_test.go | 12 ++---------- internal/session/session.go | 5 +---- internal/traces/stream.go | 25 +++++-------------------- internal/traces/stream_test.go | 26 +++++--------------------- internal/upload/preprocess.go | 3 --- 16 files changed, 36 insertions(+), 145 deletions(-) diff --git a/cmd/main/main.go b/cmd/main/main.go index fc5bf8e..c329126 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -65,10 +65,6 @@ func main() { mon := heartbeat.NewMonitor(30 * time.Second) - // rs is assigned below (and reassigned on every rotation/schedule - // resume); streamsFn is only ever called later, from the heartbeat - // monitor's own goroutine, by which point rs is always set -- so it's - // safe to close over it here, before its first assignment. var rs *recorderSet streamsFn := func() *persistentStreams { if rs == nil { @@ -330,45 +326,40 @@ loop: } } -// registerHeartbeats registers every stream's heartbeat check. streams -// resolves to the persistent-stream set currently in use -- called lazily by -// the heartbeat monitor, never at registration time, so it's safe to pass a -// closure over a variable that isn't assigned yet (see main's rs). The five -// DDS-backed streams register with a reconnect callback: plain DDS discovery -// does not always recover on its own after the publisher restarts, so the -// heartbeat monitor recreates the subscription itself once it notices the -// stream has gone quiet (see heartbeat.Monitor.RegisterRecoverable). +// registerHeartbeats registers every stream's heartbeat check. The five +// DDS-backed streams register a reconnect callback via streams, resolved +// lazily since the stream objects don't exist yet at the first call site. func registerHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartbeatNames []string, streams func() *persistentStreams) { if cfg.EnableLidar { - mon.RegisterRecoverable(lidar.HeartbeatName, 10, func() { // ~10 Hz nominal + mon.RegisterRecoverable(lidar.HeartbeatName, 10, func() { if p := streams(); p != nil && p.lidarStream != nil { p.lidarStream.Reconnect() } }) } if cfg.EnablePointCloud { - mon.RegisterRecoverable(pointcloud.HeartbeatName, 10, func() { // ~10 Hz nominal + mon.RegisterRecoverable(pointcloud.HeartbeatName, 10, func() { if p := streams(); p != nil && p.pointCloudStream != nil { p.pointCloudStream.Reconnect() } }) } if cfg.EnableDepth { - mon.RegisterRecoverable(depth.HeartbeatName, 10, func() { // measured 14.9 Hz on a G1; floor at 10 + mon.RegisterRecoverable(depth.HeartbeatName, 10, func() { if p := streams(); p != nil && p.depthStream != nil { p.depthStream.Reconnect() } }) } if cfg.EnableOdom { - mon.RegisterRecoverable(odom.HeartbeatName, 30, func() { // Go2 ~150, G1 ~495; 30 = safe floor + mon.RegisterRecoverable(odom.HeartbeatName, 30, func() { if p := streams(); p != nil && p.odomStream != nil { p.odomStream.Reconnect() } }) } if cfg.EnableLowstate { - mon.RegisterRecoverable(lowstate.HeartbeatName, 400, func() { // Go2 ~500, G1 ~1053; 400 = safe floor + mon.RegisterRecoverable(lowstate.HeartbeatName, 400, func() { if p := streams(); p != nil && p.lowstateStream != nil { p.lowstateStream.Reconnect() } @@ -380,7 +371,7 @@ func registerHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartbea mon.Register(features.HeartbeatName, 0) // 0 = liveness check only } if cfg.Traces.Enabled { - mon.Register(traces.HeartbeatName, 0) // 0 = liveness check only -- polls are regular, new records are not + mon.Register(traces.HeartbeatName, 0) } for _, name := range videoHeartbeatNames { mon.Register(name, 0) diff --git a/config/config.go b/config/config.go index 2172b49..3693df4 100644 --- a/config/config.go +++ b/config/config.go @@ -245,9 +245,6 @@ func Load(sessionDir string) Config { URL: envStr("TRACES_URL", "http://localhost:9090/traces/metrics"), PollInterval: envDuration("TRACES_POLL_INTERVAL", 30*time.Second), OutputFile: filepath.Join(sessionDir, "traces.jsonl"), - // Outside sessionDir deliberately: this must survive both session - // rotation and a full process restart, not just live for one - // session's lifetime -- see traces.Config.CursorFile. CursorFile: filepath.Join(RecordingsDir(), ".traces_cursor"), }, SessionRotateInterval: envDuration("SESSION_ROTATE_INTERVAL", 5*time.Minute), diff --git a/internal/depth/stream.go b/internal/depth/stream.go index e960419..e9544a8 100644 --- a/internal/depth/stream.go +++ b/internal/depth/stream.go @@ -97,11 +97,7 @@ func (d *DepthStream) Rotate(dataFile, timestampsFile string) error { } // Reconnect tears down and recreates the DDS subscription without touching -// output files. Plain DDS discovery does not always self-heal after the -// publisher restarts (see heartbeat.Monitor's RegisterRecoverable doc -// comment for why); this forces a fresh discovery attempt on demand. -// Non-blocking -- a request that arrives while one is already pending is -// dropped, since it would have the same effect. +// output files. Non-blocking; see heartbeat.Monitor.RegisterRecoverable. func (d *DepthStream) Reconnect() { select { case d.reconnect <- struct{}{}: diff --git a/internal/heartbeat/heartbeat.go b/internal/heartbeat/heartbeat.go index b2be5b2..3e17435 100644 --- a/internal/heartbeat/heartbeat.go +++ b/internal/heartbeat/heartbeat.go @@ -39,16 +39,6 @@ func (m *Monitor) Register(name string, expectedHz float64) { // RegisterRecoverable is like Register, but reconnect is called once per // check interval for as long as the stream stays broken. -// -// Plain DDS discovery is not self-healing in every case: a writer that -// restarts (e.g. a sensor power-cycling) announces itself with a burst of -// discovery packets and then falls back to a slow steady-state interval: if -// that initial burst is lost, a reader that has been sitting idle for a -// while -- rather than actively rebroadcasting its own interest -- can miss -// it and never match, indefinitely. reconnect should tear down and recreate -// the stream's DDS subscription so it sends a fresh discovery burst of its -// own, giving the handshake another chance. A reconnect already in flight is -// never duplicated. func (m *Monitor) RegisterRecoverable(name string, expectedHz float64, reconnect func()) { m.register(name, expectedHz, reconnect) } diff --git a/internal/heartbeat/heartbeat_test.go b/internal/heartbeat/heartbeat_test.go index 7449515..61f4139 100644 --- a/internal/heartbeat/heartbeat_test.go +++ b/internal/heartbeat/heartbeat_test.go @@ -145,9 +145,7 @@ func TestCheck_noWarnWhenTicksArrive(t *testing.T) { } // Reproduces the real gap this closes: a DDS reader that never received the -// writer's post-restart discovery burst just sits there silently forever -- -// nothing in plain DDS retries that handshake. RegisterRecoverable's -// reconnect callback is what has to notice and force a retry. +// writer's post-restart discovery burst just sits there silently forever. func TestRegisterRecoverable_callsReconnectWhenBroken(t *testing.T) { mon := NewMonitor(5 * time.Millisecond) called := make(chan struct{}, 1) @@ -158,7 +156,7 @@ func TestRegisterRecoverable_callsReconnectWhenBroken(t *testing.T) { } }) - time.Sleep(20 * time.Millisecond) // past the 2x-interval grace period + time.Sleep(20 * time.Millisecond) mon.check() select { @@ -191,9 +189,7 @@ func TestRegisterRecoverable_doesNotCallReconnectWhileHealthy(t *testing.T) { } } -// A reconnect can legitimately take longer than one check interval (it tears -// down and recreates a real DDS participant); check() must not pile up a new -// goroutine calling reconnect again on top of one still running. +// check() must not pile up a new reconnect goroutine on top of one still running. func TestRegisterRecoverable_doesNotOverlapReconnects(t *testing.T) { mon := NewMonitor(5 * time.Millisecond) var calls atomic.Int32 @@ -204,8 +200,8 @@ func TestRegisterRecoverable_doesNotOverlapReconnects(t *testing.T) { }) time.Sleep(20 * time.Millisecond) - mon.check() // starts a reconnect that blocks on release - mon.check() // must see one already in flight and skip + mon.check() + mon.check() time.Sleep(20 * time.Millisecond) require.Equal(t, int32(1), calls.Load(), "a reconnect already in flight must not be duplicated") diff --git a/internal/lidar/reconnect_test.go b/internal/lidar/reconnect_test.go index 6fc6ce0..d657567 100644 --- a/internal/lidar/reconnect_test.go +++ b/internal/lidar/reconnect_test.go @@ -47,15 +47,8 @@ func waitForLines(t *testing.T, path string, want int, timeout time.Duration, ms } } -// Reconnect exists for exactly one real-world scenario: the physical sensor -// (or its driver process) restarts, the reader that was already running -// misses the writer's post-restart discovery burst, and -- unlike a brand -// new reader, which would match immediately -- it never recovers on its -// own. This test doesn't reproduce a lost discovery packet (not practical -// over real loopback DDS), but it does prove the mechanical half of the -// fix: Reconnect() tears the subscription down and rebuilds it without -// losing the stream's ability to receive -- so whatever heartbeat.Monitor -// decides to call it on gets a working reader back. +// Proves Reconnect() tears the subscription down and rebuilds it without +// losing the stream's ability to receive. func TestReconnect_stillReceivesAfterRecreatingSubscription(t *testing.T) { if testing.Short() { t.Skip("skipping DDS loopback test in short mode") @@ -87,19 +80,11 @@ func TestReconnect_stillReceivesAfterRecreatingSubscription(t *testing.T) { defer stream.Stop() require.NoError(t, ddstest.PublishScan(writer, 8, 0)) - waitForLines(t, tsFile, 1, 2*time.Second) // +1 for the CSV header + waitForLines(t, tsFile, 1, 2*time.Second) stream.Reconnect() - // Give record() time to observe the request and tear down the old - // participant/reader before the recreated one starts discovery. time.Sleep(300 * time.Millisecond) - // The recreated reader still has to complete DDS discovery with the - // (already-running) writer before a sample lands, and a single publish - // racing that handshake could be missed entirely (VOLATILE durability - // delivers only to readers already matched at publish time) -- so - // publish repeatedly, like the real writer's continuous stream would, - // until the new subscription has clearly caught up. deadline := time.After(5 * time.Second) for countDataLines(t, tsFile) < 2 { require.NoError(t, ddstest.PublishScan(writer, 8, 1)) diff --git a/internal/lidar/stream.go b/internal/lidar/stream.go index ab274fc..09a96bf 100644 --- a/internal/lidar/stream.go +++ b/internal/lidar/stream.go @@ -97,11 +97,7 @@ func (l *LidarStream) Rotate(dataFile, timestampsFile string) error { } // Reconnect tears down and recreates the DDS subscription without touching -// output files or the dedup/rotation state. Plain DDS discovery does not -// always self-heal after the publisher restarts (see heartbeat.Monitor's -// RegisterRecoverable doc comment for why); this forces a fresh discovery -// attempt on demand. Non-blocking -- a request that arrives while one is -// already pending is dropped, since it would have the same effect. +// output files. Non-blocking; see heartbeat.Monitor.RegisterRecoverable. func (l *LidarStream) Reconnect() { select { case l.reconnect <- struct{}{}: diff --git a/internal/lowstate/stream.go b/internal/lowstate/stream.go index d1415fd..15995a3 100644 --- a/internal/lowstate/stream.go +++ b/internal/lowstate/stream.go @@ -96,11 +96,7 @@ func (l *LowstateStream) Rotate(dataFile, timestampsFile string) error { } // Reconnect tears down and recreates the DDS subscription without touching -// output files. Plain DDS discovery does not always self-heal after the -// publisher restarts (see heartbeat.Monitor's RegisterRecoverable doc -// comment for why); this forces a fresh discovery attempt on demand. -// Non-blocking -- a request that arrives while one is already pending is -// dropped, since it would have the same effect. +// output files. Non-blocking; see heartbeat.Monitor.RegisterRecoverable. func (l *LowstateStream) Reconnect() { select { case l.reconnect <- struct{}{}: diff --git a/internal/odom/stream.go b/internal/odom/stream.go index fa436d3..27e93a9 100644 --- a/internal/odom/stream.go +++ b/internal/odom/stream.go @@ -95,11 +95,7 @@ func (o *OdomStream) Rotate(dataFile, timestampsFile string) error { } // Reconnect tears down and recreates the DDS subscription without touching -// output files. Plain DDS discovery does not always self-heal after the -// publisher restarts (see heartbeat.Monitor's RegisterRecoverable doc -// comment for why); this forces a fresh discovery attempt on demand. -// Non-blocking -- a request that arrives while one is already pending is -// dropped, since it would have the same effect. +// output files. Non-blocking; see heartbeat.Monitor.RegisterRecoverable. func (o *OdomStream) Reconnect() { select { case o.reconnect <- struct{}{}: diff --git a/internal/pointcloud/stream.go b/internal/pointcloud/stream.go index 8ad0c9c..ae8f710 100644 --- a/internal/pointcloud/stream.go +++ b/internal/pointcloud/stream.go @@ -109,11 +109,7 @@ func (c *PointCloudStream) Rotate(dataFile, timestampsFile string) error { } // Reconnect tears down and recreates the DDS subscription without touching -// output files or the encoder. Plain DDS discovery does not always self-heal -// after the publisher restarts (see heartbeat.Monitor's RegisterRecoverable -// doc comment for why); this forces a fresh discovery attempt on demand. -// Non-blocking -- a request that arrives while one is already pending is -// dropped, since it would have the same effect. +// output files. Non-blocking; see heartbeat.Monitor.RegisterRecoverable. func (c *PointCloudStream) Reconnect() { select { case c.reconnect <- struct{}{}: diff --git a/internal/retention/retention.go b/internal/retention/retention.go index 572bc10..90542f4 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -43,10 +43,7 @@ const uploadTimeout = 10 * time.Minute const minSessionAge = 30 * time.Second // tooYoungToSweep reports whether dir's own recorded start time is within -// minSessionAge of now -- see minSessionAge's doc comment. A directory whose -// start time can't be read (missing/corrupt meta.json) is not protected by -// this check; that's an existing edge case the current-dir check alone -// already had to live with. +// minSessionAge of now. func tooYoungToSweep(dir string) bool { start := ReadStartedAt(dir) if start.IsZero() { diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index f723fd5..ececce6 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -251,26 +251,18 @@ func TestSweep_uploadsOldestUnmarkedFirstAndSkipsProtectedAndAlreadyUploaded(t * } // Reproduces the race this protection closes: a session directory that -// exists on disk (session.OpenNext already created it and wrote meta.json) -// but that the caller hasn't yet reported as "current" -- the exact gap -// between OpenNext returning and cmd/main's current pointer being updated. -// Without the age check, ListClosed would surface it and the sweep would -// upload whatever the handful of streams had flushed in the first second, -// then mark it uploaded -- so the real end-of-session upload later silently -// no-ops against a server that already thinks the session is complete. +// exists on disk but hasn't yet been reported as "current" must not upload. func TestSweep_neverUploadsAVeryYoungDirEvenIfNotReportedCurrent(t *testing.T) { api, apiURL := newMinimalFakeAPI(t) client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) root := t.TempDir() justOpened := filepath.Join(root, "2026-08-31", "2026-08-31_21-22-33") - startedNs := time.Now().Add(-1 * time.Second).UnixNano() // opened a moment ago, well inside minSessionAge + startedNs := time.Now().Add(-1 * time.Second).UnixNano() writeFile(t, justOpened, "meta.json", []byte(fmt.Sprintf(`{"session_start_unix_ns":%d}`, startedNs))) bootTimebasePath := filepath.Join(root, "does-not-exist.jsonl") - // currentDir is deliberately NOT justOpened -- simulating the moment - // before cmd/main's "current" pointer has caught up to it. Sweep(control.New(), client, root, bootTimebasePath, "", 0) require.False(t, IsUploaded(justOpened), diff --git a/internal/session/session.go b/internal/session/session.go index 76f594e..bfe7a27 100644 --- a/internal/session/session.go +++ b/internal/session/session.go @@ -441,10 +441,7 @@ func SortedNames(dirs []string) []string { } // ListClosed returns every dated session directory under root, oldest -// first -- including the one currently being recorded to. Despite the -// name, it does not check meta.json's session_end field or otherwise -// verify a directory is actually closed; callers (retention's sweep) are -// responsible for excluding the live session themselves. +// first. It does not verify a directory is actually closed. func ListClosed(root string) ([]string, error) { dateEntries, err := os.ReadDir(root) if err != nil { diff --git a/internal/traces/stream.go b/internal/traces/stream.go index 662f59a..b4f4310 100644 --- a/internal/traces/stream.go +++ b/internal/traces/stream.go @@ -173,11 +173,8 @@ func (s *TraceStream) ensureFileOpen() error { return nil } -// poll fetches and parses one batch from OM1's trace-export endpoint and -// appends any records newer than the dedup cursor. Errors (network, parse) -// are logged and left for the next tick -- OM1's exporter buffers the last -// 200 records, so a poller that's behind by less than that window catches up -// without losing anything. +// poll fetches one batch and appends any records newer than the dedup +// cursor. Errors are logged and retried on the next tick. func (s *TraceStream) poll(ctx context.Context) { records, err := s.fetch(ctx) if err != nil { @@ -219,15 +216,8 @@ func (s *TraceStream) poll(ctx context.Context) { s.saveCursor(newest) } -// loadCursor restores the dedup cursor from CursorFile, if set and present. -// -// Without this, a full process restart (not just a session rotation, which -// Rotate already handles) resets the in-memory cursor to zero. OM1's -// exporter keeps serving its whole buffer (up to 200 records) regardless of -// what already got written -- so a freshly-started process would treat -// everything still in that buffer as new and write it all into whichever -// session happens to be open at that moment, mixing in records that are -// chronologically well outside that session's own time window. +// loadCursor restores the dedup cursor from CursorFile, if set and present, +// so a full process restart doesn't re-ingest OM1's whole buffered backlog. func (s *TraceStream) loadCursor() { if s.cfg.CursorFile == "" { return @@ -247,9 +237,7 @@ func (s *TraceStream) loadCursor() { } // saveCursor persists the dedup cursor so loadCursor can restore it after a -// restart. Best-effort: a failure here just means the next restart falls -// back to re-ingesting whatever OM1 still has buffered, same as before this -// existed -- not worth aborting the poll loop over. +// restart. Best-effort: failures are only logged. func (s *TraceStream) saveCursor(ts time.Time) { if s.cfg.CursorFile == "" { return @@ -308,9 +296,6 @@ func (s *TraceStream) fetch(ctx context.Context) ([]record, error) { return nil, fmt.Errorf("unexpected status %s", resp.Status) } - // om1_trace_info is a plain ASCII, underscore-separated Prometheus name - // (client_golang's classic exposition format), not a UTF-8 name -- so - // LegacyValidation, not the module-wide default of UTF8Validation. parser := expfmt.NewTextParser(model.LegacyValidation) families, err := parser.TextToMetricFamilies(resp.Body) if err != nil { diff --git a/internal/traces/stream_test.go b/internal/traces/stream_test.go index 47b1fda..7c46c7a 100644 --- a/internal/traces/stream_test.go +++ b/internal/traces/stream_test.go @@ -22,10 +22,8 @@ func testConfig(t *testing.T, url string) Config { } } -// exposition builds a minimal om1_trace_info text-exposition-format body, -// exactly as OM1's exporter (a real prometheus client_golang GaugeVec) would -// serialize it -- escaped quotes/newlines included, to exercise the parser -// the same way it would see a real scrape. +// exposition builds a minimal om1_trace_info exposition-format body, as +// OM1's real exporter would serialize it. func exposition(records ...[5]string) string { var b strings.Builder b.WriteString("# HELP om1_trace_info test\n# TYPE om1_trace_info gauge\n") @@ -132,8 +130,6 @@ func TestPoll_writesNewRecordsOnce(t *testing.T) { waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, cfg.OutputFile)) == 1 }) - // The same record is served on every subsequent poll (OM1 keeps it - // buffered until evicted); it must not be re-written. time.Sleep(150 * time.Millisecond) require.Len(t, fileLines(t, cfg.OutputFile), 1, "an already-seen record must not be duplicated across polls") require.Contains(t, fileLines(t, cfg.OutputFile)[0], `"llm_input":"hello there"`) @@ -167,7 +163,6 @@ func TestPoll_appendsNewRecordsAcrossPolls(t *testing.T) { } func TestPoll_handlesEscapedQuotesAndNewlines(t *testing.T) { - // Mirrors how a real client_golang exposition encoder escapes label values. rec := [5]string{"0", "2026-08-31T17:41:36.000000000Z", "1", `line one\nline two \"quoted\"`, "[]"} server := serveText(t, func() string { return exposition(rec) }) @@ -196,18 +191,12 @@ func TestRotate_preservesDedupCursor(t *testing.T) { secondFile := filepath.Join(t.TempDir(), "traces2.jsonl") require.NoError(t, stream.Rotate(secondFile)) - // OM1 keeps serving the same buffered record; it was already consumed - // before the rotation, so the new file must stay empty. time.Sleep(150 * time.Millisecond) require.Empty(t, fileLines(t, secondFile), "a record already written before Rotate must not reappear in the new file") } -// Reproduces the real bug: a process restart (a fresh TraceStream, not just -// Rotate on the same one) used to reset the in-memory cursor to zero, so a -// still-buffered OM1 backlog would all look new again and get dumped into -// whatever session happened to be open at that moment -- even records that -// were already written, chronologically outside that session's window, -// minutes to hours earlier. CursorFile is what closes that gap. +// Reproduces the real bug: a fresh process's cursor started at zero and +// re-ingested OM1's whole buffered backlog into whatever session was open. func TestCursorFile_survivesProcessRestart(t *testing.T) { rec := [5]string{"0", "2026-08-31T17:41:36.000000000Z", "1", "hello", "[]"} server := serveText(t, func() string { return exposition(rec) }) @@ -223,8 +212,6 @@ func TestCursorFile_survivesProcessRestart(t *testing.T) { waitFor(t, 2*time.Second, func() bool { return len(fileLines(t, firstOutput)) == 1 }) first.Stop() - // A brand-new TraceStream, as a fresh process restart would construct -- - // no in-memory state carried over, only CursorFile on disk. secondOutput := filepath.Join(t.TempDir(), "traces.jsonl") second := New(Config{ URL: server.URL, PollInterval: 20 * time.Millisecond, @@ -233,9 +220,6 @@ func TestCursorFile_survivesProcessRestart(t *testing.T) { second.Start() defer second.Stop() - // OM1 keeps serving the same record the first process already wrote; - // the second process must recognize it as already-seen via the - // persisted cursor and never write it into its own (new) session file. time.Sleep(150 * time.Millisecond) require.Empty(t, fileLines(t, secondOutput), "a record already written by a prior process must not be re-written after a restart") @@ -256,7 +240,7 @@ func TestPoll_skipsUnparseableTimestamp(t *testing.T) { } func TestPoll_serverUnreachable_doesNotPanic(t *testing.T) { - cfg := testConfig(t, "http://127.0.0.1:1") // nothing listens here + cfg := testConfig(t, "http://127.0.0.1:1") stream := New(cfg) require.NotPanics(t, func() { stream.Start() diff --git a/internal/upload/preprocess.go b/internal/upload/preprocess.go index 3ddce8b..914d172 100644 --- a/internal/upload/preprocess.go +++ b/internal/upload/preprocess.go @@ -98,8 +98,6 @@ func jsonlToJSONArray(src, dst string) (err error) { if !json.Valid(line) { return fmt.Errorf("%s: invalid json line: %s", src, line) } - // Each element keeps its own line -- a record-per-line array reads and - // diffs like the source .jsonl, instead of one unbroken line. if !first { if _, err := w.WriteString(",\n"); err != nil { return err @@ -114,7 +112,6 @@ func jsonlToJSONArray(src, dst string) (err error) { return fmt.Errorf("%s: %w", src, err) } if first { - // No elements: keep the array compact rather than "[\n\n]". if _, err := w.WriteString("]"); err != nil { return err } From ed40741c807815ba8b7d4621726412322665f54b Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 1 Sep 2026 14:43:24 -0500 Subject: [PATCH 07/26] Pare down remaining large const/type/package doc comments to 1-2 lines 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- cmd/main/main.go | 5 ++--- config/config.go | 3 +-- internal/retention/retention.go | 15 +-------------- internal/traces/stream.go | 27 +++------------------------ 4 files changed, 7 insertions(+), 43 deletions(-) diff --git a/cmd/main/main.go b/cmd/main/main.go index c329126..6f8fe12 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -326,9 +326,8 @@ loop: } } -// registerHeartbeats registers every stream's heartbeat check. The five -// DDS-backed streams register a reconnect callback via streams, resolved -// lazily since the stream objects don't exist yet at the first call site. +// registerHeartbeats registers every stream's heartbeat check, wiring the +// five DDS-backed streams up with a reconnect callback. func registerHeartbeats(mon *heartbeat.Monitor, cfg config.Config, videoHeartbeatNames []string, streams func() *persistentStreams) { if cfg.EnableLidar { mon.RegisterRecoverable(lidar.HeartbeatName, 10, func() { diff --git a/config/config.go b/config/config.go index 3693df4..b1703da 100644 --- a/config/config.go +++ b/config/config.go @@ -145,8 +145,7 @@ type NetworkConfig struct { } // TracesConfig configures polling a co-located OM1 process's Prometheus -// trace-export endpoint (see internal/traces). Disabled unless Enabled is set -- -// most deployments don't have an OM1 process to poll. +// trace-export endpoint (see internal/traces). type TracesConfig struct { Enabled bool URL string diff --git a/internal/retention/retention.go b/internal/retention/retention.go index 90542f4..d5ab6d5 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -26,20 +26,7 @@ const uploadMarkerName = ".uploaded" const uploadTimeout = 10 * time.Minute // minSessionAge is a second, time-based line of defense protecting the -// currently-recording session, alongside the dir == currentDir check every -// sweep caller applies. session.ListClosed does not itself verify a -// directory is closed -- it lists every dated directory, including one -// just created by session.OpenNext -- so the only thing stopping the sweep -// from grabbing a session mid-recording is comparing it against the -// in-memory "current" pointer, which is not updated atomically with the -// directory's creation on disk (a handful of statements run in between). -// A sweep tick landing in that gap would see a brand-new, virtually empty -// directory as neither current nor uploaded, and upload it -- after which -// the server reports the session complete, so the real end-of-session -// upload silently no-ops and most files are never sent. Any directory -// younger than minSessionAge (by its own recorded start time) is skipped -// regardless of the current-dir check, which is a generous margin around -// a race window that's really microseconds wide. +// currently-recording session, alongside the dir == currentDir check. const minSessionAge = 30 * time.Second // tooYoungToSweep reports whether dir's own recorded start time is within diff --git a/internal/traces/stream.go b/internal/traces/stream.go index b4f4310..7348837 100644 --- a/internal/traces/stream.go +++ b/internal/traces/stream.go @@ -1,15 +1,5 @@ // Package traces polls a co-located OM1 process's Prometheus trace-export -// endpoint (see OM1's internal/tracer/traceexport) and appends any records -// not seen yet to the session directory as traces.jsonl -- picked up by the -// existing session upload pipeline like every other stream's output. -// -// OM1 broadcasts trace records as om1_trace_info, an "info" metric (value -// always 1, full record in labels) on a private registry served at -// GET /traces/metrics -- deliberately not OM1's main /metrics endpoint, -// since it carries unbounded free-text label values a real Prometheus -// shouldn't store permanently. This package is that endpoint's one intended -// consumer: it scrapes it the same way Prometheus itself would (using the -// same exposition-format parser), not by any bespoke protocol. +// endpoint and appends any new records to the session directory as traces.jsonl. package traces import ( @@ -52,25 +42,14 @@ type Config struct { OutputFile string - // CursorFile persists the dedup cursor (the newest record timestamp - // written so far) across process restarts -- not per-session, so it - // must sit outside the rotating session directories. See loadCursor's - // doc comment for why this matters. Optional: an empty value just means - // no restart-survival, matching the stream's original behavior. + // CursorFile persists the dedup cursor across process restarts. Optional. CursorFile string Monitor *heartbeat.Monitor } // TraceStream polls Config.URL and appends new records to the current -// output file. It is a persistent stream: Rotate swaps the output file -// without restarting the poll loop, so the in-memory dedup cursor (which -// record timestamps have already been written) survives session rotation -- -// letting OM1's exporter re-serve its whole buffer on every poll without -// producing duplicate lines. The cursor is also persisted to CursorFile, so -// a full process restart resumes from it too, instead of re-ingesting -// OM1's whole buffered backlog into whatever session happens to be open at -// that moment (see loadCursor). +// output file, deduplicating by timestamp across polls, rotations, and restarts. type TraceStream struct { cfg Config running atomic.Bool From 92f819e843064fb968134829ecd0955c991ec026 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 1 Sep 2026 16:10:00 -0500 Subject: [PATCH 08/26] Point the trace poller at OM1's default /metrics endpoint 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- README.md | 11 +++++------ config/config.go | 2 +- internal/traces/stream.go | 2 +- 3 files changed, 7 insertions(+), 8 deletions(-) diff --git a/README.md b/README.md index fd84df8..65912a8 100644 --- a/README.md +++ b/README.md @@ -168,7 +168,7 @@ Any of the following override the selected profile / defaults: - `LOWSTATE_DDS_DOMAIN` - CycloneDDS domain ID for lowstate (default: `0`) - `LOWSTATE_DDS_TOPIC` - DDS topic for lowstate data (default: `rt/lowstate`) - `TRACES_ENABLED` - Poll a co-located OM1 process's Prometheus trace-export endpoint and record its LLM traces (default: `false` — most deployments have no OM1 process to poll; see "LLM trace export" below) -- `TRACES_URL` - OM1's trace-export endpoint (default: `http://localhost:9090/traces/metrics`) +- `TRACES_URL` - OM1's metrics endpoint (default: `http://localhost:9090/metrics`) - `TRACES_POLL_INTERVAL` - How often to poll `TRACES_URL` (default: `30s`) - `RECORDINGS_DIR` - Base directory for recordings (default: `recordings`) - `SESSION_ROTATE_INTERVAL` - Close the current session and open a fresh one on this cadence, so each segment can be uploaded without waiting for the whole run to end (default: `5m`; `0` disables rotation — one session for the life of the process, as before this feature existed) @@ -528,11 +528,10 @@ often than that window fills at your deployment's trace rate (`TRACES_POLL_INTERVAL`, default `30s`) or older records will be evicted on the OM1 side before this recorder ever sees them. -`TRACES_URL` must point at OM1's trace-export endpoint specifically -(`/traces/metrics`), **not** its main `/metrics` endpoint -- the two are -deliberately separate on the OM1 side, since trace records carry full -prompt/response text as unbounded label values that a real Prometheus -scrape target shouldn't ingest. +`TRACES_URL` points at OM1's main `/metrics` endpoint -- `om1_trace_info` +is broadcast there alongside every other metric, so this poller (like OM1's +own fleet-wide Prometheus, if one scrapes the same endpoint) will also see +full prompt/response text as unbounded label values on that metric. ## Scheduling diff --git a/config/config.go b/config/config.go index b1703da..0998ce7 100644 --- a/config/config.go +++ b/config/config.go @@ -241,7 +241,7 @@ func Load(sessionDir string) Config { }, Traces: TracesConfig{ Enabled: envBool("TRACES_ENABLED", false), - URL: envStr("TRACES_URL", "http://localhost:9090/traces/metrics"), + URL: envStr("TRACES_URL", "http://localhost:9090/metrics"), PollInterval: envDuration("TRACES_POLL_INTERVAL", 30*time.Second), OutputFile: filepath.Join(sessionDir, "traces.jsonl"), CursorFile: filepath.Join(RecordingsDir(), ".traces_cursor"), diff --git a/internal/traces/stream.go b/internal/traces/stream.go index 7348837..a9e56b6 100644 --- a/internal/traces/stream.go +++ b/internal/traces/stream.go @@ -35,7 +35,7 @@ const traceMetricFamily = "om1_trace_info" const httpTimeout = 10 * time.Second type Config struct { - // URL is OM1's trace-export endpoint, e.g. http://localhost:9090/traces/metrics. + // URL is OM1's metrics endpoint, e.g. http://localhost:9090/metrics. URL string PollInterval time.Duration From e50c56cc7041bba0216c85cc28ed2743c92ff17c Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 1 Sep 2026 16:47:40 -0500 Subject: [PATCH 09/26] Stop audio/video segment misfiling caused by long-running ffmpeg clock 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- internal/audio/stream.go | 35 ++++++++++++----------- internal/audio/stream_test.go | 54 ++++++++++++++++++++++++++++------- internal/video/stream.go | 35 ++++++++++++----------- internal/video/stream_test.go | 54 ++++++++++++++++++++++++++++------- 4 files changed, 126 insertions(+), 52 deletions(-) diff --git a/internal/audio/stream.go b/internal/audio/stream.go index 69d13ce..64c159c 100644 --- a/internal/audio/stream.go +++ b/internal/audio/stream.go @@ -175,7 +175,6 @@ func (a *AudioRTSPStream) record(ctx context.Context) error { } start := time.Now() - startMono := clock.MonoNs() pattern := filepath.Join(a.cfg.ScratchDir, "%Y%m%dT%H%M%S.ogg") cmd := exec.CommandContext(ctx, "ffmpeg", @@ -238,7 +237,7 @@ func (a *AudioRTSPStream) record(ctx context.Context) error { // Must fully drain stdout before calling Wait: Wait closes the pipe once // it reaps the process, and reading after that races the close. - a.watchSegments(stdout, start, startMono) + a.watchSegments(stdout) waitErr := cmd.Wait() close(hbStop) @@ -251,14 +250,14 @@ func (a *AudioRTSPStream) record(ctx context.Context) error { // (filename,start_seconds,end_seconds), and relocates, indexes, and // extracts frame timestamps for each segment as it completes. Returns once // ffmpeg closes stdout, i.e. once the process exits. -func (a *AudioRTSPStream) watchSegments(stdout io.Reader, processStart time.Time, processStartMonoNs int64) { +func (a *AudioRTSPStream) watchSegments(stdout io.Reader) { scanner := bufio.NewScanner(stdout) for scanner.Scan() { line := strings.TrimSpace(scanner.Text()) if line == "" { continue } - name, startSeconds, ok := parseSegmentListLine(line) + name, startSeconds, endSeconds, ok := parseSegmentListLine(line) if !ok { slog.Warn("audio: unrecognized segment_list line", "line", line) continue @@ -266,7 +265,8 @@ func (a *AudioRTSPStream) watchSegments(stdout io.Reader, processStart time.Time // ffmpeg's segment_list reports the filename as written to its // pattern, without the directory -- join it back to ScratchDir. scratchFile := filepath.Join(a.cfg.ScratchDir, name) - a.finishSegment(scratchFile, startSeconds, processStart, processStartMonoNs) + duration := time.Duration((endSeconds - startSeconds) * float64(time.Second)) + a.finishSegment(scratchFile, duration, time.Now(), clock.MonoNs()) } if err := scanner.Err(); err != nil { slog.Warn("audio: segment_list read error", "err", err) @@ -275,24 +275,27 @@ func (a *AudioRTSPStream) watchSegments(stdout io.Reader, processStart time.Time // parseSegmentListLine parses one "-segment_list_type csv" line: // filename,start_seconds,end_seconds. -func parseSegmentListLine(line string) (file string, startSeconds float64, ok bool) { +func parseSegmentListLine(line string) (file string, startSeconds, endSeconds float64, ok bool) { parts := strings.Split(line, ",") - if len(parts) < 2 { - return "", 0, false + if len(parts) < 3 { + return "", 0, 0, false } start, err := strconv.ParseFloat(strings.TrimSpace(parts[1]), 64) if err != nil { - return "", 0, false + return "", 0, 0, false } - return strings.TrimSpace(parts[0]), start, true + end, err := strconv.ParseFloat(strings.TrimSpace(parts[2]), 64) + if err != nil { + return "", 0, 0, false + } + return strings.TrimSpace(parts[0]), start, end, true } -// finishSegment relocates a just-closed segment from the scratch directory -// into the current target's session directory, indexes it, and kicks off -// its (async) frame extraction. -func (a *AudioRTSPStream) finishSegment(scratchFile string, startSeconds float64, processStart time.Time, processStartMonoNs int64) { - startWallClock := processStart.Add(time.Duration(startSeconds * float64(time.Second))) - startMonoNs := processStartMonoNs + int64(startSeconds*float64(time.Second)) +// finishSegment relocates a just-closed segment into the current target's +// session directory, indexes it, and kicks off its (async) frame extraction. +func (a *AudioRTSPStream) finishSegment(scratchFile string, duration time.Duration, observedNow time.Time, observedMonoNs int64) { + startWallClock := observedNow.Add(-duration) + startMonoNs := observedMonoNs - duration.Nanoseconds() target := a.targetFor(startWallClock) finalFile := filepath.Join(filepath.Dir(target.timestampsFile), diff --git a/internal/audio/stream_test.go b/internal/audio/stream_test.go index 94d457f..987c16d 100644 --- a/internal/audio/stream_test.go +++ b/internal/audio/stream_test.go @@ -74,18 +74,19 @@ func TestStop_idempotent(t *testing.T) { } func TestParseSegmentListLine_parsesFilenameAndStart(t *testing.T) { - file, start, ok := parseSegmentListLine("20260826T185832.ogg,12.500000,15.000000") + file, start, end, ok := parseSegmentListLine("20260826T185832.ogg,12.500000,15.000000") require.True(t, ok) require.Equal(t, "20260826T185832.ogg", file) require.InDelta(t, 12.5, start, 1e-9) + require.InDelta(t, 15.0, end, 1e-9) } func TestParseSegmentListLine_rejectsMalformedLine(t *testing.T) { - _, _, ok := parseSegmentListLine("not,a,valid,,line") + _, _, _, ok := parseSegmentListLine("not,a,valid,,line") require.False(t, ok, "a non-numeric start field must be rejected") - _, _, ok = parseSegmentListLine("onlyonefield") - require.False(t, ok, "a line missing the start field must be rejected") + _, _, _, ok = parseSegmentListLine("onlyonefield") + require.False(t, ok, "a line missing the start/end fields must be rejected") } func TestFinishSegment_relocatesFileIndexesItAndPrefixesWithStem(t *testing.T) { @@ -103,7 +104,8 @@ func TestFinishSegment_relocatesFileIndexesItAndPrefixesWithStem(t *testing.T) { processStart := time.Unix(1_800_000_000, 0) stream.Rotate(processStart, filepath.Join(sessionDir, "audio_timestamps.csv"), "") // no frames file: skip async ffprobe - stream.finishSegment(scratchFile, 12.5, processStart, 5_000_000_000) + segmentStart := processStart.Add(12500 * time.Millisecond) + stream.finishSegment(scratchFile, 0, segmentStart, 5_000_000_000) wantFinal := filepath.Join(sessionDir, "audio_20260826T185832.ogg") require.FileExists(t, wantFinal, "the segment must be relocated with its stem prefixed") @@ -113,8 +115,7 @@ func TestFinishSegment_relocatesFileIndexesItAndPrefixesWithStem(t *testing.T) { require.NoError(t, err) content := string(data) require.Contains(t, content, "recording_start_unix_ns,segment_file,mono_ns") - wantStartUnixNs := processStart.Add(12500 * time.Millisecond).UnixNano() - require.Contains(t, content, fmt.Sprintf("%d", wantStartUnixNs), "the indexed start time must include the segment's offset into the stream") + require.Contains(t, content, fmt.Sprintf("%d", segmentStart.UnixNano()), "the indexed start time must match the segment's own start") require.Contains(t, content, "audio_20260826T185832.ogg") } @@ -132,10 +133,9 @@ func TestWatchSegments_joinsBareFilenameFromSegmentListWithScratchDir(t *testing OutputFile: filepath.Join(t.TempDir(), "audio.ogg"), ScratchDir: scratchDir, }) - processStart := time.Unix(1_800_000_000, 0) - stream.Rotate(processStart, filepath.Join(sessionDir, "audio_timestamps.csv"), "") + stream.Rotate(time.Now(), filepath.Join(sessionDir, "audio_timestamps.csv"), "") - stream.watchSegments(strings.NewReader("20260826T185832.ogg,0.000000,3.000000\n"), processStart, 0) + stream.watchSegments(strings.NewReader("20260826T185832.ogg,0.000000,3.000000\n")) require.FileExists(t, filepath.Join(sessionDir, "audio_20260826T185832.ogg"), "watchSegments must join the segment_list's bare filename with ScratchDir before relocating") @@ -198,6 +198,40 @@ func TestTargetFor_attributesByOwnTimestampEvenWhenRotateRacesAhead(t *testing.T require.NoFileExists(t, filepath.Join(sessionN1Dir, "audio_seg.ogg")) } +// Regression: a segment starting just after a rotation boundary must land +// in the new session even after a long-running process's clock has drifted. +func TestFinishSegment_notMisledByAccumulatedProcessDrift(t *testing.T) { + scratchDir := t.TempDir() + sessionNDir := t.TempDir() + sessionN1Dir := t.TempDir() + + sessionNStart := time.Unix(1_800_000_000, 0) + sessionN1Start := sessionNStart.Add(5 * time.Minute) + + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "audio.ogg"), + TimestampsFile: filepath.Join(sessionNDir, "audio_timestamps.csv"), + SessionStart: sessionNStart, + ScratchDir: scratchDir, + }) + stream.ensureTarget() + stream.Rotate(sessionN1Start, filepath.Join(sessionN1Dir, "audio_timestamps.csv"), "") + + segmentDuration := 5 * time.Minute + trueSegmentStart := sessionN1Start.Add(1 * time.Second) + observedClose := trueSegmentStart.Add(segmentDuration) + + seg := filepath.Join(scratchDir, "seg.ogg") + require.NoError(t, os.WriteFile(seg, []byte("a"), 0o644)) + + stream.finishSegment(seg, segmentDuration, observedClose, 0) + + require.FileExists(t, filepath.Join(sessionN1Dir, "audio_seg.ogg"), + "a segment observed to close one full span after starting just past the rotation boundary must land in the new session") + require.NoFileExists(t, filepath.Join(sessionNDir, "audio_seg.ogg")) +} + func TestAppendSegmentEntry_emptyPath_isNoOp(t *testing.T) { err := appendSegmentEntry("", time.Now(), 0, "/data/audio.ogg") require.NoError(t, err) diff --git a/internal/video/stream.go b/internal/video/stream.go index 7053e69..aeab841 100644 --- a/internal/video/stream.go +++ b/internal/video/stream.go @@ -182,7 +182,6 @@ func (v *VideoRTSPStream) record(ctx context.Context) error { } start := time.Now() - startMono := clock.MonoNs() pattern := filepath.Join(v.cfg.ScratchDir, "%Y%m%dT%H%M%S.mp4") cmd := exec.CommandContext(ctx, "ffmpeg", @@ -239,7 +238,7 @@ func (v *VideoRTSPStream) record(ctx context.Context) error { // Must fully drain stdout before calling Wait: Wait closes the pipe once // it reaps the process, and reading after that races the close. - v.watchSegments(stdout, start, startMono) + v.watchSegments(stdout) waitErr := cmd.Wait() close(hbStop) @@ -252,14 +251,14 @@ func (v *VideoRTSPStream) record(ctx context.Context) error { // (filename,start_seconds,end_seconds), and relocates, indexes, and // extracts frame timestamps for each segment as it completes. Returns once // ffmpeg closes stdout, i.e. once the process exits. -func (v *VideoRTSPStream) watchSegments(stdout io.Reader, processStart time.Time, processStartMonoNs int64) { +func (v *VideoRTSPStream) watchSegments(stdout io.Reader) { scanner := bufio.NewScanner(stdout) for scanner.Scan() { line := strings.TrimSpace(scanner.Text()) if line == "" { continue } - name, startSeconds, ok := parseSegmentListLine(line) + name, startSeconds, endSeconds, ok := parseSegmentListLine(line) if !ok { slog.Warn("video: unrecognized segment_list line", "camera", v.cfg.HeartbeatName, "line", line) continue @@ -267,7 +266,8 @@ func (v *VideoRTSPStream) watchSegments(stdout io.Reader, processStart time.Time // ffmpeg's segment_list reports the filename as written to its // pattern, without the directory -- join it back to ScratchDir. scratchFile := filepath.Join(v.cfg.ScratchDir, name) - v.finishSegment(scratchFile, startSeconds, processStart, processStartMonoNs) + duration := time.Duration((endSeconds - startSeconds) * float64(time.Second)) + v.finishSegment(scratchFile, duration, time.Now(), clock.MonoNs()) } if err := scanner.Err(); err != nil { slog.Warn("video: segment_list read error", "camera", v.cfg.HeartbeatName, "err", err) @@ -276,24 +276,27 @@ func (v *VideoRTSPStream) watchSegments(stdout io.Reader, processStart time.Time // parseSegmentListLine parses one "-segment_list_type csv" line: // filename,start_seconds,end_seconds. -func parseSegmentListLine(line string) (file string, startSeconds float64, ok bool) { +func parseSegmentListLine(line string) (file string, startSeconds, endSeconds float64, ok bool) { parts := strings.Split(line, ",") - if len(parts) < 2 { - return "", 0, false + if len(parts) < 3 { + return "", 0, 0, false } start, err := strconv.ParseFloat(strings.TrimSpace(parts[1]), 64) if err != nil { - return "", 0, false + return "", 0, 0, false } - return strings.TrimSpace(parts[0]), start, true + end, err := strconv.ParseFloat(strings.TrimSpace(parts[2]), 64) + if err != nil { + return "", 0, 0, false + } + return strings.TrimSpace(parts[0]), start, end, true } -// finishSegment relocates a just-closed segment from the scratch directory -// into the current target's session directory, indexes it, and kicks off -// its (async) frame extraction. -func (v *VideoRTSPStream) finishSegment(scratchFile string, startSeconds float64, processStart time.Time, processStartMonoNs int64) { - startWallClock := processStart.Add(time.Duration(startSeconds * float64(time.Second))) - startMonoNs := processStartMonoNs + int64(startSeconds*float64(time.Second)) +// finishSegment relocates a just-closed segment into the current target's +// session directory, indexes it, and kicks off its (async) frame extraction. +func (v *VideoRTSPStream) finishSegment(scratchFile string, duration time.Duration, observedNow time.Time, observedMonoNs int64) { + startWallClock := observedNow.Add(-duration) + startMonoNs := observedMonoNs - duration.Nanoseconds() target := v.targetFor(startWallClock) finalFile := filepath.Join(filepath.Dir(target.timestampsFile), diff --git a/internal/video/stream_test.go b/internal/video/stream_test.go index d64901c..ab87b4b 100644 --- a/internal/video/stream_test.go +++ b/internal/video/stream_test.go @@ -116,18 +116,19 @@ func TestRecord_createsOutputFileDirectory(t *testing.T) { } func TestParseSegmentListLine_parsesFilenameAndStart(t *testing.T) { - file, start, ok := parseSegmentListLine("20260826T185832.mp4,12.500000,15.000000") + file, start, end, ok := parseSegmentListLine("20260826T185832.mp4,12.500000,15.000000") require.True(t, ok) require.Equal(t, "20260826T185832.mp4", file) require.InDelta(t, 12.5, start, 1e-9) + require.InDelta(t, 15.0, end, 1e-9) } func TestParseSegmentListLine_rejectsMalformedLine(t *testing.T) { - _, _, ok := parseSegmentListLine("not,a,valid,,line") + _, _, _, ok := parseSegmentListLine("not,a,valid,,line") require.False(t, ok, "a non-numeric start field must be rejected") - _, _, ok = parseSegmentListLine("onlyonefield") - require.False(t, ok, "a line missing the start field must be rejected") + _, _, _, ok = parseSegmentListLine("onlyonefield") + require.False(t, ok, "a line missing the start/end fields must be rejected") } func TestFinishSegment_relocatesFileIndexesItAndPrefixesWithStem(t *testing.T) { @@ -145,7 +146,8 @@ func TestFinishSegment_relocatesFileIndexesItAndPrefixesWithStem(t *testing.T) { processStart := time.Unix(1_800_000_000, 0) stream.Rotate(processStart, filepath.Join(sessionDir, "front_camera_timestamps.csv"), "") // no frames file: skip async ffprobe - stream.finishSegment(scratchFile, 12.5, processStart, 5_000_000_000) + segmentStart := processStart.Add(12500 * time.Millisecond) + stream.finishSegment(scratchFile, 0, segmentStart, 5_000_000_000) wantFinal := filepath.Join(sessionDir, "front_camera_20260826T185832.mp4") require.FileExists(t, wantFinal, "the segment must be relocated with its camera stem prefixed") @@ -155,8 +157,7 @@ func TestFinishSegment_relocatesFileIndexesItAndPrefixesWithStem(t *testing.T) { require.NoError(t, err) content := string(data) require.Contains(t, content, "recording_start_unix_ns,segment_file,mono_ns") - wantStartUnixNs := processStart.Add(12500 * time.Millisecond).UnixNano() - require.Contains(t, content, fmt.Sprintf("%d", wantStartUnixNs), "the indexed start time must include the segment's offset into the stream") + require.Contains(t, content, fmt.Sprintf("%d", segmentStart.UnixNano()), "the indexed start time must match the segment's own start") require.Contains(t, content, "front_camera_20260826T185832.mp4") } @@ -174,10 +175,9 @@ func TestWatchSegments_joinsBareFilenameFromSegmentListWithScratchDir(t *testing OutputFile: filepath.Join(t.TempDir(), "front_camera.mp4"), ScratchDir: scratchDir, }) - processStart := time.Unix(1_800_000_000, 0) - stream.Rotate(processStart, filepath.Join(sessionDir, "front_camera_timestamps.csv"), "") + stream.Rotate(time.Now(), filepath.Join(sessionDir, "front_camera_timestamps.csv"), "") - stream.watchSegments(strings.NewReader("20260826T185832.mp4,0.000000,3.000000\n"), processStart, 0) + stream.watchSegments(strings.NewReader("20260826T185832.mp4,0.000000,3.000000\n")) require.FileExists(t, filepath.Join(sessionDir, "front_camera_20260826T185832.mp4"), "watchSegments must join the segment_list's bare filename with ScratchDir before relocating") @@ -240,6 +240,40 @@ func TestTargetFor_attributesByOwnTimestampEvenWhenRotateRacesAhead(t *testing.T require.NoFileExists(t, filepath.Join(sessionN1Dir, "front_camera_seg.mp4")) } +// Regression: a segment starting just after a rotation boundary must land +// in the new session even after a long-running process's clock has drifted. +func TestFinishSegment_notMisledByAccumulatedProcessDrift(t *testing.T) { + scratchDir := t.TempDir() + sessionNDir := t.TempDir() + sessionN1Dir := t.TempDir() + + sessionNStart := time.Unix(1_800_000_000, 0) + sessionN1Start := sessionNStart.Add(5 * time.Minute) + + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "front_camera.mp4"), + TimestampsFile: filepath.Join(sessionNDir, "front_camera_timestamps.csv"), + SessionStart: sessionNStart, + ScratchDir: scratchDir, + }) + stream.ensureTarget() + stream.Rotate(sessionN1Start, filepath.Join(sessionN1Dir, "front_camera_timestamps.csv"), "") + + segmentDuration := 5 * time.Minute + trueSegmentStart := sessionN1Start.Add(1 * time.Second) + observedClose := trueSegmentStart.Add(segmentDuration) + + seg := filepath.Join(scratchDir, "seg.mp4") + require.NoError(t, os.WriteFile(seg, []byte("a"), 0o644)) + + stream.finishSegment(seg, segmentDuration, observedClose, 0) + + require.FileExists(t, filepath.Join(sessionN1Dir, "front_camera_seg.mp4"), + "a segment observed to close one full span after starting just past the rotation boundary must land in the new session") + require.NoFileExists(t, filepath.Join(sessionNDir, "front_camera_seg.mp4")) +} + func TestAppendSegmentEntry_emptyPath_isNoOp(t *testing.T) { err := appendSegmentEntry("", time.Now(), 0, "/data/video.mp4") require.NoError(t, err) From da78810b2cecaec20db3d6e035e6c8241ba402df Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 1 Sep 2026 19:13:14 -0500 Subject: [PATCH 10/26] Never skip uploading based on server-reported session status 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 Claude-Session: https://claude.ai/code/session_01REFHurqqySZu4SZL5dpb3o --- internal/upload/client.go | 4 ---- internal/upload/client_test.go | 24 +++++++++++++----------- 2 files changed, 13 insertions(+), 15 deletions(-) diff --git a/internal/upload/client.go b/internal/upload/client.go index f93dbb3..ec9e1f1 100644 --- a/internal/upload/client.go +++ b/internal/upload/client.go @@ -77,7 +77,6 @@ type presignedPOST struct { type sessionResp struct { SessionID string `json:"session_id"` S3Prefix string `json:"s3_prefix"` - Status string `json:"status"` Upload *presignedPOST `json:"upload"` } @@ -107,9 +106,6 @@ func (c *Client) UploadSession(ctx context.Context, localDir, sessionDir string, if err != nil { return fmt.Errorf("upload: create session: %w", err) } - if sess.Status == "complete" { - return nil - } if err := c.uploadFiles(ctx, sess, localDir, files); err != nil { c.fail(ctx, sess.SessionID, err) diff --git a/internal/upload/client_test.go b/internal/upload/client_test.go index da14cf5..fc5ead9 100644 --- a/internal/upload/client_test.go +++ b/internal/upload/client_test.go @@ -24,7 +24,7 @@ type fakeAPI struct { sessions map[string]*fakeSession nextID int - preComplete string // session_dir that should short-circuit as already complete + preComplete string // session_dir the server reports as already "complete" on creation failRequests map[string]int multipartData map[string][]byte // uploadID -> reassembled bytes @@ -105,20 +105,16 @@ func (a *fakeAPI) createSession(w http.ResponseWriter, r *http.Request) { a.mu.Lock() defer a.mu.Unlock() + status := "uploading" if body.SessionDir == a.preComplete { - w.WriteHeader(http.StatusOK) - _ = json.NewEncoder(w).Encode(map[string]any{ - "session_id": "already-done", - "status": "complete", - }) - return + status = "complete" } a.nextID++ id := fmt.Sprintf("sess-%d", a.nextID) sess := &fakeSession{ id: id, sessionDir: body.SessionDir, startedAt: body.StartedAt, - status: "uploading", prefix: "cust/key/" + id + "/", + status: status, prefix: "cust/key/" + id + "/", uploaded: map[string][]byte{}, } a.sessions[id] = sess @@ -337,12 +333,14 @@ func TestUploadSession_uploadsFilesConcurrently(t *testing.T) { require.LessOrEqual(t, api.maxRunning, 4, "concurrency should be bounded by Config.Concurrency") } -func TestUploadSession_alreadyCompleteShortCircuits(t *testing.T) { +// Regression: the client used to skip uploading whenever createSession +// reported the session already "complete", which could silently drop files. +func TestUploadSession_uploadsEvenWhenServerReportsAlreadyComplete(t *testing.T) { api, apiSrv, _ := newFakeAPI(t) api.preComplete = "recordings/done" dir := t.TempDir() - writeFile(t, dir, "meta.json", []byte(`{}`)) + writeFile(t, dir, "meta.json", []byte(`{"ok":true}`)) c := New(Config{BaseURL: apiSrv.URL, APIKey: "test-key"}) err := c.UploadSession(context.Background(), dir, "recordings/done", time.Now(), Options{}) @@ -350,7 +348,11 @@ func TestUploadSession_alreadyCompleteShortCircuits(t *testing.T) { api.mu.Lock() defer api.mu.Unlock() - require.Empty(t, api.sessions, "should not have created a new session for one already complete") + require.Len(t, api.sessions, 1) + for _, sess := range api.sessions { + require.Equal(t, []byte(`{"ok":true}`), sess.uploaded["meta.json"], + "local files must still be uploaded even when the server claims the session is already complete") + } } func TestUploadSession_skipsDotfiles(t *testing.T) { From 3ed24db930111f289ac1253244c344e2baaca61b Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Wed, 2 Sep 2026 18:23:21 -0500 Subject: [PATCH 11/26] Wait for video/audio segments before uploading a session 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 Claude-Session: https://claude.ai/code/session_016o2Qem6WxyDBJpKotKFkKS --- cmd/main/main.go | 38 +++++++++++- internal/audio/stream.go | 48 ++++++++++++++- internal/audio/stream_test.go | 91 ++++++++++++++++++++++++++++ internal/retention/retention.go | 21 +++++-- internal/retention/retention_test.go | 45 +++++++++++++- internal/video/stream.go | 48 ++++++++++++++- internal/video/stream_test.go | 91 ++++++++++++++++++++++++++++ 7 files changed, 372 insertions(+), 10 deletions(-) diff --git a/cmd/main/main.go b/cmd/main/main.go index 6f8fe12..9441bcb 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -201,7 +201,10 @@ func main() { retention.SnapshotTimebase(bootTimebasePath, finished.RealDir()) ctl.SetRecording(false) slog.Info("recording paused by schedule", "session", finished.RealDir()) - retention.UploadFinishedSessionAsync(&uploadWG, uploader, ctl, recordingsDir, bootTimebasePath, finished, uploadDelete) + persistent := rs.persistent + finishedStart := time.Unix(0, finished.StartUnixNs()) + retention.UploadFinishedSessionAsync(&uploadWG, uploader, ctl, recordingsDir, bootTimebasePath, finished, uploadDelete, + func(ctx context.Context) { persistent.awaitSegments(ctx, finishedStart) }) } // resumeRecording is the schedule's open-half: same as a rotation's open-half. @@ -295,7 +298,9 @@ loop: slog.Info("session rotated", "session", sess.RealDir()) - retention.UploadFinishedSessionAsync(&uploadWG, uploader, ctl, recordingsDir, bootTimebasePath, finished, uploadDelete) + finishedStart := time.Unix(0, finished.StartUnixNs()) + retention.UploadFinishedSessionAsync(&uploadWG, uploader, ctl, recordingsDir, bootTimebasePath, finished, uploadDelete, + func(ctx context.Context) { persistent.awaitSegments(ctx, finishedStart) }) } } @@ -312,7 +317,9 @@ loop: if uploader != nil && ctl.Uploading() { opts := retention.UploadOptions(bootTimebasePath, sess.RealDir()) - retention.UploadSession(ctl, uploader, sess.RealDir(), retention.APISessionDir(recordingsDir, sess.RealDir()), time.Unix(0, sess.StartUnixNs()), uploadDelete, opts) + // No awaitReady needed: rs.Stop() above already drains ffmpeg's + // final segment (and its relocation) before returning. + retention.UploadSession(ctl, uploader, sess.RealDir(), retention.APISessionDir(recordingsDir, sess.RealDir()), time.Unix(0, sess.StartUnixNs()), uploadDelete, opts, nil) } } uploadWG.Wait() @@ -591,6 +598,31 @@ func (p *persistentStreams) rotate(cfg config.Config, sess *session.Session) { p.audioStream.Rotate(sessionStart, audioTs, framesFileFor(audioOut, "_packets.csv")) } +// awaitSegments blocks until every video stream and the audio stream have +// relocated the segment belonging to the session that started at +// sessionStart, or ctx ends. Meant to run right before that session gets +// uploaded: video/audio only relocate a segment once ffmpeg reports it +// closed, which happens a full segment_time (== the rotation interval) +// after the segment began -- i.e. at roughly the same moment as the next +// rotation, not this one. Uploading on rotation without this wait races +// that and silently ships the session without its video/audio. +func (p *persistentStreams) awaitSegments(ctx context.Context, sessionStart time.Time) { + var wg sync.WaitGroup + for _, vs := range p.videoStreams { + wg.Add(1) + go func(vs *video.VideoRTSPStream) { + defer wg.Done() + vs.WaitSegment(ctx, sessionStart) + }(vs) + } + wg.Add(1) + go func() { + defer wg.Done() + p.audioStream.WaitSegment(ctx, sessionStart) + }() + wg.Wait() +} + // realPath rewrites path to sit in realDir instead of whatever directory it // was built from. func realPath(path, realDir string) string { diff --git a/internal/audio/stream.go b/internal/audio/stream.go index 64c159c..b58406f 100644 --- a/internal/audio/stream.go +++ b/internal/audio/stream.go @@ -68,6 +68,18 @@ type segmentTarget struct { sessionStart time.Time timestampsFile string framesWrite *recordutil.FrameCSVWriter + + // ready closes once this target has received (or, on relocation + // failure, definitively won't receive) its first segment -- see + // WaitSegment. + ready chan struct{} + readyOnce sync.Once +} + +// markReady unblocks any WaitSegment callers for this target. Safe to call +// more than once (a target may receive several segments, or none). +func (t *segmentTarget) markReady() { + t.readyOnce.Do(func() { close(t.ready) }) } func New(cfg Config) *AudioRTSPStream { @@ -127,7 +139,7 @@ func newSegmentTarget(sessionStart time.Time, timestampsFile, framesFile string) if framesFile != "" { fw = recordutil.NewFrameCSVWriter(framesFile) } - return &segmentTarget{sessionStart: sessionStart, timestampsFile: timestampsFile, framesWrite: fw} + return &segmentTarget{sessionStart: sessionStart, timestampsFile: timestampsFile, framesWrite: fw, ready: make(chan struct{})} } // targetFor returns the target whose session started most recently at or @@ -147,6 +159,38 @@ func (a *AudioRTSPStream) targetFor(startWallClock time.Time) *segmentTarget { return best } +// WaitSegment blocks until the target for sessionStart (installed by an +// earlier Rotate/ensureTarget call with that exact value) has relocated its +// first segment, or ctx ends. Reports whether a segment actually arrived; +// false also covers "no such target" and "ctx ended first". +// +// This exists because a video/audio segment closes (and only then becomes +// visible to a directory listing) a full segment_time after it began -- the +// same duration as a session rotation interval -- so its close notification +// lands at roughly the same instant as the *next* rotation, well after the +// session it belongs to has already closed. A caller uploading that session +// immediately on rotation would otherwise race this and upload without it. +func (a *AudioRTSPStream) WaitSegment(ctx context.Context, sessionStart time.Time) bool { + a.targetMu.Lock() + var target *segmentTarget + for _, t := range a.targets { + if t.sessionStart.Equal(sessionStart) { + target = t + break + } + } + a.targetMu.Unlock() + if target == nil { + return false + } + select { + case <-target.ready: + return true + case <-ctx.Done(): + return false + } +} + func (a *AudioRTSPStream) loop(ctx context.Context) { defer close(a.done) a.ensureTarget() @@ -303,6 +347,7 @@ func (a *AudioRTSPStream) finishSegment(scratchFile string, duration time.Durati if err := os.Rename(scratchFile, finalFile); err != nil { slog.Error("audio: could not relocate segment", "err", err) + target.markReady() return } @@ -311,6 +356,7 @@ func (a *AudioRTSPStream) finishSegment(scratchFile string, duration time.Durati "file", target.timestampsFile, "err", err) } slog.Info("audio segment closed", "file", finalFile) + target.markReady() if target.framesWrite == nil { return diff --git a/internal/audio/stream_test.go b/internal/audio/stream_test.go index 987c16d..01127dd 100644 --- a/internal/audio/stream_test.go +++ b/internal/audio/stream_test.go @@ -1,6 +1,7 @@ package audio import ( + "context" "fmt" "os" "path/filepath" @@ -232,6 +233,96 @@ func TestFinishSegment_notMisledByAccumulatedProcessDrift(t *testing.T) { require.NoFileExists(t, filepath.Join(sessionNDir, "audio_seg.ogg")) } +// Regression: an uploader triggered right on rotation must be able to wait +// for the session's own segment to land instead of racing finishSegment. +func TestWaitSegment_blocksUntilFinishSegmentRelocatesThatSessionsSegment(t *testing.T) { + scratchDir := t.TempDir() + sessionDir := t.TempDir() + sessionStart := time.Unix(1_800_000_000, 0) + + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "audio.ogg"), + TimestampsFile: filepath.Join(sessionDir, "audio_timestamps.csv"), + SessionStart: sessionStart, + ScratchDir: scratchDir, + }) + stream.ensureTarget() + + waited := make(chan bool, 1) + go func() { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + waited <- stream.WaitSegment(ctx, sessionStart) + }() + + select { + case <-waited: + t.Fatal("WaitSegment returned before finishSegment relocated anything") + case <-time.After(20 * time.Millisecond): + } + + seg := filepath.Join(scratchDir, "seg.ogg") + require.NoError(t, os.WriteFile(seg, []byte("a"), 0o644)) + stream.finishSegment(seg, 0, sessionStart, 0) + + require.True(t, <-waited, "WaitSegment must return true once finishSegment relocates the session's segment") +} + +// A target that never receives a segment (RTSP never delivered data for +// that session) must not hang WaitSegment past its context. +func TestWaitSegment_returnsFalseWhenContextEndsFirst(t *testing.T) { + sessionStart := time.Unix(1_800_000_000, 0) + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "audio.ogg"), + SessionStart: sessionStart, + ScratchDir: t.TempDir(), + }) + stream.ensureTarget() + + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Millisecond) + defer cancel() + require.False(t, stream.WaitSegment(ctx, sessionStart)) +} + +// A relocation failure must still unblock waiters rather than leaving them +// to time out every time. +func TestWaitSegment_returnsTrueImmediatelyAfterRelocationFailure(t *testing.T) { + sessionDir := t.TempDir() + sessionStart := time.Unix(1_800_000_000, 0) + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "audio.ogg"), + TimestampsFile: filepath.Join(sessionDir, "audio_timestamps.csv"), + SessionStart: sessionStart, + ScratchDir: t.TempDir(), + }) + stream.ensureTarget() + + // scratchFile does not exist, so os.Rename inside finishSegment fails. + stream.finishSegment(filepath.Join(t.TempDir(), "missing.ogg"), 0, sessionStart, 0) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.True(t, stream.WaitSegment(ctx, sessionStart), + "a relocation failure must still mark the target ready so callers don't wait out the full timeout") +} + +// No target was ever installed for this sessionStart. +func TestWaitSegment_returnsFalseForUnknownSessionStart(t *testing.T) { + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "audio.ogg"), + ScratchDir: t.TempDir(), + }) + stream.ensureTarget() + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.False(t, stream.WaitSegment(ctx, time.Unix(1_900_000_000, 0))) +} + func TestAppendSegmentEntry_emptyPath_isNoOp(t *testing.T) { err := appendSegmentEntry("", time.Now(), 0, "/data/audio.ogg") require.NoError(t, err) diff --git a/internal/retention/retention.go b/internal/retention/retention.go index d5ab6d5..ec6c630 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -143,7 +143,14 @@ func SnapshotTimebase(bootPath, sessionDir string) { // dir is claimed for the duration of the upload, so a concurrent call for // the same dir (another upload path, or retention's cap enforcement) skips // it instead of racing. -func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir string, startedAt time.Time, deleteAfter bool, opts upload.Options) { +// +// awaitReady, if non-nil, is called first (bounded by the same upload +// timeout) so a caller can block until still-relocating streams -- notably +// video/audio, whose segment only closes well after the session itself +// rotates -- have settled before dir's contents get listed for upload. A nil +// awaitReady uploads whatever is in dir immediately, which is fine for a +// catch-up sweep over sessions that have been closed for a while. +func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir string, startedAt time.Time, deleteAfter bool, opts upload.Options, awaitReady func(context.Context)) { if !ctl.TryClaimDir(dir) { slog.Info("retention: skipping upload, already in flight", "dir", dir) return @@ -153,6 +160,10 @@ func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir st ctx, cancel := context.WithTimeout(context.Background(), uploadTimeout) defer cancel() + if awaitReady != nil { + awaitReady(ctx) + } + if err := client.UploadSession(ctx, dir, sessionDir, startedAt, opts); err != nil { slog.Error("session upload failed; files kept locally for retry", "dir", dir, "err", err) return @@ -168,7 +179,9 @@ func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir st } // UploadFinishedSessionAsync kicks off finished's upload in the background if uploading is enabled. -func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl *control.State, recordingsDir, bootTimebasePath string, finished *session.Session, uploadDelete bool) { +// +// awaitReady is passed straight through to UploadSession -- see its doc. +func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl *control.State, recordingsDir, bootTimebasePath string, finished *session.Session, uploadDelete bool, awaitReady func(context.Context)) { if uploader == nil || !ctl.Uploading() { return } @@ -176,7 +189,7 @@ func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl wg.Add(1) go func(dir, apiDir string, startedAt time.Time, opts upload.Options) { defer wg.Done() - UploadSession(ctl, uploader, dir, apiDir, startedAt, uploadDelete, opts) + UploadSession(ctl, uploader, dir, apiDir, startedAt, uploadDelete, opts, awaitReady) }(finished.RealDir(), APISessionDir(recordingsDir, finished.RealDir()), time.Unix(0, finished.StartUnixNs()), opts) } @@ -206,7 +219,7 @@ func CatchUpUploads(ctl *control.State, uploader *upload.Client, dirs []string, continue } opts := UploadOptions(bootTimebasePath, dir) - UploadSession(ctl, uploader, dir, APISessionDir(recordingsDir, dir), ReadStartedAt(dir), false, opts) + UploadSession(ctl, uploader, dir, APISessionDir(recordingsDir, dir), ReadStartedAt(dir), false, opts, nil) } } diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index ececce6..a7dc8c9 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -319,7 +319,7 @@ func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { wg.Add(1) go func() { defer wg.Done() - UploadSession(ctl, client, dir, "api/dir", time.Time{}, false, upload.Options{}) + UploadSession(ctl, client, dir, "api/dir", time.Time{}, false, upload.Options{}, nil) }() } @@ -332,6 +332,49 @@ func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { "the second concurrent UploadSession call for the same dir must be skipped entirely, not just deduplicated after the fact") } +// Regression: video/audio only relocate their segment into dir a full +// segment_time after the session itself rotates, so an upload triggered +// right on rotation must wait for awaitReady before listing dir's files -- +// otherwise it silently ships the session without them. This proves +// awaitReady runs to completion, and any files it adds are visible, before +// the upload's network calls start. +func TestUploadSession_awaitReadyCompletesBeforeUploadStarts(t *testing.T) { + api, apiURL := newMinimalFakeAPI(t) + client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) + + dir := t.TempDir() + writeFile(t, dir, "meta.json", []byte(`{}`)) + + release := make(chan struct{}) + var awaitReadyDone atomic.Bool + awaitReady := func(ctx context.Context) { + <-release + writeFile(t, dir, "front_camera_raw_seg.mp4", []byte("video")) + awaitReadyDone.Store(true) + } + + done := make(chan struct{}) + go func() { + defer close(done) + UploadSession(control.New(), client, dir, "api/dir", time.Time{}, false, upload.Options{}, awaitReady) + }() + + sessionCreated := func() bool { + api.mu.Lock() + defer api.mu.Unlock() + return api.createCalls["api/dir"] > 0 + } + require.Never(t, sessionCreated, 50*time.Millisecond, 5*time.Millisecond, + "the session must not be created -- which is when regularFiles snapshots dir -- until awaitReady returns") + + close(release) + <-done + + require.True(t, awaitReadyDone.Load()) + require.True(t, sessionCreated()) + require.True(t, IsUploaded(dir), "the session, including the file awaitReady added, must be reported as fully uploaded") +} + // Cap enforcement must not block on a stuck catch-up upload. func TestRunSweeps_capEnforcementNotBlockedByStuckCatchUpUpload(t *testing.T) { const sweepInterval = 20 * time.Millisecond diff --git a/internal/video/stream.go b/internal/video/stream.go index aeab841..aca6dab 100644 --- a/internal/video/stream.go +++ b/internal/video/stream.go @@ -70,6 +70,18 @@ type segmentTarget struct { sessionStart time.Time timestampsFile string framesWrite *recordutil.FrameCSVWriter + + // ready closes once this target has received (or, on relocation + // failure, definitively won't receive) its first segment -- see + // WaitSegment. + ready chan struct{} + readyOnce sync.Once +} + +// markReady unblocks any WaitSegment callers for this target. Safe to call +// more than once (a target may receive several segments, or none). +func (t *segmentTarget) markReady() { + t.readyOnce.Do(func() { close(t.ready) }) } func New(cfg Config) *VideoRTSPStream { @@ -133,7 +145,7 @@ func newSegmentTarget(sessionStart time.Time, timestampsFile, framesFile string) if framesFile != "" { fw = recordutil.NewFrameCSVWriter(framesFile) } - return &segmentTarget{sessionStart: sessionStart, timestampsFile: timestampsFile, framesWrite: fw} + return &segmentTarget{sessionStart: sessionStart, timestampsFile: timestampsFile, framesWrite: fw, ready: make(chan struct{})} } // targetFor returns the target whose session started most recently at or @@ -153,6 +165,38 @@ func (v *VideoRTSPStream) targetFor(startWallClock time.Time) *segmentTarget { return best } +// WaitSegment blocks until the target for sessionStart (installed by an +// earlier Rotate/ensureTarget call with that exact value) has relocated its +// first segment, or ctx ends. Reports whether a segment actually arrived; +// false also covers "no such target" and "ctx ended first". +// +// This exists because a video/audio segment closes (and only then becomes +// visible to a directory listing) a full segment_time after it began -- the +// same duration as a session rotation interval -- so its close notification +// lands at roughly the same instant as the *next* rotation, well after the +// session it belongs to has already closed. A caller uploading that session +// immediately on rotation would otherwise race this and upload without it. +func (v *VideoRTSPStream) WaitSegment(ctx context.Context, sessionStart time.Time) bool { + v.targetMu.Lock() + var target *segmentTarget + for _, t := range v.targets { + if t.sessionStart.Equal(sessionStart) { + target = t + break + } + } + v.targetMu.Unlock() + if target == nil { + return false + } + select { + case <-target.ready: + return true + case <-ctx.Done(): + return false + } +} + func (v *VideoRTSPStream) loop(ctx context.Context) { defer close(v.done) v.ensureTarget() @@ -304,6 +348,7 @@ func (v *VideoRTSPStream) finishSegment(scratchFile string, duration time.Durati if err := os.Rename(scratchFile, finalFile); err != nil { slog.Error("video: could not relocate segment", "camera", v.cfg.HeartbeatName, "err", err) + target.markReady() return } @@ -312,6 +357,7 @@ func (v *VideoRTSPStream) finishSegment(scratchFile string, duration time.Durati "file", target.timestampsFile, "err", err) } slog.Info("video segment closed", "camera", v.cfg.HeartbeatName, "file", finalFile) + target.markReady() if target.framesWrite == nil { return diff --git a/internal/video/stream_test.go b/internal/video/stream_test.go index ab87b4b..88b9d62 100644 --- a/internal/video/stream_test.go +++ b/internal/video/stream_test.go @@ -1,6 +1,7 @@ package video import ( + "context" "fmt" "os" "path/filepath" @@ -274,6 +275,96 @@ func TestFinishSegment_notMisledByAccumulatedProcessDrift(t *testing.T) { require.NoFileExists(t, filepath.Join(sessionNDir, "front_camera_seg.mp4")) } +// Regression: an uploader triggered right on rotation must be able to wait +// for the session's own segment to land instead of racing finishSegment. +func TestWaitSegment_blocksUntilFinishSegmentRelocatesThatSessionsSegment(t *testing.T) { + scratchDir := t.TempDir() + sessionDir := t.TempDir() + sessionStart := time.Unix(1_800_000_000, 0) + + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "front_camera.mp4"), + TimestampsFile: filepath.Join(sessionDir, "front_camera_timestamps.csv"), + SessionStart: sessionStart, + ScratchDir: scratchDir, + }) + stream.ensureTarget() + + waited := make(chan bool, 1) + go func() { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + waited <- stream.WaitSegment(ctx, sessionStart) + }() + + select { + case <-waited: + t.Fatal("WaitSegment returned before finishSegment relocated anything") + case <-time.After(20 * time.Millisecond): + } + + seg := filepath.Join(scratchDir, "seg.mp4") + require.NoError(t, os.WriteFile(seg, []byte("a"), 0o644)) + stream.finishSegment(seg, 0, sessionStart, 0) + + require.True(t, <-waited, "WaitSegment must return true once finishSegment relocates the session's segment") +} + +// A target that never receives a segment (RTSP never delivered data for +// that session) must not hang WaitSegment past its context. +func TestWaitSegment_returnsFalseWhenContextEndsFirst(t *testing.T) { + sessionStart := time.Unix(1_800_000_000, 0) + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "front_camera.mp4"), + SessionStart: sessionStart, + ScratchDir: t.TempDir(), + }) + stream.ensureTarget() + + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Millisecond) + defer cancel() + require.False(t, stream.WaitSegment(ctx, sessionStart)) +} + +// A relocation failure must still unblock waiters rather than leaving them +// to time out every time. +func TestWaitSegment_returnsTrueImmediatelyAfterRelocationFailure(t *testing.T) { + sessionDir := t.TempDir() + sessionStart := time.Unix(1_800_000_000, 0) + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "front_camera.mp4"), + TimestampsFile: filepath.Join(sessionDir, "front_camera_timestamps.csv"), + SessionStart: sessionStart, + ScratchDir: t.TempDir(), + }) + stream.ensureTarget() + + // scratchFile does not exist, so os.Rename inside finishSegment fails. + stream.finishSegment(filepath.Join(t.TempDir(), "missing.mp4"), 0, sessionStart, 0) + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.True(t, stream.WaitSegment(ctx, sessionStart), + "a relocation failure must still mark the target ready so callers don't wait out the full timeout") +} + +// No target was ever installed for this sessionStart. +func TestWaitSegment_returnsFalseForUnknownSessionStart(t *testing.T) { + stream := New(Config{ + RTSPURL: "rtsp://192.0.2.1:8554/unreachable", + OutputFile: filepath.Join(t.TempDir(), "front_camera.mp4"), + ScratchDir: t.TempDir(), + }) + stream.ensureTarget() + + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + require.False(t, stream.WaitSegment(ctx, time.Unix(1_900_000_000, 0))) +} + func TestAppendSegmentEntry_emptyPath_isNoOp(t *testing.T) { err := appendSegmentEntry("", time.Now(), 0, "/data/video.mp4") require.NoError(t, err) From 7878405add8fbaa37900ba5d4557a520c57d4ab4 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Fri, 4 Sep 2026 18:25:55 -0500 Subject: [PATCH 12/26] Add .dockerignore to keep host-built CycloneDDS/Draco out of image builds 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 Claude-Session: https://claude.ai/code/session_01HcFEZMmK9xhXsKjtFyiqRi --- .dockerignore | 13 +++++++++++++ 1 file changed, 13 insertions(+) create mode 100644 .dockerignore diff --git a/.dockerignore b/.dockerignore new file mode 100644 index 0000000..8624ff3 --- /dev/null +++ b/.dockerignore @@ -0,0 +1,13 @@ +.DS_Store +.claude/ +.cyclonedds/ +.draco/ +.zenoh-c/ +__pycache__/ +bin/ +internal/ddsgen/ +myenv/ +recordings/ +.env +docker-compose.override.yml +.git From 1c8346e6290ec13a190333046f16cbf5e1b9f4e4 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Fri, 4 Sep 2026 19:14:16 -0500 Subject: [PATCH 13/26] Pare this PR's doc comments to 1-2 lines 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 --- cmd/main/main.go | 10 ++-------- internal/audio/stream.go | 18 ++++-------------- internal/retention/retention.go | 19 ++++--------------- internal/retention/retention_test.go | 8 ++------ internal/video/stream.go | 18 ++++-------------- 5 files changed, 16 insertions(+), 57 deletions(-) diff --git a/cmd/main/main.go b/cmd/main/main.go index 9441bcb..ae6173d 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -598,14 +598,8 @@ func (p *persistentStreams) rotate(cfg config.Config, sess *session.Session) { p.audioStream.Rotate(sessionStart, audioTs, framesFileFor(audioOut, "_packets.csv")) } -// awaitSegments blocks until every video stream and the audio stream have -// relocated the segment belonging to the session that started at -// sessionStart, or ctx ends. Meant to run right before that session gets -// uploaded: video/audio only relocate a segment once ffmpeg reports it -// closed, which happens a full segment_time (== the rotation interval) -// after the segment began -- i.e. at roughly the same moment as the next -// rotation, not this one. Uploading on rotation without this wait races -// that and silently ships the session without its video/audio. +// awaitSegments waits for every video/audio stream to relocate +// sessionStart's segment before upload -- ffmpeg closes segments a full rotation interval late, so this must run first. func (p *persistentStreams) awaitSegments(ctx context.Context, sessionStart time.Time) { var wg sync.WaitGroup for _, vs := range p.videoStreams { diff --git a/internal/audio/stream.go b/internal/audio/stream.go index b58406f..038fa71 100644 --- a/internal/audio/stream.go +++ b/internal/audio/stream.go @@ -69,9 +69,8 @@ type segmentTarget struct { timestampsFile string framesWrite *recordutil.FrameCSVWriter - // ready closes once this target has received (or, on relocation - // failure, definitively won't receive) its first segment -- see - // WaitSegment. + // ready closes once this target's first segment lands (or definitively + // won't, on relocation failure) -- see WaitSegment. ready chan struct{} readyOnce sync.Once } @@ -159,17 +158,8 @@ func (a *AudioRTSPStream) targetFor(startWallClock time.Time) *segmentTarget { return best } -// WaitSegment blocks until the target for sessionStart (installed by an -// earlier Rotate/ensureTarget call with that exact value) has relocated its -// first segment, or ctx ends. Reports whether a segment actually arrived; -// false also covers "no such target" and "ctx ended first". -// -// This exists because a video/audio segment closes (and only then becomes -// visible to a directory listing) a full segment_time after it began -- the -// same duration as a session rotation interval -- so its close notification -// lands at roughly the same instant as the *next* rotation, well after the -// session it belongs to has already closed. A caller uploading that session -// immediately on rotation would otherwise race this and upload without it. +// WaitSegment blocks until the target for sessionStart has relocated its +// first segment, or ctx ends; reports whether a segment actually arrived. func (a *AudioRTSPStream) WaitSegment(ctx context.Context, sessionStart time.Time) bool { a.targetMu.Lock() var target *segmentTarget diff --git a/internal/retention/retention.go b/internal/retention/retention.go index ec6c630..1581602 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -138,18 +138,8 @@ func SnapshotTimebase(bootPath, sessionDir string) { } } -// UploadSession uploads one finished session directory; on failure the files are kept locally for a later retry. -// -// dir is claimed for the duration of the upload, so a concurrent call for -// the same dir (another upload path, or retention's cap enforcement) skips -// it instead of racing. -// -// awaitReady, if non-nil, is called first (bounded by the same upload -// timeout) so a caller can block until still-relocating streams -- notably -// video/audio, whose segment only closes well after the session itself -// rotates -- have settled before dir's contents get listed for upload. A nil -// awaitReady uploads whatever is in dir immediately, which is fine for a -// catch-up sweep over sessions that have been closed for a while. +// UploadSession uploads one finished session directory (kept locally for +// retry on failure); awaitReady, if non-nil, blocks first so still-relocating streams can settle before dir's contents are listed. func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir string, startedAt time.Time, deleteAfter bool, opts upload.Options, awaitReady func(context.Context)) { if !ctl.TryClaimDir(dir) { slog.Info("retention: skipping upload, already in flight", "dir", dir) @@ -178,9 +168,8 @@ func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir st } } -// UploadFinishedSessionAsync kicks off finished's upload in the background if uploading is enabled. -// -// awaitReady is passed straight through to UploadSession -- see its doc. +// UploadFinishedSessionAsync kicks off finished's upload in the background +// if uploading is enabled; awaitReady is passed straight through to UploadSession. func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl *control.State, recordingsDir, bootTimebasePath string, finished *session.Session, uploadDelete bool, awaitReady func(context.Context)) { if uploader == nil || !ctl.Uploading() { return diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index a7dc8c9..334b869 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -332,12 +332,8 @@ func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { "the second concurrent UploadSession call for the same dir must be skipped entirely, not just deduplicated after the fact") } -// Regression: video/audio only relocate their segment into dir a full -// segment_time after the session itself rotates, so an upload triggered -// right on rotation must wait for awaitReady before listing dir's files -- -// otherwise it silently ships the session without them. This proves -// awaitReady runs to completion, and any files it adds are visible, before -// the upload's network calls start. +// Proves awaitReady runs to completion, and any files it adds are visible, +// before UploadSession's network calls start. func TestUploadSession_awaitReadyCompletesBeforeUploadStarts(t *testing.T) { api, apiURL := newMinimalFakeAPI(t) client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) diff --git a/internal/video/stream.go b/internal/video/stream.go index aca6dab..475f4f5 100644 --- a/internal/video/stream.go +++ b/internal/video/stream.go @@ -71,9 +71,8 @@ type segmentTarget struct { timestampsFile string framesWrite *recordutil.FrameCSVWriter - // ready closes once this target has received (or, on relocation - // failure, definitively won't receive) its first segment -- see - // WaitSegment. + // ready closes once this target's first segment lands (or definitively + // won't, on relocation failure) -- see WaitSegment. ready chan struct{} readyOnce sync.Once } @@ -165,17 +164,8 @@ func (v *VideoRTSPStream) targetFor(startWallClock time.Time) *segmentTarget { return best } -// WaitSegment blocks until the target for sessionStart (installed by an -// earlier Rotate/ensureTarget call with that exact value) has relocated its -// first segment, or ctx ends. Reports whether a segment actually arrived; -// false also covers "no such target" and "ctx ended first". -// -// This exists because a video/audio segment closes (and only then becomes -// visible to a directory listing) a full segment_time after it began -- the -// same duration as a session rotation interval -- so its close notification -// lands at roughly the same instant as the *next* rotation, well after the -// session it belongs to has already closed. A caller uploading that session -// immediately on rotation would otherwise race this and upload without it. +// WaitSegment blocks until the target for sessionStart has relocated its +// first segment, or ctx ends; reports whether a segment actually arrived. func (v *VideoRTSPStream) WaitSegment(ctx context.Context, sessionStart time.Time) bool { v.targetMu.Lock() var target *segmentTarget From c665e425f3dd73f1d2f78dd0b0548b5e1b40808f Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 8 Sep 2026 13:41:19 -0500 Subject: [PATCH 14/26] Retry the boot session's own directory in catch-up uploads 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 Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH --- internal/retention/retention.go | 35 +++++++++++++++-------- internal/retention/retention_test.go | 42 ++++++++++++++++++++++++++++ 2 files changed, 66 insertions(+), 11 deletions(-) diff --git a/internal/retention/retention.go b/internal/retention/retention.go index 1581602..d8a4b7c 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -190,12 +190,20 @@ func Sweep(ctl *control.State, uploader *upload.Client, recordingsDir, bootTimeb return } - protected := func(dir string) bool { + // The boot session's own directory must never be deleted out from under its + // still-growing clock journal, but it must still be retried on the upload + // path: UploadOptions already excludes that live journal from the upload + // (see PreserveJSONL), so retrying only re-sends the rest of the directory + // -- camera clips, lidar, odom, etc. -- which finished long ago. Excluding + // the whole directory from CatchUpUploads would instead strand it forever + // behind one failed rotation-time attempt, for as long as the process runs. + uploadProtected := func(dir string) bool { return dir == currentDir || tooYoungToSweep(dir) } + deleteProtected := func(dir string) bool { return dir == currentDir || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) } - CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) - EnforceRetentionCap(ctl, recordingsDir, dirs, protected, maxBytes) + CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) + EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, maxBytes) } // CatchUpUploads retries every closed, not-yet-uploaded, non-protected directory in dirs, oldest first. @@ -287,16 +295,21 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot interval = 5 * time.Minute } - listClosed := func() (dirs []string, protected func(string) bool, ok bool) { + // See the comment in Sweep: uploads may still target the boot session's own + // directory (its live clock journal is excluded per-file via + // UploadOptions), but deletion must not touch that directory at all. + listClosed := func() (dirs []string, uploadProtected, deleteProtected func(string) bool, ok bool) { dirs, err := session.ListClosed(recordingsDir) if err != nil { slog.Warn("retention: cannot list session directories", "dir", recordingsDir, "err", err) - return nil, nil, false + return nil, nil, nil, false } cd := currentDir() - return dirs, func(dir string) bool { + uploadProtected = func(dir string) bool { return dir == cd || tooYoungToSweep(dir) } + deleteProtected = func(dir string) bool { return dir == cd || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) - }, true + } + return dirs, uploadProtected, deleteProtected, true } var wg sync.WaitGroup @@ -312,8 +325,8 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot case <-ctx.Done(): return case <-ticker.C: - if dirs, protected, ok := listClosed(); ok { - EnforceRetentionCap(ctl, recordingsDir, dirs, protected, cfg.MaxBytes) + if dirs, _, deleteProtected, ok := listClosed(); ok { + EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, cfg.MaxBytes) } } } @@ -330,8 +343,8 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot if !ctl.Uploading() { return } - if dirs, protected, ok := listClosed(); ok { - CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) + if dirs, uploadProtected, _, ok := listClosed(); ok { + CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) } } for { diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index 334b869..0cff91a 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -16,6 +16,7 @@ import ( "github.com/stretchr/testify/require" "om1-telemetry/config" + "om1-telemetry/internal/clock" "om1-telemetry/internal/control" "om1-telemetry/internal/upload" ) @@ -295,6 +296,47 @@ func TestSweep_uploadsADirOlderThanMinSessionAge(t *testing.T) { require.Equal(t, 1, api.createCalls[APISessionDir(root, old)]) } +// A failed upload-on-rotation attempt for the boot session's own directory +// must still be retried by later catch-up sweeps -- otherwise one lost race +// against a slow API strands that directory's camera/lidar/odom files for as +// long as the process keeps running, since nothing else ever asks it to +// upload again. The still-growing clock journal itself must never be +// touched: not uploaded (UploadOptions.PreserveJSONL keeps it off the +// request), and not deleted by cap enforcement either. +func TestSweep_retriesBootSessionDirOnUploadButNeverDeletesIt(t *testing.T) { + api, apiURL := newMinimalFakeAPI(t) + client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) + + root := t.TempDir() + bootDir := filepath.Join(root, "2026-08-14", "2026-08-14_00-00-00") + startedNs := time.Now().Add(-2 * minSessionAge).UnixNano() + writeFile(t, bootDir, "meta.json", []byte(fmt.Sprintf(`{"session_start_unix_ns":%d}`, startedNs))) + writeFile(t, bootDir, "lidar_scans.bin", make([]byte, 200)) + bootTimebasePath := filepath.Join(bootDir, clock.TimebaseName) + require.NoError(t, os.WriteFile(bootTimebasePath, []byte(`{"kind":"start"}`+"\n"), 0o644)) + + // A first attempt (e.g. on rotation) already failed, exactly as it would + // after a "context deadline exceeded" from the API -- so the directory is + // closed but not yet marked uploaded, same as any other stalled session. + + Sweep(control.New(), client, root, bootTimebasePath, "", 0) + + require.True(t, IsUploaded(bootDir), + "a catch-up sweep must retry the boot session's own directory, not strand it behind one failed attempt") + api.mu.Lock() + require.Equal(t, 1, api.createCalls[APISessionDir(root, bootDir)]) + api.mu.Unlock() + require.FileExists(t, bootTimebasePath, "the live clock journal must never be swept away, uploaded or not") + + // Now force cap enforcement to want to reclaim space: the boot dir is the + // only, and now uploaded, directory on disk, so it would normally be first + // in line -- but it must still be spared because its journal is live. + Sweep(control.New(), client, root, bootTimebasePath, "", 10) + + require.DirExists(t, bootDir, "cap enforcement must never delete the boot session directory while its journal is live") + require.FileExists(t, bootTimebasePath) +} + // Rotation's async upload and a concurrent catch-up sweep must never both // upload the same directory at once. func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { From c6c35b69f626ae1d471844a61643d84c1078472f Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 8 Sep 2026 13:44:35 -0500 Subject: [PATCH 15/26] Revert "Retry the boot session's own directory in catch-up uploads" This reverts commit c665e425f3dd73f1d2f78dd0b0548b5e1b40808f. --- internal/retention/retention.go | 35 ++++++++--------------- internal/retention/retention_test.go | 42 ---------------------------- 2 files changed, 11 insertions(+), 66 deletions(-) diff --git a/internal/retention/retention.go b/internal/retention/retention.go index d8a4b7c..1581602 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -190,20 +190,12 @@ func Sweep(ctl *control.State, uploader *upload.Client, recordingsDir, bootTimeb return } - // The boot session's own directory must never be deleted out from under its - // still-growing clock journal, but it must still be retried on the upload - // path: UploadOptions already excludes that live journal from the upload - // (see PreserveJSONL), so retrying only re-sends the rest of the directory - // -- camera clips, lidar, odom, etc. -- which finished long ago. Excluding - // the whole directory from CatchUpUploads would instead strand it forever - // behind one failed rotation-time attempt, for as long as the process runs. - uploadProtected := func(dir string) bool { return dir == currentDir || tooYoungToSweep(dir) } - deleteProtected := func(dir string) bool { + protected := func(dir string) bool { return dir == currentDir || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) } - CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) - EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, maxBytes) + CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) + EnforceRetentionCap(ctl, recordingsDir, dirs, protected, maxBytes) } // CatchUpUploads retries every closed, not-yet-uploaded, non-protected directory in dirs, oldest first. @@ -295,21 +287,16 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot interval = 5 * time.Minute } - // See the comment in Sweep: uploads may still target the boot session's own - // directory (its live clock journal is excluded per-file via - // UploadOptions), but deletion must not touch that directory at all. - listClosed := func() (dirs []string, uploadProtected, deleteProtected func(string) bool, ok bool) { + listClosed := func() (dirs []string, protected func(string) bool, ok bool) { dirs, err := session.ListClosed(recordingsDir) if err != nil { slog.Warn("retention: cannot list session directories", "dir", recordingsDir, "err", err) - return nil, nil, nil, false + return nil, nil, false } cd := currentDir() - uploadProtected = func(dir string) bool { return dir == cd || tooYoungToSweep(dir) } - deleteProtected = func(dir string) bool { + return dirs, func(dir string) bool { return dir == cd || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) - } - return dirs, uploadProtected, deleteProtected, true + }, true } var wg sync.WaitGroup @@ -325,8 +312,8 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot case <-ctx.Done(): return case <-ticker.C: - if dirs, _, deleteProtected, ok := listClosed(); ok { - EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, cfg.MaxBytes) + if dirs, protected, ok := listClosed(); ok { + EnforceRetentionCap(ctl, recordingsDir, dirs, protected, cfg.MaxBytes) } } } @@ -343,8 +330,8 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot if !ctl.Uploading() { return } - if dirs, uploadProtected, _, ok := listClosed(); ok { - CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) + if dirs, protected, ok := listClosed(); ok { + CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) } } for { diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index 0cff91a..334b869 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -16,7 +16,6 @@ import ( "github.com/stretchr/testify/require" "om1-telemetry/config" - "om1-telemetry/internal/clock" "om1-telemetry/internal/control" "om1-telemetry/internal/upload" ) @@ -296,47 +295,6 @@ func TestSweep_uploadsADirOlderThanMinSessionAge(t *testing.T) { require.Equal(t, 1, api.createCalls[APISessionDir(root, old)]) } -// A failed upload-on-rotation attempt for the boot session's own directory -// must still be retried by later catch-up sweeps -- otherwise one lost race -// against a slow API strands that directory's camera/lidar/odom files for as -// long as the process keeps running, since nothing else ever asks it to -// upload again. The still-growing clock journal itself must never be -// touched: not uploaded (UploadOptions.PreserveJSONL keeps it off the -// request), and not deleted by cap enforcement either. -func TestSweep_retriesBootSessionDirOnUploadButNeverDeletesIt(t *testing.T) { - api, apiURL := newMinimalFakeAPI(t) - client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) - - root := t.TempDir() - bootDir := filepath.Join(root, "2026-08-14", "2026-08-14_00-00-00") - startedNs := time.Now().Add(-2 * minSessionAge).UnixNano() - writeFile(t, bootDir, "meta.json", []byte(fmt.Sprintf(`{"session_start_unix_ns":%d}`, startedNs))) - writeFile(t, bootDir, "lidar_scans.bin", make([]byte, 200)) - bootTimebasePath := filepath.Join(bootDir, clock.TimebaseName) - require.NoError(t, os.WriteFile(bootTimebasePath, []byte(`{"kind":"start"}`+"\n"), 0o644)) - - // A first attempt (e.g. on rotation) already failed, exactly as it would - // after a "context deadline exceeded" from the API -- so the directory is - // closed but not yet marked uploaded, same as any other stalled session. - - Sweep(control.New(), client, root, bootTimebasePath, "", 0) - - require.True(t, IsUploaded(bootDir), - "a catch-up sweep must retry the boot session's own directory, not strand it behind one failed attempt") - api.mu.Lock() - require.Equal(t, 1, api.createCalls[APISessionDir(root, bootDir)]) - api.mu.Unlock() - require.FileExists(t, bootTimebasePath, "the live clock journal must never be swept away, uploaded or not") - - // Now force cap enforcement to want to reclaim space: the boot dir is the - // only, and now uploaded, directory on disk, so it would normally be first - // in line -- but it must still be spared because its journal is live. - Sweep(control.New(), client, root, bootTimebasePath, "", 10) - - require.DirExists(t, bootDir, "cap enforcement must never delete the boot session directory while its journal is live") - require.FileExists(t, bootTimebasePath) -} - // Rotation's async upload and a concurrent catch-up sweep must never both // upload the same directory at once. func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { From f6e11a6e9622db5c9e091f44c9c8583ece506988 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 8 Sep 2026 13:45:28 -0500 Subject: [PATCH 16/26] Reapply "Retry the boot session's own directory in catch-up uploads" This reverts commit c6c35b69f626ae1d471844a61643d84c1078472f. --- internal/retention/retention.go | 25 +++++++++++++---------- internal/retention/retention_test.go | 30 ++++++++++++++++++++++++++++ 2 files changed, 44 insertions(+), 11 deletions(-) diff --git a/internal/retention/retention.go b/internal/retention/retention.go index 1581602..efdf08c 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -190,12 +190,13 @@ func Sweep(ctl *control.State, uploader *upload.Client, recordingsDir, bootTimeb return } - protected := func(dir string) bool { + uploadProtected := func(dir string) bool { return dir == currentDir || tooYoungToSweep(dir) } + deleteProtected := func(dir string) bool { return dir == currentDir || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) } - CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) - EnforceRetentionCap(ctl, recordingsDir, dirs, protected, maxBytes) + CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) + EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, maxBytes) } // CatchUpUploads retries every closed, not-yet-uploaded, non-protected directory in dirs, oldest first. @@ -287,16 +288,18 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot interval = 5 * time.Minute } - listClosed := func() (dirs []string, protected func(string) bool, ok bool) { + listClosed := func() (dirs []string, uploadProtected, deleteProtected func(string) bool, ok bool) { dirs, err := session.ListClosed(recordingsDir) if err != nil { slog.Warn("retention: cannot list session directories", "dir", recordingsDir, "err", err) - return nil, nil, false + return nil, nil, nil, false } cd := currentDir() - return dirs, func(dir string) bool { + uploadProtected = func(dir string) bool { return dir == cd || tooYoungToSweep(dir) } + deleteProtected = func(dir string) bool { return dir == cd || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) - }, true + } + return dirs, uploadProtected, deleteProtected, true } var wg sync.WaitGroup @@ -312,8 +315,8 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot case <-ctx.Done(): return case <-ticker.C: - if dirs, protected, ok := listClosed(); ok { - EnforceRetentionCap(ctl, recordingsDir, dirs, protected, cfg.MaxBytes) + if dirs, _, deleteProtected, ok := listClosed(); ok { + EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, cfg.MaxBytes) } } } @@ -330,8 +333,8 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot if !ctl.Uploading() { return } - if dirs, protected, ok := listClosed(); ok { - CatchUpUploads(ctl, uploader, dirs, protected, recordingsDir, bootTimebasePath) + if dirs, uploadProtected, _, ok := listClosed(); ok { + CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) } } for { diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index 334b869..d5e8251 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -16,6 +16,7 @@ import ( "github.com/stretchr/testify/require" "om1-telemetry/config" + "om1-telemetry/internal/clock" "om1-telemetry/internal/control" "om1-telemetry/internal/upload" ) @@ -295,6 +296,35 @@ func TestSweep_uploadsADirOlderThanMinSessionAge(t *testing.T) { require.Equal(t, 1, api.createCalls[APISessionDir(root, old)]) } +// A failed upload for the boot session's own directory must still be +// retried by later sweeps, without ever touching its live clock journal. +func TestSweep_retriesBootSessionDirOnUploadButNeverDeletesIt(t *testing.T) { + api, apiURL := newMinimalFakeAPI(t) + client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) + + root := t.TempDir() + bootDir := filepath.Join(root, "2026-08-14", "2026-08-14_00-00-00") + startedNs := time.Now().Add(-2 * minSessionAge).UnixNano() + writeFile(t, bootDir, "meta.json", []byte(fmt.Sprintf(`{"session_start_unix_ns":%d}`, startedNs))) + writeFile(t, bootDir, "lidar_scans.bin", make([]byte, 200)) + bootTimebasePath := filepath.Join(bootDir, clock.TimebaseName) + require.NoError(t, os.WriteFile(bootTimebasePath, []byte(`{"kind":"start"}`+"\n"), 0o644)) + + Sweep(control.New(), client, root, bootTimebasePath, "", 0) + + require.True(t, IsUploaded(bootDir), + "a catch-up sweep must retry the boot session's own directory, not strand it behind one failed attempt") + api.mu.Lock() + require.Equal(t, 1, api.createCalls[APISessionDir(root, bootDir)]) + api.mu.Unlock() + require.FileExists(t, bootTimebasePath, "the live clock journal must never be swept away, uploaded or not") + + Sweep(control.New(), client, root, bootTimebasePath, "", 10) + + require.DirExists(t, bootDir, "cap enforcement must never delete the boot session directory while its journal is live") + require.FileExists(t, bootTimebasePath) +} + // Rotation's async upload and a concurrent catch-up sweep must never both // upload the same directory at once. func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { From 7d0d264045cc393a5c081f68eeef001fd1daf783 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 8 Sep 2026 19:36:38 -0500 Subject: [PATCH 17/26] Escalate to a full restart when a stream stays stuck 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 --- cmd/main/main.go | 23 +++++++++++ internal/heartbeat/heartbeat.go | 28 ++++++++++++++ internal/heartbeat/heartbeat_test.go | 57 ++++++++++++++++++++++++++++ 3 files changed, 108 insertions(+) diff --git a/cmd/main/main.go b/cmd/main/main.go index ae6173d..e4a79d4 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -33,6 +33,10 @@ import ( // scheduleTickInterval is how often the schedule reconciler checks for a state change. const scheduleTickInterval = 30 * time.Second +// stuckStreamThreshold is consecutive 30s heartbeat failures (~5 minutes) +// before a recoverable stream escalates from reconnecting to a full restart. +const stuckStreamThreshold = 10 + func main() { // Sampled before anything else, so the session's monotonic anchor covers // the whole run. @@ -65,6 +69,14 @@ func main() { mon := heartbeat.NewMonitor(30 * time.Second) + restartSignal := make(chan string, 1) + mon.SetStuckThreshold(stuckStreamThreshold, func(stream string) { + select { + case restartSignal <- stream: + default: + } + }) + var rs *recorderSet streamsFn := func() *persistentStreams { if rs == nil { @@ -255,12 +267,19 @@ func main() { reconcileSchedule() } + var restartRequested bool + loop: for { select { case <-shutdownSignal: break loop + case stream := <-restartSignal: + slog.Error("restarting process to recover a stuck stream", "stream", stream) + restartRequested = true + break loop + case <-scheduleC: reconcileSchedule() @@ -331,6 +350,10 @@ loop: "dir", sess.RealDir(), "note", "it will be dated on a later start if it ever syncs") } + + if restartRequested { + os.Exit(1) + } } // registerHeartbeats registers every stream's heartbeat check, wiring the diff --git a/internal/heartbeat/heartbeat.go b/internal/heartbeat/heartbeat.go index 3e17435..9bff7c2 100644 --- a/internal/heartbeat/heartbeat.go +++ b/internal/heartbeat/heartbeat.go @@ -12,6 +12,9 @@ import ( type Monitor struct { streams sync.Map interval time.Duration + + stuckThreshold int + stuckHandler func(stream string) } type state struct { @@ -27,12 +30,24 @@ type state struct { // finds the stream still broken -- see RegisterRecoverable. reconnect func() reconnecting atomic.Bool + + // consecutiveBad counts checks in a row that found the stream broken; + // reset the moment it recovers. Drives the stuck-handler escalation. + consecutiveBad int + escalated bool } func NewMonitor(checkInterval time.Duration) *Monitor { return &Monitor{interval: checkInterval} } +// SetStuckThreshold calls handler once, from check's goroutine, if a +// recoverable stream is still broken after threshold consecutive checks. +func (m *Monitor) SetStuckThreshold(threshold int, handler func(stream string)) { + m.stuckThreshold = threshold + m.stuckHandler = handler +} + func (m *Monitor) Register(name string, expectedHz float64) { m.register(name, expectedHz, nil) } @@ -141,6 +156,19 @@ func (m *Monitor) check() { }() } + if bad && s.reconnect != nil { + s.consecutiveBad++ + if m.stuckThreshold > 0 && s.consecutiveBad >= m.stuckThreshold && !s.escalated { + s.escalated = true + slog.Error("recorder still broken after repeated reconnects; escalating", + "stream", name, "consecutive_failures", s.consecutiveBad) + m.stuckHandler(name) + } + } else { + s.consecutiveBad = 0 + s.escalated = false + } + s.lastTicks = current s.lastTime = now return true diff --git a/internal/heartbeat/heartbeat_test.go b/internal/heartbeat/heartbeat_test.go index 61f4139..1f148e7 100644 --- a/internal/heartbeat/heartbeat_test.go +++ b/internal/heartbeat/heartbeat_test.go @@ -207,3 +207,60 @@ func TestRegisterRecoverable_doesNotOverlapReconnects(t *testing.T) { require.Equal(t, int32(1), calls.Load(), "a reconnect already in flight must not be duplicated") close(release) } + +// Reader-level reconnects can loop forever without ever restoring data if +// the real fault is upstream of the reader, so a stream stuck past the +// threshold must escalate exactly once, not on every remaining bad check. +func TestSetStuckThreshold_escalatesOnceAtThreshold(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + mon.RegisterRecoverable("pointcloud", 10, func() {}) + + var stuckCalls int + var lastStream string + mon.SetStuckThreshold(2, func(stream string) { + stuckCalls++ + lastStream = stream + }) + + time.Sleep(20 * time.Millisecond) + mon.check() + require.Zero(t, stuckCalls, "must not escalate before reaching the threshold") + + mon.check() + require.Equal(t, 1, stuckCalls, "must escalate once the threshold is reached") + require.Equal(t, "pointcloud", lastStream) + + mon.check() + require.Equal(t, 1, stuckCalls, "must not escalate again while still broken") +} + +func TestSetStuckThreshold_recoveryResetsTheCount(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + mon.RegisterRecoverable("odom", 10, func() {}) + + var stuckCalls int + mon.SetStuckThreshold(2, func(string) { stuckCalls++ }) + + time.Sleep(20 * time.Millisecond) + mon.check() + + for range 50 { + mon.Tick("odom") + } + mon.check() + + mon.check() + require.Zero(t, stuckCalls, "one failure right after recovering must not immediately re-escalate") +} + +func TestSetStuckThreshold_disabledByDefault(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + mon.RegisterRecoverable("lidar", 10, func() {}) + + time.Sleep(20 * time.Millisecond) + require.NotPanics(t, func() { + for range 10 { + mon.check() + } + }) +} From dd21f2c619da028525a3e496571f5f0350b9f38d Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Tue, 8 Sep 2026 20:41:43 -0500 Subject: [PATCH 18/26] Fix DDS wait busy-loop spinning a CPU core 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 --- internal/ddscore/participant.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/internal/ddscore/participant.go b/internal/ddscore/participant.go index af0a0c3..e745736 100644 --- a/internal/ddscore/participant.go +++ b/internal/ddscore/participant.go @@ -127,10 +127,13 @@ func NewWaitSet(participant *Participant, reader Entity) (*WaitSet, error) { return &WaitSet{entity: ws, cond: cond}, nil } +// Wait blocks for up to timeout; on error it sleeps for timeout too, since +// callers retry on error with no backoff of their own. func (w *WaitSet) Wait(timeout time.Duration) (bool, error) { var xs [1]C.dds_attach_t ret := C.dds_waitset_wait(C.dds_entity_t(w.entity), &xs[0], 1, C.dds_duration_t(timeout.Nanoseconds())) if ret < 0 { + time.Sleep(timeout) return false, fmt.Errorf("dds_waitset_wait: %w", retcodeError(ret)) } return ret > 0, nil From 2b205995aca57e19b0b25ac9ab13b16cb2f23e80 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Wed, 9 Sep 2026 13:07:28 -0500 Subject: [PATCH 19/26] Fix stuck-stream escalation getting reset by session rotation 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 --- internal/heartbeat/heartbeat.go | 22 +++++++++-- internal/heartbeat/heartbeat_test.go | 56 +++++++++++++++++++++++++--- 2 files changed, 69 insertions(+), 9 deletions(-) diff --git a/internal/heartbeat/heartbeat.go b/internal/heartbeat/heartbeat.go index 9bff7c2..b3a704f 100644 --- a/internal/heartbeat/heartbeat.go +++ b/internal/heartbeat/heartbeat.go @@ -35,6 +35,10 @@ type state struct { // reset the moment it recovers. Drives the stuck-handler escalation. consecutiveBad int escalated bool + + // everWorked latches true on the first tick ever; only a stream that + // worked and got stuck is eligible to escalate. + everWorked bool } func NewMonitor(checkInterval time.Duration) *Monitor { @@ -58,14 +62,23 @@ func (m *Monitor) RegisterRecoverable(name string, expectedHz float64, reconnect m.register(name, expectedHz, reconnect) } +// register (re)creates name's tracking state, carrying consecutiveBad and +// escalated over from any existing entry so periodic re-registration can't reset them. func (m *Monitor) register(name string, expectedHz float64, reconnect func()) { now := time.Now() - m.streams.Store(name, &state{ + s := &state{ expectedHz: expectedHz, lastTime: now, registered: now, reconnect: reconnect, - }) + } + if prev, ok := m.streams.Load(name); ok { + p := prev.(*state) + s.consecutiveBad = p.consecutiveBad + s.escalated = p.escalated + s.everWorked = p.everWorked + } + m.streams.Store(name, s) } // Unregister stops tracking name, so a deliberately stopped stream isn't flagged NOT WORKING. @@ -103,6 +116,9 @@ func (m *Monitor) check() { s := v.(*state) current := s.ticks.Load() + if current > 0 { + s.everWorked = true + } delta := current - s.lastTicks elapsed := now.Sub(s.lastTime).Seconds() var rate float64 @@ -156,7 +172,7 @@ func (m *Monitor) check() { }() } - if bad && s.reconnect != nil { + if bad && s.reconnect != nil && s.everWorked { s.consecutiveBad++ if m.stuckThreshold > 0 && s.consecutiveBad >= m.stuckThreshold && !s.escalated { s.escalated = true diff --git a/internal/heartbeat/heartbeat_test.go b/internal/heartbeat/heartbeat_test.go index 1f148e7..652060a 100644 --- a/internal/heartbeat/heartbeat_test.go +++ b/internal/heartbeat/heartbeat_test.go @@ -209,11 +209,12 @@ func TestRegisterRecoverable_doesNotOverlapReconnects(t *testing.T) { } // Reader-level reconnects can loop forever without ever restoring data if -// the real fault is upstream of the reader, so a stream stuck past the -// threshold must escalate exactly once, not on every remaining bad check. +// the real fault is upstream of the reader, so a stream that worked and +// then got stuck must escalate exactly once, not on every remaining bad check. func TestSetStuckThreshold_escalatesOnceAtThreshold(t *testing.T) { mon := NewMonitor(5 * time.Millisecond) mon.RegisterRecoverable("pointcloud", 10, func() {}) + mon.Tick("pointcloud") // it worked once, then got stuck var stuckCalls int var lastStream string @@ -223,6 +224,9 @@ func TestSetStuckThreshold_escalatesOnceAtThreshold(t *testing.T) { }) time.Sleep(20 * time.Millisecond) + mon.check() // consumes the initial tick; establishes the baseline + require.Zero(t, stuckCalls) + mon.check() require.Zero(t, stuckCalls, "must not escalate before reaching the threshold") @@ -234,25 +238,65 @@ func TestSetStuckThreshold_escalatesOnceAtThreshold(t *testing.T) { require.Equal(t, 1, stuckCalls, "must not escalate again while still broken") } -func TestSetStuckThreshold_recoveryResetsTheCount(t *testing.T) { +// A stream with no hardware ever attached (e.g. no camera connected) never +// ticks at all; restarting it can never help, so it must never escalate no +// matter how long it stays "broken" -- otherwise the process would restart +// itself forever because of a permanently, expectedly absent device. +func TestSetStuckThreshold_neverEscalatesAStreamThatNeverWorked(t *testing.T) { mon := NewMonitor(5 * time.Millisecond) - mon.RegisterRecoverable("odom", 10, func() {}) + mon.RegisterRecoverable("depth", 10, func() {}) var stuckCalls int mon.SetStuckThreshold(2, func(string) { stuckCalls++ }) time.Sleep(20 * time.Millisecond) - mon.check() + for range 20 { + mon.check() + } + require.Zero(t, stuckCalls, "a stream that has never ticked must never escalate") +} + +func TestSetStuckThreshold_recoveryResetsTheCount(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + mon.RegisterRecoverable("odom", 10, func() {}) + + var stuckCalls int + mon.SetStuckThreshold(2, func(string) { stuckCalls++ }) for range 50 { mon.Tick("odom") } - mon.check() + time.Sleep(20 * time.Millisecond) + mon.check() // consumes the ticks; establishes the baseline mon.check() require.Zero(t, stuckCalls, "one failure right after recovering must not immediately re-escalate") } +// Session rotation re-registers every stream every few minutes; that must +// not reset a stream's progress toward the stuck threshold, or a stream +// broken for hours would never escalate. +func TestSetStuckThreshold_survivesReRegistration(t *testing.T) { + mon := NewMonitor(5 * time.Millisecond) + mon.RegisterRecoverable("pointcloud", 10, func() {}) + mon.Tick("pointcloud") + + var stuckCalls int + mon.SetStuckThreshold(3, func(string) { stuckCalls++ }) + + time.Sleep(20 * time.Millisecond) + mon.check() // consumes the initial tick + mon.check() // consecutiveBad=1 + require.Zero(t, stuckCalls, "must not escalate before reaching the threshold") + + mon.RegisterRecoverable("pointcloud", 10, func() {}) + time.Sleep(20 * time.Millisecond) + mon.check() // consecutiveBad=2 despite the re-registration in between + require.Zero(t, stuckCalls) + mon.check() // consecutiveBad=3 + require.Equal(t, 1, stuckCalls, "re-registration must not reset progress toward the stuck threshold") +} + func TestSetStuckThreshold_disabledByDefault(t *testing.T) { mon := NewMonitor(5 * time.Millisecond) mon.RegisterRecoverable("lidar", 10, func() {}) From 60e13abec5ec21fb73b221ccd06d9e0c8e25b9d4 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Wed, 9 Sep 2026 19:41:38 -0500 Subject: [PATCH 20/26] fix upload issue 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. --- cmd/main/main.go | 9 +- internal/retention/retention.go | 35 ++++--- internal/retention/retention_test.go | 26 ++--- internal/upload/client.go | 142 ++++++++++++++++++--------- internal/upload/client_test.go | 86 +++++++++++++--- 5 files changed, 207 insertions(+), 91 deletions(-) diff --git a/cmd/main/main.go b/cmd/main/main.go index e4a79d4..85c5abe 100644 --- a/cmd/main/main.go +++ b/cmd/main/main.go @@ -37,6 +37,9 @@ const scheduleTickInterval = 30 * time.Second // before a recoverable stream escalates from reconnecting to a full restart. const stuckStreamThreshold = 10 +// shutdownUploadTimeout bounds the synchronous upload of the live session at shutdown. +const shutdownUploadTimeout = 10 * time.Minute + func main() { // Sampled before anything else, so the session's monotonic anchor covers // the whole run. @@ -140,7 +143,7 @@ func main() { // Uploading (never cap enforcement) is gated on ctl.Uploading -- see retention.RunSweeps. sweepCtx, sweepCancel := context.WithCancel(context.Background()) - go retention.RunSweeps(sweepCtx, uploader, recordingsDir, bootTimebasePath, currentDirFn, cfg.Retention, ctl) + go retention.RunSweeps(sweepCtx, uploader, recordingsDir, bootTimebasePath, currentDirFn, cfg.Retention, ctl, cfg.Upload.DeleteAfterUpload) rs = startRecorders(cfg, mon, recordingsDir, sess, videoHeartbeatNames) @@ -338,7 +341,9 @@ loop: opts := retention.UploadOptions(bootTimebasePath, sess.RealDir()) // No awaitReady needed: rs.Stop() above already drains ffmpeg's // final segment (and its relocation) before returning. - retention.UploadSession(ctl, uploader, sess.RealDir(), retention.APISessionDir(recordingsDir, sess.RealDir()), time.Unix(0, sess.StartUnixNs()), uploadDelete, opts, nil) + ctx, cancel := context.WithTimeout(context.Background(), shutdownUploadTimeout) + retention.UploadSession(ctx, ctl, uploader, sess.RealDir(), retention.APISessionDir(recordingsDir, sess.RealDir()), time.Unix(0, sess.StartUnixNs()), uploadDelete, opts, nil) + cancel() } } uploadWG.Wait() diff --git a/internal/retention/retention.go b/internal/retention/retention.go index efdf08c..42ef013 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -22,9 +22,6 @@ import ( // uploadMarkerName marks a session directory as already uploaded. const uploadMarkerName = ".uploaded" -// uploadTimeout bounds one session's upload, whether kicked off by rotation, schedule, or shutdown. -const uploadTimeout = 10 * time.Minute - // minSessionAge is a second, time-based line of defense protecting the // currently-recording session, alongside the dir == currentDir check. const minSessionAge = 30 * time.Second @@ -138,18 +135,21 @@ func SnapshotTimebase(bootPath, sessionDir string) { } } -// UploadSession uploads one finished session directory (kept locally for -// retry on failure); awaitReady, if non-nil, blocks first so still-relocating streams can settle before dir's contents are listed. -func UploadSession(ctl *control.State, client *upload.Client, dir, sessionDir string, startedAt time.Time, deleteAfter bool, opts upload.Options, awaitReady func(context.Context)) { +// UploadSession uploads one finished session directory; on failure the files are kept locally for a later retry. +// awaitReady, if non-nil, blocks first so still-relocating streams can settle before dir's contents are listed. +// +// dir is claimed for the duration of the upload, so a concurrent call for +// the same dir (another upload path, or retention's cap enforcement) skips +// it instead of racing. No deadline is added here beyond ctx: each request is +// bounded by the caller and the client, and an interrupted upload resumes +// from its last completed file. +func UploadSession(ctx context.Context, ctl *control.State, client *upload.Client, dir, sessionDir string, startedAt time.Time, deleteAfter bool, opts upload.Options, awaitReady func(context.Context)) { if !ctl.TryClaimDir(dir) { slog.Info("retention: skipping upload, already in flight", "dir", dir) return } defer ctl.ReleaseDir(dir) - ctx, cancel := context.WithTimeout(context.Background(), uploadTimeout) - defer cancel() - if awaitReady != nil { awaitReady(ctx) } @@ -178,12 +178,12 @@ func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl wg.Add(1) go func(dir, apiDir string, startedAt time.Time, opts upload.Options) { defer wg.Done() - UploadSession(ctl, uploader, dir, apiDir, startedAt, uploadDelete, opts, awaitReady) + UploadSession(context.Background(), ctl, uploader, dir, apiDir, startedAt, uploadDelete, opts, awaitReady) }(finished.RealDir(), APISessionDir(recordingsDir, finished.RealDir()), time.Unix(0, finished.StartUnixNs()), opts) } // Sweep runs catch-up uploads and cap enforcement once; kept as a building block for tests. -func Sweep(ctl *control.State, uploader *upload.Client, recordingsDir, bootTimebasePath, currentDir string, maxBytes int64) { +func Sweep(ctx context.Context, ctl *control.State, uploader *upload.Client, recordingsDir, bootTimebasePath, currentDir string, maxBytes int64, deleteAfter bool) { dirs, err := session.ListClosed(recordingsDir) if err != nil { slog.Warn("retention: cannot list session directories", "dir", recordingsDir, "err", err) @@ -195,21 +195,24 @@ func Sweep(ctl *control.State, uploader *upload.Client, recordingsDir, bootTimeb return dir == currentDir || BootSessionDir(bootTimebasePath, dir) || tooYoungToSweep(dir) } - CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) + CatchUpUploads(ctx, ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath, deleteAfter) EnforceRetentionCap(ctl, recordingsDir, dirs, deleteProtected, maxBytes) } // CatchUpUploads retries every closed, not-yet-uploaded, non-protected directory in dirs, oldest first. -func CatchUpUploads(ctl *control.State, uploader *upload.Client, dirs []string, protected func(string) bool, recordingsDir, bootTimebasePath string) { +func CatchUpUploads(ctx context.Context, ctl *control.State, uploader *upload.Client, dirs []string, protected func(string) bool, recordingsDir, bootTimebasePath string, deleteAfter bool) { if uploader == nil { return } for _, dir := range dirs { + if ctx.Err() != nil { + return + } if protected(dir) || IsUploaded(dir) { continue } opts := UploadOptions(bootTimebasePath, dir) - UploadSession(ctl, uploader, dir, APISessionDir(recordingsDir, dir), ReadStartedAt(dir), false, opts, nil) + UploadSession(ctx, ctl, uploader, dir, APISessionDir(recordingsDir, dir), ReadStartedAt(dir), deleteAfter, opts, nil) } } @@ -282,7 +285,7 @@ func EnforceRetentionCap(ctl *control.State, recordingsDir string, dirs []string } // RunSweeps drives catch-up uploads and cap enforcement on separate tickers until ctx is canceled. -func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, bootTimebasePath string, currentDir func() string, cfg config.RetentionConfig, ctl *control.State) { +func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, bootTimebasePath string, currentDir func() string, cfg config.RetentionConfig, ctl *control.State, deleteAfter bool) { interval := cfg.SweepInterval if interval <= 0 { interval = 5 * time.Minute @@ -334,7 +337,7 @@ func RunSweeps(ctx context.Context, uploader *upload.Client, recordingsDir, boot return } if dirs, uploadProtected, _, ok := listClosed(); ok { - CatchUpUploads(ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath) + CatchUpUploads(ctx, ctl, uploader, dirs, uploadProtected, recordingsDir, bootTimebasePath, deleteAfter) } } for { diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index d5e8251..cfaa739 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -158,7 +158,7 @@ func TestSweep_nilUploaderSkipsCatchUpButStillEnforcesCap(t *testing.T) { writeFile(t, underCap, "a.bin", []byte("data")) ctl := control.New() - Sweep(ctl, nil, root, filepath.Join(root, "boot_timebase.jsonl"), "", 100) + Sweep(context.Background(), ctl, nil, root, filepath.Join(root, "boot_timebase.jsonl"), "", 100, false) require.False(t, IsUploaded(underCap), "without an uploader nothing can be marked uploaded") require.DirExists(t, underCap, "comfortably under the cap, so nothing needs to be deleted") @@ -166,7 +166,7 @@ func TestSweep_nilUploaderSkipsCatchUpButStillEnforcesCap(t *testing.T) { overCap := filepath.Join(root, "2026-08-15", "2026-08-15_00-00-00") writeFile(t, overCap, "b.bin", make([]byte, 200)) - Sweep(ctl, nil, root, filepath.Join(root, "boot_timebase.jsonl"), "", 100) + Sweep(context.Background(), ctl, nil, root, filepath.Join(root, "boot_timebase.jsonl"), "", 100, false) require.NoDirExists(t, underCap, "with no uploader configured, cap enforcement must still delete the oldest directory rather than let the disk fill up") @@ -238,7 +238,7 @@ func TestSweep_uploadsOldestUnmarkedFirstAndSkipsProtectedAndAlreadyUploaded(t * bootTimebasePath := filepath.Join(root, "does-not-exist.jsonl") // no boot session protection in play - Sweep(control.New(), client, root, bootTimebasePath, live, 0) + Sweep(context.Background(), control.New(), client, root, bootTimebasePath, live, 0, false) require.True(t, IsUploaded(oldest), "the oldest not-yet-uploaded closed dir must get uploaded") require.False(t, IsUploaded(live), "the currently-open session must never be swept") @@ -264,7 +264,7 @@ func TestSweep_neverUploadsAVeryYoungDirEvenIfNotReportedCurrent(t *testing.T) { bootTimebasePath := filepath.Join(root, "does-not-exist.jsonl") - Sweep(control.New(), client, root, bootTimebasePath, "", 0) + Sweep(context.Background(), control.New(), client, root, bootTimebasePath, "", 0, false) require.False(t, IsUploaded(justOpened), "a directory younger than minSessionAge must never be uploaded, even when it isn't reported as the current session") @@ -287,7 +287,7 @@ func TestSweep_uploadsADirOlderThanMinSessionAge(t *testing.T) { bootTimebasePath := filepath.Join(root, "does-not-exist.jsonl") - Sweep(control.New(), client, root, bootTimebasePath, "", 0) + Sweep(context.Background(), control.New(), client, root, bootTimebasePath, "", 0, false) require.True(t, IsUploaded(old), "a directory well past minSessionAge must upload normally") @@ -310,7 +310,7 @@ func TestSweep_retriesBootSessionDirOnUploadButNeverDeletesIt(t *testing.T) { bootTimebasePath := filepath.Join(bootDir, clock.TimebaseName) require.NoError(t, os.WriteFile(bootTimebasePath, []byte(`{"kind":"start"}`+"\n"), 0o644)) - Sweep(control.New(), client, root, bootTimebasePath, "", 0) + Sweep(context.Background(), control.New(), client, root, bootTimebasePath, "", 0, false) require.True(t, IsUploaded(bootDir), "a catch-up sweep must retry the boot session's own directory, not strand it behind one failed attempt") @@ -319,7 +319,7 @@ func TestSweep_retriesBootSessionDirOnUploadButNeverDeletesIt(t *testing.T) { api.mu.Unlock() require.FileExists(t, bootTimebasePath, "the live clock journal must never be swept away, uploaded or not") - Sweep(control.New(), client, root, bootTimebasePath, "", 10) + Sweep(context.Background(), control.New(), client, root, bootTimebasePath, "", 10, false) require.DirExists(t, bootDir, "cap enforcement must never delete the boot session directory while its journal is live") require.FileExists(t, bootTimebasePath) @@ -349,7 +349,7 @@ func TestUploadSession_concurrentCallsForSameDirOnlyUploadOnce(t *testing.T) { wg.Add(1) go func() { defer wg.Done() - UploadSession(ctl, client, dir, "api/dir", time.Time{}, false, upload.Options{}, nil) + UploadSession(context.Background(), ctl, client, dir, "api/dir", time.Time{}, false, upload.Options{}, nil) }() } @@ -382,7 +382,7 @@ func TestUploadSession_awaitReadyCompletesBeforeUploadStarts(t *testing.T) { done := make(chan struct{}) go func() { defer close(done) - UploadSession(control.New(), client, dir, "api/dir", time.Time{}, false, upload.Options{}, awaitReady) + UploadSession(context.Background(), control.New(), client, dir, "api/dir", time.Time{}, false, upload.Options{}, awaitReady) }() sessionCreated := func() bool { @@ -426,7 +426,7 @@ func TestRunSweeps_capEnforcementNotBlockedByStuckCatchUpUpload(t *testing.T) { done := make(chan struct{}) go func() { - RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, control.New()) + RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, control.New(), false) close(done) }() @@ -472,7 +472,7 @@ func TestRunSweeps_uploadDisabled_skipsCatchUpButStillEnforcesCap(t *testing.T) done := make(chan struct{}) go func() { - RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, ctl) + RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, ctl, false) close(done) }() @@ -518,7 +518,7 @@ func TestRunSweeps_uploadTrigger_runsImmediateSweep(t *testing.T) { done := make(chan struct{}) go func() { - RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, ctl) + RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, ctl, false) close(done) }() @@ -560,7 +560,7 @@ func TestRunSweeps_capDisabled_stillRunsCatchUpUploads(t *testing.T) { done := make(chan struct{}) go func() { - RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, ctl) + RunSweeps(ctx, client, root, filepath.Join(root, "missing-boot.jsonl"), func() string { return "" }, cfg, ctl, false) close(done) }() diff --git a/internal/upload/client.go b/internal/upload/client.go index ec9e1f1..a4f06eb 100644 --- a/internal/upload/client.go +++ b/internal/upload/client.go @@ -8,6 +8,7 @@ import ( "errors" "fmt" "io" + "log/slog" "mime/multipart" "net/http" "os" @@ -80,8 +81,47 @@ type sessionResp struct { Upload *presignedPOST `json:"upload"` } +// uploadStateName journals, inside the session directory, which files already reached S3 for a session ID. +const uploadStateName = ".upload-state.json" + +type uploadState struct { + SessionID string `json:"session_id"` + Done []string `json:"done"` +} + +func (s uploadState) pending(files []string) []string { + done := make(map[string]bool, len(s.Done)) + for _, name := range s.Done { + done[name] = true + } + var out []string + for _, name := range files { + if !done[name] { + out = append(out, name) + } + } + return out +} + +func loadUploadState(localDir string) uploadState { + var st uploadState + if raw, err := os.ReadFile(filepath.Join(localDir, uploadStateName)); err == nil { + _ = json.Unmarshal(raw, &st) + } + return st +} + +func saveUploadState(localDir string, st uploadState) error { + raw, err := json.Marshal(st) + if err != nil { + return err + } + return os.WriteFile(filepath.Join(localDir, uploadStateName), raw, 0o644) +} + // UploadSession preprocesses localDir, uploads every regular file under it under sessionDir, then marks -// the session complete. Best-effort: on error the session is marked "failed" server-side for a later retry. +// the session complete. Progress is journaled in localDir, so a retry continues the same server-side +// session and skips files that already reached S3. func (c *Client) UploadSession(ctx context.Context, localDir, sessionDir string, startedAt time.Time, opts Options) error { if !c.cfg.Ready() { return errors.New("upload: not configured (base URL / API key unset)") @@ -106,17 +146,40 @@ func (c *Client) UploadSession(ctx context.Context, localDir, sessionDir string, if err != nil { return fmt.Errorf("upload: create session: %w", err) } + statePath := filepath.Join(localDir, uploadStateName) - if err := c.uploadFiles(ctx, sess, localDir, files); err != nil { - c.fail(ctx, sess.SessionID, err) - return fmt.Errorf("upload: %w", err) + st := loadUploadState(localDir) + if st.SessionID != sess.SessionID { + st = uploadState{SessionID: sess.SessionID} + } + // The preserved journal's conversion is re-sent on every attempt: its source is still growing. + live := strings.TrimSuffix(opts.PreserveJSONL, "l") + var stMu sync.Mutex + done := func(name string) { + if name == live { + return + } + stMu.Lock() + defer stMu.Unlock() + st.Done = append(st.Done, name) + if err := saveUploadState(localDir, st); err != nil { + slog.Warn("upload: could not journal progress", "dir", localDir, "err", err) + } } - return c.complete(ctx, sess.SessionID) + if err := c.uploadFiles(ctx, sess, localDir, st.pending(files), done); err != nil { + return fmt.Errorf("upload: %w", err) + } + if err := c.complete(ctx, sess.SessionID); err != nil { + return err + } + _ = os.Remove(statePath) + return nil } -// uploadFiles uploads every file in files, up to Concurrency at a time; the first failure cancels the rest. -func (c *Client) uploadFiles(ctx context.Context, sess *sessionResp, localDir string, files []string) error { +// uploadFiles uploads every file in files, up to Concurrency at a time, calling done after each success; +// the first failure cancels the rest. +func (c *Client) uploadFiles(ctx context.Context, sess *sessionResp, localDir string, files []string, done func(name string)) error { uploadCtx, cancel := context.WithCancel(ctx) defer cancel() @@ -127,20 +190,20 @@ func (c *Client) uploadFiles(ctx context.Context, sess *sessionResp, localDir st var once sync.Once var firstErr error - fail := func(name string, err error) { - once.Do(func() { - firstErr = fmt.Errorf("%s: %w", name, err) - cancel() - }) - } - for _, name := range files { sem <- struct{}{} wg.Add(1) go func(name string) { defer wg.Done() defer func() { <-sem }() - c.uploadOne(uploadCtx, sess, localDir, name, post, fail) + if err := c.uploadOne(uploadCtx, sess, localDir, name, post); err != nil { + once.Do(func() { + firstErr = fmt.Errorf("%s: %w", name, err) + cancel() + }) + return + } + done(name) }(name) } wg.Wait() @@ -148,38 +211,32 @@ func (c *Client) uploadFiles(ctx context.Context, sess *sessionResp, localDir st return firstErr } -// uploadOne uploads a single file, choosing multipart vs. direct-POST by size, reporting failure via fail. -func (c *Client) uploadOne(ctx context.Context, sess *sessionResp, localDir, name string, post *postBox, fail func(name string, err error)) { +// uploadOne uploads a single file, choosing multipart vs. direct-POST by size. +func (c *Client) uploadOne(ctx context.Context, sess *sessionResp, localDir, name string, post *postBox) error { path := filepath.Join(localDir, name) info, err := os.Stat(path) if err != nil { - fail(name, fmt.Errorf("stat %s: %w", path, err)) - return + return fmt.Errorf("stat %s: %w", path, err) } if info.Size() >= c.cfg.MultipartThreshold { - if err := c.uploadMultipart(ctx, sess.SessionID, path, name); err != nil { - fail(name, err) - } - return + return c.uploadMultipart(ctx, sess.SessionID, path, name) } p, err := post.get(ctx, c) if err != nil { - fail(name, fmt.Errorf("renew policy: %w", err)) - return - } - if err := c.uploadDirect(ctx, p, sess.S3Prefix+name, path); err != nil { - // Retry once against a freshly-presigned policy in case the old one expired. - p, rerr := post.forceRenew(ctx, c) - if rerr != nil { - fail(name, err) - return - } - if err := c.uploadDirect(ctx, p, sess.S3Prefix+name, path); err != nil { - fail(name, err) - } + return fmt.Errorf("renew policy: %w", err) + } + err = c.uploadDirect(ctx, p, sess.S3Prefix+name, path) + if err == nil { + return nil + } + // Retry once against a freshly-presigned policy in case the old one expired. + p, rerr := post.forceRenew(ctx, c) + if rerr != nil { + return err } + return c.uploadDirect(ctx, p, sess.S3Prefix+name, path) } // postBox holds the presigned-POST policy files share for direct uploads within one session. @@ -244,19 +301,6 @@ func (c *Client) complete(ctx context.Context, sessionID string) error { map[string]string{"status": "complete"}, nil) } -// fail best-effort marks a session failed server-side. -func (c *Client) fail(ctx context.Context, sessionID string, cause error) { - if sessionID == "" { - return - } - msg := cause.Error() - if len(msg) > 500 { - msg = msg[:500] - } - _ = c.doJSON(ctx, http.MethodPost, "/data/collection/sessions/"+sessionID+"/complete", - map[string]string{"status": "failed", "error": msg}, nil) -} - // uploadDirect POSTs one file straight to S3 using a presigned POST policy. func (c *Client) uploadDirect(ctx context.Context, post *presignedPOST, key, path string) error { f, err := os.Open(path) diff --git a/internal/upload/client_test.go b/internal/upload/client_test.go index fc5ead9..941c887 100644 --- a/internal/upload/client_test.go +++ b/internal/upload/client_test.go @@ -27,6 +27,8 @@ type fakeAPI struct { preComplete string // session_dir the server reports as already "complete" on creation failRequests map[string]int multipartData map[string][]byte // uploadID -> reassembled bytes + failPosts map[string]int // file name -> direct-POST attempts still to reject + postCount map[string]int // file name -> direct-POST attempts received // postDelay makes every direct-POST S3 upload take that long, so concurrency can be measured by wall-clock time. postDelay time.Duration @@ -49,6 +51,8 @@ func newFakeAPI(t *testing.T) (*fakeAPI, *httptest.Server, *httptest.Server) { sessions: map[string]*fakeSession{}, failRequests: map[string]int{}, multipartData: map[string][]byte{}, + failPosts: map[string]int{}, + postCount: map[string]int{}, } s3 := httptest.NewServer(http.HandlerFunc(api.handleS3)) @@ -110,6 +114,14 @@ func (a *fakeAPI) createSession(w http.ResponseWriter, r *http.Request) { status = "complete" } + // Like the real API, an in-progress session for the same dir is handed back instead of a new one. + for _, sess := range a.sessions { + if sess.sessionDir == body.SessionDir && sess.status == "uploading" { + a.writeSession(w, http.StatusOK, sess) + return + } + } + a.nextID++ id := fmt.Sprintf("sess-%d", a.nextID) sess := &fakeSession{ @@ -118,10 +130,13 @@ func (a *fakeAPI) createSession(w http.ResponseWriter, r *http.Request) { uploaded: map[string][]byte{}, } a.sessions[id] = sess + a.writeSession(w, http.StatusCreated, sess) +} - w.WriteHeader(http.StatusCreated) +func (a *fakeAPI) writeSession(w http.ResponseWriter, code int, sess *fakeSession) { + w.WriteHeader(code) _ = json.NewEncoder(w).Encode(map[string]any{ - "session_id": id, + "session_id": sess.id, "s3_prefix": sess.prefix, "status": sess.status, "upload": map[string]any{ @@ -246,6 +261,18 @@ func (a *fakeAPI) handleS3(w http.ResponseWriter, r *http.Request) { return } key := r.FormValue("key") + name := filepath.Base(key) + a.mu.Lock() + a.postCount[name]++ + reject := a.failPosts[name] > 0 + if reject { + a.failPosts[name]-- + } + a.mu.Unlock() + if reject { + w.WriteHeader(http.StatusInternalServerError) + return + } f, _, err := r.FormFile("file") if err != nil { w.WriteHeader(http.StatusBadRequest) @@ -414,23 +441,60 @@ func TestUploadSession_largeFileUsesMultipart(t *testing.T) { require.Equal(t, big, got, "reassembled multipart bytes must match the source file") } -func TestUploadSession_failureMarksSessionFailed(t *testing.T) { - api, apiSrv, s3 := newFakeAPI(t) - s3.Close() // every S3 request will now fail to connect +func TestUploadSession_retryResumesSameSessionAndSkipsUploadedFiles(t *testing.T) { + api, apiSrv, _ := newFakeAPI(t) + api.failPosts["b.bin"] = 2 // the first attempt's initial try and its policy-renew retry both fail + + dir := t.TempDir() + writeFile(t, dir, "a.bin", []byte("aaa")) + writeFile(t, dir, "b.bin", []byte("bbb")) + + c := New(Config{BaseURL: apiSrv.URL, APIKey: "test-key", Concurrency: 1}) + require.Error(t, c.UploadSession(context.Background(), dir, "recordings/resume", time.Now(), Options{})) + require.FileExists(t, filepath.Join(dir, uploadStateName)) + + require.NoError(t, c.UploadSession(context.Background(), dir, "recordings/resume", time.Now(), Options{})) + require.NoFileExists(t, filepath.Join(dir, uploadStateName)) + + api.mu.Lock() + defer api.mu.Unlock() + require.Len(t, api.sessions, 1, "the retry must continue the server-side session, not open a new one") + for _, sess := range api.sessions { + require.Equal(t, "complete", sess.status) + require.Equal(t, []byte("aaa"), sess.uploaded["a.bin"]) + require.Equal(t, []byte("bbb"), sess.uploaded["b.bin"]) + } + require.Equal(t, 1, api.postCount["a.bin"], "a file that already reached S3 must not be re-sent") + require.Equal(t, 3, api.postCount["b.bin"]) +} + +func TestUploadSession_preservedJournalIsResentOnRetry(t *testing.T) { + api, apiSrv, _ := newFakeAPI(t) + api.failPosts["meta.json"] = 2 dir := t.TempDir() + writeFile(t, dir, "clock_timebase.jsonl", []byte("{\"kind\":\"start\"}\n")) writeFile(t, dir, "meta.json", []byte(`{}`)) - c := New(Config{BaseURL: apiSrv.URL, APIKey: "test-key"}) - err := c.UploadSession(context.Background(), dir, "recordings/fails", time.Now(), Options{}) - require.Error(t, err) + c := New(Config{BaseURL: apiSrv.URL, APIKey: "test-key", Concurrency: 1}) + opts := Options{PreserveJSONL: "clock_timebase.jsonl"} + require.Error(t, c.UploadSession(context.Background(), dir, "recordings/live", time.Now(), opts)) + + f, err := os.OpenFile(filepath.Join(dir, "clock_timebase.jsonl"), os.O_APPEND|os.O_WRONLY, 0o644) + require.NoError(t, err) + _, err = f.WriteString("{\"kind\":\"sync\"}\n") + require.NoError(t, err) + require.NoError(t, f.Close()) + + require.NoError(t, c.UploadSession(context.Background(), dir, "recordings/live", time.Now(), opts)) api.mu.Lock() defer api.mu.Unlock() - require.Len(t, api.sessions, 1) + require.Equal(t, 2, api.postCount["clock_timebase.json"], "the still-growing journal must be re-sent") for _, sess := range api.sessions { - require.Equal(t, "failed", sess.status) - require.NotEmpty(t, sess.failReason) + var records []map[string]any + require.NoError(t, json.Unmarshal(sess.uploaded["clock_timebase.json"], &records)) + require.Len(t, records, 2) } } From f7d6e1d2a425b1fce2e7c285f0595bd42d8af32b Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Thu, 10 Sep 2026 13:44:59 -0500 Subject: [PATCH 21/26] Bound dds_delete so a never-connected DDS entity can't wedge shutdown 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 Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH --- internal/ddscore/participant.go | 38 ++++++++++++++++++++++++++------- 1 file changed, 30 insertions(+), 8 deletions(-) diff --git a/internal/ddscore/participant.go b/internal/ddscore/participant.go index e745736..6fd8901 100644 --- a/internal/ddscore/participant.go +++ b/internal/ddscore/participant.go @@ -40,11 +40,36 @@ func NewParticipant(domainID uint32) (*Participant, error) { return &Participant{entity: e}, nil } -func (p *Participant) Close() error { - if ret := C.dds_delete(C.dds_entity_t(p.entity)); ret < 0 { - return fmt.Errorf("dds_delete(participant): %w", retcodeError(ret)) +// closeTimeout bounds how long dds_delete is given to return. An entity +// built on a subscription that never received any data can leave the call +// hanging in native code forever, which no Go-level cancellation can +// interrupt, so callers stop waiting instead of wedging shutdown. +const closeTimeout = 5 * time.Second + +// closeEntity deletes entity, abandoning (and leaking) the underlying +// cgo call if it does not return within closeTimeout. +func closeEntity(entity C.dds_entity_t, what string) error { + done := make(chan error, 1) + go func() { + if ret := C.dds_delete(entity); ret < 0 { + done <- retcodeError(ret) + return + } + done <- nil + }() + select { + case err := <-done: + if err != nil { + return fmt.Errorf("dds_delete(%s): %w", what, err) + } + return nil + case <-time.After(closeTimeout): + return fmt.Errorf("dds_delete(%s): timed out after %s, abandoning", what, closeTimeout) } - return nil +} + +func (p *Participant) Close() error { + return closeEntity(C.dds_entity_t(p.entity), "participant") } func (p *Participant) CreateTopic(name string, descriptor unsafe.Pointer) (Entity, error) { @@ -140,8 +165,5 @@ func (w *WaitSet) Wait(timeout time.Duration) (bool, error) { } func (w *WaitSet) Close() error { - if ret := C.dds_delete(C.dds_entity_t(w.entity)); ret < 0 { - return fmt.Errorf("dds_delete(waitset): %w", retcodeError(ret)) - } - return nil + return closeEntity(C.dds_entity_t(w.entity), "waitset") } From 7a1f4efc424635a2c837096def489c3b6b6c16bc Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Thu, 10 Sep 2026 14:36:46 -0500 Subject: [PATCH 22/26] Upload multipart parts concurrently instead of one at a time 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 Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH --- internal/upload/client.go | 72 ++++++++++++++++++++++++++-------- internal/upload/client_test.go | 42 +++++++++++++------- 2 files changed, 84 insertions(+), 30 deletions(-) diff --git a/internal/upload/client.go b/internal/upload/client.go index a4f06eb..eaadf45 100644 --- a/internal/upload/client.go +++ b/internal/upload/client.go @@ -364,7 +364,10 @@ type completedPart struct { ETag string `json:"etag"` } -// uploadMultipart sends one file through the API's S3-multipart endpoints, reading it in PartSize chunks. +// uploadMultipart sends one file through the API's S3-multipart endpoints, +// uploading up to Concurrency parts at once: a single lossy connection caps +// throughput by its own loss/RTT, so parallel parts each get their own +// connection instead of all sharing that one ceiling for the whole file. func (c *Client) uploadMultipart(ctx context.Context, sessionID, path, filename string) error { f, err := os.Open(path) if err != nil { @@ -372,6 +375,17 @@ func (c *Client) uploadMultipart(ctx context.Context, sessionID, path, filename } defer func() { _ = f.Close() }() + info, err := f.Stat() + if err != nil { + return err + } + size := info.Size() + partSize := c.cfg.PartSize + numParts := (size + partSize - 1) / partSize + if numParts == 0 { + numParts = 1 + } + var start struct { UploadID string `json:"upload_id"` } @@ -385,26 +399,52 @@ func (c *Client) uploadMultipart(ctx context.Context, sessionID, path, filename map[string]string{"filename": filename, "upload_id": start.UploadID}, nil) } + uploadCtx, cancel := context.WithCancel(ctx) + defer cancel() + + sem := make(chan struct{}, c.cfg.Concurrency) + var wg sync.WaitGroup + var mu sync.Mutex var parts []completedPart - buf := make([]byte, c.cfg.PartSize) - for partNumber := int64(1); ; partNumber++ { - n, readErr := io.ReadFull(f, buf) - if n > 0 { - etag, err := c.uploadPart(ctx, sessionID, filename, start.UploadID, partNumber, buf[:n]) + var once sync.Once + var firstErr error + + for partNumber := int64(1); partNumber <= numParts; partNumber++ { + offset := (partNumber - 1) * partSize + n := partSize + if offset+n > size { + n = size - offset + } + + sem <- struct{}{} + wg.Add(1) + go func(partNumber, offset, n int64) { + defer wg.Done() + defer func() { <-sem }() + + buf := make([]byte, n) + if _, err := f.ReadAt(buf, offset); err != nil { + once.Do(func() { firstErr = err; cancel() }) + return + } + etag, err := c.uploadPart(uploadCtx, sessionID, filename, start.UploadID, partNumber, buf) if err != nil { - abort() - return err + once.Do(func() { firstErr = err; cancel() }) + return } + mu.Lock() parts = append(parts, completedPart{PartNumber: partNumber, ETag: etag}) - } - if readErr == io.EOF || readErr == io.ErrUnexpectedEOF { - break - } - if readErr != nil { - abort() - return readErr - } + mu.Unlock() + }(partNumber, offset, n) } + wg.Wait() + + if firstErr != nil { + abort() + return firstErr + } + + sort.Slice(parts, func(i, j int) bool { return parts[i].PartNumber < parts[j].PartNumber }) return c.doJSON(ctx, http.MethodPost, "/data/collection/sessions/"+sessionID+"/files/complete", map[string]any{"filename": filename, "upload_id": start.UploadID, "parts": parts}, nil) diff --git a/internal/upload/client_test.go b/internal/upload/client_test.go index 941c887..78b0819 100644 --- a/internal/upload/client_test.go +++ b/internal/upload/client_test.go @@ -9,6 +9,7 @@ import ( "net/http/httptest" "os" "path/filepath" + "strconv" "sync" "testing" "time" @@ -22,13 +23,14 @@ type fakeAPI struct { s3URL string - sessions map[string]*fakeSession - nextID int - preComplete string // session_dir the server reports as already "complete" on creation - failRequests map[string]int - multipartData map[string][]byte // uploadID -> reassembled bytes - failPosts map[string]int // file name -> direct-POST attempts still to reject - postCount map[string]int // file name -> direct-POST attempts received + sessions map[string]*fakeSession + nextID int + preComplete string // session_dir the server reports as already "complete" on creation + failRequests map[string]int + multipartParts map[string]map[int64][]byte // uploadID -> part number -> that part's bytes + multipartData map[string][]byte // uploadID -> parts reassembled in part-number order, set on complete + failPosts map[string]int // file name -> direct-POST attempts still to reject + postCount map[string]int // file name -> direct-POST attempts received // postDelay makes every direct-POST S3 upload take that long, so concurrency can be measured by wall-clock time. postDelay time.Duration @@ -48,11 +50,12 @@ type fakeSession struct { func newFakeAPI(t *testing.T) (*fakeAPI, *httptest.Server, *httptest.Server) { api := &fakeAPI{ - sessions: map[string]*fakeSession{}, - failRequests: map[string]int{}, - multipartData: map[string][]byte{}, - failPosts: map[string]int{}, - postCount: map[string]int{}, + sessions: map[string]*fakeSession{}, + failRequests: map[string]int{}, + multipartParts: map[string]map[int64][]byte{}, + multipartData: map[string][]byte{}, + failPosts: map[string]int{}, + postCount: map[string]int{}, } s3 := httptest.NewServer(http.HandlerFunc(api.handleS3)) @@ -202,7 +205,7 @@ func (a *fakeAPI) startMultipart(w http.ResponseWriter, r *http.Request) { _ = json.NewDecoder(r.Body).Decode(&body) uploadID := "up-" + body.Filename a.mu.Lock() - a.multipartData[uploadID] = nil + a.multipartParts[uploadID] = map[int64][]byte{} a.mu.Unlock() w.WriteHeader(http.StatusOK) _ = json.NewEncoder(w).Encode(map[string]string{"upload_id": uploadID, "key": "k/" + body.Filename}) @@ -231,6 +234,16 @@ func (a *fakeAPI) completeMultipart(w http.ResponseWriter, r *http.Request) { } `json:"parts"` } _ = json.NewDecoder(r.Body).Decode(&body) + + a.mu.Lock() + parts := a.multipartParts[body.UploadID] + var reassembled []byte + for _, p := range body.Parts { + reassembled = append(reassembled, parts[p.PartNumber]...) + } + a.multipartData[body.UploadID] = reassembled + a.mu.Unlock() + w.WriteHeader(http.StatusOK) _ = json.NewEncoder(w).Encode(map[string]string{"message": "Upload completed", "key": body.Filename}) } @@ -293,10 +306,11 @@ func (a *fakeAPI) handleS3(w http.ResponseWriter, r *http.Request) { case r.Method == http.MethodPut && r.URL.Path == "/part": uploadID := r.URL.Query().Get("upload_id") part := r.URL.Query().Get("part") + partNumber, _ := strconv.ParseInt(part, 10, 64) data, _ := io.ReadAll(r.Body) a.mu.Lock() - a.multipartData[uploadID] = append(a.multipartData[uploadID], data...) + a.multipartParts[uploadID][partNumber] = data a.mu.Unlock() w.Header().Set("ETag", `"etag-`+uploadID+`-`+part+`"`) From 2afcf4ac55e5e07b3e1d30b335dbc757a3a58a39 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Thu, 10 Sep 2026 15:43:25 -0500 Subject: [PATCH 23/26] Compress lowstate/odom per-frame timestamp CSVs before upload 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 Claude-Session: https://claude.ai/code/session_015EnX4gj1MKZfFTPMf1WmaH --- internal/compress/zstd.go | 4 ++++ internal/compress/zstd_test.go | 10 ++++++++-- 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/internal/compress/zstd.go b/internal/compress/zstd.go index 67a9bdc..b8a941c 100644 --- a/internal/compress/zstd.go +++ b/internal/compress/zstd.go @@ -15,6 +15,10 @@ var wholeFileTargets = []string{ "lowstate_frames.bin", "odom_frames.bin", "lidar_scans.bin", + // Per-frame timestamp CSVs: repetitive numeric text, and large enough at + // lowstate's 400Hz to be worth compressing like their sibling data files. + "lowstate_timestamps.csv", + "odom_timestamps.csv", } // WholeFiles replaces each of wholeFileTargets with a zstd-compressed copy. diff --git a/internal/compress/zstd_test.go b/internal/compress/zstd_test.go index e1f2a3d..d0f485d 100644 --- a/internal/compress/zstd_test.go +++ b/internal/compress/zstd_test.go @@ -32,15 +32,20 @@ func TestWholeFiles_roundTripsAndDeletesOriginal(t *testing.T) { require.Equal(t, original, decompressed) } -func TestWholeFiles_compressesAllThreeTargets(t *testing.T) { +func TestWholeFiles_compressesAllTargets(t *testing.T) { dir := t.TempDir() writeFile(t, dir, "lowstate_frames.bin", []byte("aaaaaaaaaaaaaaaa")) writeFile(t, dir, "odom_frames.bin", []byte("bbbbbbbbbbbbbbbb")) writeFile(t, dir, "lidar_scans.bin", []byte("cccccccccccccccc")) + writeFile(t, dir, "lowstate_timestamps.csv", []byte("dddddddddddddddd")) + writeFile(t, dir, "odom_timestamps.csv", []byte("eeeeeeeeeeeeeeee")) require.NoError(t, WholeFiles(dir)) - for _, name := range []string{"lowstate_frames.zstd", "odom_frames.zstd", "lidar_scans.zstd"} { + for _, name := range []string{ + "lowstate_frames.zstd", "odom_frames.zstd", "lidar_scans.zstd", + "lowstate_timestamps.zstd", "odom_timestamps.zstd", + } { require.FileExists(t, filepath.Join(dir, name)) } } @@ -73,4 +78,5 @@ func TestCompressWholeFile_isIdempotentOnRetry(t *testing.T) { func TestZstdName(t *testing.T) { require.Equal(t, "lowstate_frames.zstd", zstdName("lowstate_frames.bin")) + require.Equal(t, "lowstate_timestamps.zstd", zstdName("lowstate_timestamps.csv")) } From 2b422953b30e938cb1e6b1d0eb066743ee9de5ec Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Thu, 10 Sep 2026 18:36:50 -0500 Subject: [PATCH 24/26] Bound async session upload's context to fix a shutdown deadlock 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 Claude-Session: https://claude.ai/code/session_015KeydH8jwQFhRpXPXTMGdD --- internal/retention/retention.go | 15 ++++++++++- internal/retention/retention_test.go | 40 ++++++++++++++++++++++++++++ 2 files changed, 54 insertions(+), 1 deletion(-) diff --git a/internal/retention/retention.go b/internal/retention/retention.go index 42ef013..e97489d 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -168,6 +168,17 @@ func UploadSession(ctx context.Context, ctl *control.State, client *upload.Clien } } +// asyncUploadTimeout bounds a finished session's background upload, awaitReady +// included. Without this, a recorder stream stuck badly enough to never +// deliver awaitReady's segment -- exactly the condition that also trips the +// heartbeat monitor's stuck-stream restart -- leaves this goroutine blocked +// on context.Background() forever. main's shutdown path waits on every such +// goroutine before it can os.Exit to let the container restart, so an +// unbounded goroutine here silently defeats that recovery. A timed-out +// attempt just gets picked up by the next catch-up sweep, same as any other +// failed upload. +var asyncUploadTimeout = 10 * time.Minute // var so tests can shrink it + // UploadFinishedSessionAsync kicks off finished's upload in the background // if uploading is enabled; awaitReady is passed straight through to UploadSession. func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl *control.State, recordingsDir, bootTimebasePath string, finished *session.Session, uploadDelete bool, awaitReady func(context.Context)) { @@ -178,7 +189,9 @@ func UploadFinishedSessionAsync(wg *sync.WaitGroup, uploader *upload.Client, ctl wg.Add(1) go func(dir, apiDir string, startedAt time.Time, opts upload.Options) { defer wg.Done() - UploadSession(context.Background(), ctl, uploader, dir, apiDir, startedAt, uploadDelete, opts, awaitReady) + ctx, cancel := context.WithTimeout(context.Background(), asyncUploadTimeout) + defer cancel() + UploadSession(ctx, ctl, uploader, dir, apiDir, startedAt, uploadDelete, opts, awaitReady) }(finished.RealDir(), APISessionDir(recordingsDir, finished.RealDir()), time.Unix(0, finished.StartUnixNs()), opts) } diff --git a/internal/retention/retention_test.go b/internal/retention/retention_test.go index cfaa739..ad89d1a 100644 --- a/internal/retention/retention_test.go +++ b/internal/retention/retention_test.go @@ -18,6 +18,7 @@ import ( "om1-telemetry/config" "om1-telemetry/internal/clock" "om1-telemetry/internal/control" + "om1-telemetry/internal/session" "om1-telemetry/internal/upload" ) @@ -401,6 +402,45 @@ func TestUploadSession_awaitReadyCompletesBeforeUploadStarts(t *testing.T) { require.True(t, IsUploaded(dir), "the session, including the file awaitReady added, must be reported as fully uploaded") } +// Regression test for a real production deadlock: a recorder stream stuck +// badly enough to never satisfy awaitReady -- exactly what trips the +// heartbeat monitor's stuck-stream restart -- must not be able to block +// UploadFinishedSessionAsync's goroutine forever. It used to run awaitReady +// under context.Background(), so main's shutdown-time wg.Wait() (guarding the +// os.Exit that lets the container actually restart and recover the stream) +// never returned, silently defeating the restart it was blocking on. +func TestUploadFinishedSessionAsync_boundsAHungAwaitReady(t *testing.T) { + orig := asyncUploadTimeout + asyncUploadTimeout = 20 * time.Millisecond + t.Cleanup(func() { asyncUploadTimeout = orig }) + + _, apiURL := newMinimalFakeAPI(t) + client := upload.New(upload.Config{BaseURL: apiURL, APIKey: "k"}) + + sess, err := session.Open(t.TempDir(), clock.NewWithSync(clock.SyncYes)) + require.NoError(t, err) + + // Shaped like the real awaitSegments/WaitSegment: it only ever returns via + // ctx, never on its own -- so this proves the fix is the bounded context, + // not some change to how awaitReady itself behaves. + awaitReady := func(ctx context.Context) { <-ctx.Done() } + + var wg sync.WaitGroup + UploadFinishedSessionAsync(&wg, client, control.New(), t.TempDir(), "", sess, false, awaitReady) + + done := make(chan struct{}) + go func() { + wg.Wait() + close(done) + }() + + select { + case <-done: + case <-time.After(2 * time.Second): + t.Fatal("UploadFinishedSessionAsync's goroutine never returned -- a hung awaitReady must not be able to block it forever") + } +} + // Cap enforcement must not block on a stuck catch-up upload. func TestRunSweeps_capEnforcementNotBlockedByStuckCatchUpUpload(t *testing.T) { const sweepInterval = 20 * time.Millisecond From 910415f05c3508bffd62ce2ca854cc5760736471 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Thu, 10 Sep 2026 21:35:05 -0500 Subject: [PATCH 25/26] Bound dds_create_* calls, not just dds_delete, against hanging 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 --- internal/ddscore/participant.go | 96 ++++++++++++++++++++++++--------- 1 file changed, 71 insertions(+), 25 deletions(-) diff --git a/internal/ddscore/participant.go b/internal/ddscore/participant.go index 6fd8901..6d5001a 100644 --- a/internal/ddscore/participant.go +++ b/internal/ddscore/participant.go @@ -32,8 +32,29 @@ type Participant struct { entity Entity } +// createTimeout bounds how long a dds_create_* cgo call is given to return. +// The same degraded-domain conditions that make dds_delete hang (see +// closeTimeout) can, after enough create/destroy churn from a stream that +// keeps reconnecting, make entity creation hang too. +const createTimeout = 5 * time.Second + +// boundedCreate runs create with a bound of createTimeout, abandoning (and +// leaking) it on timeout instead of blocking its caller forever. +func boundedCreate(create func() C.dds_entity_t) (Entity, error) { + done := make(chan C.dds_entity_t, 1) + go func() { done <- create() }() + select { + case ret := <-done: + return check(ret) + case <-time.After(createTimeout): + return 0, errors.New("timed out") + } +} + func NewParticipant(domainID uint32) (*Participant, error) { - e, err := check(C.dds_create_participant(C.dds_domainid_t(domainID), nil, nil)) + e, err := boundedCreate(func() C.dds_entity_t { + return C.dds_create_participant(C.dds_domainid_t(domainID), nil, nil) + }) if err != nil { return nil, fmt.Errorf("dds_create_participant(domain=%d): %w", domainID, err) } @@ -72,15 +93,20 @@ func (p *Participant) Close() error { return closeEntity(C.dds_entity_t(p.entity), "participant") } +// CreateTopic creates topic. cname is freed inside the bounded goroutine, +// after the cgo call actually returns, rather than via defer here -- a +// timed-out call is abandoned but not necessarily dead, and freeing cname +// early would risk a use-after-free if it eventually runs. func (p *Participant) CreateTopic(name string, descriptor unsafe.Pointer) (Entity, error) { cname := C.CString(name) - defer C.free(unsafe.Pointer(cname)) - - e, err := check(C.dds_create_topic( - C.dds_entity_t(p.entity), - (*C.dds_topic_descriptor_t)(descriptor), - cname, nil, nil, - )) + e, err := boundedCreate(func() C.dds_entity_t { + defer C.free(unsafe.Pointer(cname)) + return C.dds_create_topic( + C.dds_entity_t(p.entity), + (*C.dds_topic_descriptor_t)(descriptor), + cname, nil, nil, + ) + }) if err != nil { return 0, fmt.Errorf("dds_create_topic(%q): %w", name, err) } @@ -88,7 +114,9 @@ func (p *Participant) CreateTopic(name string, descriptor unsafe.Pointer) (Entit } func (p *Participant) CreateReader(topic Entity) (Entity, error) { - e, err := check(C.dds_create_reader(C.dds_entity_t(p.entity), C.dds_entity_t(topic), nil, nil)) + e, err := boundedCreate(func() C.dds_entity_t { + return C.dds_create_reader(C.dds_entity_t(p.entity), C.dds_entity_t(topic), nil, nil) + }) if err != nil { return 0, fmt.Errorf("dds_create_reader: %w", err) } @@ -96,7 +124,9 @@ func (p *Participant) CreateReader(topic Entity) (Entity, error) { } func (p *Participant) CreateWriter(topic Entity) (Entity, error) { - e, err := check(C.dds_create_writer(C.dds_entity_t(p.entity), C.dds_entity_t(topic), nil, nil)) + e, err := boundedCreate(func() C.dds_entity_t { + return C.dds_create_writer(C.dds_entity_t(p.entity), C.dds_entity_t(topic), nil, nil) + }) if err != nil { return 0, fmt.Errorf("dds_create_writer: %w", err) } @@ -132,24 +162,40 @@ type WaitSet struct { cond Entity } +// NewWaitSet builds a waitset in its own goroutine, bounded by createTimeout, +// for the same reason boundedCreate exists -- any of its three cgo calls can +// hang on a degraded domain. func NewWaitSet(participant *Participant, reader Entity) (*WaitSet, error) { - ws, err := check(C.dds_create_waitset(C.dds_entity_t(participant.entity))) - if err != nil { - return nil, fmt.Errorf("dds_create_waitset: %w", err) + type result struct { + ws *WaitSet + err error } - - cond, err := check(C.dds_create_readcondition(C.dds_entity_t(reader), C.DDS_ANY_STATE)) - if err != nil { - _ = C.dds_delete(C.dds_entity_t(ws)) - return nil, fmt.Errorf("dds_create_readcondition: %w", err) - } - - if ret := C.dds_waitset_attach(C.dds_entity_t(ws), C.dds_entity_t(cond), C.dds_attach_t(cond)); ret < 0 { - _ = C.dds_delete(C.dds_entity_t(ws)) - return nil, fmt.Errorf("dds_waitset_attach: %w", retcodeError(ret)) + done := make(chan result, 1) + go func() { + ws, err := check(C.dds_create_waitset(C.dds_entity_t(participant.entity))) + if err != nil { + done <- result{nil, fmt.Errorf("dds_create_waitset: %w", err)} + return + } + cond, err := check(C.dds_create_readcondition(C.dds_entity_t(reader), C.DDS_ANY_STATE)) + if err != nil { + _ = C.dds_delete(C.dds_entity_t(ws)) + done <- result{nil, fmt.Errorf("dds_create_readcondition: %w", err)} + return + } + if ret := C.dds_waitset_attach(C.dds_entity_t(ws), C.dds_entity_t(cond), C.dds_attach_t(cond)); ret < 0 { + _ = C.dds_delete(C.dds_entity_t(ws)) + done <- result{nil, fmt.Errorf("dds_waitset_attach: %w", retcodeError(C.dds_return_t(ret)))} + return + } + done <- result{&WaitSet{entity: ws, cond: cond}, nil} + }() + select { + case r := <-done: + return r.ws, r.err + case <-time.After(createTimeout): + return nil, fmt.Errorf("dds_create_waitset(construction): timed out after %s, abandoning", createTimeout) } - - return &WaitSet{entity: ws, cond: cond}, nil } // Wait blocks for up to timeout; on error it sleeps for timeout too, since From 83e626556171849d35689f69bc412e51d09a3d22 Mon Sep 17 00:00:00 2001 From: jerinpeter Date: Fri, 11 Sep 2026 18:07:43 -0500 Subject: [PATCH 26/26] Trim over-long doc comments down to the 2-line standard Co-Authored-By: Claude Sonnet 5 --- internal/ddscore/participant.go | 23 ++++++++--------------- internal/retention/retention.go | 11 ++--------- internal/upload/client.go | 6 ++---- 3 files changed, 12 insertions(+), 28 deletions(-) diff --git a/internal/ddscore/participant.go b/internal/ddscore/participant.go index 6d5001a..e143e99 100644 --- a/internal/ddscore/participant.go +++ b/internal/ddscore/participant.go @@ -32,10 +32,8 @@ type Participant struct { entity Entity } -// createTimeout bounds how long a dds_create_* cgo call is given to return. -// The same degraded-domain conditions that make dds_delete hang (see -// closeTimeout) can, after enough create/destroy churn from a stream that -// keeps reconnecting, make entity creation hang too. +// createTimeout bounds how long a dds_create_* cgo call is given to return: +// the same degraded-domain conditions that make dds_delete hang can also make entity creation hang. const createTimeout = 5 * time.Second // boundedCreate runs create with a bound of createTimeout, abandoning (and @@ -61,10 +59,8 @@ func NewParticipant(domainID uint32) (*Participant, error) { return &Participant{entity: e}, nil } -// closeTimeout bounds how long dds_delete is given to return. An entity -// built on a subscription that never received any data can leave the call -// hanging in native code forever, which no Go-level cancellation can -// interrupt, so callers stop waiting instead of wedging shutdown. +// closeTimeout bounds how long dds_delete is given to return: a never-connected entity +// can hang the call forever in native code, uninterruptible from Go. const closeTimeout = 5 * time.Second // closeEntity deletes entity, abandoning (and leaking) the underlying @@ -93,10 +89,8 @@ func (p *Participant) Close() error { return closeEntity(C.dds_entity_t(p.entity), "participant") } -// CreateTopic creates topic. cname is freed inside the bounded goroutine, -// after the cgo call actually returns, rather than via defer here -- a -// timed-out call is abandoned but not necessarily dead, and freeing cname -// early would risk a use-after-free if it eventually runs. +// CreateTopic creates topic. cname is freed inside the goroutine after the cgo call +// returns, not via defer, to avoid a use-after-free if a timed-out call eventually runs. func (p *Participant) CreateTopic(name string, descriptor unsafe.Pointer) (Entity, error) { cname := C.CString(name) e, err := boundedCreate(func() C.dds_entity_t { @@ -162,9 +156,8 @@ type WaitSet struct { cond Entity } -// NewWaitSet builds a waitset in its own goroutine, bounded by createTimeout, -// for the same reason boundedCreate exists -- any of its three cgo calls can -// hang on a degraded domain. +// NewWaitSet builds a waitset in its own goroutine, bounded by createTimeout: +// any of its three cgo calls can hang on a degraded domain, same as boundedCreate. func NewWaitSet(participant *Participant, reader Entity) (*WaitSet, error) { type result struct { ws *WaitSet diff --git a/internal/retention/retention.go b/internal/retention/retention.go index e97489d..2a461d5 100644 --- a/internal/retention/retention.go +++ b/internal/retention/retention.go @@ -168,15 +168,8 @@ func UploadSession(ctx context.Context, ctl *control.State, client *upload.Clien } } -// asyncUploadTimeout bounds a finished session's background upload, awaitReady -// included. Without this, a recorder stream stuck badly enough to never -// deliver awaitReady's segment -- exactly the condition that also trips the -// heartbeat monitor's stuck-stream restart -- leaves this goroutine blocked -// on context.Background() forever. main's shutdown path waits on every such -// goroutine before it can os.Exit to let the container restart, so an -// unbounded goroutine here silently defeats that recovery. A timed-out -// attempt just gets picked up by the next catch-up sweep, same as any other -// failed upload. +// asyncUploadTimeout bounds a finished session's background upload (awaitReady included), so a +// stream stuck forever there can't block shutdown's wg.Wait() and defeat the restart recovering it. var asyncUploadTimeout = 10 * time.Minute // var so tests can shrink it // UploadFinishedSessionAsync kicks off finished's upload in the background diff --git a/internal/upload/client.go b/internal/upload/client.go index eaadf45..c3c502e 100644 --- a/internal/upload/client.go +++ b/internal/upload/client.go @@ -364,10 +364,8 @@ type completedPart struct { ETag string `json:"etag"` } -// uploadMultipart sends one file through the API's S3-multipart endpoints, -// uploading up to Concurrency parts at once: a single lossy connection caps -// throughput by its own loss/RTT, so parallel parts each get their own -// connection instead of all sharing that one ceiling for the whole file. +// uploadMultipart sends one file through the API's S3-multipart endpoints, uploading up to +// Concurrency parts at once so no single connection's loss/RTT caps the whole file's throughput. func (c *Client) uploadMultipart(ctx context.Context, sessionID, path, filename string) error { f, err := os.Open(path) if err != nil {