Skip to content

1.2.0 — Trustworthy closed-loop latency measurement

Choose a tag to compare

@MarkSant MarkSant released this 08 Aug 21:33
· 4 commits to main since this release

Latency data recorded with earlier versions is not valid. The timing columns written before 1.2.0 were an instrumentation artefact, not a measurement. Optical validation showed the software log understating real physical latency by 2.8x (411 ms real vs 148 ms logged). Sessions recorded before this release should be re-measured, not reanalysed.

Why this release exists

A statistical audit of latency_log.csv showed the file could not be describing physical events:

  • 346 of 354 rows had a sub-millisecond serial round trip — impossible at 9600 baud
  • the end-to-end column was near-uniform over exactly one frame interval
  • the serial leg correlated negatively with the total

Every cause was confirmed in code and fixed. Two live-mode freezes surfaced while validating the result on the rig and are fixed here too.

Fixed — instrumentation

  • Acknowledgements read one command late. The serial input buffer was drained after the read instead of before the write, so from the second trigger onward readline returned the previous command's ACK, already buffered. Root cause of the 346 impossible rows.
  • End-to-end timestamp referred to the wrong frame. It came from a module-level global overwritten by the free-running camera reader on every cap.read(), including frames never consumed. The capture timestamp now travels with the frame.
  • Every command logged as a nack. The code required the reply "OK"; the firmware sends "Red LED 1 ON". Commands were recorded as failures despite the LED firing.
  • Videos stamped with the wrong frame rate. The configured 30 fps was written into a ~39 fps stream. The container now carries the measured rate.
  • Session teardown raced concurrent logging. Counters could be snapshotted mid-increment and a writer holding the session handle could write to a closed file, leaving the metadata sidecar disagreeing with the CSVs.

Fixed — live-mode freezes

  • Preview wedged the analysis thread. cv2.imshow/waitKey ran on a worker thread while Tk owned the main thread; the two Win32 message loops can attach and waitKey never returns. Preview now renders through Tk, throttled and downscaled, dropping frames rather than blocking.
  • A stalled serial write froze everything. The port was opened without write_timeout, which on Windows means an unbounded wait. One stalled write blocked detection, preview and recording for 60 s. write_timeout is now set, and serial I/O runs on its own thread, so a stalled port costs counted trigger drops instead of a frozen application.
  • Thread joins are bounded and name the offending thread; the live loops log exceptions instead of dying silently.

Added

  • Per-session latency files, written into the recording folder: 6_Latency_<base>.csv (one row per trigger, with capture/decision/send/ACK timestamps and the derived legs), 7_FrameLedger_<base>.csv (exact video-to-pipeline frame mapping), 8_LatencyMeta_<base>.json (measured fps, trigger and drop counts, detector and ROI configuration).
  • Queue drops and lost triggers are counted rather than silent, including those lost to a write timeout or a full dispatch queue.
  • Camera.get_frame_ts(), Camera.measured_fps(), Arduino.send_command_async().
  • Documentation for config.local.yaml (bench-local camera index and serial port, untracked) and for the session output files.

Not changed, deliberately

CAP_PROP_BUFFERSIZE and the free-running camera reader. This unit is expected to show much lower camera delay than the DRerio unit, whose reader sleeps between reads and measured 102.6 ms — almost exactly 4.0 frame intervals, the signature of a DirectShow buffer. That is a real architectural difference between two published systems and should be measured, not normalised away beforehand.

Full Changelog: 1.1.0...1.2.0