Skip to content

lessons/281: unchecked json.Unmarshal can put a ~56-year outlier into the latency histogram #527

Description

@Novohudonossor

Environment

Repo at current main, code from lessons/281 (the Redis vs Valkey Performance 8.6 vs 9.0 benchmark, commit ba681ef). Found by reading the code, not from a running benchmark — all four points below were re-checked against the file on main before filing.

Observed — the only dropped error in the loop is the one that feeds the metric

lessons/281/app/main.go:118

var loaded User
json.Unmarshal([]byte(val), &loaded)

delta := time.Now().UnixNano() - loaded.Timestamp
duration := time.Duration(delta)
m.Hist.WithLabelValues("redis").Observe(duration.Seconds())

json.Marshal, rdb.Set and rdb.Get immediately above all check err and continue. This call doesn't.

Impact

If a value ever fails to decode, loaded.Timestamp stays 0 and delta becomes the current Unix time in nanoseconds — the histogram records a sample of roughly 56 years. That sample lands in the top bucket and in _sum of the same histogram that produces the numbers you publish. Any quantile over a window containing it resolves into the +Inf bucket, and rate(_sum)/rate(_count) over that window reports an average in the hundreds of millions of seconds. One bad decode is enough to visibly move a chart the video is built around.

The fix is one line and matches the three calls above it.

Secondary — the histogram label says redis for both engines

main.go:128 hardcodes WithLabelValues("redis"), while lessons/281/test/clients.yaml deploys the same image twice:

- name: redis-client
  image: aputra/app-281:v6
  args: ["-addr", "redis.antonputra.pvt:6379"]
- name: valkey-client
  image: aputra/app-281:v6
  args: ["-addr", "valkey.antonputra.pvt:6379"]

So the valkey client emits its latency under engine="redis". Your dashboards almost certainly separate the two by job/pod, so the charts are likely correct — but the series itself carries the wrong engine name, which bites anyone who reuses the metric outside your dashboard, and a -name flag would remove the ambiguity.

Two smaller ones, if useful

  • main.go:80 — when count >= *rate the branch sleeps for the rest of the second and then falls through and performs one more operation; the counter only resets on the next iteration. That is rate + 1 operations per second: 0.1% at -rate 1000, 10% at -rate 10.
  • main.go:98 — a json.Marshal failure logs "rdb.Set failed".

Provenance

These came out of a review run with ReviewGate (https://reviewgate.dev), a review gate I build that runs before the pull request — local CLI, your own model key, nothing about the code leaves the machine. I ran it over that commit while testing the tool on real code and verified every point by hand before filing. Happy to share the full report; feel free to close anything that is intentional.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions