Repository navigation
churn-close after loadgen#87: change ErrBudget 0.5 with the loadgen pin bump; lithium's churn-close becomes real churn; latency and teardown discontinuity #424
Description
goceleris/loadgen#87 is being fixed in goceleris/loadgen#90 (open). probatorium pins loadgen v1.4.13 (go.mod:8), so nothing changes until a loadgen release and a pin bump. Once that bump lands, churn-close numbers change on every server.
Order matters: the budget change below must not reach probatorium main after the pin bump. How that is enforced:
- The budget change is made in the same probatorium PR that re-pins loadgen to the release carrying fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90, so the new budget and the new client land in one merge and no commit on main has one without the other. That PR is prepared with the v1.6.0 apparatus re-pin.
- dependabot can still open a bump of its own. Its
all-go-depsgroup (.github/dependabot.yml: gomod,patterns: "*", minor and patch, daily) includesgithub.com/goceleris/loadgen, and it has bumped loadgen on its own before (911b586, "deps: bump github.com/goceleris/loadgen", 2026-06-29). No workflow at 6f5521c merges dependabot PRs (none of.github/workflows/*acts on them; the repository allows auto-merge, but only a person can turn it on for a PR), so such a PR waits for a review: the Main ruleset needs an approving review from the code owner before any merge (organization admins can bypass it). It can appear only after loadgen tags a release: dependabot takes its candidates fromgo list -m -versions, which lists tags only (dependabot-corego_modules/.../package_details_fetcher.rb:83; for loadgen today: v1.0.0 … v1.4.13, no pseudo-version), and loadgen tags only through its manual release workflow. Merging fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90 alone therefore opens no such PR. Do not merge a dependabot PR that movesgithub.com/goceleris/loadgenpast v1.4.13 as it is: close it, or add the budget change to it. - Nothing mechanical enforces this yet. The alternatives remain: merge the budget change on its own first (it costs nothing under v1.4.13, see §1), or add a dependabot
ignoreforgithub.com/goceleris/loadgenuntil this issue closes. Either one must land before loadgen tags the release carrying fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90, since the tag is what lets dependabot open its bump. Neither has been done; the loadgen PR does not edit probatorium.
Evidence: evidence/loadgen-apparatus-fix/close/ in the loadgen PR (round 2: r2/, round 3: r3/, round 4: r4/).
1. ErrBudget 0.5 must change before the pin bump, not after it
scenarios/static.go:226-246 gives churn-close ErrBudget: 0.5. Its comment says that means "failed dial attempts may not outnumber completed requests". The value was calibrated against the loadgen artifact:
- With loadgen ≤ v1.4.13, every successful close-mode request is followed by one counted EOF error, so errors/(errors+requests) is about 0.5 on every server that closes as asked. Every such cell is a coin flip around the budget.
- After the fix, the ratio is the genuine error rate. A budget of 0.5 would then publish a server that fails half its churn attempts as
ok.
Changing the budget first costs nothing under v1.4.13. Recount of docs ae6b949, per dataset (r2/impact/published-churn-close-all.txt):
- x86, every dataset: 42-44 of 45 churn-close cells are already
suspect, all with a delta of 100.000-100.006. The only zero-delta cells are lithium and ntex (plus adnfnbio-h1 in v1.5.5). They have 0 errors and stayokunder any budget. - arm64 20260829: 35
suspect, plus 10ok: 9 of them with a delta of about 100, and lithium. - A tighter budget under v1.4.13 therefore moves only those 9 coin-flip arm64 cells to
suspect, the more honest status.
Suggested: the default budget (0.05), or a churn-specific one set from the first post-fix run's genuine refused-dial rates. Also update the comment.
2. lithium's churn-close is keep-alive today; it becomes real churn
lithium never parses a Connection header (servers/lithium/third_party/lithium_http_server.hh has no match for it), so it ignores Connection: close. loadgen ≤ v1.4.13 then reused the connection and counted no error, so lithium's published churn-close cell is a keep-alive measurement. docs ae6b949, every dataset:
| dataset | lithium churn-close saturation_mode_rps |
its get-simple |
latency_at_slo["churn-close"] |
|---|---|---|---|
| x86 20260624 … 20260829 (8) | 458,510 – 481,817 | 882,751 – 1,012,442 | 419,983 – 424,669 in 3 datasets; 343,883 in v1.5.5 (1000 key only); absent in 4 |
| arm64 20260829 | 196,704 | 329,287 | 177,034 |
- Scale: about 2.9-3.1× the next server on x86 (h2o: 158,367 in v1.5.5, 152,191 in 20260829), and 6.7× on arm64 (drogon: 29,558).
- Status:
ok, with nosent_vs_handled_delta_pct(the key is omitted at 0). This row carries the only rated churn-close data in most x86 datasets. - ntex was the same in v1.5.5-v1.5.7: 455,577-462,757,
ok, no delta. Since v1.5.8 it honours close: about 130k,suspect.
After the bump, lithium gets one connection per request. Its saturation_mode_rps, latency_at_slo and rated_mode_p99_at_target_rps for churn-close fall from keep-alive values to churn values. This is not a lithium regression and should be marked as such.
No loadgen port ceiling. A server that keeps the connection open is reset by loadgen 50 ms after the response (SO_LINGER 0), so msa2-client keeps no TIME_WAIT for it. A FIN would put a TIME_WAIT on the loadgen host per request. With tcp_tw_reuse=1 and ports 1024-65535 (ansible/tasks/bench_tuning.yml:40-43), that caps new connections to one server ip:port at about 60k/s.
Measured on macOS, paced at 2,000 req/s for 1 s:
| client | TIME_WAIT on the loadgen host | TIME_WAIT on the server |
|---|---|---|
| loadgen round-1 code (73e86b8) | 1,736 (one per request) | 0 |
| loadgen round-2 code (c913657) | 0 | 0 |
lithium does keep about rate × 50 ms connections open (5,000 at 100k/s).
3. Every other server: which published fields change on churn-close
This applies to the 42-44 servers per dataset that close as asked.
sent_vs_handled_delta_pctis 100 × errors / requests (report/aggregate.go:294-296). It falls from about 100 to the genuine rate. At 0 the key is omitted (report/document.go:137-152).cell_statusesmoves fromsuspecttook, unless genuine errors exceed the budget (see 1). The check iscmd/runner/main.go:1394.- The rated sweep now runs. Suspect cells skip it (
cmd/runner/main.go:1244-1251). Solatency_at_slo["churn-close"]andrated_mode_p99_at_target_rps["churn-close"]appear for every server, and rated profiles get one churn-close sweep per server longer (budget/profiles.go:39-45). saturation_mode_rpschanges. Each success now costs a dial and a request. Before, it cost a request, a wasted write, an EOF read and a dial.loadgen_cpu_p95["churn-close"]changes. Each request now starts a goroutine with a read deadline, instead of a wasted write and an EOF read.connect_errors["churn-close"](omitted at 0) keeps its meaning: main also recorded one connect error per failed dial (mainh1client.go:230-237,:257-260), as fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90'sredialdoes. It was 0 in every dataset and should stay about 0.timeseries.json.gzfor churn-close: the per-seconderrorsfalls from aboutrpsto about 0, andp99_msnow includes the connect. The dashboard's over-time charts plot both (docssrc/dashboard/views/OverTime.tsx:69-70).histograms.json.gz(hdr_histogram_b64["churn-close"],report/document.go:173-175): the saturation histogram now includes the connect, like the percentiles.resources["churn-close"]: unchanged for a server that closes as asked (its connections end at its own close). For a server that ignoresConnection: close(lithium), each connection stays open about 50 ms before the client's reset, so itsfd_hwmrises by about rate × 0.05 s (5,000 at 100k/s; lithium's x86 20260829fd_hwmis 1,044).throughput_bpsscales with the success count. Its only published use isnetwork_bound(isNetworkBound,report/document.go:212), which cannot fire on churn-close's small body.- loadgen's Result gains
close_aborts(fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90, round 4): the done connections the client reset because the server's FIN had not come 50 ms after the response. It is in the runner's per-cellresultand is not published unless probatorium maps it. Expect aboutrequestsfor lithium and about 0 for a server that closes as asked.
Latency now includes the TCP connect, and with it any SYN retransmission. In saturation mode the dial used to sit in the failed attempt after each success, whose time was not recorded. In rated mode latency is measured from each request's intended send time (loadgen bench.go ratedWorker), so a failed attempt's dial, SYN retransmissions included, already delayed the following slots and reached part of their latency; that concerns only the cells with rated churn-close data (the 9 ok arm64 20260829 cells, lithium, and ntex in v1.5.5-v1.5.7). The churn-close latency series is not comparable across the bump.
- The connect inside a recorded success now includes the kernel's SYN retransmissions. When the SUT's accept queue is full, Linux drops the SYN (
tcp_conn_request,sk_acceptq_is_full), and the client resends it after 1 s, then 3 s. - The scenario says backlog overflow is part of what it measures (
scenarios/static.go:232-234). In saturation mode that second or more sat in the unrecorded failed attempt, so published saturation percentiles never showed it. - After the bump, a server with a small listen backlog can show a mode at 1 s or more. That mode sets its newly published
latency_at_sloandrated_mode_p99_at_target_rps. - Read such a tail as backlog drops, not as a server latency regression. loadgen's own 10/25 ms dial retry fires only on ECONNRESET (
dial.goisTransientDialRST), which Linux rarely returns here.
The teardown on the server changes too. Measured, paced at 2,000 req/s for 1 s against net/http:
| loadgen | TIME_WAIT on the server |
|---|---|
| main | 0 |
| fixed | 1,664 of 1,664 connections |
- Before: the server's FIN was followed by loadgen's next request written into the half-closed socket. The server kernel answered with an RST, and neither side kept a TIME_WAIT.
- After: the server closes first and keeps one TIME_WAIT per 4-tuple.
- The TIME_WAIT table does not overflow on the cluster. An earlier version of this issue said a server churning 100-150k connections/s fills
tcp_max_tw_buckets=200000013-20 s into a 90 s window. That was wrong:- The bench has one loadgen host (msa2-client, one source IP) and one SUT ip:port (
target_ip:8080). With ports 1024-65535 there are at most 64,512 distinct 4-tuples: 3.2% of the table. - Linux v6.8
connect()tries ports of one parity first (__inet_hash_connect). With no client-side TIME_WAIT, that pass always finds a free port, so the working set is about 32,256 ports. - At 100-150k connections/s each client port comes back every 0.2-0.65 s. So almost every new SYN lands on a server TIME_WAIT for the same 4-tuple. Linux recycles it:
tcp_timewait_state_processreturnsTCP_TW_SYNwhen the SYN's sequence number or timestamp is newer. Timestamps are on, and their offset is per host pair, so consecutive connections' timestamps increase. - The server's TIME_WAIT count levels off near that working set and never overflows.
r3/impact/tw-bound.pyhas the arithmetic;r3/impact/linux-v6.8-tw-excerpts.txthas the kernel code. - TIME_WAIT sockets are kernel-owned: no fd, and not in the SUT's RSS. So they do not change
resources.
- The bench has one loadgen host (msa2-client, one source IP) and one SUT ip:port (
- What is actually new: nearly every churn connection goes through SYN-on-TIME_WAIT acceptance. If that acceptance fails (a PAWS reject, counted in
TcpExtPAWSEstab), the TIME_WAIT answers with an ACK, and the client resends its SYN after at least 1 s. That second then lands inside a recorded success, like the backlog drop above. - A saturated SUT that closes more than 50 ms after its response gets a client RST instead of an orderly FIN exchange. No request is miscounted, because the response was already complete. But server-side teardown and reset counters then record client RSTs on healthy connections. The celeris reset investigations (epoll: PauseAccept silently drops connections already waiting in the accept queue — their requests get EOF (8/8, deterministic), and a promotion on a GitHub runner loses ~1/3 of 2048 connections celeris#662, adaptive ramp: the 'read: reset' losses are celeris#662's accept hand-over, not a hand-off — 14,554 of 14,554 never accepted; #674 is the fix celeris#686) read those counters.
4. Keep-alive H1 scenarios: small, error-bearing cells only
Where error counts go down. After a response with Connection: close, main wrote the next request into the closing connection, and that request failed with EOF. After a fault in the middle of a response (a truncated or reset body, a short status line, a body over MaxResponseSize), main left the dead or desynced connection in the slot, and the next request failed too, so one fault counted twice. Now the next request dials a fresh connection and succeeds, with the connect inside its latency.
Where error counts stay the same, but latency changes. A connection that fails before or while its status line or headers are read (an unannounced close while idle, goceleris/loadgen#94; a reset; headers cut off) cost main one error too, and main redialed inside that failed, unrecorded request (main h1client.go:245-263, :279-295), so the next request found a live connection. Now the next request dials, so one connect per such error moves into a recorded success's latency. On the LAN a connect takes tens of µs, against ms-scale driver latency.
The one exception to "error counts go down or stay":
- A write error on a connection the request itself just dialed is now returned with no retry. main retried every write failure once.
- So a request whose new connection is reset before the write is now an error with no latency sample, where main may have retried it into a recorded success.
- This is rare, since the write follows the connect by microseconds.
A keep-alive connection the server closes without notice (an idle timeout, or a max-requests limit without Connection: close) still fails the one request written into it. goceleris/loadgen#94 tracks a retry of idempotent methods. No published cell is known to hit it: rated passes run at a fraction of the saturation RPS.
In docs ae6b949, the only keep-alive H1 cells with loadgen errors are 15 driver-pg-write cells and one get-simple-1024c cell (celeris-iouring-auto+upg-async, arm64 20260829, 0.00035%, ok).
- Two driver-pg-write cells could move under the 0.05 default budget, but only if their errors were double-counted: gin-h2, arm64 20260829 (ratio 0.0845), and fiber-h1, x86 20260829 (0.0533).
- The
ok, rated driver-pg-write cells that carry errors are echo-h1 arm64 20260829 (0.028), stdhttp-hybrid arm64 20260829 (0.045), hertz-h1 x86 20260829 (0.032) and gin-h2 x86 20260829 (0.0011). Their saturation histogram,latency_at_sloandrated_mode_p99_at_target_rpsshift slightly if their errors are of the connection-level class above; nobody has identified that class yet.
To do here
- In the PR that re-pins loadgen to the release carrying fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90: change churn-close's
ErrBudgetand its comment, andTestErrorBudgets(scenarios/scenarios_test.go:168-188, which pins 0.5 at :171 and checks the v3.8 ratio against it at :187).mage_bench_skip_test.go:82quotes a recorded v3.8 status string and needs no change. Until then, do not merge a dependabot PR that moves loadgen past v1.4.13 as it is. - Mark the churn-close series discontinuity in the published docs, including the dashboard's over-time
errorsandp99_mscharts:- latency includes the connect and any SYN retransmission (a 1 s+ mode is backlog drops);
- the teardown changed;
- lithium's cell becomes churn.
- Check the first post-bump run:
- on lithium: churn-close
connect_errors; - on msa2-client:
ss -s, to confirm the loadgen host keeps no TIME_WAIT at cluster rates, andTcpExtTCPSynRetrans(nstat -az) for the SYN resends; - on msa2-server:
ss -tan state time-wait | wc -lduring a churn-close cell (expect ≤ 64,512, near 32k), plusTcpExtTCPTimeWaitOverflow(expect 0) andTcpExtPAWSEstab; - in the per-cell results:
close_aborts(aboutrequestson lithium, about 0 elsewhere), and any churn-close cell withrequests > 0andthroughput_bps == 0, which is a close-delimited body that loadgen reads as empty (h1client: the response framing parser leaves the connection at the wrong position for close-delimited bodies, HEAD/1xx/204/304, TE+CL, trailers and HTTP/1.0 loadgen#93), not a fast server.
- on lithium: churn-close
Activity
FumingPower3925 commentedon Sep 27, 2026
The same re-pin carries goceleris/loadgen#91 (the HTTP/2 client: #85 status, #86 body bytes, #88 no lifetime deadline, #89 redial of dead connections). Its effects on the 32 H2 cells per arch (
get-json-h2,post-4k-h2) are listed in the PR under "What changes in probatorium's published numbers". Like churn-close here, the H2 rows measure something different after the bump. Nothing in probatorium stops a before/after comparison yet.Where the comparison happens today (
6f5521c):BenchSince→diffBenchResults→report.DiffLatencyAtSLO(mage_bench.go:1575-1597,:2128;report/slo_gate.go:88) flattenslatency_at_sloof the baseline and current trees. It fails on any drop past the threshold, or on a baseline cell that is missing. It never readsloadgen_version.report/markdown.go:94,:752writeRegressionSection) diffs the same field by adapter and scenario, also without it.loadgen_versionis recorded only as run metadata:benchmark_config.loadgen_version(report/schema.go:463; the v1.5.8summary.jsonhas"loadgen_version": "v1.4.13"), andLoadgenVersionin the split index (report/split.go:98).Proposal: the regression gate and the report section compare only runs whose
benchmark_config.loadgen_versionis equal. When the versions differ, they either:churn-closefor fix(h1client): never reuse a connection that is closing, so -close stops counting one error per request (#87) loadgen#90,get-json-h2andpost-4k-h2for fix(h2client): real status and body bytes, no lifetime deadline, redial dead connections (#85, #86, #88, #89) loadgen#91), and exclude only those rows.A version check is two lines in
diffBenchResultsandwriteRegressionSection. It should land before or with the re-pin PR, so that the first post-bump run cannot fail the gate, or pass it, on a measurement change. The re-pin PR should also:scenarios/static.go:251-253, which says "32 TCP conns × default 100 concurrent streams". The runner setsWorkers = Connections(cmd/runner/main.go:1055), and loadgen multiplies HTTP/2 workers by 4 (bench.go:503), so each H2 cell runs 4 streams per connection, and MaxStreams 100 never binds.One scope note for the rated fields: the H2 rows are not in
RatedScenarios(budget/profiles.go:39-45). They carrylatency_at_sloandrated_mode_p99_at_target_rpsonly because BenchTier rates every clean cell (#418; the sweep atcmd/runner/main.go:1259has no scenario filter). Once #418 is fixed, the gate above sees no H2 rows at all, and their before/after difference shows only inhdr_histogram_b64and the timeseriesp99_ms.test(runner,scenarios): pin a raised error budget end to end; correct…
test(runner,scenarios): pin a raised error budget end to end; correct…
deps: re-pin loadgen v1.4.14, with churn-close on the default 5% erro…
FumingPower3925 commentedon Oct 2, 2026
First run after the bump (full bench 36441790519, loadgen v1.4.14): lithium is OOM-killed on churn-close and the column is lost on both arches
The kills. From the kernel journal in
cluster-forensics-36441790519-1/<host>/host-forensics.txt, a global OOM killed lithium 5 times per arch within about 40 s, at 2026-10-02 04:13:24-04:14:05Z. This was during churn-close, its first scenario.Lost cells.
dnf("server-down: pre-cell probe ... connection refused"), withempty_windowresources.Churn-close itself.
suspect, 623 rps, 3,978 errors (3,866 connect-class).okin both raw and merged documents, at 994 rps with 3,814 errors against 89,468 requests (under the 5% budget), although the server died during the cell. Its rated passes all failed with connection refused (0 kept).okwhen its SUT died mid-cell. A respawn inside a cell should force a non-ok status.Before the bump (v1.5.8, loadgen v1.4.13): this cell was the keep-alive measurement this issue describes, at 466k rps with 2.4 GB peak RSS. The lithium source is unchanged between 1463849 and 38779a4.
Not investigated: why lithium's memory grows to about 56 GB under real churn. The "about rate x 50 ms open connections" in this issue would not account for it alone. The lithium column has no usable data in this run, and the README's server count should say so.
Churn-close on every other column is clean: no churn-close cell outside lithium is
suspecton either arch. In v1.5.8 there were 47 / 39 suspects, almost all churn-close. That fits the -close fix.Evidence:
evidence/bench-36441790519/census/(census.out, scan_events.out) andcorrect/s12_churn_close.py.FumingPower3925 commentedon Oct 16, 2026
Second consecutive full bench: lithium is OOM-killed again on both arches (bench 38431303162, loadgen v1.4.14), 54-61 GB anon RSS
The behaviour in the 2026-10-02 comment (bench 36441790519) repeats with the same shape, on a run with a different celeris pin (v1.5.12-0.20261013133423-7d9ff01dab67, probatorium 2ca0563). So it is not a one-off.
Evidence root (maintainer's machine; paths relative to it):
~/.claude/projects/-Users-fuming-Documents-github-celeris-probatorium/evidence/cluster-reads-20261016/bench-38431303162/The kills. Kernel journal in
artifacts/cluster-forensics-38431303162-1/<host>/host-forensics.txt: five global OOM kills per arch, 6-8 s apart, during lithium's first scenario (churn-close: msa2-server cell 11:24:50-11:26:40Z, msr1 11:30:34-11:32:24Z).(bench 36441790519 for comparison: 56.1-56.4 GB on msa2-server, 58.2-59.1 GB on msr1.) The respawn guard gives up after attempt 4 (
server.log:[respawn] SUT exited rc=137, attempts 0-4;census/scan_events.out). The hostoom_killcounter reads 10 on both SUT hosts, which also counts the 5 of the previous run.Lost cells. Per arch, the other nine lithium cells are
dnf(server-down: pre-cell probe: dial tcp ...:8080: connect: connection refused):get-json,get-json-1k,get-simple,get-simple-1c/128c/256c/512c/1024c,post-4k. Whatever the column does after the first scenario is unmeasured. Lithium'schurn-closeitself:suspect(error ratio 0.070, connect-class; 597 rps, 4,051 errors over 53,721 requests, with no rated pass);ok(1,017 rps, 3,837 errors over 91,487 requests, under the 5% budget) although the server was killed five times during the cell, with no rated pass. This is the "classifier can mark a cellokwhen its SUT died mid-cell" case from the earlier comment.What this adds. The same 54-61 GB at the same point in the same scenario in two runs 13 days apart points to a repeatable growth under churn load (the earlier comment's "rate x 50 ms open connections" does not account for it). The cause is still not investigated. The apparatus side is that two full benches have now run with one competitor column lost on both arches and no flag in the published cells beyond per-cell
dnf; the README and docs server count would be wrong again for v1.6.0 unless lithium is fixed, bounded (a memory limit that fails the cell cleanly instead of a host-wide OOM) or listed as lost.Related: #441, #476.