Repository navigation
timestamp fixes for the vllp_logstream and evlog - #67
Merged
Merged
Conversation
evlog() samples the clock before taking the log mutex, so concurrent writers can commit out of order. evlog_msg_done() clamped the negative delta to 0 but still moved ts_head backwards, so every such race pushed the reconstructed timestamps of later entries further ahead of real time. Once the drift exceeds the delivery latency, evlog_svc_pull() computed ms_ago as an unsigned underflow (~2^64 / 1000), sent as a 7 byte delta. Pin ts_head on a negative delta and compute ms_ago signed, clamped at 0. Co-Authored-By: Claude <noreply@anthropic.com>
The delta bytes were shifted as int, which is undefined for shifts of 32 or more. On aarch64 the shift count wraps mod 32, folding the high bytes into the low bits. An underflowed "-1 ms" delta from the MCU decoded as ~14.7 days ago, giving alternating log timestamps. Co-Authored-By: Claude <noreply@anthropic.com>
After consuming the first 'l' the 64 bit branch looked at fmt[1] for the second, so "%lld" left an 'l' as the conversion character. Nothing was printed and the argument was never read, shifting every argument that followed. Co-Authored-By: Claude <noreply@anthropic.com>
Split the frame decoding out of vllp_log_rx() into vllp_logstream_decode() and build just that part into the host test binary (VLLP_SIM compiles out the channel glue). evlog-decode runs the decoder on hand-made frames: every delta width, discontinuity and truncation. evlog provokes the writer race in evlog() on the device and reads the "log" service with the host VLLP client, checking the age reported for each entry. Without the eventlog fix the probe entry reads as 18446744073709541 ms ago; with the old decoder, as 1271377911 ms (~14.7 days), the same jump seen on BMCU logs in the field. Co-Authored-By: Claude <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
vllp_logstream: decode timestamp deltas wider than 4 bytes correctly
The delta bytes were shifted as int, which is undefined for shifts of
32 or more. On aarch64 the shift count wraps mod 32, folding the high
bytes into the low bits. An underflowed "-1 ms" delta from the MCU
decoded as ~14.7 days ago, giving alternating log timestamps.
evlog() samples the clock before taking the log mutex, so concurrent
writers can commit out of order. evlog_msg_done() clamped the negative
delta to 0 but still moved ts_head backwards, so every such race pushed
the reconstructed timestamps of later entries further ahead of real time.
Once the drift exceeds the delivery latency, evlog_svc_pull() computed
ms_ago as an unsigned underflow (~2^64 / 1000), sent as a 7 byte delta.
Pin ts_head on a negative delta and compute ms_ago signed, clamped at 0.
libc: parse %lld on 64 bit targets
After consuming the first 'l' the 64 bit branch looked at fmt[1] for
the second, so "%lld" left an 'l' as the conversion character. Nothing
was printed and the argument was never read, shifting every argument
that followed.
Co-Authored-By: Claude noreply@anthropic.com