Stats-timer publication stalls during Starlink-only ops while data-republish keeps working

[rolker]

Observation

During the 2026-05-19 BizzyBoat deployment Phase 1 (Starlink-only at the operator station), the operator-side udp_bridge stats publication stalled for the entire ~1h17m of the Starlink-only phase (salmon log §14, §15).

Three operator-side topics dropped to 0 msg/s within ~60 s of the WiFi-down cutover at 12:53 EDT and stayed at 0 through to recovery at 14:10 EDT:

• /operator/udp_bridge/topic_statistics — operator's own local stats (salmon-published)
• /operator/udp_bridge/bridge_info — operator's own local bridge info
• /operator/udp_bridge/remotes/bizzy/topic_statistics — operator's view of boat-side stats (forwarded)

Meanwhile the data plane stayed healthy:

• Boat heartbeat clean at exactly 1.000 s spacing (Starlink delivering small high-priority payloads)
• CAMP video and rqt camera grid: continued flowing throughout — operator confirmed no stalls there
• Costmap (large fragmented topic): degraded over WiFi pre-cut (~78% loss per salmon §13), but no evidence of stall over Starlink either
• Operator udp_bridge process alive: PID 57723, Sl+ (sleeping multithreaded), no crash

So the stall is specific to the stats publishing path, not bridge-wide. The work-queue-saturation framing from the initial field write-up doesn't fit — if the work queue were saturated, video would have suffered too.

Open question: did boat-side stats also stall?

The operator-side mirror (/operator/udp_bridge/remotes/bizzy/topic_statistics) going to 0 doesn't distinguish:

• (A) boat-side stopped publishing → mirror naturally went to 0
• (B) boat-side kept publishing but operator-side stopped subscribing / republishing those specific topics

To answer this, replay the boat-side system bag at ~/data/logs/bizzyboat/2026-05-19T16-07-37+00-00 and check whether /bizzy/udp_bridge/topic_statistics kept publishing across the 12:53 WiFi-down cutover. The bag config (bizzyboat_project11/config/bizzyboat.yaml line 269+) records both /bizzy/udp_bridge/topic_statistics and /bizzy/udp_bridge/remotes/operator/topic_statistics, plus /rosout.

Concurrent observation

A resend-give-up WARN storm was running throughout: ~670/s right after the WiFi cut, settling to ~306/s by recovery. The "Giving up on resend… after N attempts" template's N varied 5/6/1 across the session. Whether N is meaningful or a counter-tracking glitch is a separate question (tracked elsewhere).

Impact

CAMP / rqt statistics panels were frozen for the operator throughout exactly the operational mode the deployment was trying to validate. The boat was visibly autonomous and OK via heartbeat + video, but operator's view of bridge-internal health was blind. For an actual over-horizon survey, the operator depends on these panels to spot pre-degradation trends. Today's mode was an OK condition; the stall masks a problem under a worse one.

Investigation leads (in suggested order)

1. Replay boat-side bag ~/data/logs/bizzyboat/2026-05-19T16-07-37+00-00 — check /bizzy/udp_bridge/topic_statistics rate around 12:53 EDT cutover. Answers (A) vs (B).
2. Replay operator-side bag ~/data/logs/operator/2026-05-19/bags/operator_2026-05-19T12.08.34/ — pin exact stall start/end timestamps + any /rosout errors from operator.udp_bridge.
3. Code inspection — is the stats publisher on its own timer? Why might that timer specifically stall while the data-republish path stays healthy? Check for any shared mutex / queue / condition variable between stats and data-republish paths.

Related

• Deployment: #135 — salmon log §14, §15 in the PR #136 bundle.
• Concurrent observation: resend-give-up N=5/6/1 (separate issue if filed).
• The udp_bridge build deployed today is at the post-udp_bridge#13 (resend-loop amplification fix) baseline — the stats stall is post-fix behavior, not original amplification.

---

Authored-By: Claude Code Agent
Model: Claude Opus 4.7 (1M context)

[rolker]

Answer to the boat-side stall question + autonomy-active correlation

Bag analysis of the 2026-05-19 boat-side bag answers the open question in this issue's body about whether boat-side stats also stalled.

Boat-side did NOT stall

/bizzy/udp_bridge/topic_statistics and /bizzy/udp_bridge/bridge_info published steadily throughout the deployment. Per-minute sample counts on boat-side stats topics:

• Pre-launch idle (12:08–12:15): ~60 samples/min
• Phase 1 WiFi-on (12:15–12:53): ~60 samples/min
• WiFi-OFF window (12:53–13:47): ~60 samples/min
• WiFi-back recovery (13:47–14:09): ~60 samples/min

No interruption on the boat side. So the operator-side /operator/udp_bridge/topic_statistics going to 0 msg/s for the entire ≈1h17m of Starlink-only operation (per salmon log §14 in PR #136) is operator-side-bridge specific — not a bridge-wide condition.

Implications for the fix scope: the stats-publish callback that stalls is the operator-side instance's local timer or callback path. Boat-side instance is fine. Investigation should focus on what's different about the operator-side bridge's environment under Starlink-only load.

Storm scales 23× when autonomy-stack is active, not when WiFi is cut

The resend storm gabby log §3 + salmon log §11/§14 characterized at 670 WARN/s on operator side (after the WiFi-cut at 12:53) doesn't actually scale until mission execution starts ~19 min later. Per-minute boat-side throughput across the WiFi-off window:

Minute (from bag start)	EDT	msg/s	send_success kB/s	Note
42–64	12:49–13:11	~540	~830	Normal: WiFi on or recent cut, no mission
65	13:12	16,372	2,838	Roland tries to run mission — storm onset
66	13:13	17,206	2,955
67–68	13:14–13:15	11,602–22,652	2,252–3,666	Nav stack bringup fails, first restarts
69–82	13:16–13:29	132,627–132,687	~19,200	Storm peak — 23× normal msg rate
83	13:30	456	414	Storm collapses with full-stack relaunch
84–100	13:31–13:47	~590	~830	Normal again (mission running cleanly)

WiFi cut alone (at min 46 = 12:53 EDT) caused only a modest throughput shift. The 23× msg-rate explosion only happens when mission execution + half-broken comms coincide. The storm's collapse at 13:30 corresponds exactly to the mru_transform revert + full-stack relaunch — once the nav stack came up cleanly, the storm ended.

Why this matters for the resend-loop fix

The bridge is sending 19 MB/s out the wire during the storm vs ~830 kB/s normal. That's bridge-internal effort, not productive ROS topic delivery — most of those bytes are resend attempts that the operator side can't ack on the broken path. The post-fix behavior (this build is post-udp_bridge#13) isn't amplification in the original sense, but it is heavy churn.

A behavior worth designing toward: bridge should detect a stuck-resend condition and back off aggressively (or pause resends entirely for a given remote) rather than burning 19 MB/s of wire bandwidth on packets the remote can't ack. Today's storm was harmless because Starlink could absorb it; on a more bandwidth-limited path it'd starve productive traffic.

Source

Boat-side bag SQLite at ~/data/logs/analysis/2026-05-19/bizzyboat.db. The full per-minute breakdown is in the dev log's "Post-mission data review" section of PR #136.

---

Authored-By: Claude Code Agent
Model: Claude Opus 4.7 (1M context)

[rolker]

Correction to earlier comment

The earlier post-mission comment framed the 13:12–13:29 EDT period as "resend storm scales 23× when autonomy is active over half-broken comms." After tracing the udp_bridge code and replaying the raw bag's topic_statistics, that framing was misleading.

What messages_per_second actually measures

MessageStatistics::add() is called twice per outgoing ROS message:

• Once on receipt (line 494 of udp_bridge.cpp) — init data point in the ("","") bucket
• Once per destination the message is sent to (line 541) — per (remote, connection) bucket

messages_per_second for each TopicStatistics entry = count / time_span, with a 10s buffer window. The SQLite extractor in bag_analysis SUMS across all entries in the array.

Resends do NOT count here. They go through Connection::send() → sent_packet_statistics_.add() (a different PacketSendStatistics object on PacketSizeData).

What the bag replay actually shows

Replaying the raw topic_statistics messages from the boat-side bag with per-bucket breakdown:

Window	Top source_topic	msg/s per bucket	Cause
13:10 (pre-spike)	/tf	21.6	normal
13:20 (spike peak)	/bizzy/marine/response	48,990	feedback loop

/bizzy/marine/response was being seen by the boat-side bridge at 48,990 msg/s during the 13:12–13:29 window, ~5000× its normal rate. Across 3 contributing buckets (init + vpn-destination + wifi-destination), that single topic accounts for ~150k of the ~132k summed messages_per_second spike.

Why marine/response feedback loop

Both boat-side and operator-side bizzyboat.yaml bridge configs route command_response: {source: marine/response} — bidirectional. That sets up the loop:

1. Boat publishes marine/response (an ack from command_bridge_receiver)
2. Boat bridge subscribes, forwards to operator
3. Operator bridge receives, publishes to operator-local marine/response
4. Operator bridge ALSO subscribes to local marine/response (its own publication), forwards back to boat
5. Boat bridge receives, publishes to boat-local marine/response, sees its own re-publication, forwards back
6. Loop runs at bridge-sustained rate (~48k/s in this case)

Why the loop activates at 13:12 specifically: not pinned. Probably something about node state at the nav-stack restart at 13:13 lifted whatever was preventing it during normal ops. Not yet investigated.

Boat-side SQLite recording for marine/response

The boat-side bag's local subscription to /bizzy/marine/response shows only 2 messages in the pre-window and 7 in the failure window — looks like 0/s. That's a recording artifact, not the topic's true rate. A QoS-depth-10 subscription drops messages under 48k/s pressure; the bridge's own statistics (which see every published message via its own subscription) capture the actual rate.

The original observation that DOES stand

Boat-side topic_statistics publication itself did not stall — sample rate stayed at ~60 samples/min throughout. The operator-side stall (this issue's main subject) is still operator-side-bridge-specific. That finding is unchanged.

What the original framing got wrong

• "Storm scales 23× when autonomy is active" → the metric scales because of a feedback loop in marine/response, not because of any direct correlation with autonomy. Autonomy/nav-restart probably triggered the loop's onset, but the storm isn't ROS-traffic load — it's pathological topic-bridging.
• "23× normal traffic ... 19 MB/s through bridge" → still true on the wire, but the source is the loop, not generalized autonomy load. Half a deployment running the autonomy stack without the loop would not produce this.

What still applies to this issue

The operator-side stats stall (this issue's actual subject) is independent from the marine/response loop. The stall is a separate concern requiring its own investigation. Apologies for the noise the earlier comment added.

---

Authored-By: Claude Code Agent
Model: Claude Opus 4.7 (1M context)

[rolker]

Answer to the open question: (B) — boat-side kept publishing

Queried the 2026-05-19 boat-side analysis DB
(~/data/logs/analysis/2026-05-19/bizzyboat.db) during Phase 0 of the
bench-harness work on #18.

Both directions of bridge-forwarded stats stayed at 1 Hz at the boat
through the entire 16:53–18:10 UTC stall window:

• t_bizzy_udp_bridge_topic_statistics (boat's own local stats) —
  60 msgs/min, every minute from 16:07 to 18:15 UTC. One isolated dip
  to 26/min at 17:30 UTC (not the stall window) — likely a bag-write
  hiccup, not the publisher.
• t_bizzy_udp_bridge_remotes_operator_topic_statistics (operator's
  stats received at the boat via udp_bridge) — also ~60 msgs/min
  steady throughout. Means the operator's bridge was publishing AND
  the link delivered it to the boat.

So the bridges on both sides kept exchanging stats. The stall is
purely operator-side, downstream of the bridge — something on the
operator host stopped handling the topics that #20 lists, while the
underlying bridge layer kept doing its job.

This rules out investigation lead #1 (replay boat-side bag — done; bag
shows steady publication) and sharpens lead #3 (code inspection of the
operator-side stats subscriber / republisher path). Specifically, the
three stalled topics are all things the operator-side udp_bridge node
re-publishes locally — the question becomes why that node's local
publisher stalled while its bridge_info ingest stayed healthy.

Query

-- Boat-side own stats publication rate, per minute, full bag window
SELECT
  datetime(t_ns/1e9, 'unixepoch') AS at_utc,
  COUNT(*) AS msgs_per_min
FROM t_bizzy_udp_bridge_topic_statistics
GROUP BY CAST(t_ns / 60000000000 AS INTEGER)
ORDER BY t_ns;

(126 rows, 60 msgs/min through 16:07–18:15 UTC, one 26-row anomaly at
17:30 outside the stall window.)

---

Authored-By: Claude Code Agent
Model: Claude Opus 4.7 (1M context)