fix(sd): use the device's own timestamp clock when parsing SD logs (closes #426) - #429
Conversation
…loses #426) SdCardDeviceConfiguration.FromDevice hardcoded TimestampFrequency: 0 even though it is handed a live device that knows its real clock. Firmware 3.7.2 and earlier embed no frequency in SD card logs, so parsing fell back to the 50 MHz default while the bench Nq1's counter runs at 42 MHz — stretching every reconstructed timestamp by 50/42 (~19%), silently and with exit code 0. FromDevice now passes device.TimestampFrequency, keeping 0 only when the device genuinely reported none. A file that states its own frequency still wins, so this is a backstop rather than an override of better data. The fallback is also no longer silent: SdCardLogSession reports the frequency it actually converted with and, via the new SdCardTimestampSource, where that figure came from — mirroring ITimestampProcessor.HasTimestampFrequency. The CSV and JSON parsers seeded the fallback before merging the device override, which meant a connected device's real clock could never win; all three parsers now share one precedence: file, then device, then fallback. Measured on the bench Nq1 (FW 3.7.2), parsing the log from the issue: 125 samples spanned 5.208 s (42.00 ms/interval) before and 6.200 s (50.00 ms/interval) after, against the 20 Hz the data was logged at. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
/agentic_review |
PR Summary by QodoFix SD log timestamp conversion by using device-reported clock frequency
AI Description
Diagram
High-Level Assessment
Files changed (11)
|
Code Review by Qodo🐞 Bugs (0) 📘 Rule violations (0) 📎 Requirement gaps (0)
Great, no issues found!Qodo reviewed your code and found no material issues that require reviewTo customize comments, go to the Qodo configuration screen, or learn more in the docs. |
Why
Every timestamp reconstructed from an SD card log was about 19% fast.
SdCardDeviceConfiguration.FromDevicewas handed a live, initialized device and threw away the one thing it was uniquely able to supply — the device's real timestamp clock — so parsing fell back to 50 MHz while the hardware counts at 42 MHz. Nothing warned and the exit code was 0: a recording that really spanned 6.2 seconds simply reported 5.2, and--sd-export-csvbaked the error into theTimecolumn for anything downstream.What
Parse an SD log with the device connected and the timestamps now come out at the rate the data was actually logged at — 50.0 ms apart for a 20 Hz log instead of 42.0 ms. When neither the log file nor a connected device can supply a frequency, the parser still falls back to a guess, but the session now reports which frequency it used and where that number came from, so a wrong answer can no longer be mistaken for a right one.
How
FromDevicenow passesdevice.TimestampFrequencyinstead of a hardcoded 0, keeping 0 only when the device genuinely reported none. A log that states its own frequency still wins, so this is a backstop rather than an override of better data.SdCardLogSessiongained two additive properties —TimestampFrequencyandTimestampFrequencySource— that name the figure used and whether it came from the file, the device, or a fallback guess, mirroring the existingITimestampProcessor.HasTimestampFrequencyidea.Second bug fixed here, worth calling out on its own: the CSV and JSON parsers seeded the fallback frequency before merging the device override, so a connected device's real clock could never win — it was always beaten by the 50 MHz guess. That made fix #1 inert for those two formats. All three parsers now share one precedence: file, then device, then fallback. One existing JSON test asserted the old behaviour explicitly ("Inferred frequency takes precedence"); that assertion is deliberately inverted in this PR, since it codified the bug.
Bench test
Bench Nq1, FW 3.7.2, parsing
log_20260802_084946.bin— the exact file from the issue, 125 samples logged at 20 Hz (50.0 ms expected).USB / serial, before (Core
main):USB / serial, after (this branch):
WiFi / TCP
192.168.1.30:9760, after (one consolidated run; SD-over-TCP works since #327):Supporting measurements from the same unit: the live status message reports
TimestampFreq = 42,000,000 Hz, and raw stream tick deltas were 4,200,000 @ 10 Hz, 2,100,000 @ 20 Hz and 840,000 @ 50 Hz — each one exactly 42 MHz divided by the requested rate.Full Core suite green: 2483 passed, 0 failed, on both net9.0 and net10.0, with 14 new tests.
Not covered by this bench run
The fresh
--sd-log-start→--sd-list→--sd-downloadrepro cycle did not complete. Once SD logging stopped, every subsequent serial connect failed withdid not report its channel configuration within 8s— twice, including after a 25 second settle — on a freshly power-cycled unit, while TCP to the same device kept working normally throughout. This looks like a previously unrecorded device behaviour (writing an SD log leaves the serial interface unable to complete init for a while) and is distinct from the known low-heap empty-transfer state, which presents as an empty marker-only download rather than a failed init. It is not caused by this change: the same binary downloaded and parsed successfully seconds earlier over the same port. The before/after evidence above does not depend on that cycle, since it uses the exact log file from the issue.Two things the reviewer should decide on
1. The issue's claim that this is unrelated to firmware #716 is wrong, and this PR does not fix the residual error. Timing the live stream against the host clock shows the counter advances at ~33.34 MHz in real time, not 42 MHz — and 33.34/42.0 = 0.794, exactly firmware #716's "streams at 79.4% of the requested rate". The tick deltas were perfectly uniform with no dropped samples or buffered backlog, at rates far below any bandwidth limit, so this is not a transport artifact: the device's declared timebase and its slow sample cadence are one and the same firmware defect. Practically, after this PR an SD timestamp matches the device's declared timebase and the nominal logged rate, but is still about 26% short of true wall-clock elapsed time until firmware corrects its clock constant. I deliberately did not bake 33.34 MHz into Core — trusting the device's declared frequency is the right contract, and a compensation constant would silently become wrong the moment firmware is fixed.
2.
TimestampProcessor.DefaultTimestampFrequencyis left at 50 MHz. Changing it to 42 MHz would retime data for every live-streaming consumer, not just the SD path, and it is only ever reached when a device reports no frequency at all. I corrected its documentation to say plainly that it matches no shipped board rather than swapping the value, and made the SD fallback observable instead. Happy to change the constant if you'd rather take that behaviour change.Closes #426