Repository navigation
feat(perf): benchmark shelltime track latency on every PR and main push - #317
Conversation
The shell hooks run `shelltime track` in the foreground before and after every command, so its whole-process latency is user-facing. Nothing measured it. perf/ is a separate Go module (so golang.org/x/perf never affects version selection for the shipped binaries) with: - a harness that execs the real binary per iteration, as the zsh hook does, in an isolated $HOME: startup baseline, daemon pre/post against a fake daemon socket, and direct pre/post/post-sync against a seeded txt store and a fake API. Each scenario checks it took the intended path, because track always exits 0. - perfreport, which compares base and head with benchmath (medians, Mann-Whitney U) and renders a markdown report. A scenario is flagged when it is >10% and >0.25 ms slower with p < 0.05. - compare.sh, which builds base and head with identical flags, skips when the binaries are byte-identical, and runs one harness against both in interleaved ABBA rounds. The Track Perf workflow runs it on pull requests, pushes to main and on demand. It writes the report to the job summary and a sticky PR comment, and raises warning annotations on regressions without failing the check. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01QuSfoWGrqsxjw5Yyegzzyt
|
You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard. |
Codecov Report✅ All modified and coverable lines are covered by tests.
Flags with carried forward coverage won't be shown. Click here to find out more. 🚀 New features to boost your workflow:
|
⏱️
|
| Scenario | base | head | Δ | p | |
|---|---|---|---|---|---|
Startup/floor |
481 µs ±3% | 478 µs ±4% | ~ | 0.579 | A/A |
Startup/version |
3.58 ms ±2% | 3.53 ms ±3% | ~ | 0.631 | ✅ |
Track/daemon/pre |
3.83 ms ±2% | 3.83 ms ±3% | ~ | 0.853 | ✅ |
Track/daemon/post |
3.83 ms ±2% | 3.81 ms ±2% | ~ | 0.436 | ✅ |
Track/direct/pre |
3.78 ms ±2% | 3.77 ms ±3% | ~ | 0.684 | ✅ |
Track/direct/post |
7.21 ms ±1% | 7.15 ms ±1% | ~ | 0.190 | ✅ |
Track/direct/post-sync |
8.73 ms ±1% | 8.60 ms ±3% | ~ | 0.165 | ✅ |
Binary size: 19.1 MiB → 19.1 MiB (+0.0%).
CPU, tail latency and memory
Per exec, base → head (Δ when significant).
| Scenario | p95 wall | user CPU | sys CPU | peak RSS |
|---|---|---|---|---|
Startup/floor |
538 µs → 537 µs | 280 µs → 280 µs | 147 µs → 154 µs | 12.2 MiB → 12.1 MiB |
Startup/version |
3.91 ms → 3.88 ms | 1.73 ms → 1.65 ms | 2.29 ms → 2.27 ms | 18.3 MiB → 18.3 MiB |
Track/daemon/pre |
4.19 ms → 4.17 ms | 1.88 ms → 1.85 ms | 2.44 ms → 2.49 ms | 19.1 MiB → 19.1 MiB |
Track/daemon/post |
4.18 ms → 4.20 ms | 1.86 ms → 1.85 ms | 2.45 ms → 2.42 ms | 18.9 MiB → 18.9 MiB |
Track/direct/pre |
4.14 ms → 4.13 ms | 1.88 ms → 1.85 ms | 2.39 ms → 2.38 ms | 19.1 MiB → 19.1 MiB |
Track/direct/post |
7.83 ms → 7.77 ms | 5.07 ms → 5.01 ms | 3.30 ms → 3.35 ms | 21.3 MiB → 21.2 MiB |
Track/direct/post-sync |
9.61 ms → 9.49 ms (-1.24%) | 6.63 ms → 6.54 ms | 4.44 ms → 4.43 ms | 23.4 MiB → 23.5 MiB |
benchstat
goos: linux
goarch: amd64
pkg: github.com/malamtime/cli/perf
cpu: AMD EPYC 7763 64-Core Processor
│ base │ head │
│ sec/op │ sec/op vs base │
Startup/floor-4 481.3µ ± 3% 478.2µ ± 4% ~ (p=0.579 n=10)
Startup/version-4 3.581m ± 2% 3.526m ± 3% ~ (p=0.631 n=10)
Track/daemon/pre-4 3.833m ± 2% 3.827m ± 3% ~ (p=0.853 n=10)
Track/daemon/post-4 3.835m ± 2% 3.809m ± 2% ~ (p=0.436 n=10)
Track/direct/pre-4 3.777m ± 2% 3.773m ± 3% ~ (p=0.684 n=10)
Track/direct/post-4 7.214m ± 1% 7.150m ± 1% ~ (p=0.190 n=10)
Track/direct/post-sync-4 8.735m ± 1% 8.604m ± 3% ~ (p=0.165 n=10)
geomean 3.468m 3.440m -0.79%
│ base │ head │
│ p50-sec/op │ p50-sec/op vs base │
Startup/floor-4 474.1µ ± 3% 467.6µ ± 3% ~ (p=0.436 n=10)
Startup/version-4 3.557m ± 3% 3.516m ± 2% ~ (p=0.684 n=10)
Track/daemon/pre-4 3.814m ± 3% 3.839m ± 2% ~ (p=0.796 n=10)
Track/daemon/post-4 3.815m ± 2% 3.768m ± 2% ~ (p=0.165 n=10)
Track/direct/pre-4 3.771m ± 2% 3.779m ± 2% ~ (p=0.912 n=10)
Track/direct/post-4 7.143m ± 2% 7.087m ± 1% ~ (p=0.123 n=10)
Track/direct/post-sync-4 8.744m ± 1% 8.582m ± 3% ~ (p=0.105 n=10)
geomean 3.447m 3.419m -0.80%
│ base │ head │
│ p95-sec/op │ p95-sec/op vs base │
Startup/floor-4 537.7µ ± 3% 537.3µ ± 4% ~ (p=0.912 n=10)
Startup/version-4 3.913m ± 1% 3.881m ± 2% ~ (p=0.631 n=10)
Track/daemon/pre-4 4.194m ± 1% 4.172m ± 3% ~ (p=0.739 n=10)
Track/daemon/post-4 4.182m ± 1% 4.196m ± 2% ~ (p=0.529 n=10)
Track/direct/pre-4 4.139m ± 2% 4.131m ± 1% ~ (p=0.631 n=10)
Track/direct/post-4 7.830m ± 2% 7.765m ± 1% ~ (p=0.075 n=10)
Track/direct/post-sync-4 9.611m ± 1% 9.493m ± 2% -1.24% (p=0.043 n=10)
geomean 3.802m 3.784m -0.48%
│ base │ head │
│ peak-rss-B │ peak-rss-B vs base │
Startup/floor-4 12.19Mi ± 2% 12.14Mi ± 16% ~ (p=0.796 n=10)
Startup/version-4 18.28Mi ± 1% 18.28Mi ± 1% ~ (p=0.912 n=10)
Track/daemon/pre-4 19.12Mi ± 1% 19.09Mi ± 1% ~ (p=0.579 n=10)
Track/daemon/post-4 18.92Mi ± 1% 18.90Mi ± 1% ~ (p=0.971 n=10)
Track/direct/pre-4 19.08Mi ± 0% 19.08Mi ± 1% ~ (p=0.853 n=10)
Track/direct/post-4 21.29Mi ± 1% 21.23Mi ± 1% ~ (p=0.315 n=10)
Track/direct/post-sync-4 23.42Mi ± 0% 23.46Mi ± 0% ~ (p=0.218 n=10)
geomean 18.59Mi 18.57Mi -0.11%
│ base │ head │
│ sys-sec/op │ sys-sec/op vs base │
Startup/floor-4 147.1µ ± 13% 153.5µ ± 19% ~ (p=0.796 n=10)
Startup/version-4 2.293m ± 9% 2.275m ± 6% ~ (p=0.739 n=10)
Track/daemon/pre-4 2.441m ± 7% 2.493m ± 6% ~ (p=0.315 n=10)
Track/daemon/post-4 2.449m ± 5% 2.415m ± 5% ~ (p=0.631 n=10)
Track/direct/pre-4 2.393m ± 5% 2.383m ± 7% ~ (p=0.853 n=10)
Track/direct/post-4 3.304m ± 4% 3.345m ± 3% ~ (p=0.631 n=10)
Track/direct/post-sync-4 4.440m ± 3% 4.426m ± 5% ~ (p=0.579 n=10)
geomean 1.838m 1.850m +0.66%
│ base │ head │
│ user-sec/op │ user-sec/op vs base │
Startup/floor-4 280.5µ ± 6% 280.4µ ± 4% ~ (p=0.912 n=10)
Startup/version-4 1.728m ± 7% 1.654m ± 7% ~ (p=0.063 n=10)
Track/daemon/pre-4 1.885m ± 6% 1.847m ± 11% ~ (p=0.436 n=10)
Track/daemon/post-4 1.859m ± 3% 1.847m ± 5% ~ (p=0.393 n=10)
Track/direct/pre-4 1.879m ± 4% 1.853m ± 6% ~ (p=0.529 n=10)
Track/direct/post-4 5.068m ± 4% 5.009m ± 3% ~ (p=0.165 n=10)
Track/direct/post-sync-4 6.631m ± 2% 6.544m ± 3% ~ (p=0.436 n=10)
geomean 1.950m 1.920m -1.55%
Δ compares medians; ~ means no significant difference (Mann-Whitney U, p ≥ 0.05). A scenario is flagged when it is more than 10% and more than 250µs slower with p < 0.05. Startup/floor runs true, not shelltime: it is an A/A check of runner noise. Runner: linux/amd64, AMD EPYC 7763 64-Core Processor . go1.27.1, 10 rounds × 100 execs per scenario and binary.
Code reviewNo issues found. Checked for bugs and CLAUDE.md compliance. |
Why
The shell hooks run
shelltime trackin the foreground before and after every command, so its latency is felt at every prompt. That latency covers the whole process: exec, Go init of a large dependency tree,main's config read, then the track logic. Nothing measured it until now.What
perf/is a new, separate Go module. Keeping it separate meansgolang.org/x/perfnever affects version selection for the shipped binaries, and the root./..., mockery, codecov and goreleaser never see it.harness_test.go,track_bench_test.go):Execs the real binary once per iteration, with the exact flags the zsh hook passes, in an isolated
$HOME.Scenarios:
Startup/floortrue, as an A/A runner-noise checkStartup/versionshelltime --versionTrack/daemon/{pre,post}trackagainst a fake daemon on/tmp/shelltime.sockTrack/direct/pretrack -p=prewith no daemonTrack/direct/posttrack -p=postwith no daemon, over 500 seeded store pairsTrack/direct/post-syncflushCount, sending its batch to a fake APIEvery scenario checks that it took its intended path (daemon events, store growth, API batches, no errors in
log.log).trackalways exits 0, so without these checks a broken run would just look fast.Besides wall time, it reports user/sys CPU, p50/p95 and peak RSS.
The Track scenarios are skipped when a real daemon owns the socket.
cmd/perfreport:benchmath: medians with a 95% confidence interval, and a Mann-Whitney U test.::warningannotations, andregression=/skipped=step outputs.compare.sh:-trimpath -buildvcs=false -s -w).comment.shcreates or updates a single sticky PR comment throughgh api. No third-party action gets a write token..github/workflows/perf.yaml("Track Perf"):main, pushes tomain(compared against the previous tip) andworkflow_dispatch.Docs:
perf/README.md, plus short sections inCLAUDE.mdandAGENTS.md.Verification (local, Linux container)
go -C perf vet ./... && go -C perf test ./...pass.shellcheckandactionlintare clean.FORCE=1, 10×100): ✅ no significant change in any scenario. It took about 1m50s.time.Sleep(3ms)incommandTrack, not committed):regression=true.Startup/versionwas correctly not flagged./usr/bin/truefails every Track scenario with a clear message.This PR only adds the harness, so its own run is effectively a forced A/A check on CI runners.
🤖 Generated with Claude Code
https://claude.ai/code/session_01QuSfoWGrqsxjw5Yyegzzyt
Generated by Claude Code