mirror of
https://github.com/rcourtman/Pulse.git
synced 2026-10-25 13:10:03 +00:00
fix: measure workload chart generation in performance guards
The chart benchmark warmed its response cache and then timed a fresh payload-retaining recorder. That hid store-backed work behind test buffer allocation and made the regression signal ambiguous. Measure cached handler work, fresh-service computation and real loopback HTTP transfer separately. Wait for store startup maintenance, preserve the original failed comparison and record the paired diagnostic limits. Make the adjacent SLO exercise uncached chart generation at its existing budget. Refs #3052
This commit is contained in:
rcourtman
+154
@@ -0,0 +1,154 @@
|
||||
# Workload chart benchmark reliability, 18 October 2026
|
||||
|
||||
Scope: the optional chart benchmark failure in #3052 and the measurement
|
||||
contract for `BenchmarkHandleWorkloadCharts_StoreBacked`. The owning residual
|
||||
remains `performance-post-rc-headroom` in L10. This investigation does not close
|
||||
that residual or change release qualification.
|
||||
|
||||
## Original evidence
|
||||
|
||||
[Build and Test 39135315179, Benchmarks job 117698772365](https://github.com/rcourtman/Pulse/actions/runs/39135315179/job/117698772365)
|
||||
failed the significant-regression threshold for
|
||||
`HandleWorkloadCharts_StoreBacked/range=4h-4`:
|
||||
|
||||
| Measurement | Baseline | Candidate | Comparison |
|
||||
| --- | --- | --- | --- |
|
||||
| Time per operation | 333.0 µs ±16% | 375.3 µs ±13% | +12.72%, p=0.043, n=10 |
|
||||
| Bytes per operation | 1.577 MiB | 1.577 MiB | unchanged |
|
||||
| Allocations per operation | 25.50 | 25.50 | unchanged |
|
||||
|
||||
The failure threshold was greater than 10% with p less than 0.05. Collection
|
||||
used alternating paired 100 ms samples with Go 1.26.9 on Linux amd64, an AMD
|
||||
EPYC 7763 runner and the runtime-default GOMAXPROCS setting (benchmark suffix
|
||||
`-4`). These identities come from the retained run metadata, including the
|
||||
synthetic merge used by the PR checkout:
|
||||
|
||||
| Identity | Baseline | Candidate |
|
||||
| --- | --- | --- |
|
||||
| Commit | `98817ebce4e02545ca8870519ae929cee9c724c8` | `2ff11395ed9a08cbd4c38134d3645330aaade109` |
|
||||
| Committed tree | `6599a0d8b8296f1ca91ddcf156ba1445e48a1d82` | `3d7d273e14f4d7c045cd35a16d2095c6da8eafa8` |
|
||||
| Executable SHA-256 | `978566737d0a53c6a64fe42fdf482ed694483a1fbc60fbf869837f912bfa6d36` | `e3562eda32a9662df28a5e5cc6725dcab13b775e7b02a3c182d96a3face67868` |
|
||||
|
||||
The candidate tree equals the PR head and landed merge tree. Original
|
||||
executables were not retained. A prior 20-sample focused reconstruction on
|
||||
`pulse-dev` gave the opposite direction, 692.6 µs versus 575.0 µs
|
||||
(-16.97%, p=0.020), with different executable hashes and a loaded host.
|
||||
That diagnostic did not reproduce or clear the original result. An unchanged
|
||||
benchmark body also does not prove equivalent executable timing.
|
||||
|
||||
## Confirmed benchmark defect and correction
|
||||
|
||||
The fixture seeds 84,000 points for 70 workloads, then makes a sanity request
|
||||
that fills the short-lived response cache. The legacy timed loop mostly served
|
||||
that cached response into a fresh `httptest.ResponseRecorder`. It allocated a
|
||||
second copy of roughly 1.6 MiB on each iteration and did not reliably exercise
|
||||
the store-backed query it claimed to protect.
|
||||
|
||||
A 5,000-iteration profile of the reconstructed candidate measured 363,878 ns/op,
|
||||
1,653,504 B/op and 25 allocs/op. `bytes.growSlice`, reached through
|
||||
`ResponseRecorder.Write`, accounted for 7,874.91 MiB of 8,022.89 MiB allocated
|
||||
(98.16%). The CPU profile also contains untimed fixture seeding, so its global
|
||||
SQLite and GC percentages are not handler-only attribution.
|
||||
|
||||
The benchmark now separates three boundaries:
|
||||
|
||||
- `warm-handler` reuses a request and a counting writer without retaining the
|
||||
response body. It measures handler work under the production cache policy.
|
||||
- `cold-service` constructs a fresh router and chart service per request. It
|
||||
includes construction, store-backed reads and serialization with an empty
|
||||
response cache. SQLite and OS caches are not cleared.
|
||||
- `http-transfer` warms a loopback connection, then reads and closes every full
|
||||
response. It includes client, server and loopback transport costs.
|
||||
|
||||
The shared metrics-store fixture also waits for queued startup maintenance,
|
||||
matching the existing SLO harness boundary. All cases retain the seeded
|
||||
payload sanity checks. The adjacent `TestSLO_WorkloadCharts` had the same
|
||||
cache-warming blind spot. It now constructs a fresh router and chart service
|
||||
for each sample, retaining its existing 90 ms local and 550 ms hosted budgets.
|
||||
No runtime endpoint, cache policy, query, schema,
|
||||
retention or rendered behavior changed. The runtime already writes the
|
||||
immutable cached payload directly, so adding another cache or changing its
|
||||
semantics would not address the confirmed recorder allocation.
|
||||
|
||||
## Final verification
|
||||
|
||||
A diagnostic applied the same revised router benchmark to both exact recorded
|
||||
runtime trees and compiled fixed executables with Go 1.26.9. It warmed both,
|
||||
then alternated execution order for 20 paired 100 ms samples with `-cpu=4`
|
||||
and no affinity. It used Linux amd64 on the shared 8-CPU Ryzen 5 3600 worker.
|
||||
Initial load was 2.92/3.55/3.85 with 16% guest CPU in the final initial vmstat
|
||||
sample. At the last pair, load was 5.18/5.11/4.54 with 13% guest CPU. This was
|
||||
not an idle-host proof.
|
||||
|
||||
| Case | Baseline | Candidate | Comparison |
|
||||
| --- | --- | --- | --- |
|
||||
| warm-handler | 1.348 µs ±6% | 1.331 µs ±8% | no significant change, p=0.779 |
|
||||
| cold-service | 153.7 ms ±6% | 152.2 ms ±10% | no significant change, p=0.925 |
|
||||
| http-transfer | 606.0 µs ±11% | 619.8 µs ±9% | no significant change, p=0.883 |
|
||||
|
||||
The comparison's router harness SHA-256 was
|
||||
`a7ce0422aae85d5a9fc5076d987bd548cf922ddb300388bc748fc1c0efaa6496`.
|
||||
Its fixed executables were:
|
||||
|
||||
- Baseline: `6afeb3965503d218f83c12581545acf1c51a0a291c93d6eff9ff0a260e2e23a1`.
|
||||
- Candidate: `c8905f56c8ae80400a619a7318f56b21ea883d3ebc62be50a9e9f0c090d800e6`.
|
||||
|
||||
That comparison predates the final test-client timeout correction, actual
|
||||
transfer-byte accounting and SLO sample correction. Its source overlays and executable identities remain
|
||||
explicit. It is a diagnostic of the revised boundaries, not qualification
|
||||
of the final test sources. The race smoke first stopped on a missing ignored
|
||||
CI embed fixture. With that supplied, cold generation under race instrumentation
|
||||
took 5.96 seconds and the HTTP warmup exceeded the fixture's five-second client
|
||||
timeout. The test client now has a bounded 30-second allowance. This changes
|
||||
neither a production timeout nor the SLO budgets.
|
||||
|
||||
The corrected SLO ran on the shared worker with its final test source hash
|
||||
`aecd6d939d1b2f2b767d28f6b9ae49917a58dbc748141fba4fa62886eda8bac5`.
|
||||
It measured p50 175.081 ms, p95 215.634 ms and p99 234.951 ms. All requests
|
||||
completed, but the existing shared-host policy skipped the 90 ms local budget
|
||||
assertion. This is not a strict latency pass. Initial load was 2.40/3.09/4.04,
|
||||
and final load was 2.64/3.09/3.89. The non-race Release Dry Run enforces the
|
||||
unchanged 550 ms hosted envelope. Build and Test uses race-enabled API shards,
|
||||
which intentionally skip latency SLOs. Required source checks therefore do not
|
||||
establish a strict latency pass. This source-only investigation does not run
|
||||
or claim release qualification.
|
||||
|
||||
The next race smoke passed all three cases. A final throughput-accounting edit
|
||||
overlapped its initial metadata capture, so that run is retained as diagnostic
|
||||
evidence only. The final race proof uses frozen sources, a retained executable,
|
||||
and source hash checks before compilation and after execution.
|
||||
|
||||
The frozen-source race smoke passed all three cases. Both source hashes
|
||||
matched before and after execution. The router benchmark hash is
|
||||
`7b3dd99ffb24c621252193545b024edb3dd70a93c8c056b5da644784d6112ddd`,
|
||||
and the SLO hash is the one recorded above. The retained race executable has
|
||||
SHA-256 `b960e7386b84074ed1dc97188681359b1d0d684577af914c6d911a998c0d7800`.
|
||||
Collection ran from 16:16:45 to 16:17:50 UTC. Host load rose from
|
||||
8.75/5.95/4.46 to 11.55/7.14/4.96, with 18% guest CPU in the final initial
|
||||
vmstat sample. Race timings are not production latency evidence.
|
||||
|
||||
## Interpretation and retained evidence
|
||||
|
||||
The revised names intentionally start new benchmark series. A PR comparison
|
||||
against the old harness has no matching chart names and cannot establish a
|
||||
chart improvement. The controlled overlay comparison uses the same revised
|
||||
harness on both recorded runtime trees. It measures those boundaries with the
|
||||
new harness and does not recreate the original executable bytes or runner.
|
||||
|
||||
The original +12.72% remains an unresolved historical benchmark observation.
|
||||
The confirmed measurement and coverage defects are corrected. There is no
|
||||
validated chart-runtime regression or product speedup from this investigation.
|
||||
L10 remains partial with a bounded residual under the existing follow-up.
|
||||
|
||||
Worker evidence is retained under
|
||||
`/opt/pulse-release-worker/task-proofs/chart-benchmark-investigation-20261018`:
|
||||
`profile-metadata.txt`, `profile.log`, CPU and allocation profiles and summaries,
|
||||
`paired/` for the initial revised-harness diagnostic, `paired-final/` for the
|
||||
identical-harness comparison, `race.log` for the retained fixture failure,
|
||||
and `race-final.log`, `slo-local.log` and `final-checks-metadata.txt` for the
|
||||
SLO and diagnostic race checks. `bound-source.sha256`, `race-bound.log`,
|
||||
`race-bound-metadata.txt` and `race-final.test` bind the final race proof to its
|
||||
source and executable bytes. The original reconstructed
|
||||
executables and first focused repeat remain under the previous notification
|
||||
investigation's `chart-benchmark/` evidence directory. Each reconstructed
|
||||
executable has its own hash. None is represented as the original CI binary.
|
||||
@@ -1757,10 +1757,22 @@ dashboard-specific overview, trend, or summary transport.
|
||||
modules remain lazy for the same phone-startup reason.
|
||||
The same protected hot path now also owns proof harness steadiness.
|
||||
Store-backed chart SLO and benchmark helpers in `pkg/metrics/store_slo_test.go`,
|
||||
`internal/api/slo_bench_test.go`, and `internal/monitoring/monitor_metrics_slo_test.go`
|
||||
must wait for deferred metrics-store startup maintenance to quiesce before
|
||||
timing steady-state reads, so one-time retention or auto-vacuum cleanup does
|
||||
not masquerade as summary-route or chart-batch regression latency.
|
||||
`internal/api/router_bench_test.go`, `internal/api/slo_bench_test.go`, and
|
||||
`internal/monitoring/monitor_metrics_slo_test.go` must wait for deferred
|
||||
metrics-store startup maintenance to quiesce before timing steady-state
|
||||
reads, so one-time retention or auto-vacuum cleanup does not masquerade as
|
||||
summary-route or chart-batch regression latency.
|
||||
`BenchmarkHandleWorkloadCharts_StoreBacked` separates cached handler work
|
||||
through a counting writer, fresh-service store-backed computation, and a
|
||||
fully drained loopback HTTP exchange. Keep those measurement boundaries
|
||||
explicit. A payload-retaining test recorder must not stand in for cached
|
||||
handler cost, and warm response-cache hits must not stand in for query
|
||||
latency. Fresh services do not clear SQLite or OS caches. Preserve old
|
||||
failed comparisons across harness changes and establish new baselines
|
||||
rather than claiming that renamed cases prove a runtime speedup.
|
||||
`TestSLO_WorkloadCharts` must similarly use a fresh service per timed
|
||||
sample so its existing query-latency budgets cannot be satisfied solely
|
||||
by a response-cache hit after the sanity request.
|
||||
31. Keep the retired dashboard overview route absent from the protected hot
|
||||
path. `frontend-modern/src/pages/Dashboard.tsx`,
|
||||
`frontend-modern/src/hooks/useDashboardOverview.ts`, and
|
||||
@@ -3997,8 +4009,13 @@ system `go version` outside the repository reports 1.26.5 but the module's
|
||||
toolchain directive selected 1.26.8 for compilation. Neither worker run
|
||||
reproduced the CI magnitude or establishes an improvement. Keep the signal
|
||||
open as an environment-bound observation under the existing
|
||||
`performance-post-rc-headroom` follow-up; no chart-path code change is
|
||||
justified by this comparison alone.
|
||||
`performance-post-rc-headroom` follow-up. The later #3052 legacy-recorder
|
||||
signal has the same unresolved historical status. Its investigation identified
|
||||
response-buffer allocation and absent cold-service coverage in the benchmark.
|
||||
The corrected measurement boundaries are defined above and in
|
||||
`scripts/BENCHMARK_EVIDENCE.md`. `docs/release-control/v6/internal/records/workload-chart-benchmark-reliability-2026-10-18.md`
|
||||
retains the original comparison and the controlled diagnostic evidence. Neither legacy
|
||||
signal alone justifies a chart-runtime change.
|
||||
|
||||
### Shared drawer History window calculation
|
||||
|
||||
|
||||
@@ -3,6 +3,7 @@ package api
|
||||
import (
|
||||
"encoding/json"
|
||||
"fmt"
|
||||
"io"
|
||||
"net/http"
|
||||
"net/http/httptest"
|
||||
"path/filepath"
|
||||
@@ -50,6 +51,9 @@ func newBenchMetricsStore(b *testing.B) *metrics.Store {
|
||||
b.Fatalf("NewStore: %v", err)
|
||||
}
|
||||
b.Cleanup(func() { store.Close() })
|
||||
if err := store.WaitForMaintenance(5 * time.Second); err != nil {
|
||||
b.Fatalf("WaitForMaintenance: %v", err)
|
||||
}
|
||||
return store
|
||||
}
|
||||
|
||||
@@ -289,9 +293,10 @@ func BenchmarkHandleMetricsHistory_MemoryFallback(b *testing.B) {
|
||||
})
|
||||
}
|
||||
|
||||
// BenchmarkHandleWorkloadCharts_StoreBacked measures the workloads charts
|
||||
// endpoint under a store-backed 4h range. This is the workloads summary
|
||||
// sparkline hot path and should avoid per-workload N+1 queries.
|
||||
// BenchmarkHandleWorkloadCharts_StoreBacked separates warmed handler work,
|
||||
// fresh service computation, and real HTTP response transfer. A recorder that
|
||||
// retains the full response would measure its large buffer allocation instead
|
||||
// of the warmed handler. The cold case must still exercise store-backed reads.
|
||||
func BenchmarkHandleWorkloadCharts_StoreBacked(b *testing.B) {
|
||||
suppressBenchLogs(b)
|
||||
|
||||
@@ -443,17 +448,92 @@ func BenchmarkHandleWorkloadCharts_StoreBacked(b *testing.B) {
|
||||
// Go calls a benchmark function again for every b.N it tries, and seeding
|
||||
// 84,000 points costs far more than the measured request. A parent with a
|
||||
// sub-benchmark runs once, so the store is seeded once per run.
|
||||
b.Run("range=4h", func(b *testing.B) {
|
||||
b.Run("range=4h/warm-handler", func(b *testing.B) {
|
||||
// net/http supplies the request and writer to the handler. Reuse those
|
||||
// inputs here without accumulating a copy of the cached JSON body.
|
||||
writer := &benchmarkChartWriter{header: make(http.Header)}
|
||||
b.ReportAllocs()
|
||||
b.ResetTimer()
|
||||
for i := 0; i < b.N; i++ {
|
||||
req := httptest.NewRequest(http.MethodGet, url, nil)
|
||||
rec := httptest.NewRecorder()
|
||||
router.handleWorkloadCharts(rec, req)
|
||||
if rec.Code != http.StatusOK {
|
||||
b.Fatalf("unexpected status %d", rec.Code)
|
||||
writer.reset()
|
||||
router.handleWorkloadCharts(writer, req)
|
||||
if writer.status != http.StatusOK || writer.bytes == 0 {
|
||||
b.Fatalf("unexpected response: status=%d bytes=%d", writer.status, writer.bytes)
|
||||
}
|
||||
}
|
||||
})
|
||||
b.Run("range=4h/cold-service", func(b *testing.B) {
|
||||
writer := &benchmarkChartWriter{header: make(http.Header)}
|
||||
b.ReportAllocs()
|
||||
b.ResetTimer()
|
||||
for i := 0; i < b.N; i++ {
|
||||
writer.reset()
|
||||
// A fresh service has no response cache or singleflight result.
|
||||
// Include its construction rather than adding cache-reset hooks to
|
||||
// production code or manufacturing query-string variants.
|
||||
cold := &Router{monitor: monitor}
|
||||
cold.handleWorkloadCharts(writer, req)
|
||||
if writer.status != http.StatusOK || writer.bytes == 0 {
|
||||
b.Fatalf("unexpected cold response: status=%d bytes=%d", writer.status, writer.bytes)
|
||||
}
|
||||
}
|
||||
})
|
||||
b.Run("range=4h/http-transfer", func(b *testing.B) {
|
||||
server := httptest.NewServer(http.HandlerFunc(router.handleWorkloadCharts))
|
||||
b.Cleanup(server.Close)
|
||||
client := server.Client()
|
||||
// This bounds fixture failures, not endpoint latency. Race-instrumented
|
||||
// cold cache warmup can take seconds before timed transfer begins.
|
||||
client.Timeout = 30 * time.Second
|
||||
b.Cleanup(client.CloseIdleConnections)
|
||||
requestURL := server.URL + url
|
||||
read := func() int64 {
|
||||
response, err := client.Get(requestURL)
|
||||
if err != nil {
|
||||
b.Fatal(err)
|
||||
}
|
||||
n, readErr := io.Copy(io.Discard, response.Body)
|
||||
closeErr := response.Body.Close()
|
||||
if response.StatusCode != http.StatusOK || n == 0 || readErr != nil || closeErr != nil {
|
||||
b.Fatalf("unexpected HTTP response: status=%d bytes=%d read=%v close=%v", response.StatusCode, n, readErr, closeErr)
|
||||
}
|
||||
return n
|
||||
}
|
||||
read() // Warm the connection and response caches outside the timer.
|
||||
b.ReportAllocs()
|
||||
b.ResetTimer()
|
||||
var transferred int64
|
||||
for i := 0; i < b.N; i++ {
|
||||
transferred += read()
|
||||
}
|
||||
b.StopTimer()
|
||||
b.SetBytes(transferred / int64(b.N))
|
||||
})
|
||||
}
|
||||
|
||||
// benchmarkChartWriter observes handler status and bytes without retaining a
|
||||
// payload-sized test buffer. HTTP transfer is measured separately above.
|
||||
type benchmarkChartWriter struct {
|
||||
header http.Header
|
||||
status int
|
||||
bytes int
|
||||
}
|
||||
|
||||
func (w *benchmarkChartWriter) Header() http.Header { return w.header }
|
||||
func (w *benchmarkChartWriter) WriteHeader(status int) {
|
||||
if w.status == 0 {
|
||||
w.status = status
|
||||
}
|
||||
}
|
||||
func (w *benchmarkChartWriter) Write(payload []byte) (int, error) {
|
||||
w.WriteHeader(http.StatusOK)
|
||||
w.bytes += len(payload)
|
||||
return len(payload), nil
|
||||
}
|
||||
func (w *benchmarkChartWriter) reset() {
|
||||
clear(w.header)
|
||||
w.status = 0
|
||||
w.bytes = 0
|
||||
}
|
||||
|
||||
// BenchmarkHandleMetricsStoreStats measures latency of the /api/metrics-store/stats
|
||||
|
||||
@@ -622,7 +622,11 @@ func TestSLO_WorkloadCharts(t *testing.T) {
|
||||
latencies := measureEndpointLatencies(t, func() {
|
||||
req := httptest.NewRequest(http.MethodGet, url, nil)
|
||||
rec := httptest.NewRecorder()
|
||||
router.handleWorkloadCharts(rec, req)
|
||||
// Each sample must compute the store-backed response. The sanity
|
||||
// request above warms router's payload cache and would otherwise turn
|
||||
// this query-latency guard into a cached response-copy measurement.
|
||||
cold := &Router{monitor: monitor}
|
||||
cold.handleWorkloadCharts(rec, req)
|
||||
if rec.Code != http.StatusOK {
|
||||
t.Fatalf("unexpected status %d", rec.Code)
|
||||
}
|
||||
|
||||
@@ -62,3 +62,37 @@ Keep untimed work per iteration in proportion to timed work. Setup between
|
||||
with all of that setup. `BenchmarkRegistryProjectionSnapshot`'s empty cold cases
|
||||
took 16 s per sample at a 100 ms benchtime that way and pushed paired runs past
|
||||
their timeout.
|
||||
|
||||
The workload-chart benchmark has three distinct measurement boundaries under
|
||||
`HandleWorkloadCharts_StoreBacked/range=4h`:
|
||||
|
||||
- `warm-handler` reuses a request and a counting response writer. It measures
|
||||
cached handler work without retaining another copy of the response body.
|
||||
It does not measure HTTP transfer or provide a throughput number.
|
||||
- `cold-service` creates a fresh router and chart service for every request.
|
||||
It includes construction, empty-response-cache computation, store-backed
|
||||
reads and serialization. SQLite and OS caches remain warm. It is not a
|
||||
cold-disk or process-startup measurement.
|
||||
- `http-transfer` uses a real loopback HTTP server and fully drains each body.
|
||||
It includes client, server and local transport costs. Connection and response
|
||||
caches are warmed before timing. Its throughput applies to that loopback
|
||||
exchange, not a deployed network.
|
||||
|
||||
All three share the same 70-workload fixture and payload sanity checks. The
|
||||
store fixture waits for queued startup maintenance before seeding and timing.
|
||||
`TestSLO_WorkloadCharts` also creates a fresh service for each timed sample,
|
||||
so its existing latency budgets cover chart generation rather than cached
|
||||
payload copies. It retains the separate sanity request and payload checks.
|
||||
The warm cases use the production cache lifetime, so a run longer than that
|
||||
lifetime also includes refreshes. Keep duration and cache policy visible when
|
||||
interpreting or comparing them.
|
||||
|
||||
These names replace the legacy `range=4h` case, whose timed work included a
|
||||
fresh `httptest.ResponseRecorder` and a payload-sized buffer allocation after
|
||||
warming the response cache. Their timings are not interchangeable. The first
|
||||
CI comparison across this test change has no matching chart-case names and
|
||||
establishes a new baseline. Retain the old failed comparison and use the same
|
||||
revised harness on both recorded runtime trees for diagnostic continuity.
|
||||
The original +12.72% signal from #3052 remains historical evidence, not a
|
||||
validated chart-runtime regression or a claimed speedup from this harness fix.
|
||||
See the scoped [investigation record](../docs/release-control/v6/internal/records/workload-chart-benchmark-reliability-2026-10-18.md).
|
||||
|
||||
Reference in New Issue
Block a user