Skip to content

Commit 88acca6

Browse files
kriszypclaude
andcommitted
test(stress): fix throughput-floor gate, throttle scan contamination, harden metrics
Applies review findings from PR #617: - largeCatchup: the grace-adjusted deadline let a converged run post a measured rate below ENFORCED_FLOOR_MBPS and still pass, since the gate checked convergedAt !== null rather than the achieved rate itself. Gate on catchupMBps >= ENFORCED_FLOOR_MBPS directly, which also covers an outright timeout without a separate check. - largeCatchup: the exact_count convergence poll forces a full value scan of B's table every 5s, and that scan grows with B's row count and competes with the replication replay it's trying to measure. Widen the poll interval (HARPER_STRESS_LARGE_CATCHUP_POLL_SECS, default 15s) to reduce how often the benchmark scans itself. - stressShared: writeStressMetrics's fixed path can be read as fresh data after a crash that happens before it's called, on a self-hosted runner that reuses its workspace across runs. Add clearStressMetrics(), called at suite start, so an early failure uploads nothing rather than a stale prior run. - stressShared: sampleHostCounters().window() pushed its on-demand reading into the same samples array the timer fills on a fixed cadence; two entries landing milliseconds apart produce a manufactured peak rate when summariseHostSamples() walks them pairwise. Stop pushing from window(). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
1 parent 12ec14a commit 88acca6

2 files changed

Lines changed: 48 additions & 8 deletions

File tree

integrationTests/stress/largeCatchup.test.mjs

Lines changed: 21 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ import {
5656
summariseHostSamples,
5757
formatHostCounters,
5858
writeStressMetrics,
59+
clearStressMetrics,
5960
writeJobSummary,
6061
fabricRocksConfig,
6162
mb,
@@ -119,6 +120,13 @@ if (!stressEnabled()) {
119120
// worker is blocked inside a RocksDB write stall — see harper-pro#603), so only a genuine
120121
// wedge trips it.
121122
const STALL_SECS = Number(process.env.HARPER_STRESS_LARGE_STALL_SECS ?? 300);
123+
// The convergence poll's exact_count forces a full value scan of B's table (see the
124+
// comment at the poll site), and that scan grows with B's row count and competes with
125+
// replication replay for the same RocksDB I/O/CPU it's trying to measure — a 5s cadence
126+
// means dozens of full-table scans self-contaminate the very throughput being gated.
127+
// Widening the interval cuts scan overhead roughly proportionally; STALL_SECS (300s) and
128+
// the metrics/log cadence stay coarse-poll-friendly at this interval.
129+
const CATCHUP_POLL_SECS = Number(process.env.HARPER_STRESS_LARGE_CATCHUP_POLL_SECS ?? 15);
122130
// Generous write budget: 5 min per GB plus 10 min fixed overhead.
123131
const WRITE_BUDGET_SECS = TARGET_GB * 300 + 600;
124132
const SUITE_TIMEOUT_MS = (WRITE_BUDGET_SECS + CATCHUP_BUDGET_SECS + 600) * 1000;
@@ -130,6 +138,7 @@ if (!stressEnabled()) {
130138

131139
suite(`Large catch-up — ${TARGET_GB} GB`, { timeout: SUITE_TIMEOUT_MS }, (ctx) => {
132140
before(async () => {
141+
clearStressMetrics('large-catchup');
133142
const rocks = fabricRocksConfig();
134143
// Catch-up throughput is gated by the WriteBufferManager budget: once B's memtables
135144
// exhaust it, RocksDB stalls writers and replay collapses (see harper-pro#603). Log the
@@ -357,7 +366,7 @@ if (!stressEnabled()) {
357366
`[large-catchup] catchup poll: B=${lastCount}/${targetCount} (${remaining}s remaining, ` +
358367
`stalled ${stalledFor.toFixed(0)}s) ${formatHostCounters(hostSampler.window())}`
359368
);
360-
await delay(5_000);
369+
await delay(CATCHUP_POLL_SECS * 1000);
361370
}
362371

363372
const aSummary = summariseSamples(aSampler.stop());
@@ -444,13 +453,19 @@ if (!stressEnabled()) {
444453
const uncaughtRe = /\[error\]: uncaughtException/g;
445454
const [logA, logB] = await Promise.all([readLog(A), readLog(B)]);
446455

447-
// Missing the deadline means the run averaged below CATCHUP_FLOOR_MBPS, because the
448-
// deadline is derived from that floor — so this reads as a throughput regression, not
449-
// as "the clock ran out". Ordinary slow-mode nights (~5 MB/s at 10 GB) stay green.
456+
// Gate on the measured rate itself, not on "did it converge before the deadline".
457+
// The deadline is grace-padded (CATCHUP_GRACE_SECS added on top of the floor-implied
458+
// time) so B has room to reconnect before the first batch lands, but a run that
459+
// consumes that whole padded window to converge posts a catchupMBps below
460+
// ENFORCED_FLOOR_MBPS despite convergedAt being non-null — convergedAt!==null alone
461+
// let that pass. Checking the rate directly closes that gap and still fails an
462+
// outright timeout for free (partial progress over the full budget is always < the
463+
// rate needed to finish it).
450464
ok(
451-
convergedAt !== null,
465+
catchupMBps >= ENFORCED_FLOOR_MBPS,
452466
`B averaged ${catchupMBps.toFixed(1)} MB/s, under the ${ENFORCED_FLOOR_MBPS.toFixed(1)} MB/s catch-up floor ` +
453-
`(${appliedRecords}/${targetCount - seedRecords.length} records in ${CATCHUP_BUDGET_SECS}s) — ` +
467+
`(${appliedRecords}/${targetCount - seedRecords.length} records in ${catchupSecs.toFixed(1)}s` +
468+
`${convergedAt ? '' : ', TIMED OUT'}) — ` +
454469
`slow replay, not a wedge; a wedge would have tripped the ${STALL_SECS}s no-progress guard. ` +
455470
`Host during catch-up: ${formatHostCounters(hostSummary)}`
456471
);

integrationTests/stress/stressShared.mjs

Lines changed: 27 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@
99

1010
import { equal } from 'node:assert';
1111
import { readFile } from 'node:fs/promises';
12-
import { appendFileSync, mkdirSync, readFileSync, writeFileSync } from 'node:fs';
12+
import { appendFileSync, mkdirSync, readFileSync, rmSync, writeFileSync } from 'node:fs';
1313
import { join } from 'node:path';
1414
import { setTimeout as delay } from 'node:timers/promises';
1515

@@ -145,6 +145,13 @@ export function hostCounterDelta(before, after) {
145145
* Harper node — it reads /proc directly — so it keeps running across node
146146
* restarts. `window()` returns the rates since the previous window() call (or
147147
* since start), which is what a poll loop wants to print alongside its progress.
148+
*
149+
* `window()` reads its own on-demand sample rather than pushing into `samples` —
150+
* `samples` is the timer's uniformly-spaced series that summariseHostSamples()
151+
* walks pairwise to find peaks; interleaving an on-demand reading (called from a
152+
* poll loop running close to, but not synchronized with, the same interval) can
153+
* land two entries milliseconds apart, and dividing a real counter delta by that
154+
* near-zero elapsed time manufactures a spurious peak rate.
148155
*/
149156
export function sampleHostCounters(opts = {}) {
150157
const interval = opts.intervalMs ?? 5000;
@@ -162,7 +169,6 @@ export function sampleHostCounters(opts = {}) {
162169
window() {
163170
const now = readHostCounters();
164171
if (!now) return null;
165-
samples.push(now);
166172
const delta = hostCounterDelta(windowStart, now);
167173
windowStart = now;
168174
return delta;
@@ -243,6 +249,25 @@ export function writeStressMetrics(name, metrics) {
243249
}
244250
}
245251

252+
/**
253+
* Remove any previously-written metrics file for `name` before a run starts. Self-hosted
254+
* runners reuse the same workspace across runs (unlike ephemeral GH-hosted ones), so the
255+
* fixed path in writeStressMetrics() persists between them: a run that crashes before
256+
* reaching writeStressMetrics — e.g. during setup, or an early OOM/wedge — would otherwise
257+
* leave the *previous* run's metrics file in place, and CI uploads it as if it were this
258+
* run's data. Call this at the start of a suite so an early failure uploads no file rather
259+
* than a stale one that reads as a fresh success.
260+
*/
261+
export function clearStressMetrics(name) {
262+
const dir = process.env.HARPER_INTEGRATION_TEST_LOG_DIR;
263+
if (!dir) return;
264+
try {
265+
rmSync(join(dir, `${name}-metrics.json`), { force: true });
266+
} catch {
267+
// Best effort — a failure here must never fail the test.
268+
}
269+
}
270+
246271
/** Append a markdown block to the GitHub Actions job summary, when running under one. */
247272
export function writeJobSummary(markdown) {
248273
const path = process.env.GITHUB_STEP_SUMMARY;

0 commit comments

Comments
 (0)