fix: rate limit the non increasing dts warning - #5068
Conversation
2f96d5c to
1866c35
Compare
fallenmi
left a comment
There was a problem hiding this comment.
The new one-second limiter needs to use a monotonic clock. This stores SystemTimePoint values sampled from std::chrono::system_clock, so an NTP or manual wall-clock correction changes the elapsed-time decision: a backward correction can suppress every warning until wall time catches up, while a forward correction can admit another warning before one real second has elapsed.
On exact head 1866c357e3130743d0f3e5d18c975d1eeb2dc6fd, I mirrored this gate with controlled samples using the repository's clock aliases. After an initial warning at wall time 10 s, correcting the clock to 0 s and then advancing ten real seconds through wall times 0..9 produced only 1 warning versus 11 from the monotonic oracle. A forward wall-time jump from 10 s to 100 s after 10 ms of real time produced 2 warnings versus 1 from the monotonic oracle.
Please store the limiter timestamp as the existing TimePoint alias and sample std::chrono::steady_clock::now(). Please also add a regression around an injectable/extracted limiter clock that covers backward and forward wall-time corrections; the repository's mandatory bug-fix workflow requires a regression test, but this PR currently changes only production files.
The exact-head upstream checks are 7/7 green, and the focused C++17 oracle compiled with -Wall -Wextra -Werror and passed all assertions.
AI disclosure: I used OpenAI Codex to help inspect the diff, construct and run the deterministic exact-head oracle, and draft this review. I manually verified the source lines, outputs, and conclusion.
|
Good catch. On steady_clock now, and the limiter is pulled out into LogThrottle so it takes the time as a parameter rather than sampling a clock itself. Passing a wall clock reading is a compile error now, since the two time_point types differ. tests/zm_log_throttle.cpp covers both your cases. Your probe also showed the new header was leaning on transitive includes for uint64, fixed that too. |
fallenmi
left a comment
There was a problem hiding this comment.
Thanks — this addresses my prior clock-domain finding. On exact head 4c80090c03ebc0f87cd8904068b4ed8d5ee88b51, the extracted LogThrottle measures admission with the repository’s TimePoint / steady_clock, and the distinct non-convertible SystemTimePoint type prevents accidentally supplying wall time.
The synthetic-time regression covers first admission, the exact interval boundary, suppressed-count reset, and both backward and forward wall-clock corrections without sleeping; it is wired into tests/CMakeLists.txt, satisfying the repository’s bug-regression requirement. I rechecked current master bd74472fa3bc060833a70f28cddcf51da19b65be and merge 2559f532e197b6ec49348889ea6c77e077277417; the changed-head blobs land unchanged. All seven checks, six suites, and five workflows are green.
Disclosure: I used OpenAI Codex to assist this changed-head source/API review. I verified the exact public diff, source paths, refs, interactions, policy, merge, and CI metadata; I did not run a local build for this follow-up.
|
I don't like that addition of yet another set of files/objects to implement a simple capability that should just be built into the log object. These warnings happen for one of two reasons: Some cameras, the packet following a keyframe has the same dts as the keyframe. Easy to detect and fix. The others are due to large jumps back in time, likely due to ntp sync. Solveable by using shorted ntp sync intervals. In reality, the input side of ZM should handle any jump back in time as a break in capture and we do this for a large enough jump back. It takes too long to re-prime a capture and is unecessary. We really need to refactor the input side a bit, to indicate short blip in capture, such that the event ends and a new event begins and then these don't need to be warnings. |
Fixes #4242.
Rebased onto 8a4ac91 and changed approach. This originally dropped the decreasing-dts message to Debug, but you added the regression size to it two days later, so you clearly want the warning. @SteveGilvarry's other suggestion on the issue was to rate limit it, which keeps the message and still fixes the flooding the reporter saw at 20+ a second.
One a second per stream, and the suppressed ones are counted into the next message so the volume is still visible.