Host USB read stall ends the scan early and triggers ~88 spurious scan start/stop cycles

[boringethan]

Problem

A host-side USB read stall of well under a second is enough to make the sensor firmware abandon a running scan and then free-run dozens of spurious scan start/stop cycles, which corrupts the host's frame accounting and ultimately stalls the bulk endpoint hard enough that the module drops off the bus.

Observed in the field on a 20-minute all-camera scan (bloodflow-app 1.4.0-dev.2, SDK 1.6.0.post1.dev331, console FW 1.8.0, sensor FW 1.8.1-rc.2, debug flags 0x81 = USB printf ON). Full log analysis: OpenwaterHealth/openmotion-bloodflow-app#300.

Sequence (from the field log, open-motion-20260702_104931.log)

11:02:55.466  [LEFT ] HISTO enqueue fail: queue full (count=4 size=4 enq=393 deq=389 …)
11:02:55.468  [RIGHT] HISTO enqueue fail: queue full (count=4 size=4 enq=397 deq=393 …)
11:02:55.47x  USBD_HISTO_SendData failed: 3
              COMM USB TX Timeout   (×many)
              Error in USART1/2/3/6: Overrun error
              failed to setup receive for Camera 1/3/4/5 channel
11:02:55.501  [RIGHT] Scan finished (741352 ms, 29600 frames)   <- requested duration was 1200 s
11:02:55.535  [LEFT ] Scan finished (741355 ms, 29602 frames)
11:02:55.502  [RIGHT] Scan started
11:02:55.537  [LEFT ] Scan started
   … ~88 further Scan started / Scan finished pairs over the next 52 s,
     e.g. "Scan finished (194 ms, 2 frames)", "(430 ms, 4 frames)" …
11:03:47.913  host: RIGHT-HISTO stream error (device lost): [Errno 32] Pipe error

Both modules hit queue-full within 2 ms and declared Scan finished within 3 ms of each other. They are independent USB devices with independent firmware, so the common cause is the host: the SDK's stream reader blocks on a bounded packet queue (data_queue.put(..., timeout=1.0)) while a storage sink stalls, so dev.read() stops being called for a few hundred ms. Tracked host-side as OpenwaterHealth/openmotion-sdk#116 (fix PR openmotion-sdk#113 still open). That host bug should be fixed — but the firmware's reaction to it is disproportionate and is what turns a recoverable ~1 s hiccup into a dead scan.

Two firmware behaviours to fix

1. A blocked USB TX must not end the scan. Scan state should follow the host command / trigger, not the health of the histogram TX queue or the camera receive channels. Right now the firmware ends the scan ~7.6 minutes early and reports Scan finished with a frame count the host has no way to reconcile.
2. Don't auto-restart. After the false finish the firmware re-armed a new scan on the next frame and repeated that ~88 times in 52 s. Each cycle resets the frame counters, which on the host produced 81 TimestampMisalignmentWindow events, thousands of NaN-filled frames, and Histogram sum mismatch … got 3408230087, expected 2457606 (parser reading a reset counter as payload). The endpoint stall (errno 32) that finally killed the module came out of this storm, not out of the original 1 s stall.

Secondary: USB printf being ON makes it self-amplifying — the error storm floods the COMM endpoint, which competes with the histogram endpoint and deepens the very stall that caused it. Consider rate-limiting or dropping repeated printf lines under TX pressure.

Suggested acceptance

• Inject a host-side read stall of 0.5–3 s mid-scan (e.g. a debug flag that pauses the host drain, or sensor-fw#75's suppress-sends flag inverted) and confirm: no Scan finished, no spurious Scan started, frame counters continue monotonically, scan runs to the commanded duration, and the endpoint survives.
• Confirm the host sees a clean data gap (dropped frames) rather than a counter reset.

Related

• Right-side cameras and L7 lose data at the end of the scan; L7 does not recover in the next scan openmotion-bloodflow-app#300 — field report + full log analysis
• Host-side sink stalls starve the USB drain and overflow the firmware histo queue (frame drops on long scans) openmotion-sdk#116 / openmotion-sdk#113 — host-side cause (sink stalls starve the USB drain)
• rle_compress worst case (~25 ms) can overrun the per-frame budget on incompressible/brownout data -> SPI/USART overruns #70 — rle_compress worst case overrunning the per-frame budget → SPI/USART overruns (same overrun symptom, different trigger)
• RIGHT sensor: intermittent 15–30 s histogram stall mid-scan (camera dropout) under laser-on #68 — RIGHT sensor intermittent histogram stall

🤖 Generated with Claude Code