fix(json): stop truncating/colliding deep-percentile keys in JSON output - #517
fix(json): stop truncating/colliding deep-percentile keys in JSON output#517slice4e wants to merge 4 commits into
Conversation
result_print_to_json() built the "Percentile Latencies" key with snprintf(buf, sizeof(buf) - 1, "p%.3f", quantile) into an 8-byte buffer. The size-1 arg wasted a byte, and %.3f both rounds sub-100 quantiles up to "100" and doesn't fit 3+ digit integer parts + 3 decimals + NUL. For --print-percentiles requests with more than 2 decimal places (e.g. 99.999, 99.9999) this silently duplicated JSON keys (99.999 emitted under "p99.99", already used by 99.99) and mislabeled 99.9999 as "p100.0", colliding with an explicit p100 request. The plain-text table was unaffected; only the JSON was wrong. Fix: widen the buffer and use "%.10g", matching the format already used for the equivalent text-table column header in run_stats::print() (which fixed the same class of bug for the CLI table). This keeps every requested quantile distinct and correctly labeled (e.g. "p50", "p99", "p99.9", "p99.999", "p99.9999") without rounding tail values up to "p100".
The per-second "Time-Serie" block had the same defect as "Percentile
Latencies": `snprintf(buf8, sizeof(buf)-1, "p%.2f", quantile)` rounds and
then truncates, so `--print-percentiles=99.99999,99.999999` emitted the
key "p100.0" twice and one value was silently overwritten in the JSON
object. Switch it to `p%.10g` into a 32-byte buffer so both JSON blocks
now agree with each other and with the stdout table headers.
BREAKING CHANGE: this deliberately drops the backwards-compat "pNN.NN"
key shape that the removed comment in result_print_to_json() promised
("legacy consumers and tests expect this exact format"). Time-Serie
percentile keys change p50.00 -> p50, p99.00 -> p99, p99.90 -> p99.9,
matching the "Percentile Latencies" change in the previous commit.
Consumers that hard-code these key names need updating; consumers that
iterate the dict are unaffected. Keeping the old shape is not possible
while also being collision-free, since no fixed-decimal format can
distinguish 99.99999 from 99.999999.
Tests updated: tests_oss_simple_flow.py (4 sites) and
test_monitor_input.py (2 sites).
…ld_flag
test_cpu_warn_threshold_flag counted the substring "of a core" and compared
the result against the number of threads whose authoritative run-average
cores_used exceeds 1.0. But two different warnings contain that substring:
memtier_benchmark.cpp:3059 "high CPU on thread %u: %.1f%% of a core ..."
run_stats.cpp:2435 "thread %u averaged %.1f%% of a core over the
run ..."
Only the second is the end-of-run warning the assertion is about. With
--cpu-warn-threshold=100 the live per-second warning is also armed at 100%
of a core, and a 1s sample can legitimately exceed that because the wall
window and the CPU-clock sampling do not line up (the same file already
allows up to PER_THREAD_PCT_CEILING = 110%). When that happens the live
warning fires, end_warnings becomes 1 while over_one_core is 0, and the
test fails - intermittently, depending on runner load.
Match "of a core over the run", which is unique to the end-of-run message.
Verified against a live run: a single invocation emits both warnings, so
count("of a core") == 2 while count("of a core over the run") == 1.
Pre-existing since redis#471; unrelated to the JSON percentile-key change on
this branch.
|
Thanks for this — went through it, the root-cause diagnosis (the The big one: And separately — does the fix actually need to touch every key, or only the ones that collide? The default config is On testing: per #364's own bar, a JSON-format fix needs a regression test that fails on master and passes here — not just a manual Nitpicking: The flaky-test fix looks fine and orthogonal — you already offered to split it, that's enough for me, no need to actually do it unless someone else feels strongly. Buffer widening and the switch to (would file this as a comment, not a formal block) |
Problem
--json-out-filetruncates and collides percentile keys for--print-percentilesvalues with more than two decimal places. Both JSON blocks that emit percentile keys are affected, and both start failing at the same, unremarkable input — this is not a deep-tail-only bug.Both sites build the key with a fixed-decimal format into an 8-byte buffer, but pass
sizeof(buf) - 1as the size, so only 6 characters of key survive. The longest key that fits isp99.99. That 6-char ceiling — not the format string — is what caps both blocks at two effective decimal places.Percentile Latencies(result_print_to_json()inrun_stats.cpp):Time-Serie(per-second stats, same function):The
%.3flooks like it carries an extra decimal, butp99.991is 7 characters and gets chopped back top99.99, so in practice both blocks resolve to the same two decimals.Where it starts
Any quantile with three or more decimal places collides with its two-decimal neighbour, in both blocks.
--print-percentiles=99.99,99.991emitsp99.99twice; the second write overwrites the first in the JSON object and one requested percentile disappears with no warning.--print-percentiles=99.9,99.99,99.999,100is enough to lose a value.The two blocks differ only in how they are wrong, not in when:
Time-Serierounds99.995and above up to100.00, then truncates top100.0— mislabeling a deep percentile as the maximum and colliding with an explicit100request.Percentile Latenciestruncates those same values top99.99— colliding with a genuine99.99request instead.Either way, requested percentiles are silently dropped and the surviving key carries a value that does not match its label. Everything from roughly
99.999upward —99.9999,99.99999,99.999999,100— collapses onto a single key in both blocks.The plain-text table is unaffected; only the JSON is wrong.
Fix
Both sites now use the format already used for the text-table column header (
run_stats::print()), which solved this exact problem there:%.10gvaries the number of decimals shown instead of rounding to a fixed count, so every requested quantile gets a distinct, correctly-labeled key. The buffer is sized to hold the full key, andsizeof(buf)is no longer needlessly reduced by one.This deliberately removes the backwards-compatibility guarantee that was documented in the code. The
Time-Seriebranch carried this comment, which this PR deletes:Flagging that explicitly rather than letting it disappear in a diff: that promise is being broken on purpose, in both JSON blocks.
Percentile Latenciesp50.00,p99.00,p99.90p50,p99,p99.9Time-Seriep50.00,p99.00,p99.90p50,p99,p99.9Consumers that look up a fixed key name — e.g.
result["ALL STATS"]["Totals"]["Percentile Latencies"]["p99.00"]— will get aKeyErrorafter this change. Consumers that iterate the dict are unaffected. Values are unchanged; only key spelling changes.Why this can't be avoided: no fixed-decimal-place format can stay backward-compatible for the common case (
p99.00) while also staying collision-free for deeper percentiles, since two decimals cannot represent99.99and99.991as distinct strings without rounding one onto the other. Varying the decimal count (%.10g) is the only way to fix the collision, and it necessarily changes the shallow keys too.Why both blocks, rather than only fixing
Percentile Latencies: an earlier revision of this PR leftTime-Seriealone to limit the blast radius. That was the wrong call — it is the same defect, in the same function, with the same threshold, and leaving it would have shipped a JSON document keyed inconsistently with itself (Totals.Percentile Latencies.p99next toTotals.Time-Serie.<ts>.p99.00) whileTime-Seriestill silently dropped percentiles. Since consumers have to be updated either way, it is better to break once, consistently, than to ship a half-fixed schema and a second breaking change later.Testing
make format-checkpasses; builds clean with no new warnings.--print-percentiles=50,99,99.9,99.99,99.99999,99.999999. Both blocks now emit six distinct, correctly-valued keys instead of collapsing the tail onto one:json.load().tests/test_monitor_cluster_backpressure.py,tests/differential_redis_benchmark.py(Percentile Latencies)tests/tests_oss_simple_flow.py(4 sites),tests/test_monitor_input.py(2 sites) (Time-Serie)tests_oss_simple_flow.py::test_default_set_get_with_print_percentilesneeded no change — it already normalizes withkey.split(".")[0].p50.00/p99.00/p99.90.Drive-by: unrelated flaky test fix
test_cpu_stats.py::test_cpu_warn_threshold_flagwas failing CI on this branch. It is not related to this change —tests/test_cpu_stats.pyis untouched here, and it has been flaky since #471.The test counted the substring
'of a core'in stderr and compared it against the number of threads whose authoritative run-averagecores_usedexceeds 1.0. Two different warnings contain that substring:Only the second is the end-of-run warning the assertion is about. With
--cpu-warn-threshold=100the live per-second warning is armed at 100% of a core too, and a 1-second sample can legitimately exceed that because the wall window and the CPU-clock sampling do not line up — the same file already tolerates this viaPER_THREAD_PCT_CEILING = 110.0. When the live warning fires,end_warningsbecomes 1 whileover_one_coreis 0 and the test fails, intermittently, depending on runner load.Fixed by matching
'of a core over the run', which is unique to the end-of-run message. Confirmed against a live run — one invocation emits both warnings:Happy to split this into its own PR if you'd prefer to keep this one single-purpose.
Note
Cursor Bugbot is generating a summary for commit 1dbb49e. Configure here.