Skip to content

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

Open

Description

@FumingPower3925

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-deps group (.github/dependabot.yml: gomod, patterns: "*", minor and patch, daily) includes github.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 from go list -m -versions, which lists tags only (dependabot-core go_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 moves github.com/goceleris/loadgen past 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 ignore for github.com/goceleris/loadgen until 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 a dnf nbio-h1 in v1.5.5). They have 0 errors and stay ok under any budget.
  • arm64 20260829: 35 suspect, plus 10 ok: 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 no sent_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_pct is 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_statuses moves from suspect to ok, unless genuine errors exceed the budget (see 1). The check is cmd/runner/main.go:1394.
  • The rated sweep now runs. Suspect cells skip it (cmd/runner/main.go:1244-1251). So latency_at_slo["churn-close"] and rated_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_rps changes. 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 (main h1client.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's redial does. It was 0 in every dataset and should stay about 0.
  • timeseries.json.gz for churn-close: the per-second errors falls from about rps to about 0, and p99_ms now includes the connect. The dashboard's over-time charts plot both (docs src/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 ignores Connection: close (lithium), each connection stays open about 50 ms before the client's reset, so its fd_hwm rises by about rate × 0.05 s (5,000 at 100k/s; lithium's x86 20260829 fd_hwm is 1,044).
  • throughput_bps scales with the success count. Its only published use is network_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-cell result and is not published unless probatorium maps it. Expect about requests for 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_slo and rated_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.go isTransientDialRST), 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=2000000 13-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_process returns TCP_TW_SYN when 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.py has the arithmetic; r3/impact/linux-v6.8-tw-excerpts.txt has the kernel code.
    • TIME_WAIT sockets are kernel-owned: no fd, and not in the SUT's RSS. So they do not change resources.
  • 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_slo and rated_mode_p99_at_target_rps shift 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 ErrBudget and its comment, and TestErrorBudgets (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:82 quotes 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 errors and p99_ms charts:
    • 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:

Activity

  1. FumingPower3925 commented on Sep 27, 2026

    @FumingPower3925
    ContributorAuthor

    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) flattens latency_at_slo of the baseline and current trees. It fails on any drop past the threshold, or on a baseline cell that is missing. It never reads loadgen_version.
    • The markdown report's "Regression vs baseline" section (report/markdown.go:94, :752 writeRegressionSection) diffs the same field by adapter and scenario, also without it.
    • loadgen_version is recorded only as run metadata: benchmark_config.loadgen_version (report/schema.go:463; the v1.5.8 summary.json has "loadgen_version": "v1.4.13"), and LoadgenVersion in the split index (report/split.go:98).

    Proposal: the regression gate and the report section compare only runs whose benchmark_config.loadgen_version is equal. When the versions differ, they either:

    A version check is two lines in diffBenchResults and writeRegressionSection. 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:

    • say in its description that the H2 and churn-close series restart at the bump;
    • correct scenarios/static.go:251-253, which says "32 TCP conns × default 100 concurrent streams". The runner sets Workers = 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 carry latency_at_slo and rated_mode_p99_at_target_rps only because BenchTier rates every clean cell (#418; the sweep at cmd/runner/main.go:1259 has no scenario filter). Once #418 is fixed, the gate above sees no H2 rows at all, and their before/after difference shows only in hdr_histogram_b64 and the timeseries p99_ms.

  2. FumingPower3925 commented on Oct 2, 2026

    @FumingPower3925
    ContributorAuthor

    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.

    host lithium anon RSS other
    msa2-server 56.1-56.4 GB pswpout 2.08M; host oom_kill counter 5
    msr1 58.2-59.1 GB host oom_kill counter 5

    Lost cells.

    • The respawn guard gave up after attempt 4.
    • The other 9 lithium cells are dnf ("server-down: pre-cell probe ... connection refused"), with empty_window resources.
    • That covers get-json, get-json-1k, get-simple, get-simple-1024c/128c/1c/256c/512c and post-4k.

    Churn-close itself.

    • amd64: suspect, 623 rps, 3,978 errors (3,866 connect-class).
    • arm64: recorded ok in 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).
    • So the classifier can mark a cell ok when 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 suspect on 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) and correct/s12_churn_close.py.

  3. FumingPower3925 commented on Oct 16, 2026

    @FumingPower3925
    ContributorAuthor

    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).

    host kills lithium anon RSS
    msa2-server 5 (pids 1023387-1023537) 54.5-54.8 GB
    msr1 5 (pids 390892-391799) 59.0-60.7 GB

    (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 host oom_kill counter 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's churn-close itself:

    • amd64: suspect (error ratio 0.070, connect-class; 597 rps, 4,051 errors over 53,721 requests, with no rated pass);
    • arm64: recorded 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 cell ok when 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.

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

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions