bench: the corpus open-loop ceiling is the replay server's accept thread and listen backlog

bench/chromium/.gitignore

@@ -72,3 +72,7 @@ results/corpusextra-*/corpus-dns.log
 # The pointer from a run to the replay logs kept in ejc3/fcvm-bench-records
 # (campaign_summary.py EXTERNAL_LOGS).
 !results/**/external-logs.json
+# The replay server's listener log (corpus_serve.py --listen-log): one row a second per
+# busy listener plus the kernel's accept-queue overflows. A measurement, not DNS evidence.
+!results/**/*.corpus-listen.log
+!results/**/corpus-listen.log

bench/chromium/AGENTS.md

@@ -412,6 +412,11 @@ easy to get wrong:
   OCI runtime exit files directory: mkdir /run/user/1000: permission denied`. A user
   with no login session has no `XDG_RUNTIME_DIR`; `sudo -u <user>` does not create one.
   Fix is `loginctl enable-linger <user>`. Do not go looking for crun.
+- **Raise `fs.inotify.max_user_instances` before an open-loop run above about 4 requests per
+  second per path.** `reqbench.py` opens one inotify instance per request in flight and Ubuntu's
+  default is 128; the run then fails requests with `OSError: [Errno 24] inotify_init1 on
+  /mnt/fcvm-btrfs/state` and the failures look like a host ceiling (#1159). The same runs need a
+  descriptor limit well above 1024 in the driver.
 - **`fcvm setup` must have run, and `build` will not tell you.** Without the fc-agent
   initrd the golden phase dies one second in with `setting up fc-agent initrd:
   fc-agent initrd not found`, after `build` reported success — the two phases check

bench/chromium/REVIEW.md

@@ -20,6 +20,7 @@ the table below records why.
 | `results/reqbench-20260816-*-corpus` (14 runs), `results/reqbench-20260814-042319-uffd`, `results/cpuprobe-20260816` | 2026-08-14 to 2026-08-16 | **WITHDRAWN IN FULL** on 2026-09-02, live-DNS contamination; see "The 2026-08-16 corpus series" below. Each directory carries a `WITHDRAWN` marker with its evidence and stays in the tree. `results/campaign-20260816-summary.json` is a hand-written index of these cells, not a record. |
 | `results/reqbench-20260830-171007-corpus` | 2026-08-30 | DNS-verified corpus record (`dns-evidence.json` verdict clean); 712.6 ms [610.5, 808.5] cdp p50 at 2 vCPU. Still verified; the headline moved to the 4 vCPU rung of the ladder below. |
 | `results/reqbench-20260902-023115-corpus-c2`, `results/reqbench-20260902-025115-corpus-c4`, `results/reqbench-20260902-031115-corpus-c8` | 2026-09-02 | DNS-verified 2/4/8 vCPU ladder, one golden per rung on one runtime bundle (each `dns-evidence.json` verdict clean, first_mismatch null, diag violations none); cdp p50 770.3 [596.2, 807.8], 549.4 [467.9, 632.4] and 580.2 [520.8, 645.9] ms, n=202 each. 549.4 at 4 vCPU is the current corpus headline. Each rung ran once: from 2 to 4 vCPUs the median fell 220.9 ms, the 4 and 8 vCPU medians each sit inside the other's interval, and the stage where 8 loses (the wait for the target, +53.1 ms in the mean) moves in 50 ms poll steps, so these runs do not show that 4 is faster than 8 or locate a knee. Indexed by `results/campaign-20260902-box2-ladder-summary.json`. |
+| `results/scale-ceiling-20261026/` | 2026-10-26 | Open-loop corpus throughput with the replay server's listener measured (#1159): the default replay's single accept thread, which runs the TLS handshake, and its listen backlog of 5 are what limited the s13 run; section "The corpus open-loop ceiling is the replay server's listener" below. |
 | `results/reqbench-20261022-corpus-*` (serial runs), `results/reqbench-20261022-corpus-s13/scale-*`, `results/corpusextra-2026102[23]-*` | 2026-10-22 to 10-23 | The corpus campaign the report now quotes, on one c8g.metal-48xl (spot; reclaimed once, resumed on a replacement): serial runs at 2, 4 and 8 vCPUs, prefetch pairs, the poll-interval and copy-mode A/B/As, memory with many clones (screenshot and HTML), host Chromium controls, and an open-loop throughput run. Every serial run DNS-verified clean with 0 failures in 230 attempts per arm. Records carry `host_boot_sha256` (#1153). Harness defects found on the way are items 1 to 19 of "Harness bugs the 2026-10-22 campaign's first runs exposed" below. |
 
 ---
@@ -235,10 +236,11 @@ change mid-run (sha256 in `hostinfo.json`).
 - **Egress-mode ordering** needs repeated *independent runs*, not more reps within one run —
   run-to-run variance dominates within-run SE by ~6x.
 - **The ANGLE race** was not re-amplified in this run.
-- **`minor` sustained-throughput ceiling** was observed but not root-caused (single serve process
-  suspected; not proven). The 2026-10-22 corpus scale attempts collapsed at 2.8 requests per
-  second per restore path, FILE and UFFD alike (harness bug 15 below), so the limit is not the
-  memory server alone; what limits it is still not identified.
+- **The corpus open-loop throughput ceiling** is located in the replay server's listener
+  (next section, #1159). Open: where the ceiling lies once the listener is out of the way
+  (4 guest vCPUs: the handshake-in-handler runs went to 4.2 per restore path, the static
+  page to 5.6; beyond that the harness's own limits end the runs first, see the section below), and which stage is
+  the next limit.
 - **Hugepage `minor` at 4K-equivalent page counts** — the hugepage win conflates page size with
   sharing mode; a 4K `minor` vs 2 MiB `minor` decomposition would separate them.
 - **Teardown** (175 ms, post-artifact) was not moved off the response path in this run.
@@ -458,6 +460,65 @@ clones. Two spot hosts were terminated mid-run by the parallel-box idle
 watchdog, which reads a measured run of one request at a time on a
 192-vCPU host as idle; their unfinished runs are not records.
 
+## The corpus open-loop ceiling is the replay server's listener (#1159)
+
+`results/scale-ceiling-20261026/` (`summary.json`, `commands.txt`, the listener logs). c8g.metal-48xl,
+on demand, 4 guest vCPUs unless stated, FILE and UFFD interleaved, the s13 gates, seed 20261022.
+`corpus_serve.py --listen-log` was added for these runs; it records, once a second, what happens
+before the replay's handler thread starts timing (`duration_ms` in the access log starts there).
+
+- **Default replay (listen backlog 5, TLS handshake inside the one accept thread).** At 1.40 per
+  path the accept thread was inside `accept()` 43% of the time on average (2.8 ms per connection, 46,392
+  connections in the 300 s of scoring windows, 52 per page load) and the kernel dropped 13,869
+  connections for a full accept queue (`ListenOverflows`). At 1.87 it was 62% busy (3.0 ms), 26,105 drops,
+  median navigation 1,072 ms against 370 ms at 1.40, 364 of 1,120 requests over 2 s, and the run failed the
+  `departure` gate (1.78 completed per second) as s13 did. The first run on this tree offered 2.33 and 2.8:
+  both failed (2.8: 244 of 336 requests failed, the accept thread spent up to 11.2 s inside one
+  `accept()`, 15,182 drops; navigation median 33 s). A dropped SYN is retried after 1 s, so the 5 s p95
+  that s13 recorded at every rate comes partly from here.
+- **`--backlog 1024` alone**: 0 drops, median navigation 267 to 306 ms from 1.40 to 2.33 per path. In the
+  second run (`backlog-1024-b`, the only one with an analysis) 1.40 and 1.87 pass every gate and 2.33 is
+  recorded as a failed rate (one failed request among 1,400, a teardown leaving a lock file); the first run
+  was stopped at burst 12 of 18 by the sampler fault fixed in this PR, so its windows are 240 s at 1.40 and
+  180 s at 1.87 and 2.33 and it has no analysis. The accept thread is then 37% to 61% busy at 2.4 to 2.5 ms per connection, which puts
+  its own limit near 3.8 per path (1 / 2.44 ms = 410 connections per second, 53 per page load, two paths).
+- **`--tls-handshake-in-handler`** (the default backlog): the accept thread is 0.5% to 2.4% busy (0.03 to
+  0.05 ms per connection), handler time per request 6 to 9 ms (mean), and 1.40, 1.87, 2.33 and 2.8 all pass
+  (median navigation 262, 290, 307, 281 ms). In a second run set 3.27, 3.73 and 4.20 had 0, 3 and 1 failed
+  scored requests among 1,960, 2,240 and 2,520 (a failed request fails its rate under the strict policy,
+  and that run's analysis was refused for a 16.2% host-control drift), median navigation 322, 346 and
+  392 ms, 38, 75 and 244 dropped connections. At 2 guest vCPUs the same setting had 4 failed of
+  2,520 at 4.2 and none of 1,680 at 2.8, and failed 2,295 of 3,360 requests at 5.6 (267 drops).
+  Its 1.40 cell lost 62 requests in one burst (b0011) to the per-request Firecracker probe
+  ("firecracker-def pid N is outside run cgroup", one line per thread of one clone), which is not a
+  replay effect and is open.
+- **Replay out of the path** (one page the guest serves itself, `SCALE_URL_OVERRIDE`): 5.6 per path
+  completed 3,357 of 3,360 requests (median 502 ms against 423 ms at 1.40; the 3 failures were the harness's
+  Firecracker-pid probe, not the host).
+- **Above about 4.2 per path the failures are the harness's own limits, not a host measurement.** Every
+  failed request at 5.6 with 2 vCPUs (2,021 "firecracker-def pid N is outside run cgroup", 976
+  `inotify_init1: Too many open files`) and at 8.4 and 6.5 with the page or the replay was one of those two
+  or a descriptor-exhaustion error. `reqbench.py` opens one inotify instance per request in flight, and
+  Ubuntu's `fs.inotify.max_user_instances` is 128. With it at 65,536 the static page again held 5.6
+  (669 ok, 3 failed) and at 8.4 completed 609 and failed 399 requests, 804 of the 805 failed requests at that
+  rate being the cgroup-membership probe (median 1.1 s); at 11.2 the driver ran out of file
+  descriptors. So the host's own ceiling is not established above 5.6 per path (static page) or 4.2 (corpus
+  with the handshake fix), and a rerun of the corpus arm with the sysctl raised stopped at its first burst
+  on a process left in a request's cgroup ("inter-burst cgroup membership is not quiescent").
+
+What this does not show: what limits the corpus above 4.2 per path once the harness's inotify, descriptor and
+cgroup-probe limits are out of the way (the accept thread is idle; at most 57 handler threads were
+running at 4.2 with 4 vCPUs), whether the Python replay or the host side of pasta is
+the next limit, and what a page's navigation costs apart from the listener (with the listener fixed, 476 of 6,300
+scored requests in the 2.8-per-path run set took over 2 s navigation, and 460 of them are all 460
+requests for www.elmundo.es; the 5 s p95 of s13 is that page plus the listener's dropped connections). Every figure above is the 5 scored bursts of one
+run (300 s of scoring windows per rate), except the `base-first` rows, which are 60 s windows of the first
+attempt, and the `backlog-1024-a` rows (240 and 180 s); none has a repeat except the default-replay 1.40 (median navigation 362.7 and 370.0 ms in two runs, 355.4 in s13).
+
+The earlier s13 record (`reqbench-20261022-corpus-s13`) used the default replay, so its 1.40 and 1.87
+results are this table's first rows. The replay options default to the old behavior; the 2026-10-22 serial
+records are unchanged by this work.
+
 ## Binding requirements for any future run
 
 Unchanged from the previous ledger, plus:

bench/chromium/corpus_campaign.sh

@@ -162,7 +162,8 @@ acquire_diag_lock || exit 2
 # logs under logs/ are not the record and stay.
 rm -f "$RESULTS"/dns-evidence.json "$RESULTS"/verify-dns*.json "$RESULTS"/dns-owner.log \
     "$RESULTS"/replay-queries.log \
-    "$RESULTS"/corpus-dns.log "$RESULTS"/corpus-access.log "$RESULTS"/corpus-serve.status \
+    "$RESULTS"/corpus-dns.log "$RESULTS"/corpus-access.log "$RESULTS"/corpus-listen.log \
+    "$RESULTS"/corpus-serve.status \
     "$RESULTS"/reqbench.jsonl "$RESULTS"/analysis.json "$RESULTS"/diag/summary.json
 release_diag_lock
 
@@ -649,12 +650,13 @@ write_dns_evidence() {
     printf '%s\n' "$verdict"
 }
 
-# The scale run's sub-make, with the corpus, tag, memory-server mode, output
-# directory and control page this campaign decides. The schedule check in the
+# The scale run's sub-make, with the corpus (or SCALE_URL_OVERRIDE: one page
+# the guest serves itself, to take the replay out of the request path), tag,
+# memory-server mode, output directory and control page this campaign decides. The schedule check in the
 # preflight and the measured run both go through it, so the check validates
 # exactly what the run will be given.
 scale_make() {
-    SCALE_URL="$URLS" SCALE_TAG="$TAG" SCALE_OUT="$SCALE_DIR" \
+    SCALE_URL="${SCALE_URL_OVERRIDE:-$URLS}" SCALE_TAG="$TAG" SCALE_OUT="$SCALE_DIR" \
         SCALE_UFFD_MODE="$UFFD_MODE" SCALE_UFFD_PREFETCH="$UFFD_PREFETCH" \
         SCALE_CONTROL_URL="${SCALE_CONTROL_URL:-${URLS%%,*}}" \
         SCALE_CONTROL_RESOLVE_ALL_TO="${SCALE_CONTROL_RESOLVE_ALL_TO:-127.0.0.1}" \
@@ -828,9 +830,13 @@ SERVE_STATUS_FILE="$RESULTS/corpus-serve.status"
 rm -f "$SERVE_PIDFILE" "$SERVE_STATUS_FILE"
 # --dns-log / --access-log: the server's per-query DNS log and HTTP access
 # log, kept with the run; dns-evidence.json records their sha256.
-sudo -b sh -c 'python3 "$2" --root "$3" --port 80 --tls-port 443 --dns-addr 127.0.0.1 --dns-port 53 --answer-ip 10.0.2.2 --dns-log "$4" --access-log "$5" & pid=$!; echo "$pid" > "$1"; wait "$pid"; rc=$?; echo "$rc" > "$6.tmp" && mv "$6.tmp" "$6"' \
+# $7 is CORPUS_SERVE_ARGS, word-split on purpose: listener options for an
+# experiment (--backlog N, --tls-handshake-in-handler), none by default.
+# --listen-log is a measurement of the listeners, not evidence.
+sudo -b sh -c 'python3 "$2" --root "$3" --port 80 --tls-port 443 --dns-addr 127.0.0.1 --dns-port 53 --answer-ip 10.0.2.2 --dns-log "$4" --access-log "$5" --listen-log "$8" $7 & pid=$!; echo "$pid" > "$1"; wait "$pid"; rc=$?; echo "$rc" > "$6.tmp" && mv "$6.tmp" "$6"' \
     _ "$SERVE_PIDFILE" "$REPO/bench/chromium/corpus_serve.py" "$REPO/bench/chromium/corpus-live" \
-    "$RESULTS/corpus-dns.log" "$RESULTS/corpus-access.log" "$SERVE_STATUS_FILE" \
+    "$RESULTS/corpus-dns.log" "$RESULTS/corpus-access.log" "$SERVE_STATUS_FILE" "${CORPUS_SERVE_ARGS:-}" \
+    "$RESULTS/corpus-listen.log" \
     > "$LOGDIR/corpus_serve.log" 2>&1
 # `[ -s f ] && break` would be the last command in the body, so on the first
 # iteration (pidfile not written yet) it returns 1 and `set -e` kills the whole