From 7df3bc3020824e5ffd3851991b185c19e02ad39e Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 05:49:42 +0900 Subject: [PATCH 01/16] Add cold-build measurement harness and task records (#2849) Prepare the empty-cache forecast build work: SDLC intent, spec and plan, the cold-read sequence diagram, the ColdBuildSpeed2849 placement declaration and the measurement harness. - The owned loopback S3 peer accepts a latency control that delays every GET, HEAD and LIST by the set milliseconds (PUT is not delayed); its self-check covers the control. - The D2 smoke example uses the server's 12-permit S3 gate (was 4) and gains an aged mode that repeats the cold request after the 30-second view freshness, rebuilding the forecast views in a warm process. - cold_build_matrix.py runs two or more smoke binaries at modeled S3 delays with one seeded corpus and reports status, time, body identity and forecast reads; pure tests cover its report logic. No product code changes in this commit. Co-Authored-By: Claude Opus 5.5 --- .../diagrams/server2-cold-read.html | 13780 ++++++++++++++++ .../diagrams/server2-cold-read.sequence.json | 254 + intent/issue-2849-cold-build-speed.md | 57 + plans/issue-2849-cold-build-speed.md | 94 + server2/config/tasks/ColdBuildSpeed2849.json | 88 + server2/examples/domestic_warm_cache_smoke.rs | 24 +- server2/tests/storage/catalog_peer.py | 35 +- server2/tools/cold_build_matrix.py | 227 + server2/tools/domestic_warm_cache_smoke.py | 2 +- server2/tools/test_cold_build_matrix.py | 96 + specs/issue-2849-cold-build-speed.md | 84 + 11 files changed, 14733 insertions(+), 8 deletions(-) create mode 100644 docs/architecture/diagrams/server2-cold-read.html create mode 100644 docs/architecture/diagrams/server2-cold-read.sequence.json create mode 100644 intent/issue-2849-cold-build-speed.md create mode 100644 plans/issue-2849-cold-build-speed.md create mode 100644 server2/config/tasks/ColdBuildSpeed2849.json create mode 100644 server2/tools/cold_build_matrix.py create mode 100644 server2/tools/test_cold_build_matrix.py create mode 100644 specs/issue-2849-cold-build-speed.md diff --git a/docs/architecture/diagrams/server2-cold-read.html b/docs/architecture/diagrams/server2-cold-read.html new file mode 100644 index 000000000..0f307fce2 --- /dev/null +++ b/docs/architecture/diagrams/server2-cold-read.html @@ -0,0 +1,13780 @@ + + + + + + + + Proposed empty-cache forecast build: ordered concurrent partition lookups Diagram + + + + + + + + +
+ +
+
+
+

Proposed empty-cache forecast build: ordered concurrent partition lookups

+
+
+ + + + +
+ + Proposed empty-cache forecast build: ordered concurrent partition lookups + A sequence diagram generated by Archify. + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + Build key (workspace held) + + + + + + + + LIST partitions by month + + + + + + + + Sorted partition ids + + + + + + + + Start lookups 1..12 in order + + + + + + + + Per lookup: catalog, descriptor, raw + + + + + + + + At most 12 operations in flight + + + + + + + + Objects, decoded and verified + + + + + + + + Lookup n ready (any finish order) + + + + + + + + Partition order; caps; first error wins + + + + + + + + build_view on blocking thread + + + + + + + + Same Docs, linear accounting + + + + + + + Overlapped reads, ordered results + + + + Fold + + + + + Cache owner · one flight per view · Sequence participant + + + + Cache owner + one flight per view + + + + Partition reader · ordered consumer · Sequence participant + + + + Partition reader + ordered consumer + + + + Forecast store · admission 12 lookups · Sequence participant + + + + Forecast store + admission 12 lookups + + + + Process S3 gate · 12 permits, unchanged · Sequence participant + + + + Process S3 gate + 12 permits, unchanged + + + + S3 records · authoritative · Sequence participant + + + + S3 records + authoritative + + + + Fold · blocking, linear accounting · Sequence participant + + + + Fold + blocking, linear accounting + + + + + Legend + + + main request + + + + return + + + + message + + + +

+ + + + + + + + + +
+ + + +
+ + + + diff --git a/docs/architecture/diagrams/server2-cold-read.sequence.json b/docs/architecture/diagrams/server2-cold-read.sequence.json new file mode 100644 index 000000000..ba7f87182 --- /dev/null +++ b/docs/architecture/diagrams/server2-cold-read.sequence.json @@ -0,0 +1,254 @@ +{ + "schema_version": 1, + "diagram_type": "sequence", + "meta": { + "title": "Proposed empty-cache forecast build: ordered concurrent partition lookups", + "output": "docs/architecture/diagrams/server2-cold-read.html", + "quality_profile": "showcase", + "locale": "en", + "viewBox": [ + 1040, + 590 + ], + "column_fit": "spread", + "repository": { + "url": "https://github.com/WizardFactory/TodayWeather", + "revision": "307defeb706886217ab67ea858dc7c7b0435752f", + "link_mode": "local-only" + } + }, + "participants": [ + { + "id": "owner", + "type": "backend", + "label": "Cache owner", + "sublabel": "one flight per view", + "sources": [ + { + "path": "server2/src/domestic/kma/source/forecast_cache.rs", + "line": 384, + "end_line": 481, + "label": "Existing owner / unchanged contract" + } + ] + }, + { + "id": "reader", + "type": "backend", + "label": "Partition reader", + "sublabel": "ordered consumer", + "sources": [ + { + "path": "server2/src/domestic/kma/source/forecast_cache.rs", + "line": 482, + "end_line": 597, + "label": "Sequential read; ordered concurrency proposed" + }, + { + "path": "server2/src/domestic/kma/source/records.rs", + "line": 35, + "end_line": 69, + "label": "Scope caps applied in partition order" + } + ] + }, + { + "id": "store", + "type": "backend", + "label": "Forecast store", + "sublabel": "admission 12 lookups", + "sources": [ + { + "path": "server2/src/domestic/kma/source/mod.rs", + "line": 266, + "end_line": 281, + "label": "Existing admission 2 / proposed 12" + }, + { + "path": "server2/src/storage/catalog.rs", + "line": 684, + "end_line": 700, + "label": "Existing lookup chain" + } + ] + }, + { + "id": "gate", + "type": "backend", + "label": "Process S3 gate", + "sublabel": "12 permits, unchanged", + "sources": [ + { + "path": "server2/src/gateway/runtime.rs", + "line": 30, + "end_line": 32, + "label": "Existing combined in-flight limit" + } + ] + }, + { + "id": "s3", + "type": "database", + "label": "S3 records", + "sublabel": "authoritative", + "sources": [ + { + "path": "server2/src/storage/catalog.rs", + "line": 684, + "end_line": 700, + "label": "Catalog, descriptor and raw reads" + } + ] + }, + { + "id": "fold", + "type": "backend", + "label": "Fold", + "sublabel": "blocking, linear accounting", + "sources": [ + { + "path": "server2/src/domestic/kma/source/forecast_cache.rs", + "line": 603, + "end_line": 700, + "label": "Existing build_view" + }, + { + "path": "server2/src/domestic/kma/source/doc.rs", + "line": 416, + "end_line": 456, + "label": "Whole-collection re-weigh; incremental proposed" + } + ] + } + ], + "segments": [ + { + "from": 240, + "to": 410, + "label": "Overlapped reads, ordered results" + }, + { + "from": 420, + "to": 475, + "label": "Fold" + } + ], + "messages": [ + { + "id": "step-0", + "from": "owner", + "to": "reader", + "y": 170, + "label": "Build key (workspace held)", + "variant": "default" + }, + { + "id": "step-1", + "from": "reader", + "to": "s3", + "y": 198, + "label": "LIST partitions by month", + "variant": "default" + }, + { + "id": "step-2", + "from": "s3", + "to": "reader", + "y": 226, + "label": "Sorted partition ids", + "variant": "return" + }, + { + "id": "step-3", + "from": "reader", + "to": "store", + "y": 254, + "label": "Start lookups 1..12 in order", + "variant": "emphasis" + }, + { + "id": "step-4", + "from": "store", + "to": "gate", + "y": 282, + "label": "Per lookup: catalog, descriptor, raw", + "variant": "default" + }, + { + "id": "step-5", + "from": "gate", + "to": "s3", + "y": 310, + "label": "At most 12 operations in flight", + "variant": "emphasis" + }, + { + "id": "step-6", + "from": "s3", + "to": "store", + "y": 338, + "label": "Objects, decoded and verified", + "variant": "return" + }, + { + "id": "step-7", + "from": "store", + "to": "reader", + "y": 366, + "label": "Lookup n ready (any finish order)", + "variant": "return" + }, + { + "id": "step-8", + "from": "reader", + "to": "owner", + "y": 394, + "label": "Partition order; caps; first error wins", + "variant": "return" + }, + { + "id": "step-9", + "from": "owner", + "to": "fold", + "y": 440, + "label": "build_view on blocking thread", + "variant": "emphasis" + }, + { + "id": "step-10", + "from": "fold", + "to": "owner", + "y": 468, + "label": "Same Docs, linear accounting", + "variant": "return" + } + ], + "cards": [ + { + "dot": "amber", + "title": "Proposed contract, not runtime evidence", + "items": [ + "Lookups overlap; results are consumed in partition order, so Docs, order and errors equal the sequential read.", + "Store admission rises 2 to 12 (raw loads too); per-lookup output falls 32 to 4 MiB and controls 8 to 1 MiB: in-flight reads of all views stay within 72.75 MiB (D2: 82.125 MiB).", + "No new mode, timer, retry or provider call." + ] + }, + { + "dot": "emerald", + "title": "Preserved", + "items": [ + "Owner deadline, 3 second waiter, writer fences and install rules are unchanged.", + "The 12-permit process S3 gate is shared with other families and is not resized here.", + "Every capacity cap keeps its exact boundary." + ] + }, + { + "dot": "slate", + "title": "Local evidence only", + "items": [ + "Injected S3 delay of 10 ms: 19.8 s sequential, 3.2 s with 12 lookups and store admission 12.", + "Seoul t3.small, real S3 and TLS latency are not yet measured." + ] + } + ] +} diff --git a/intent/issue-2849-cold-build-speed.md b/intent/issue-2849-cold-build-speed.md new file mode 100644 index 000000000..11996d122 --- /dev/null +++ b/intent/issue-2849-cold-build-speed.md @@ -0,0 +1,57 @@ +# Intent: speed up one empty-cache domestic forecast build (issue #2849 follow-through) + +| Field | Recorded value | +| --- | --- | +| Task / stage / owner | `issue-2849-cold-build-speed` / intent / main (Claude Sonnet 5.5, Anthropic) | +| Date / revision | 2026-10-22 KST, revision 2 (amendment below) | +| Source / authority | AK, 2026-10-22: implement per SDLC after the #2849 investigation; keep the EC2 host time limit until implementation completes. Issues #2849 (revised body), #2850. | +| Base | `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head, branch `fix/domestic-warm-cache-2819`); this task's branch `fix/cold-build-speed-2849` | +| Endpoint | `pre-merge` as the intended constraint; delegation of external writes is **pending** (see Authority) | +| Consumers | investigation, spec, plan, builder, reviewers | + +## Problem and supporting facts + +server2 builds the forecast views of one town from raw S3 acquisitions when its memory cache is empty. D2 (PR #2841) reads the partitions of a view one at a time, each as a chain of 3–4 GETs, through a forecast catalog store limited to 2 concurrent lookups. One empty-cache request therefore performs about 2,220 forecast GETs in about 700 sequential lookups. + +- On the Seoul t3.small / 2 GiB / CPU Unlimited host with a loopback S3 fixture the request needs 8.0–9.1 s (p95 8.28 s over 20 fresh-process runs) against a 3 s native deadline and the #2705 gate "assembly-only cold p95 ≤ 2.5 s"; with the product limits it returns HTTP 502 (2026-10-21 record). +- The loopback run hides S3 round trips. A local sweep with a delay injected into every GET/HEAD/LIST gives 1.4 s (0 ms), 10.1 s (5 ms), 19.8 s (10 ms); the sequential chain costs about 2 s per millisecond of S3 delay. +- A throwaway prototype (never committed) that keeps results in partition order but looks up 12 partitions at once and raises the store limit to 12 reached 3.2 s at 10 ms and 6.2 s at 20 ms; with a 32-permit process gate 1.8 s / 2.5 s. Raising only the lookup concurrency without the store limit changed nothing; more owners changed nothing. +- Fold CPU is next: `short` 1.16 s and `shortest` 0.43 s locally, about 4× slower on t3.small. The fold re-weighs the whole Doc collection on every store (quadratic), copies `String` values on every `Row::get`, and allocates heavily. A prototype that skipped the quadratic re-weigh cut fold by about 17%. +- All outputs were identical to the goldens (13 view Docs; HTTP body sha256 `a6462aba8ad9ec34…`, 42,549 bytes). + +Affected: every first request for a town whose forecast views are not cached (restart, eviction, expiry), the 502 rate of the native route, and the #2705 cold-p95 cutover gate. Retention (how long views are kept) is #2850 and out of scope. + +## Desired outcome and acceptance criteria + +An empty-cache forecast request completes inside the unchanged 3 s native deadline with identical output, bounded memory and no new runtime mode. Goal on the measured host class: empty-cache p95 ≤ 2.5 s at a modeled S3 delay of 10 ms. If the bounded iterations cannot reach that, report the measured remaining gap; never relax the deadline or the gate. + +- **AC1 — ordered concurrent reads.** A view build looks up its partitions with bounded concurrency while consuming results in partition order. Acquisitions, order, exclusion counts and the first error equal the sequential read. With a delayed transport double the build time follows operations × delay ÷ concurrency (at least 4× faster than the sequential read for 120+ partitions at the same delay). Timeout, corruption, missing catalog and capacity paths return the same typed errors; a cancelled build leaves no installed partial view and no running lookup beyond the S06 blocking closures that already outlive their caller. +- **AC2 — identical output and limits.** All 13 view Docs equal their goldens; the HTTP bodies of the cold, warm and empty-cache-in-warm-process requests equal the reference; every capacity limit keeps its exact boundary behavior (existing ±1 tests stay green); the forecast store's in-flight read memory, summed over all views of the process, stays below D2's bound. +- **AC3 — linear fold accounting.** Retained-Doc accounting no longer re-walks the whole collection per store or the whole Doc per field set, and the grid collector's row lookup no longer copies strings per visited row; a deterministic operation-count test shows linear growth and the local fold time of `short` and `shortest` falls against the D2 baseline on the same corpus with unchanged output. +- **AC4 — Seoul t3.small evidence.** The candidate and D2-as-published are measured with the same harness on the Seoul t3.small (Unlimited) host at modeled S3 delays 0, 10 and 20 ms (empty-cache request, fresh process and warm process), bodies identical, and the gap to 2.5 s is stated. +- **AC5 — contract, documentation and placement.** No new runtime flag or mode; all added paths are under the declared `server2/` subdirectories plus the declared documents; the D2 architecture section, the operator guide and the diagram describe the new read concurrency and limits; the placement gate passes; unrelated files are untouched. + +## In scope, out of scope, constraints + +- In scope: `server2/src/domestic/kma/source/{forecast_cache,records,mod,grid,doc,items,rss,mid}.rs` as needed for AC1–AC3, tests under `server2/tests/` and unit tests in those modules, the loopback-peer latency test aid under `server2/tests/storage/`, measurement tooling under `server2/examples/` or `server2/tools/`, and the declared documents. +- Out of scope: retention, SSD tier and warm-up (#2850); packs/rollups (#2707); resizing the process S3 gate `S3_IN_FLIGHT` (a separate decision; evidence recorded); host class; legacy `server/`; provider calls; production actions. +- Constraints: a request waits at most 3 s and omits late optional parts; S3 is authoritative; responses are byte-identical; no verification-only mode; no legacy dependency; fallible/charged allocation discipline of D2 stays; reviewer provider must differ from the builder. + +## Authority and endpoint + +- Delegated now: local implementation, tests, local smoke, the Seoul EC2 host described below, local commits on the task branch. +- **Not yet delegated (needs AK's explicit authority record `pre-merge-authority.json`):** pushing the branch, creating or updating a PR (stacked on #2841), issue comments or edits, sending code to another provider's reviewer, CI reads that need a PR. Until then pr-review and completion cannot run; the work stops at a verified local candidate. +- EC2: one role-less Spot t3.small in Seoul (ap-northeast-2d), SSH from the operator address only, egress revoked, auto-shutdown timer (initially 8 h, renewed while work continues), budget envelope USD 0.30 with a stop-and-ask above it. A safety classifier blocked the first operator-script run; no AWS call has been made. Launch waits for AK's explicit confirmation. +- Always excluded: merge, auto-merge, merge queue, production deployment, secrets, new accounts, permission changes. + +## Assumptions, risks and open questions + +- Assumption: AK's "implementation" selects options A and B of #2849; C (packs) and gate resizing stay decisions. +- Risks: ordering/error-precedence regressions in the concurrent read; sharing the 12-permit process S3 gate with other families during a cold build; unaccounted in-flight bytes; timing-only tests being flaky; a stacked PR on an unmerged, conflicting base. +- Open questions for AK: (1) delegate `pre-merge` (push, stacked PR on #2841, OpenAI Codex as required reviewer, issue comments)? (2) confirm the EC2 launch now. (3) raise `S3_IN_FLIGHT` later (evidence: 12 → 3.2 s, 32 → 1.8 s at 10 ms)? + +## Intent gate + +PROCEED for local stages (investigation → build → local self-verification). NEEDS_HUMAN for external writes and the AWS launch; unaffected work continues. + +Amendment 2026-10-22 (revision 2, before any code): AC2's memory clause read "in-flight read memory stays within the previous per-view bound". The forecast catalog store is one instance shared by every view, and D2 already let two owners read at once, so its bound is process-wide; with overlapped lookups one view may now use more than one sequential D2 lookup did. The clause now compares the store's in-flight bytes over all views with D2's. Found while planning, when the raw store's refuse-rather-than-wait admission and the per-load compressed buffer were added to the arithmetic. No other criterion changes. diff --git a/plans/issue-2849-cold-build-speed.md b/plans/issue-2849-cold-build-speed.md new file mode 100644 index 000000000..b18988807 --- /dev/null +++ b/plans/issue-2849-cold-build-speed.md @@ -0,0 +1,94 @@ +# Plan: empty-cache forecast build speed (issue #2849 follow-through) + +Consumes [intent](../intent/issue-2849-cold-build-speed.md) revision 2, [spec](../specs/issue-2849-cold-build-speed.md) revision 4 and the design of 2026-10-22 (iteration 3: [sequence](../docs/architecture/diagrams/server2-cold-read.html), [editable source](../docs/architecture/diagrams/server2-cold-read.sequence.json); the written design is in the ignored task record). Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head), branch `fix/cold-build-speed-2849`, endpoint `pre-merge` as the intended constraint with external writes pending AK's authority record. Owner: main (Claude Opus 5.5; earlier stages by Claude Sonnet 5.5, both Anthropic). Execution notebook: `.planning/2026-10-22-issue-2849-uncached-forecast-build-speed/` of the coordinating workspace. + +## Placement declaration (server2) + +The new task declaration `server2/config/tasks/ColdBuildSpeed2849.json` enumerates the paths below and is the only declaration this PR changes. No path outside `server2/` holds implementation; no server2 code reads, includes or links legacy `server/`; `Cargo.toml` and `Cargo.lock` stay unchanged (`futures-util` with `std` is already a dependency). + +Intended `server2/` paths: + +| Path | Why | +| --- | --- | +| `server2/config/tasks/ColdBuildSpeed2849.json` (new) | task placement declaration | +| `server2/src/domestic/kma/source/forecast_cache.rs` | `READ_AHEAD`, ordered concurrent `read_partitions`, unit tests | +| `server2/src/domestic/kma/source/records.rs` | `forecast_lookup` (`Looked`, `Counted`) replaces `forecast_acquisitions`; `ForecastScope::admit` | +| `server2/src/domestic/kma/source/mod.rs` | forecast store admission 12/12 and per-lookup output 4 MiB / controls 1 MiB | +| `server2/src/domestic/kma/source/doc.rs` | cached exact `Doc` weight (`Weight` newtype), `Row::str_is`, accounting tests | +| `server2/src/domestic/kma/source/grid.rs` | `find_or_create` through `Row::str_is`; hot-path copies removed where a profile shows them | +| `server2/src/domestic/kma/source/items.rs`, `rss.rs` (conditional) | only if the profile of the new baseline shows a remaining shared per-read copy; unchanged otherwise | +| `server2/tests/domestic.rs`, `server2/tests/domestic/forecast_cold_read.rs` (new) | delayed/counting transport double, ordered-concurrency, fault, cap and cancellation tests | +| `server2/tests/storage/catalog_peer.py` | runtime `latency` control of the loopback peer for the measurement harness, with its own loopback self-check | +| `server2/examples/domestic_warm_cache_smoke.rs` | transport gate 4 → 12 (the product's `S3_IN_FLIGHT`), `aged` mode (cold, then a request after the 30 s freshness bound) | +| `server2/tools/domestic_warm_cache_smoke.py` (+ its test only if affected) | the runner records the example's S3 transport admission (`s3_transport_admission`), which becomes 12 | +| `server2/tools/cold_build_matrix.py`, `server2/tools/test_cold_build_matrix.py` (new) | repeatable base-versus-candidate matrix at modeled S3 delays, with pure report-check tests | + +Exact outside paths (documentation and task records only): + +| Path | Reason | +| --- | --- | +| `intent/issue-2849-cold-build-speed.md`, `specs/issue-2849-cold-build-speed.md`, `plans/issue-2849-cold-build-speed.md` | SDLC intent, spec and plan | +| `docs/architecture/server2.md` | D2 section: read concurrency, admission, in-flight bound, linear accounting | +| `docs/architecture/diagrams/server2.json`, `server2.html` | existing Archify source and delivered HTML (card "D2 forecast memory"), regenerated by Archify | +| `docs/architecture/diagrams/server2-cold-read.sequence.json`, `server2-cold-read.html` (new) | cold-read sequence, rebound to the implementation commit | +| `docs/operations/server2-domestic-cache.md` (PDF only if a statement in it becomes untrue) | operator limits and the measurement procedure | +| `docs/operations/server2-native-verification.md` (conditional) | link to the matrix procedure | +| `docs/evidence/tasks/issue-2849-cold-build-speed/verification.md` (+ small selected result files) | candidate-bound selected evidence | + +Excluded and untouched: legacy `server/`, the process S3 gate (`gateway/runtime.rs`), owner and waiter counts, lookback and retention windows, view freshness, provider paths, `.github/`, root runtime files. + +## User scenarios (machine-readable copy: `reports/sdlc/issue-2849-cold-build-speed/user-scenarios.json`) + +| ID | User and goal | Steps (summary) | Expected | Failure path | AC | Checks | +| --- | --- | --- | --- | --- | --- | --- | +| S1 | App user opens the app right after a server restart; the first request for a town needs forecast views that are not in memory | native KMA address request with an empty forecast cache while S3 answers in 10 ms | HTTP 200 inside 3 s, body identical to the reference (sha256 `a6462aba…`, 42,549 bytes) | at higher delay the waiter times out as today, the owner finishes within its 8 s bound and the next request is warm | AC1 AC2 AC4 | T-R1.1, T-R1.2, matrix, smoke | +| S2 | Same user asks again | repeat request after S1 | warm hit, zero forecast LIST/GET, parse and fold | n/a | AC2 | existing D2 tests, smoke | +| S3 | Maintainer verifies equality locally | seed, diagnostic and http modes of the isolated smoke on the candidate | 13/13 Docs equal their goldens, hashes equal, warm deltas 0 | any Doc or hash difference fails the run | AC2 | smoke | +| S4 | Operator compares D2 and the candidate | run the matrix at 0, 10, 20 ms for both binaries, fresh process and aged cache, locally and on the Seoul host | table of status, time, hash and S3 operation counts; the gap to 2.5 s is stated | host launch not confirmed: the host column is recorded as not run, never inferred | AC4 | matrix, host run | +| S5 | A different town builds at the same time (2 owners) and other S3 users run | two cold keys plus a foreign S3 operation through the same gate | all complete; the foreign operation waits at most one gate round; no deadline relaxation | queue overflow keeps the existing typed refusal | AC1 AC2 | T-R1.7 | +| S6 | Maintainer reads the D2 documents | open architecture section, operator guide, diagram | read concurrency, admission (lookups = raw loads = 12), the process-wide in-flight bound (72.75 MiB, D2 82.125 MiB) and the evidence limits are stated; links resolve | stale statement found: fix before completion | AC5 | doc review, link check, Archify | +| S7 | Maintainer checks that the fold no longer re-weighs everything per store | operation-count tests; fold timing of `short`/`shortest` on base and candidate at 0 ms; goldens | walks grow linearly; store results equal the old recomputation; fold time down ≥ 25 %; Docs identical | stale weight, accept/reject difference or a gain below target is reported with numbers, never relaxed silently | AC2 AC3 | T-R3.1–T-R3.4, fold timing, smoke | + +## Ordered implementation steps (single builder, no parallel lanes) + +Each cycle follows the `tdd` skill (Red, Green, post-refactor check) and ends in a local commit; evidence of each cycle is kept in the ignored task record. + +0. **Baseline.** Record the base's behavior with the selected suites (see Verification) and the base binary's matrix numbers with the same harness once it exists. Recorded so far: base CI run `39243883911` failed 4 of 173 `domestic` tests with `forecast cache: raw storage: Capacity` (overflow under load, not diagnosed); locally the 4 pass in isolation, the whole binary passes with `--test-threads=4` (173/0, 2 ignored) and fails 30 tests in fixture publication with the default 10 threads (host contention). Base and candidate are compared with `--test-threads=4`; the CI result of a later PR is read against this baseline, not claimed as fixed. +1. **Harness and test aids** (`catalog_peer.py` latency control + self-check, example gate/`aged` mode, `cold_build_matrix.py` + pure tests). Red: the pure tests and the peer self-check fail before the code exists. This step must precede R1 so that D2-as-published and the candidate use one harness. +2. **R1 and R2.** Red tests in `forecast_cold_read.rs` first: peak concurrent catalog lookups ≥ 8, elapsed ≤ ⅓ of the sequential estimate for ≥ 120 partitions, 4 MiB+1 partition returns `Capacity`; characterization tests for first-error precedence, scope-cap partition, jitter equality and cancellation (these pass on the base and must stay green). Green: `forecast_lookup`/`Looked`/`Counted`, `ForecastScope::admit`, `read_partitions` with `buffered(READ_AHEAD)`, store limits. +3. **R3a cached weight.** Red: a `#[cfg(test)]` counter of full weight walks shows quadratic growth on the base; cached-equals-recomputed and store-decision-versus-oracle tests are written first and pass on the base. Green: `Weight` cache in `Doc`, exact delta maintenance in `try_set`, `checked_store_with_limit` over cached weights. +4. **R3b borrowed row lookup.** Red: `Row::str_is` is absent; equality tests against `Row::get` (own, template, missing, non-string, `0xF4` canonicalization). Green: `str_is` and `find_or_create`. Then re-profile and remove further per-read copies only where the profile and equality tests justify it (R3.3, R3.4). +5. **Documentation and diagrams.** D2 architecture section, operator guide, `server2.json` card, rebind `server2-cold-read` to the implementation commit; Archify `finalize` and `visual-check` for both sources; declaration file; documentation assessment. +6. **Verification and evidence.** Full self-verification (below), selected evidence under `docs/evidence/tasks/issue-2849-cold-build-speed/`, then the Seoul host matrix when AK confirms the launch. + +Dependencies: step 1 before 2; steps 2–4 in order (measured separately); step 5 after code is final; step 6 last. A change to R1–R3 behavior after step 2 starts is recorded as a dated design amendment. + +## Verification plan + +Reuse (fresh on the candidate, not inherited): existing `doc.rs`, `grid.rs`, `rss.rs`, `forecast_cache.rs` unit tests including the exact-boundary tests; `tests/domestic/forecast_cache.rs` (warm reuse, rewind, owner continuation, 128 waiters, 2/8 owners); the whole `domestic` integration binary; the 13 view goldens through the smoke `diagnostic` mode. New tests are listed in the test plan (test-design stage). Additional local functional smoke: the isolated release smoke (seed, diagnostic, http) and the local matrix at 0/10/20 ms for base and candidate with body hashes and S3 operation counts. + +Gates: `cargo test --locked --test domestic -- --test-threads=4` for base/candidate comparison; `cargo fmt --check`; `cargo clippy --locked --workspace --all-targets -- -D warnings`; `cargo test --locked --workspace` once on the final candidate; `python3.11 tools/check_placement.py --root .. --declaration config/tasks/ColdBuildSpeed2849.json --base ` and `tools/test_placement.py`; `python3 scripts/check-artifact-policy.py --staged` before each commit and on outgoing commits before any push; Archify finalize and visual check for the two diagram sources; link check of the changed documents; grep proving no new environment variable or mode flag in `server2/src`. Cargo runs use the shared ignored target `/private/tmp/tw-2849-target` with process-scoped `CARGO_INCREMENTAL=0`, `CARGO_PROFILE_DEV_DEBUG=0`, `CARGO_PROFILE_TEST_DEBUG=0`, after checking free space (137 GiB at planning) and keeping the 3 GiB reserve. + +Not-run is never pass: anything needing credentials, the Seoul host, a PR or CI is recorded as not run until it ran. + +## Documentation and manual + +Operator limits and the matrix procedure go into the editable guide; the existing three-page PDF documents the D2 base run (executable `f131044…`, weights 37,412,992 bytes). The change is a non-UX performance change, so no new screenshot manual is produced. The PDF is regenerated through the `screenshot-manual` skill only if the documentation assessment finds a statement in it that is untrue for the candidate; otherwise the guide labels those figures as the D2 base run and the assessment says so. Logical weights quoted from the D2 run are labeled "D2 base"; the candidate's new figures come from its own diagnostic run (a `Doc` and each `Val` grow by 8 bytes). + +## Migration, rollback and blast radius + +No stored-data, wire or configuration change; rollback is reverting the PR. The blast radius is the forecast read path of the domestic KMA source (all Grid, RSS and Mid keys) and every consumer of `Doc` (accounting only; equality, cloning results and `Debug` are unchanged). The process S3 gate is shared: a cold build may hold all 12 permits while it reads (recorded in the spec; resizing is a separate decision for AK). + +## What could break, riskiest part, rejected alternatives + +- Riskiest: the cached `Doc` weight returning a stale value (wrong accept/reject at a cap) and the ordered-consumption equivalence of the concurrent read. Proof: cached-equals-recomputed under random operation sequences, store decisions equal to the old recomputation at exact boundaries, jitter-versus-serialized equality, fault precedence in partition order, goldens, and the unchanged owner/epoch tests. +- Also: lookups beyond a failing partition may have started (documented, results discarded); timing assertions (use peak concurrency and operation counts first, wide ratios second); the stacked base is unmerged, `CONFLICTING` and under review, so the branch may need a rebase; the base CI is red on 4 tests (see step 0). +- Rejected: `buffer_unordered` plus sort, spawned per-lookup tasks, charging in-flight bytes to the workspace, sampled weight checks, per-collection weight vectors and resizing the S3 gate (reasons in the design record). + +## Cleanup, retention and checker wiring + +Maintained: code and tests under `server2/`, the documents above, the selected evidence file(s) with candidate hash. Ignored: `reports/`, `.planning/`, `.archify/`, copies of executables and raw run output (kept in the task record with hashes). Selected evidence cites tracked inputs only. Scratch: `/private/tmp/tw-2849-*` and `/private/tmp/server2-s09-docker/issue-2849-*` are removed at completion after copying required executables and recording hashes; the shared Cargo target is cleaned only after all consumers finish, with the cleaned paths and space recorded. The shared read-only checker is `scripts/check-artifact-policy.py` (`--staged`, and outgoing commits before any push); CI runs `server2/tools/ci.py` (placement, tests, build). Missing wiring: the new pure tool tests are not listed in `ci.py`; wiring them is out of scope and recorded. + +## Remaining decisions and gate + +Open for AK (do not block local stages): pre-merge authority (push, stacked PR on #2841, OpenAI Codex as required reviewer, issue comments); explicit launch confirmation for the Seoul host; `S3_IN_FLIGHT` resizing (evidence: 12 → 3.2 s, 32 → 1.8 s at 10 ms). Gate: PROCEED to test-design for local work; NEEDS_HUMAN only for the external writes and the AWS launch. diff --git a/server2/config/tasks/ColdBuildSpeed2849.json b/server2/config/tasks/ColdBuildSpeed2849.json new file mode 100644 index 000000000..b9128ec88 --- /dev/null +++ b/server2/config/tasks/ColdBuildSpeed2849.json @@ -0,0 +1,88 @@ +{ + "task": "ColdBuildSpeed2849", + "stable_task": "issue-2849-cold-build-speed", + "issue": "https://github.com/WizardFactory/TodayWeather/issues/2849", + "status": "local implementation under the canonical SDLC stages; external writes pending the pre-merge authority record", + "base": "307defeb706886217ab67ea858dc7c7b0435752f", + "scope": "Empty-cache D2 forecast view build: ordered concurrent partition lookups (READ_AHEAD 12) with forecast store admission 12/12, 4 MiB output and 1 MiB controls per lookup; exact cached Doc weight and borrowed row lookup in the fold; latency control of the owned loopback peer, aged smoke mode and a base-versus-candidate matrix tool. No process S3 gate, owner/waiter, lookback, retention, freshness, provider, mode, timer or production/merge change.", + "server2_paths": [ + "server2/config/tasks/ColdBuildSpeed2849.json", + "server2/src/domestic/kma/source/forecast_cache.rs", + "server2/src/domestic/kma/source/records.rs", + "server2/src/domestic/kma/source/mod.rs", + "server2/src/domestic/kma/source/doc.rs", + "server2/src/domestic/kma/source/grid.rs", + "server2/src/domestic/kma/source/items.rs", + "server2/src/domestic/kma/source/rss.rs", + "server2/tests/domestic.rs", + "server2/tests/domestic/forecast_cold_read.rs", + "server2/tests/storage/catalog_peer.py", + "server2/examples/domestic_warm_cache_smoke.rs", + "server2/tools/domestic_warm_cache_smoke.py", + "server2/tools/test_domestic_warm_cache_smoke.py", + "server2/tools/cold_build_matrix.py", + "server2/tools/test_cold_build_matrix.py" + ], + "outside": [ + { + "path": "intent/issue-2849-cold-build-speed.md", + "category": "documentation", + "reason": "Task intent and acceptance criteria" + }, + { + "path": "specs/issue-2849-cold-build-speed.md", + "category": "documentation", + "reason": "Read concurrency, admission, in-flight bound and accounting contract" + }, + { + "path": "plans/issue-2849-cold-build-speed.md", + "category": "documentation", + "reason": "Placement declaration, user scenarios, ordered steps and verification plan" + }, + { + "path": "docs/architecture/server2.md", + "category": "documentation", + "reason": "D2 section states the new read concurrency, store limits, in-flight bound and linear accounting" + }, + { + "path": "docs/architecture/diagrams/server2.json", + "category": "documentation", + "reason": "Existing Archify source: D2 forecast memory card and source lines" + }, + { + "path": "docs/architecture/diagrams/server2.html", + "category": "documentation", + "reason": "Regenerated and checked through Archify from the updated source" + }, + { + "path": "docs/architecture/diagrams/server2-cold-read.sequence.json", + "category": "documentation", + "reason": "New cold-read sequence source bound to the implementation commit" + }, + { + "path": "docs/architecture/diagrams/server2-cold-read.html", + "category": "documentation", + "reason": "Delivered and checked cold-read sequence" + }, + { + "path": "docs/operations/server2-domestic-cache.md", + "category": "documentation", + "reason": "Operator limits and the latency matrix procedure" + }, + { + "path": "docs/operations/server2-domestic-cache.pdf", + "category": "documentation", + "reason": "Regenerated only if a statement in the existing manual becomes untrue for the candidate" + }, + { + "path": "docs/operations/server2-native-verification.md", + "category": "documentation", + "reason": "Link to the latency matrix procedure, if the native verification guide needs it" + }, + { + "path": "docs/evidence/tasks/issue-2849-cold-build-speed/verification.md", + "category": "documentation", + "reason": "Selected candidate-bound verification evidence" + } + ] +} diff --git a/server2/examples/domestic_warm_cache_smoke.rs b/server2/examples/domestic_warm_cache_smoke.rs index 53c6ff085..5ef70b2d5 100644 --- a/server2/examples/domestic_warm_cache_smoke.rs +++ b/server2/examples/domestic_warm_cache_smoke.rs @@ -1,6 +1,8 @@ //! Full-window synthetic S06 baseline. Loopback only; no dotenv or live providers. //! seed publishes exact raw formats; diagnostic uses public source answers with60s, //! native uses KmaBackend's unchanged3s ceiling; http serves the normal direct route. +//! aged repeats the cold request once the 30-second view freshness has passed, so the +//! forecast views are rebuilt in an already warm process. //! Neither diagnostic nor this owned HTTP harness is a capacity qualification. use rusty_s3::Credentials; use serde_json::{Value, json}; @@ -40,6 +42,8 @@ use tokio::time::Instant; const NOW: i64 = 1_790_214_600_000; // 2026-09-24 10:50 KST. const HOUR: i64 = 3_600_000; type Transport = BoundedS3; +/// The process S3 admission of the server (`S3_IN_FLIGHT` in `gateway/runtime.rs`). +const S3_PERMITS: usize = 12; fn transport(endpoint: &str) -> Transport { BoundedS3::new( HttpS3Transport::new( @@ -49,7 +53,7 @@ fn transport(endpoint: &str) -> Transport { Credentials::new("server2-local", "server2-local-secret"), ) .unwrap(), - 4, + S3_PERMITS, ) } #[derive(Default)] @@ -645,7 +649,7 @@ impl server2::gateway::Geocoder for NoGeo { Box::pin(async { Err(server2::gateway::GatewayError::Provider) }) } } -async fn http(endpoint: &str, manifest: &Path) { +async fn http(endpoint: &str, manifest: &Path, phases: &[&str]) { use server2::{ api::{DirectFamilies, DirectRoutes}, gateway::{BackendDispatcher, Gateway}, @@ -704,7 +708,12 @@ async fn http(endpoint: &str, manifest: &Path) { ]); let mut complete = true; let mut first_warm_success: Option> = None; - for phase in ["cold", "warm1", "warm2"] { + for &phase in phases { + if phase == "aged" { + // Outside every request timing: wait out the 30-second view freshness so this + // request rebuilds the forecast views in a warm process. + tokio::time::sleep(Duration::from_secs(31)).await; + } let before = status(endpoint).await; let cache_before = source.forecast_cache_stats(); let denied_before = [ @@ -778,7 +787,9 @@ async fn http(endpoint: &str, manifest: &Path) { denied_after[1] - denied_before[1], denied_after[2] - denied_before[2], ]; - if phase != "cold" { + // An aged request rebuilds after the freshness bound; its denied stub calls are + // recorded, not treated as warm-path work. + if phase.starts_with("warm") { complete &= denied_delta[0] == 0; } println!( @@ -837,7 +848,7 @@ async fn main() { assert_eq!( args.len(), 3, - "ENDPOINT seed|diagnostic|native|http MANIFEST" + "ENDPOINT seed|diagnostic|native|http|aged MANIFEST" ); assert!(args[0].starts_with("http://127.0.0.1:")); match args[1].as_str() { @@ -850,7 +861,8 @@ async fn main() { .await } "native" => native(&args[0]).await, - "http" => http(&args[0], Path::new(&args[2])).await, + "http" => http(&args[0], Path::new(&args[2]), &["cold", "warm1", "warm2"]).await, + "aged" => http(&args[0], Path::new(&args[2]), &["cold", "aged"]).await, _ => panic!("unknown mode"), } } diff --git a/server2/tests/storage/catalog_peer.py b/server2/tests/storage/catalog_peer.py index 1d8c6c553..11dd009d1 100644 --- a/server2/tests/storage/catalog_peer.py +++ b/server2/tests/storage/catalog_peer.py @@ -98,6 +98,17 @@ def dispatch(self): return self.error(403, 'OnlyLocalTestControl') mode = query.get('mode', [''])[0] key = query.get('key', [''])[0] + if mode == 'latency': + # Measurement aid: one fixed delay for every GET/HEAD/LIST; fault modes stay. + try: + delay = float(query.get('ms', [''])[0]) / 1000 + except ValueError: + return self.error(400, 'InvalidTestFault') + if not 0 <= delay <= 1 or not base.valid_key(key): + return self.error(400, 'InvalidTestFault') + with self.server.lock: + self.server.latency = delay + return self.send(204) if mode not in ('commit500', 'conflict409', 'forget', 'corrupt', 'clear', 'reject', 'drop-commit', 'late-reject', 'barrier', 'bad-list', 'repeat-token', 'delay', 'unexpected202', 'chunked-list', 'empty-page', 'slow-all', 'delay-after-first', 'wrong-key', 'eof-list', 'short-list') or (not base.valid_key(key) and mode not in ('bad-list','repeat-token')): return self.error(400, 'InvalidTestFault') with self.server.lock: @@ -136,6 +147,8 @@ def dispatch(self): counter = self.command + ' ' + key self.server.counts[counter] = self.server.counts.get(counter, 0) + 1 pending = self.server.pending + latency = self.server.latency + if latency and self.command in ('GET', 'HEAD'): time.sleep(latency) if mode == 'slow-all' and self.command == 'GET': time.sleep(0.02) if self.command == 'GET' and query.get('list-type') == ['2']: if mode == 'empty-page' and 'continuation-token' not in query: @@ -230,6 +243,7 @@ def make(persistent=False, fanout_capacity=False): peer = base.Peer('s3', config, {}) peer.RequestHandlerClass = PersistentHandler if persistent else Handler peer.mode, peer.fault_key, peer.pending, peer.barrier_puts = '', '', None, 0 + peer.latency = 0.0 peer.counts = {} peer.response_lock = threading.Lock() peer.response_counts = {} @@ -306,7 +320,26 @@ def check_persistent(): connection.request('GET', path, headers=auth) response = connection.getresponse() assert response.status == 200 and response.read() == body, 'early PUT response corrupted the next HTTP frame' - print('owned peer', 'persistent' if persistent else 'default', 'reuse/framing/HEAD/204/CAS/fault/payload-counters PASS') + # Measurement latency: GET, HEAD and LIST wait the set milliseconds; PUT does not, + # and 0 restores immediate answers. + def timed(method, target, payload=None, extra=None): + started = time.monotonic() + connection.request(method, target, body=payload, headers=dict(auth, **(extra or {}))) + response = connection.getresponse() + response.read() + return response.status, time.monotonic() - started + for ms in ('-1', '1001', 'x', ''): + assert timed('POST', f'/__catalog?mode=latency&key=owned&ms={ms}')[0] == 400, ms + assert timed('POST', '/__catalog?mode=latency&key=owned&ms=40')[0] == 204, 'latency control' + for method, target in (('GET', path), ('HEAD', path), ('GET', '/server2-local?list-type=2&prefix=reuse')): + status, seconds = timed(method, target) + assert status == 200 and seconds >= 0.04, (method, target, status, seconds) + status, seconds = timed('PUT', '/server2-local/latency-put', body, headers) + assert status == 200 and seconds < 0.04, ('PUT must not wait', status, seconds) + assert timed('POST', '/__catalog?mode=latency&key=owned&ms=0')[0] == 204 + status, seconds = timed('GET', path) + assert status == 200 and seconds < 0.04, ('latency 0 restores immediate answers', seconds) + print('owned peer', 'persistent' if persistent else 'default', 'reuse/framing/HEAD/204/CAS/fault/payload-counters/latency PASS') finally: connection.close() peer.shutdown() diff --git a/server2/tools/cold_build_matrix.py b/server2/tools/cold_build_matrix.py new file mode 100644 index 000000000..f2f584e09 --- /dev/null +++ b/server2/tools/cold_build_matrix.py @@ -0,0 +1,227 @@ +#!/usr/bin/env python3 +"""Empty-cache forecast build times of two or more smoke binaries at modeled S3 delays. + +Owned loopback only: one persistent S06 peer, one seeded corpus, then for every delay +and run each binary's `http` (fresh process: cold, warm1, warm2) and `aged` (cold, then +a rebuild after the 30-second freshness) modes, interleaved. The peer delays every +GET/HEAD/LIST by the modeled milliseconds; seeding runs without delay. Bodies are kept +per run and compared with the reference hash. Works on Linux and macOS; no provider, +credential or AWS access. +""" +import argparse +import hashlib +import importlib.util +import json +import math +import os +from pathlib import Path +import platform +import select +import signal +import shutil +import statistics +import subprocess +import sys +import time +import urllib.request + +SERVER2 = Path(__file__).resolve().parents[1] +REFERENCE_SHA256 = 'a6462aba8ad9ec34d8efdcab4ccd2f37b00339a301fd17caa7c1e5485d45b283' +# The original 730-acquisition corpus written by the example's seed mode (same digest as +# the D2 runner checks). +FIXTURE_SHA256 = '11606b79c26365e4ba8a5a906d5801f717845f853bafc971c2f099d27b7bbe3f' +MODES = {'http': ('cold', 'warm1', 'warm2'), 'aged': ('cold', 'aged')} +IO_CLASSES = ('LIST', 'GET_catalog', 'GET_descriptor', 'GET_raw') +CHILD_SECONDS = 180 + + +def runner(): + """The D2 runner's I/O classification, imported without running it.""" + spec = importlib.util.spec_from_file_location('warm_runner', SERVER2/'tools/domestic_warm_cache_smoke.py') + module = importlib.util.module_from_spec(spec) + spec.loader.exec_module(module) + return module + + +def digest(path): + return hashlib.sha256(Path(path).read_bytes()).hexdigest() + + +def parse_binary(text): + name, sep, path = text.partition('=') + if not sep or not name or not name.replace('-', '').replace('_', '').isalnum() or not path: + raise argparse.ArgumentTypeError('use NAME=PATH with a plain name') + return name, Path(path).resolve() + + +def percentile(values, fraction): + """Nearest-rank percentile of a non-empty list.""" + ordered = sorted(values) + return ordered[max(0, math.ceil(fraction * len(ordered)) - 1)] + + +def phase_rows(stdout_text, labels, classify): + """One row per phase record printed by the example's http/aged modes.""" + rows = [] + for line in stdout_text.splitlines(): + record = json.loads(line) + outcome = record['outcome'] + per_dataset, unknown = classify(record['status_before'], record['status_after'], labels) + forecast = {c: sum(row.get(c, 0) for label, row in per_dataset.items() if label != 'zone-support') + for c in IO_CLASSES} + before, after = record['forecast_cache_before'], record['forecast_cache_after'] + rows.append({'phase': record['phase'], 'status': outcome.get('http_status'), + 'transport_error': outcome.get('transport_error'), + 'elapsed_ms': record['elapsed_ms'], 'sha256': outcome.get('sha256'), + 'bytes': outcome.get('bytes'), 'forecast_io': forecast, + 'other_io_operations': sum(unknown.values()), + 'parses': after['parse_acquisitions'] - before['parse_acquisitions'], + 'folds': after['folds'] - before['folds']}) + return rows + + +def summarize(rows, reference): + """Per binary, mode, delay and phase: statuses, times and identity of the answers.""" + groups = {} + for row in rows: + key = (row['binary'], row['mode'], row['delay_ms'], row['phase']) + groups.setdefault(key, []).append(row) + summary = [] + for (binary, mode, delay, phase), group in sorted(groups.items()): + ok = [r for r in group if r['status'] == 200] + times = [r['elapsed_ms'] for r in group] + summary.append({ + 'binary': binary, 'mode': mode, 'delay_ms': delay, 'phase': phase, 'runs': len(group), + 'status_counts': {str(s): sum(1 for r in group if r['status'] == s) + for s in sorted({r['status'] for r in group}, key=str)}, + 'median_ms': statistics.median(times), 'p95_ms': percentile(times, 0.95), + 'min_ms': min(times), 'max_ms': max(times), + 'ok_median_ms': statistics.median([r['elapsed_ms'] for r in ok]) if ok else None, + 'hash_mismatches': sum(1 for r in ok if r['sha256'] != reference), + 'forecast_io_median': {c: statistics.median(r['forecast_io'][c] for r in group) for c in IO_CLASSES}, + }) + return summary + + +def problems(rows, exits, reference): + """Harness integrity only. A non-200 answer, and the example stopping after it, is a + measured result kept in the summary; anything else unexpected is a problem.""" + found = [] + for (binary, mode, delay, run), code in sorted(exits.items(), key=str): + mine = [r for r in rows if (r['binary'], r['mode'], r['delay_ms'], r['run']) == (binary, mode, delay, run)] + phases = tuple(r['phase'] for r in mine) + where = f'{binary} {mode} {delay}ms run{run}' + if not phases or phases != MODES[mode][:len(phases)]: + found.append(f'{where}: phases {list(phases)}, exit {code}') + continue + failed = [r for r in mine if r['status'] != 200] + if failed and failed[0] is not mine[-1]: + found.append(f'{where}: continued after a failed {failed[0]["phase"]}') + if not failed and (code != 0 or len(phases) < len(MODES[mode])): + found.append(f'{where}: exit {code} after {list(phases)} all 200') + found += [f'{where} {r["phase"]}: body {r["sha256"]} is not the reference' + for r in mine if r['status'] == 200 and r['sha256'] != reference] + return found + + +def latency(endpoint, ms): + request = urllib.request.Request(f'{endpoint}__catalog?mode=latency&key=owned&ms={ms}', data=b'', + method='POST', headers={'X-Server2-Test-Key': 'server2-local'}) + with urllib.request.build_opener(urllib.request.ProxyHandler({})).open(request, timeout=5) as response: + if response.status != 204: + raise RuntimeError(f'peer refused latency {ms}') + + +def child(binary, endpoint, mode, manifest, directory): + env = dict(os.environ, NO_PROXY='127.0.0.1,localhost', no_proxy='127.0.0.1,localhost') + with (directory/'stdout').open('w') as stdout, (directory/'stderr').open('w') as stderr: + process = subprocess.Popen([str(binary), endpoint, mode, str(manifest)], cwd=SERVER2, env=env, + stdout=stdout, stderr=stderr, start_new_session=True) + try: + return process.wait(timeout=CHILD_SECONDS) + except subprocess.TimeoutExpired: + os.killpg(process.pid, signal.SIGKILL) + process.wait() + return 'TIMEOUT' + except BaseException: + os.killpg(process.pid, signal.SIGKILL) + process.wait() + raise + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument('--binary', type=parse_binary, action='append', required=True, + help='NAME=PATH of a copied domestic_warm_cache_smoke executable; first one seeds') + parser.add_argument('--output', type=Path, required=True) + parser.add_argument('--delays', type=int, nargs='+', default=[0, 10, 20]) + parser.add_argument('--runs', type=int, default=5) + parser.add_argument('--modes', nargs='+', choices=sorted(MODES), default=['http', 'aged']) + parser.add_argument('--reference', default=REFERENCE_SHA256) + args = parser.parse_args() + names = [name for name, _ in args.binary] + if len(set(names)) != len(names) or args.runs < 1 or any(d < 0 or d > 1000 for d in args.delays): + raise SystemExit('distinct binary names, at least one run and delays of 0-1000 ms are required') + output = args.output.resolve() + if output.exists() and any(output.iterdir()): + raise SystemExit('output directory must be new or empty; existing evidence is preserved') + output.mkdir(parents=True, exist_ok=True) + classify = runner().io_delta + inputs = {'binaries': {name: {'path': str(path), 'sha256': digest(path)} for name, path in args.binary}, + 'tool_sha256': digest(__file__), 'peer_sha256': digest(SERVER2/'tests/storage/catalog_peer.py'), + 'delays_ms': args.delays, 'runs': args.runs, 'modes': args.modes, 'reference_sha256': args.reference, + 'platform': platform.platform(), 'machine': platform.machine(), 'cpus': os.cpu_count()} + (output/'inputs.json').write_text(json.dumps(inputs, indent=2)+'\n') + peer = subprocess.Popen([sys.executable, 'tests/storage/catalog_peer.py', '--persistent'], cwd=SERVER2, + stdout=subprocess.PIPE, stderr=(output/'peer.stderr').open('w'), text=True) + rows, exits = [], {} + try: + ready, _, _ = select.select([peer.stdout], [], [], 5) + if not ready: + raise SystemExit('owned peer did not report an endpoint in 5 s') + endpoint = peer.stdout.readline().strip() + if not endpoint.startswith('http://127.0.0.1:'): + raise SystemExit('owned IPv4 loopback endpoint required') + manifest = output/'fixture-manifest.json' + (output/'seed').mkdir() + if child(args.binary[0][1], endpoint, 'seed', manifest, output/'seed') != 0 or digest(manifest) != FIXTURE_SHA256: + raise SystemExit('seed failed or the corpus identity changed; see seed/stderr') + labels = json.loads(manifest.read_text())['io_object_labels'] + for delay in args.delays: + latency(endpoint, delay) + for run in range(1, args.runs+1): + for mode in args.modes: + for name, binary in args.binary: + directory = output/name/mode/f'd{delay}'/f'r{run:02d}' + directory.mkdir(parents=True) + shutil.copy2(manifest, directory/'fixture-manifest.json') + exits[(name, mode, delay, run)] = child(binary, endpoint, mode, directory/'fixture-manifest.json', directory) + for row in phase_rows((directory/'stdout').read_text(), labels, classify): + rows.append({'binary': name, 'mode': mode, 'delay_ms': delay, 'run': run, **row}) + print(json.dumps({'binary': name, 'mode': mode, 'delay_ms': delay, 'run': run, + 'exit': exits[(name, mode, delay, run)], + 'phases': {r['phase']: [r['status'], round(r['elapsed_ms'])] + for r in rows if (r['binary'], r['mode'], r['delay_ms'], r['run']) == (name, mode, delay, run)}}), + flush=True) + latency(endpoint, 0) + finally: + peer.terminate() + try: + peer.wait(timeout=5) + except subprocess.TimeoutExpired: + peer.kill() + peer.wait() + summary = summarize(rows, args.reference) + found = problems(rows, exits, args.reference) + (output/'matrix.json').write_text(json.dumps({'inputs': inputs, 'rows': rows, 'summary': summary, + 'problems': found, 'peer_exit': peer.returncode}, indent=2)+'\n') + for s in summary: + print(f"{s['binary']:>10} {s['mode']:>4} {s['delay_ms']:>3}ms {s['phase']:>5} status {s['status_counts']}" + f" median {s['median_ms']:.0f} ms p95 {s['p95_ms']:.0f} ms forecast GET {s['forecast_io_median']}") + for problem in found: + print('PROBLEM', problem) + return 1 if found else 0 + + +if __name__ == '__main__': + raise SystemExit(main()) diff --git a/server2/tools/domestic_warm_cache_smoke.py b/server2/tools/domestic_warm_cache_smoke.py index 4dd7b9e27..f755ef525 100644 --- a/server2/tools/domestic_warm_cache_smoke.py +++ b/server2/tools/domestic_warm_cache_smoke.py @@ -183,7 +183,7 @@ def main(): (output/'inputs.json').write_text(json.dumps({'binary':str(binary),'binary_sha256':digest(binary), 'runner_sha256':digest(Path(__file__)), 'example_source_sha256':digest(SERVER2/'examples/domestic_warm_cache_smoke.rs'), 'peer_script_sha256':digest(SERVER2/'tests/storage/catalog_peer.py'), 'endpoint':endpoint, - 'persistent_peer':True,'source_before_sha256':source_before,'peer_limits':expected_peer,'s3_transport_admission':4,'build_variant':args.build_variant,'modes':args.modes,'verification_scope':VERIFICATION_SCOPE,'scope':'current candidate; logical D2 admission; no production capacity claim'},indent=2)+'\n') + 'persistent_peer':True,'source_before_sha256':source_before,'peer_limits':expected_peer,'s3_transport_admission':12,'build_variant':args.build_variant,'modes':args.modes,'verification_scope':VERIFICATION_SCOPE,'scope':'current candidate; logical D2 admission; no production capacity claim'},indent=2)+'\n') manifest = output/'fixture-manifest.json' for mode in args.modes: receipt = child(binary, endpoint, mode, manifest, output) diff --git a/server2/tools/test_cold_build_matrix.py b/server2/tools/test_cold_build_matrix.py new file mode 100644 index 000000000..9e01384dc --- /dev/null +++ b/server2/tools/test_cold_build_matrix.py @@ -0,0 +1,96 @@ +#!/usr/bin/env python3 +"""Pure checks of the matrix report logic: no child, peer, Cargo or network.""" +import argparse +import importlib.util +import json +from pathlib import Path +import unittest + +TOOL = Path(__file__).with_name('cold_build_matrix.py') +spec = importlib.util.spec_from_file_location('cold_build_matrix', TOOL) +matrix = importlib.util.module_from_spec(spec) +spec.loader.exec_module(matrix) +REFERENCE = matrix.REFERENCE_SHA256 +LABELS = { + 'index/v2/data-go-kr/vilage-fcst/k/20260924-0500.json': 'short', + 'index/v2/groups/g1.json': 'short', + 'raw/v2/data-go-kr/vilage-fcst/a.raw.gz': 'short', + 'raw/v2/data-go-kr/forecast-zone/z.raw.gz': 'zone-support', +} + + +def record(phase, status=200, sha=REFERENCE, elapsed=100.0, ops=None, parses=(0, 0)): + after = {'OP GET index/v2/data-go-kr/vilage-fcst/k/20260924-0500.json': 2, + 'OP GET index/v2/groups/g1.json': 3, 'OP GET raw/v2/data-go-kr/vilage-fcst/a.raw.gz': 4, + 'OP LIST index/v2/data-go-kr/vilage-fcst/k/202609': 1, + 'OP GET raw/v2/data-go-kr/forecast-zone/z.raw.gz': 5, 'OP GET index/v2/kasi/unknown.json': 6} + after.update(ops or {}) + outcome = {'http_status': status, 'sha256': sha, 'bytes': 42549} if status else {'transport_error': 'timed out'} + return {'phase': phase, 'elapsed_ms': elapsed, 'outcome': outcome, 'status_before': {}, 'status_after': after, + 'forecast_cache_before': {'parse_acquisitions': parses[0], 'folds': 0}, + 'forecast_cache_after': {'parse_acquisitions': parses[1], 'folds': 7}} + + +def rows_of(binary, mode, delay, run, records): + text = '\n'.join(json.dumps(r) for r in records) + return [{'binary': binary, 'mode': mode, 'delay_ms': delay, 'run': run, **row} + for row in matrix.phase_rows(text, LABELS, matrix.runner().io_delta)] + + +class Report(unittest.TestCase): + def test_percentile_is_nearest_rank(self): + self.assertEqual(matrix.percentile([5, 1, 4, 2, 3], 0.95), 5) + self.assertEqual(matrix.percentile(list(range(1, 21)), 0.95), 19) + self.assertEqual(matrix.percentile([7], 0.95), 7) + + def test_binary_arguments_need_a_plain_name_and_path(self): + name, path = matrix.parse_binary('d2-base=bin/smoke') + self.assertEqual(name, 'd2-base') + self.assertTrue(path.is_absolute()) + for bad in ('=bin/smoke', 'a b=bin/smoke', 'smoke', 'name='): + with self.assertRaises(argparse.ArgumentTypeError): + matrix.parse_binary(bad) + + def test_phase_rows_separate_forecast_io_from_support_and_other_reads(self): + [row] = rows_of('cand', 'http', 10, 1, [record('cold', parses=(10, 735))]) + self.assertEqual(row['forecast_io'], {'LIST': 1, 'GET_catalog': 2, 'GET_descriptor': 3, 'GET_raw': 4}) + self.assertEqual(row['other_io_operations'], 6, 'unlabelled reads are kept, not hidden') + self.assertEqual((row['parses'], row['folds']), (725, 7)) + self.assertEqual((row['status'], row['sha256'], row['bytes']), (200, REFERENCE, 42549)) + [failed] = rows_of('cand', 'http', 10, 1, [record('cold', status=None)]) + self.assertEqual((failed['status'], failed['transport_error'], failed['sha256']), (None, 'timed out', None)) + + def test_summary_keeps_statuses_times_and_answer_identity(self): + rows = [] + for run, (status, elapsed) in enumerate([(200, 900.0), (200, 1100.0), (502, 3005.0)], 1): + rows += rows_of('d2', 'http', 10, run, [record('cold', status=status, elapsed=elapsed, + sha=REFERENCE if status == 200 else 'x')]) + rows += rows_of('cand', 'http', 10, 1, [record('cold', sha='f' * 64, elapsed=300.0)]) + summary = {(s['binary'], s['phase']): s for s in matrix.summarize(rows, REFERENCE)} + d2 = summary[('d2', 'cold')] + self.assertEqual(d2['status_counts'], {'200': 2, '502': 1}) + self.assertEqual((d2['median_ms'], d2['p95_ms'], d2['ok_median_ms']), (1100.0, 3005.0, 1000.0)) + self.assertEqual(d2['hash_mismatches'], 0, 'a failed answer is not an identity mismatch') + self.assertEqual(summary[('cand', 'cold')]['hash_mismatches'], 1) + self.assertEqual(d2['forecast_io_median']['GET_raw'], 4) + + def test_problems_are_harness_integrity_not_measured_failures(self): + complete = rows_of('c', 'http', 0, 1, [record('cold'), record('warm1'), record('warm2')]) + measured_502 = rows_of('d2', 'http', 10, 1, [record('cold', status=502, sha='x')]) + self.assertEqual(matrix.problems(complete + measured_502, {('c', 'http', 0, 1): 0, + ('d2', 'http', 10, 1): 101}, REFERENCE), []) + cases = { + 'no records': ([], 101), + 'all 200 but failed exit': (rows_of('c', 'aged', 0, 1, [record('cold'), record('aged')]), 101), + 'timeout after 200': (rows_of('c', 'aged', 0, 1, [record('cold')]), 'TIMEOUT'), + 'wrong body': (rows_of('c', 'aged', 0, 1, [record('cold'), record('aged', sha='e' * 64)]), 0), + 'continued after failure': (rows_of('c', 'aged', 0, 1, [record('cold', status=502), record('aged')]), 101), + 'phase order': (rows_of('c', 'aged', 0, 1, [record('aged'), record('cold')]), 0), + } + for name, (rows, code) in cases.items(): + with self.subTest(name): + self.assertTrue(matrix.problems(rows, {('c', 'aged', 0, 1): code}, REFERENCE), name) + + +if __name__ == '__main__': + unittest.main() diff --git a/specs/issue-2849-cold-build-speed.md b/specs/issue-2849-cold-build-speed.md new file mode 100644 index 000000000..693850682 --- /dev/null +++ b/specs/issue-2849-cold-build-speed.md @@ -0,0 +1,84 @@ +# Empty-cache forecast build speed (issue #2849 follow-through) + +Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841, D2). Intent: `intent/issue-2849-cold-build-speed.md` revision 2 (AC1–AC5). Evidence: investigation of the same task (local sweep, profile, 2026-10-21 EC2 record). Revision 4, 2026-10-22 (revision 2 amended decision D3; revision 3 refined R2.2/D1 with the control-byte bound; revision 4 corrects the R2.2 memory comparison to the process-wide store bound, adds the raw admission constraint to R2.1 and states the logical-weight shift; acceptance follows intent revision 2). Status: complete; decisions D1–D5 below are made for design, none blocks it. + +## Problem and outcome + +A forecast view is built from raw S3 acquisitions when its memory entry is missing. D2 reads the view's partitions one at a time, each as a catalog → descriptor → raw chain, through a catalog store limited to 2 concurrent lookups. One empty-cache request performs about 2,220 forecast GETs in about 700 chained lookups, so its duration grows by about 2 s per millisecond of S3 delay (19.8 s at 10 ms locally; 8–9 s on the Seoul t3.small with a loopback fixture; HTTP 502 under the 3 s deadline). Fold CPU is second (`short` ≈ 1.16 s locally, about four times that on t3.small). + +Outcome: the same Docs, order and errors, produced with the partition reads overlapped and the fold's accounting linear, so an empty-cache request fits the 3 s deadline with the 2.5 s p95 goal on the measured host class at a modeled 10 ms S3 delay. If the bounded iterations cannot reach it, the measured gap is reported; the deadline and the #2705 gate are not relaxed. + +## Scope and exclusions + +In scope: the forecast read loop and its store admission (`server2/src/domestic/kma/source/forecast_cache.rs`, `records.rs`, `mod.rs`), the retained-Doc accounting and grid row lookup in `doc.rs`, `grid.rs` (and `rss.rs`/`mid.rs` where they share the same helpers), tests, a latency-injecting loopback-peer test aid, measurement tooling, and the documents listed under AC5. + +Excluded: retention, SSD tier and warm-up (#2850); packs or rollups (#2707); the process S3 gate `S3_IN_FLIGHT` (12) and owner counts; lookback windows and retention windows; the 30 s/minute view freshness; provider calls; legacy `server/`. These are recorded as decisions for AK, not changed here. + +## Retained behavior (must not change) + +- Every view's Docs, their order, S16 input identities, `usable` partitions, exclusion counts and the HTTP bodies (reference sha256 `a6462aba8ad9ec34d8efdcab4ccd2f37b00339a301fd17caa7c1e5485d45b283`, 42,549 bytes) for the cold, warm and empty-cache-in-warm-process requests. +- D2 ownership: 2 active owners, 8 queued keys, 10 admitted flights, 128 waiters, 8 s owner deadline, ≤3 s caller wait, writer epoch/fence invalidation, no install of a partial or late view, warm hits with zero forecast I/O, parse or fold. +- Every capacity rule: page ≤1 MiB, ≤1024 partitions, ≤2048 acquisitions, ≤8192 pages, ≤32 MiB raw per scope; Doc ≤32 fields and ≤8 MiB; retained collection ≤8 MiB and ≤4096 Docs; parse scratch ≤48 MiB — with unchanged exact-boundary results. The limits and their arithmetic stay; the logical weight of the same data grows by 8 bytes per `Doc` and per stored field because a `Doc` carries its cached weight (R3). +- Error mapping of the read path: `Timeout`, `Capacity`, `Corrupt`, `NotFound`-as-excluded partition, `Invalid`, `Transport` surface exactly as the sequential read surfaces them. + +## Requirements + +**R1 — Ordered concurrent partition lookups (AC1).** +1. For every key kind (Grid, RSS, and Mid within one month) the read starts partition lookups in ascending partition order with at most `READ_AHEAD = 12` in flight per read and consumes the results strictly in that order. +2. The returned acquisitions, their order, the excluded count and the sort that follows equal the sequential read's for the same stored data. +3. Scope accounting (partitions, acquisitions, pages, page size, raw bytes) is applied to each consumed partition in order with the same arithmetic, so a cap is exceeded at the same partition and returns `Capacity` as before. Dropping unconsumed in-flight lookups after an error or cap is allowed; their results are discarded. +4. The first error in partition order is the error returned. A later partition's earlier-in-time failure never replaces it. +5. The caller or owner deadline is passed to every lookup unchanged. Dropping the read (owner timeout, shutdown) drops all in-flight lookups; the existing `build` logic still refuses to install a view that finished after its deadline. +6. A transport delay of D per operation makes a build of P partitions (c operations each) take about P × c × D ÷ min(READ_AHEAD, store admission, process gate) plus decode, rather than P × c × D. + +**R2 — Admission and in-flight memory (AC1, AC2).** +1. The forecast catalog store admits `READ_AHEAD` lookups and `READ_AHEAD` raw loads at once (was 2/2); its decode CPU permits stay 1/1. Both are below or equal to the process transport gate of 12, which is unchanged. The raw admission must equal the lookup admission: a raw load beyond it is refused with `Capacity` instead of waiting, and each lookup loads its records one at a time. +2. The forecast store's per-lookup decoded output bound becomes 4 MiB (was 32 MiB) and its per-lookup retained control bytes 1 MiB (was 8 MiB). A lookup in flight holds at most its output, its controls and one compressed body (≤ 1 MiB + 64 KiB), so the store's in-flight bytes over all views stay within 12 × (4 + 1 + 1.0625) MiB = 72.75 MiB, below D2's 2 × (32 + 8 + 1.0625) MiB = 82.125 MiB. One view may now hold all of that 72.75 MiB (D2: 41.06 MiB, one lookup at a time); the 2 × 192 MiB owner workspaces, which cover the retained 32 MiB raw scope, are unchanged. A partition whose records exceed 4 MiB, or whose catalog and descriptors exceed 1 MiB, returns `Capacity` (fixture partitions decode to at most about 0.2 MiB; their controls are a few KiB). +3. No lookup waits for admission longer than the store's existing 3 s per-lookup bound; if admission queueing exceeds it the lookup times out as before. The queueing wait is a documented property, not a new failure mode. + +**R3 — Linear fold accounting (AC3).** +1. The retained-Doc limit check for a stored Doc is computed from an incrementally maintained exact weight of the collection; for every store call the accept/reject result and the error equal the old whole-collection recomputation. +2. A field set on a Doc under the bounded setter does not re-walk unaffected fields to compute its projected weight; accept/reject results stay identical at every boundary. +3. The grid collector's row lookup (`find_or_create`) compares `date` and `time` without allocating strings; any other per-read string copy in the hot collector path is removed if it keeps results identical. +4. Local fold time of `short` and `shortest` on the 730-acquisition corpus falls by at least 25% against the base with no output change (stretch is set by the AC4 gap). + +**R4 — Evidence and documentation (AC4, AC5).** +1. A repeatable harness reports empty-cache time at modeled delays 0, 10 and 20 ms, fresh-process and warm-process, with body hash and S3 operation counts, for the candidate and for D2 as published, locally and on the Seoul t3.small. +2. The D2 architecture section, the operator guide and the diagram state the new read concurrency, the store admission and the in-flight bound. No new runtime setting or mode: the constants live in code with the same justification as the existing `LOOKUPS`. + +## Data contracts and interfaces + +- Internal only; no public API, wire or storage change. `Reader::forecast_acquisitions` stops accounting scope itself; the caller applies one `ForecastScope` check per consumed partition (the accounting moves, the arithmetic does not). `forecast_partitions` stays sequential (a few LISTs). +- `checked_store` and the bounded Doc setter keep their error type; the cached weight is private state of `Doc` that must not change equality, `Debug` output, cloning results or the observable Docs. +- Optional test-visible counter: peak concurrent partition lookups may be observed through a counting transport double in tests; no product statistic is required. + +## Failure, retry and concurrency behavior + +- A failing partition fails the whole view build with the same typed error; the owner reports it as today and nothing is installed. No retry is added. +- Cancellation: caller timeout or shutdown drops the stream of lookups; S06 blocking decode closures that already started finish and release their permits as they do today. +- Fairness: forecast lookups share the 12-permit process gate with other families. A cold build can occupy all permits for the duration of its reads; this is accepted for this task and recorded in the plan's risk list. The gate size is a separate decision. +- Different towns, views and owners run independently as in D2; the store admission is shared by all views of the process. + +## Decisions made for design (D1–D5) + +- **D1** In-flight bound: reduce the forecast store's `output_bytes` to 4 MiB and `retained_control_bytes` to 1 MiB rather than charging in-flight bytes to the workspace budget (simpler; the process-wide worst case falls from 82.125 to 72.75 MiB). Rejected: dynamic read-ahead by bytes (complex, no observed need). +- **D2** `READ_AHEAD = 12` equals the store `io`/`raw.io` and the process gate. Evidence: 12 lookups with store 12 → 3.2 s at 10 ms; store 8 → 4.6 s; raising only lookups → 16.9 s. +- **D3** (amended 2026-10-22, revision 2) Accounting keeps an exact cached `heap_weight` inside each `Doc` (thread-safe, "unknown" by default). The bounded setter updates it by the delta of the actual stored key, value and root allocation; infallible mutators and clones reset it to unknown because a clone has different capacities. The collection check sums cached per-Doc weights. The accept/reject result must equal the whole-recomputation result at every call. Rejected: sampling the check (changes boundary behavior); collection-level weight vectors (more bookkeeping, and `Doc::try_set` and the row `put` would still re-walk). The first revision rejected memoizing inside `Doc` because weights depend on capacities; exact delta maintenance from the stored objects resolves that. +- **D4** Parallel parse across the two CPU permits and skipping out-of-window publications are not part of this revision; they are candidates for a second build iteration only if AC4 shows a remaining fold-bound gap. +- **D5** `S3_IN_FLIGHT` stays 12; evidence for 32 (1.8 s at 10 ms) goes to AK as a decision. + +## Verification approach (mapped to ACs; strategy only, not evidence) + +| AC | Layer | Approach | +| --- | --- | --- | +| AC1 | integration over the owned S06 peer | counting/delaying transport wrapper: peak in-flight lookups ≥ 8 and elapsed ≤ ⅓ of the sequential estimate for ≥120 synthetic partitions; result equality against the 13 goldens; fault injection (missing, corrupt, timeout, over-cap) compares error and partition of failure; cancellation test drops the build mid-read and checks no install and no leaked in-flight count | +| AC2 | existing suites + goldens | existing exact-boundary and D2 tests stay green; diagnostic mode (13 Docs) and HTTP body hashes; a 4 MiB+1 partition returns `Capacity`; the forecast store limits are checked (lookups = raw loads = `READ_AHEAD`, 4 MiB, 1 MiB) | +| AC3 | unit + local timing | test-only counter of `heap_weight` calls shows linear growth in Doc count and field count; equality tests of borrowed row lookup against the old accessor; local fold timing against base binary | +| AC4 | harness on host | latency-injected matrix on Seoul t3.small (EC2) and locally; body hash equality; operation counts | +| AC5 | review + gates | placement gate, artifact policy checker, doc/diagram review, no new flags (grep), clean checkout links | + +## Assumptions, risks and unresolved items + +- Assumed: AK's "implement" selects options A and B of #2849. Risk: ordering/error-precedence regression (mitigated by in-order consumption and equality tests); sharing the process gate; flaky timing tests (mitigated by deterministic peak-concurrency assertions plus loose ratios); stacked PR on an unmerged, conflicting base. +- Unresolved (not blocking): external-write authority (push, PR, reviewers, issue comments); AK's explicit EC2 launch confirmation; real S3/TLS latency remains unmeasured. +- Superseded D2 text: "Process one partition at a time with checked scope totals before retention/dispatch" (`specs/issue-2819-domestic-warm-cache.md`) is replaced by R1 for the read loop; every other D2 clause stands. From 62595a9269b5ef36166f329a51e40b9e22dd87fb Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 06:08:46 +0900 Subject: [PATCH 02/16] Overlap forecast partition lookups in partition order (#2849) An empty-cache view build read its partitions one at a time through a forecast store that admitted two lookups, so one request chained about 700 catalog, descriptor and raw reads and grew by about 2 s per millisecond of S3 latency. - read_partitions keeps up to READ_AHEAD (12) lookups in flight with an ordered buffered stream and consumes them in partition order, so the retained acquisitions, the failing scope partition and the first error equal a sequential read; returning early drops the rest. - forecast_lookup returns each partition's acquisitions, excluded groups and scope totals (every S06 acquisition counted); ForecastScope::admit applies the unchanged caps per consumed partition. - The forecast store admits 12 lookups and 12 raw loads (a raw load beyond its permits is refused, not queued) with 4 MiB of records and 1 MiB of controls per lookup: 12 x (4 + 1 + 1.0625) MiB in flight over all views, below D2's 2 x (32 + 8 + 1.0625) MiB. Tests: overlapped reads inside the 12-permit gate (130 partitions at 10 ms: peak 12 lookups, 0.55 s versus 3.9 s sequential), jitter equality, first error in partition order, vanished catalog, owner deadline and lookup timeout cancellation, two cold keys with another reader, the 4 MiB boundary, store limits and scope-cap equivalence with the per-acquisition checks. Co-Authored-By: Claude Opus 5.5 --- .../src/domestic/kma/source/forecast_cache.rs | 74 ++- server2/src/domestic/kma/source/mod.rs | 47 +- server2/src/domestic/kma/source/records.rs | 187 +++++- server2/tests/domestic.rs | 2 + server2/tests/domestic/forecast_cold_read.rs | 571 ++++++++++++++++++ 5 files changed, 821 insertions(+), 60 deletions(-) create mode 100644 server2/tests/domestic/forecast_cold_read.rs diff --git a/server2/src/domestic/kma/source/forecast_cache.rs b/server2/src/domestic/kma/source/forecast_cache.rs index 3805e7fcf..2a392ddba 100644 --- a/server2/src/domestic/kma/source/forecast_cache.rs +++ b/server2/src/domestic/kma/source/forecast_cache.rs @@ -28,6 +28,9 @@ const ID_BYTES: usize = 4 * MIB; const ENTRY_BYTES: usize = 48 * MIB; const WORKSPACE: usize = 192 * MIB; const OWNER: Duration = Duration::from_secs(8); +/// Partition lookups in flight per view build: the forecast store's lookup and raw-load +/// admission, not above the process S3 gate (`S3_IN_FLIGHT` in `gateway/runtime.rs`, 12). +pub(super) const READ_AHEAD: usize = 12; pub(super) fn add(a: usize, b: usize) -> Result { a.checked_add(b).ok_or(Error::Capacity) @@ -510,21 +513,12 @@ impl Cache { deadline, ) .await?; - for part in parts.into_iter().filter(|p| *p >= oldest) { - let (mut found, e) = reader - .forecast_acquisitions( - key.source(), - key.kind(), - &provider, - &part, - &mut scope, - deadline, - ) - .await?; - excluded = add(excluded, e)?; - reserve(&mut raw, found.len())?; - raw.append(&mut found); - } + let parts = parts.into_iter().filter(|p| *p >= oldest); + let (mut found, e) = + read_partitions(reader, key, &provider, parts, &mut scope, deadline).await?; + excluded = add(excluded, e)?; + reserve(&mut raw, found.len())?; + raw.append(&mut found); } Key::Mid(..) => { for month in checked_months(now)?.into_iter().rev() { @@ -538,21 +532,12 @@ impl Cache { deadline, ) .await?; - for part in parts { - let (mut found, e) = reader - .forecast_acquisitions( - key.source(), - key.kind(), - &provider, - &part, - &mut scope, - deadline, - ) + let (mut found, e) = + read_partitions(reader, key, &provider, parts, &mut scope, deadline) .await?; - excluded = add(excluded, e)?; - reserve(&mut raw, found.len())?; - raw.append(&mut found); - } + excluded = add(excluded, e)?; + reserve(&mut raw, found.len())?; + raw.append(&mut found); // The older fallback must retain exclusions from every searched newer month. if let Key::Mid(model, code) = key { let mut inputs = Vec::new(); @@ -597,6 +582,37 @@ impl Cache { } } +/// The acquisitions and excluded groups of `parts` (ascending). Up to [`READ_AHEAD`] lookups +/// overlap, but results are consumed in partition order: the retained acquisitions, the +/// partition whose scope totals fail and the first error equal a sequential read. Returning +/// early drops the lookups still in flight. +async fn read_partitions( + reader: &Reader, + key: &Key, + provider: &ProviderKey, + parts: impl IntoIterator, + scope: &mut super::records::ForecastScope, + deadline: Instant, +) -> Result<(Vec, usize), Error> { + use futures_util::{StreamExt, stream}; + let mut lookups = stream::iter(parts) + .map(|part| async move { + reader + .forecast_lookup(key.source(), key.kind(), provider, &part, deadline) + .await + }) + .buffered(READ_AHEAD); + let (mut raw, mut excluded) = (Vec::new(), 0usize); + while let Some(looked) = lookups.next().await { + let mut looked = looked?; + scope.admit(&looked.counted)?; + excluded = add(excluded, looked.excluded)?; + reserve(&mut raw, looked.found.len())?; + raw.append(&mut looked.found); + } + Ok((raw, excluded)) +} + // Keep canonical set/completeness, wall+monotonic expiry, writer epoch, overlay // parent/original identity and counters explicit at the owned blocking boundary. #[allow(clippy::too_many_arguments)] diff --git a/server2/src/domestic/kma/source/mod.rs b/server2/src/domestic/kma/source/mod.rs index 0eb7d2461..86d018f45 100644 --- a/server2/src/domestic/kma/source/mod.rs +++ b/server2/src/domestic/kma/source/mod.rs @@ -111,6 +111,24 @@ fn lookback_ms(family: Family) -> f64 { } /// RSS rows reach two days after their publication day; retention is 216 h before the run. const RSS_LOOKBACK_MS: f64 = grid::RETENTION_MS + 4. * DAY_MS; +/// The catalog store of the forecast views, shared by every view of the source. It admits +/// the read-ahead of a view build; a raw load beyond `raw.io` is refused rather than queued, +/// so `raw.io` equals `io` (each lookup loads one record at a time). Small per-lookup records +/// and controls keep 12 lookups in flight below D2's two large ones. +fn forecast_limits() -> CatalogLimits { + let mut limits = CatalogLimits { + io: forecast_cache::READ_AHEAD, + cpu: 1, + output_bytes: 4 * 1024 * 1024, + retained_control_bytes: 1024 * 1024, + ..CatalogLimits::default() + }; + limits.raw.io = forecast_cache::READ_AHEAD; + limits.raw.cpu = 1; + limits.raw.raw_bytes = forecast_cache::PAGE_BYTES; + limits.raw.gzip_bytes = forecast_cache::PAGE_BYTES + 65_536; + limits +} /// KST months (`YYYYMM`) from [`HISTORY_START_MONTH`] through `now`, ascending. pub(crate) fn history_months(now: f64) -> Vec { let end = records::months(now, now) @@ -263,18 +281,9 @@ impl S3Source { acquire, locate, )); - let mut forecast_limits = CatalogLimits { - io: 2, - cpu: 1, - ..CatalogLimits::default() - }; - forecast_limits.raw.io = 2; - forecast_limits.raw.cpu = 1; - forecast_limits.raw.raw_bytes = forecast_cache::PAGE_BYTES; - forecast_limits.raw.gzip_bytes = forecast_cache::PAGE_BYTES + 65_536; let forecast_reader = Reader { transport: transport.clone(), - store: Arc::new(CatalogStore::new(transport.clone(), forecast_limits)?), + store: Arc::new(CatalogStore::new(transport.clone(), forecast_limits())?), }; let forecast_cache = forecast_cache::Cache::new(forecast_reader)?; Ok(Self { @@ -1867,6 +1876,24 @@ mod tests { assert_eq!(at(mx, my), None, "{mx},{my}"); } } + /// Twelve lookups and twelve raw loads (a raw load beyond its permits is refused, not + /// queued), each bounded to 4 MiB of records and 1 MiB of controls: 12 x (4 + 1 + 1.0625) + /// MiB in flight over all views, below D2's 2 x (32 + 8 + 1.0625) MiB. + #[test] + fn forecast_store_admits_the_read_ahead_with_small_lookups() { + const MIB: usize = 1024 * 1024; + let limits = forecast_limits(); + limits.validate().unwrap(); + assert_eq!((limits.io, limits.raw.io), (12, 12)); + assert_eq!((limits.cpu, limits.raw.cpu), (1, 1)); + assert_eq!(limits.output_bytes, 4 * MIB); + assert_eq!(limits.retained_control_bytes, MIB); + assert_eq!(limits.raw.raw_bytes, forecast_cache::PAGE_BYTES); + assert_eq!(limits.raw.gzip_bytes, forecast_cache::PAGE_BYTES + 65_536); + let in_flight = limits.io + * (limits.output_bytes + limits.retained_control_bytes + limits.raw.gzip_bytes); + assert!(in_flight < 2 * (32 * MIB + 8 * MIB + forecast_cache::PAGE_BYTES + 65_536)); + } } #[cfg(test)] diff --git a/server2/src/domestic/kma/source/records.rs b/server2/src/domestic/kma/source/records.rs index bdab0b1a5..1b5d5692b 100644 --- a/server2/src/domestic/kma/source/records.rs +++ b/server2/src/domestic/kma/source/records.rs @@ -48,25 +48,51 @@ impl ForecastScope { } Ok(()) } - fn acquisition(&mut self, records: &[RawRecord]) -> Result<(), Error> { - use super::forecast_cache::{PAGE_BYTES, add}; - self.acquisitions = add(self.acquisitions, 1)?; - self.pages = add(self.pages, records.len())?; - if self.acquisitions > 2048 || self.pages > 8192 { + /// One consumed partition, in partition order. Every total only grows and every violation + /// is `Capacity`, so this fails at the same partition as checking each acquisition did. + pub(super) fn admit(&mut self, counted: &Counted) -> Result<(), Error> { + use super::forecast_cache::add; + self.acquisitions = add(self.acquisitions, counted.acquisitions)?; + self.pages = add(self.pages, counted.pages)?; + self.raw = add(self.raw, counted.raw)?; + if counted.oversize + || self.acquisitions > 2048 + || self.pages > 8192 + || self.raw > 32 * 1024 * 1024 + { return Err(Error::Capacity); } - for r in records { - if r.bytes.len() > PAGE_BYTES { - return Err(Error::Capacity); - } - self.raw = add(self.raw, r.bytes.len())?; - if self.raw > 32 * 1024 * 1024 { - return Err(Error::Capacity); - } + Ok(()) + } +} +/// Scope totals of one looked-up partition: every acquisition of its S06 set, including one +/// that yields no [`Fetched`]. +#[derive(Default)] +pub(super) struct Counted { + acquisitions: usize, + pages: usize, + raw: usize, + oversize: bool, +} +impl Counted { + /// One acquisition with pages of these byte lengths. + fn acquisition(&mut self, pages: impl ExactSizeIterator) -> Result<(), Error> { + use super::forecast_cache::{PAGE_BYTES, add}; + self.acquisitions = add(self.acquisitions, 1)?; + self.pages = add(self.pages, pages.len())?; + for bytes in pages { + self.oversize |= bytes > PAGE_BYTES; + self.raw = add(self.raw, bytes)?; } Ok(()) } } +/// One partition lookup: acquisitions in S06 order, excluded groups and scope totals. +pub(super) struct Looked { + pub(super) found: Vec, + pub(super) excluded: usize, + pub(super) counted: Counted, +} /// LIST pages allowed per key and month (1,000 keys each; a month of hourly partitions is 744). const LIST_PAGES: usize = 4; /// Catalog lookups in flight at once per load (below the shared S3 admission). @@ -156,17 +182,16 @@ impl Reader { out.dedup(); Ok(out) } - /// One partition at a time. Existing S06 controls bound its decode buffers; scope admission - /// precedes any additional retained handle/identity growth in D2. - pub(super) async fn forecast_acquisitions( + /// One partition. Its S06 limits bound the lookup's records and controls while it is in + /// flight; the caller admits its scope totals in partition order before retaining it. + pub(super) async fn forecast_lookup( &self, source: &str, kind: &str, key: &ProviderKey, partition: &str, - scope: &mut ForecastScope, deadline: Instant, - ) -> Result<(Vec, usize), Error> { + ) -> Result { use super::forecast_cache::{copied, reserve}; let id = catalog(source, kind, key, partition)?; let set = match self.store.lookup(&id, deadline).await { @@ -174,12 +199,19 @@ impl Reader { Ok(LookupOutcome::Incomplete) => return Err(Error::Corrupt("incomplete catalog")), // This private path only reads partitions witnessed by LIST. A vanished catalog // is an eligible partial answer, not proof of reusable empty canonical state. - Err(Error::NotFound) => return Ok((Vec::new(), 1)), + Err(Error::NotFound) => { + return Ok(Looked { + found: Vec::new(), + excluded: 1, + counted: Counted::default(), + }); + } Err(e) => return Err(e), }; + let mut counted = Counted::default(); let mut out = Vec::new(); for a in set.acquisitions() { - scope.acquisition(a.records())?; + counted.acquisition(a.records().iter().map(|r| r.bytes.len()))?; let mut ordered = Vec::new(); reserve(&mut ordered, a.records().len())?; ordered.extend(a.records().iter()); @@ -201,7 +233,11 @@ impl Reader { pages, }); } - Ok((out, set.excluded_groups())) + Ok(Looked { + found: out, + excluded: set.excluded_groups(), + counted, + }) } fn prefix(source: &str, kind: &str, key: &ProviderKey) -> Result { Ok(format!( @@ -447,3 +483,112 @@ pub fn months(from_ms: f64, to_ms: f64) -> Vec { } out } +#[cfg(test)] +mod tests { + use super::*; + use crate::domestic::kma::source::forecast_cache::PAGE_BYTES; + const MIB: usize = 1024 * 1024; + /// A partition: its acquisitions, each the byte lengths of its pages. + type Partition = Vec>; + /// The D2 accounting: every acquisition checked in order while partitions were read one at + /// a time. The index of the partition whose acquisition failed. + fn sequential(parts: &[Partition]) -> Option { + let (mut acquisitions, mut pages, mut raw) = (0usize, 0usize, 0usize); + for (i, part) in parts.iter().enumerate() { + for acquisition in part { + acquisitions += 1; + pages += acquisition.len(); + if acquisitions > 2048 || pages > 8192 { + return Some(i); + } + for &bytes in acquisition { + if bytes > PAGE_BYTES { + return Some(i); + } + raw += bytes; + if raw > 32 * MIB { + return Some(i); + } + } + } + } + None + } + fn admitted(parts: &[Partition]) -> Option { + let mut scope = ForecastScope::default(); + for (i, part) in parts.iter().enumerate() { + let mut counted = Counted::default(); + for acquisition in part { + counted.acquisition(acquisition.iter().copied()).unwrap(); + } + if let Err(e) = scope.admit(&counted) { + assert_eq!(e, Error::Capacity); + return Some(i); + } + } + None + } + #[test] + fn partition_totals_keep_every_exact_scope_boundary() { + let one = |acquisitions, pages, raw, oversize| Counted { + acquisitions, + pages, + raw, + oversize, + }; + for (at, above) in [ + (one(2048, 0, 0, false), one(1, 0, 0, false)), + (one(0, 8192, 0, false), one(0, 1, 0, false)), + (one(0, 0, 32 * MIB, false), one(0, 0, 1, false)), + ] { + let mut scope = ForecastScope::default(); + scope.admit(&at).unwrap(); + assert_eq!(scope.admit(&above), Err(Error::Capacity)); + } + let mut page = Counted::default(); + page.acquisition([PAGE_BYTES].into_iter()).unwrap(); + ForecastScope::default().admit(&page).unwrap(); + page.acquisition([PAGE_BYTES + 1].into_iter()).unwrap(); + assert_eq!(ForecastScope::default().admit(&page), Err(Error::Capacity)); + // An acquisition without pages still counts toward the 2048. + let mut empty = Counted::default(); + for _ in 0..2049 { + empty.acquisition(std::iter::empty()).unwrap(); + } + assert_eq!(ForecastScope::default().admit(&empty), Err(Error::Capacity)); + } + #[test] + fn partition_totals_fail_at_the_same_partition_as_per_acquisition_checks() { + let mut state = 0x2545_f491_4f6c_dd1d_u64; + let mut next = |bound: u64| { + state ^= state << 13; + state ^= state >> 7; + state ^= state << 17; + state % bound + }; + for case in 0..3000 { + // Bias each case toward one of the caps: many acquisitions, many pages, large pages. + let (acquisitions, pages, large) = match case % 3 { + 0 => (40, 2, false), + 1 => (4, 40, false), + _ => (3, 3, true), + }; + let parts: Vec = (0..next(120) as usize + 1) + .map(|_| { + (0..next(acquisitions)) + .map(|_| { + (0..next(pages)) + .map(|_| match (large, next(100)) { + (true, 0) => PAGE_BYTES + 1, + (true, n) if n < 50 => PAGE_BYTES - next(2) as usize, + (_, _) => next(64 * 1024) as usize, + }) + .collect() + }) + .collect() + }) + .collect(); + assert_eq!(admitted(&parts), sequential(&parts), "case {case}"); + } + } +} diff --git a/server2/tests/domestic.rs b/server2/tests/domestic.rs index 2d2d9f756..3befb082b 100644 --- a/server2/tests/domestic.rs +++ b/server2/tests/domestic.rs @@ -10,6 +10,8 @@ mod air_s3; mod asos; #[path = "domestic/forecast_cache.rs"] mod forecast_cache; +#[path = "domestic/forecast_cold_read.rs"] +mod forecast_cold_read; #[path = "domestic/late_publication.rs"] mod late_publication; #[path = "domestic/life.rs"] diff --git a/server2/tests/domestic/forecast_cold_read.rs b/server2/tests/domestic/forecast_cold_read.rs new file mode 100644 index 000000000..f812bcde1 --- /dev/null +++ b/server2/tests/domestic/forecast_cold_read.rs @@ -0,0 +1,571 @@ +//! #2849 empty-cache forecast reads over the owned S06 peer. A probe inside the 12-permit +//! process gate models S3 latency, counts operations in flight and injects per-partition +//! faults, so overlapped partition lookups, their partition-order consumption, the first +//! error, the store bounds and cancellation are observed through the public source. +use super::source::{docs_json, same}; +use super::source_s3::{NOW, Peer, S3_PEERS, Unreachable, deadline}; +use rusty_s3::Credentials; +use serde_json::json; +use server2::domestic::asos::AsosRequest; +use server2::domestic::family::WebRequest; +use server2::domestic::kma::source::observe::Acquire; +use server2::domestic::kma::source::{Doc, Family, S3Source, Val}; +use server2::domestic::publication::Publication; +use server2::domestic::{Acquired, DomesticError}; +use server2::gateway::BoxFuture; +use server2::history::{Grid, IndexListing, schedule}; +use server2::storage::{ + CatalogId, CatalogLimits, CatalogStore, CatalogTransport, ControlObject, Error, + GroupDeclaration, GroupMember, HttpS3Transport, ListPage, Object, ObjectTransport, Pagination, + PreparedRecord, RawRecord, WriteCondition, +}; +use server2::world::BoundedS3; +use std::collections::BTreeMap; +use std::sync::{ + Arc, Mutex, + atomic::{AtomicU64, AtomicUsize, Ordering::SeqCst}, +}; +use std::time::Duration; +use tokio::time::Instant; + +/// Hourly Current partitions of one grid, all inside its 217-hour lookback. +const PARTITIONS: usize = 130; +/// Catalog, group descriptor and raw GET of one single-page partition. +const CHAIN: u64 = 3; +const GATE: usize = 12; +const HOUR_MS: i64 = 3_600_000; + +#[derive(Default)] +struct DenyProviders(AtomicUsize); +impl Acquire for DenyProviders { + fn web(&self, _: WebRequest, _: Instant) -> BoxFuture<'_, Result> { + self.0.fetch_add(1, SeqCst); + Box::pin(async { Err(DomesticError::Transport) }) + } + fn asos(&self, _: AsosRequest, _: Instant) -> BoxFuture<'_, Result> { + self.0.fetch_add(1, SeqCst); + Box::pin(async { Err(DomesticError::Transport) }) + } +} + +/// Operations in flight now and at most. +#[derive(Default)] +struct Gauge { + now: AtomicUsize, + peak: AtomicUsize, +} +impl Gauge { + fn enter(&self) -> Held<'_> { + let n = self.now.fetch_add(1, SeqCst) + 1; + self.peak.fetch_max(n, SeqCst); + Held(self) + } +} +/// Leaves the gauge when the operation ends or its future is dropped. +struct Held<'a>(&'a Gauge); +impl Drop for Held<'_> { + fn drop(&mut self) { + self.0.now.fetch_sub(1, SeqCst); + } +} +#[derive(Default)] +struct Probe { + /// Delay of every read operation while it holds its gate permit. + delay_ms: AtomicU64, + /// Non-zero: xorshift state adding 0-15 ms to each read. + jitter: AtomicU64, + all: Gauge, + catalogs: Gauge, + catalog_reads: Mutex>, + /// Partition -> delay, then this error from its catalog GET. + faults: Mutex>, +} +impl Probe { + async fn pause(&self) { + let mut ms = self.delay_ms.load(SeqCst); + let state = self.jitter.load(SeqCst); + if state != 0 { + let mut x = state; + x ^= x << 13; + x ^= x >> 7; + x ^= x << 17; + self.jitter.store(x, SeqCst); + ms += x % 16; + } + if ms > 0 { + tokio::time::sleep(Duration::from_millis(ms)).await; + } + } + fn fault(&self, partition: &str, wait: Duration, error: Error) { + self.faults + .lock() + .unwrap() + .insert(partition.to_owned(), (wait, error)); + } + fn in_flight(&self) -> usize { + self.all.now.load(SeqCst) + } +} +/// The HTTP S3 client of the peer behind the probe; writes pass through untouched. +struct Probed { + inner: HttpS3Transport, + probe: Arc, +} +impl ObjectTransport for Probed { + async fn put(&self, record: &PreparedRecord) -> Result { + self.inner.put(record).await + } + async fn head(&self, key: &str) -> Result { + let _held = self.probe.all.enter(); + self.probe.pause().await; + self.inner.head(key).await + } + async fn get(&self, key: &str, maximum: usize) -> Result { + let _held = self.probe.all.enter(); + self.probe.pause().await; + self.inner.get(key, maximum).await + } +} +impl CatalogTransport for Probed { + async fn get_control(&self, key: &str, maximum: usize) -> Result { + let _held = self.probe.all.enter(); + let catalog = !key.starts_with("index/v2/groups/"); + let _catalog = catalog.then(|| { + self.probe + .catalog_reads + .lock() + .unwrap() + .push(key.to_owned()); + self.probe.catalogs.enter() + }); + self.probe.pause().await; + let partition = key + .rsplit('/') + .next() + .and_then(|name| name.strip_suffix(".json")); + let fault = partition + .filter(|_| catalog) + .and_then(|p| self.probe.faults.lock().unwrap().get(p).cloned()); + if let Some((wait, error)) = fault { + tokio::time::sleep(wait).await; + return Err(error); + } + self.inner.get_control(key, maximum).await + } + async fn put_control( + &self, + key: &str, + body: &[u8], + condition: &WriteCondition, + ) -> Result { + self.inner.put_control(key, body, condition).await + } + async fn list_raw_document( + &self, + prefix: &str, + token: Option<&str>, + maximum_keys: usize, + maximum_bytes: usize, + ) -> Result, Error> { + let _held = self.probe.all.enter(); + self.probe.pause().await; + self.inner + .list_raw_document(prefix, token, maximum_keys, maximum_bytes) + .await + } +} +impl IndexListing for Probed { + async fn list_index(&self, prefix: &str, token: Option<&str>) -> Result { + let _held = self.probe.all.enter(); + self.probe.pause().await; + self.inner.list_index(prefix, token).await + } +} + +type Transport = BoundedS3; +type Source = S3Source; +fn http(peer: &Peer) -> HttpS3Transport { + HttpS3Transport::new( + peer.endpoint(), + "server2-local", + "ap-northeast-2", + Credentials::new("server2-local", "server2-local-secret"), + ) + .unwrap() +} +/// A fresh source (empty forecast cache) whose S3 reads pass the probe inside a gate of `gate`. +fn source(peer: &Peer, probe: &Arc, gate: usize) -> (Arc, Transport) { + let transport = BoundedS3::new( + Probed { + inner: http(peer), + probe: probe.clone(), + }, + gate, + ); + let source = S3Source::new( + transport.clone(), + Arc::new(|| NOW), + Arc::new(DenyProviders::default()), + Arc::new(Unreachable), + ) + .unwrap(); + (Arc::new(source), transport) +} +fn grid(nx: u16) -> Grid { + Grid::new(nx, 127).unwrap() +} +/// Newest first from 2026-09-24 10:00 KST (NOW is 10:50). +fn hourly(n: usize) -> Vec { + let newest = schedule::to_ms(Publication::new(20260924, 1000).unwrap()); + (0..n) + .map(|h| schedule::from_ms(newest - h as i64 * HOUR_MS)) + .collect() +} +/// Partition ids in the order a read consumes them (ascending). +fn ascending(n: usize) -> Vec { + let mut parts: Vec = hourly(n).iter().map(|p| p.partition()).collect(); + parts.sort(); + parts +} +fn current_page(grid: Grid, p: Publication, t1h: f64) -> Vec { + let values = [ + ("PTY", "0".to_owned()), + ("REH", "60".to_owned()), + ("RN1", "0".to_owned()), + ("T1H", format!("{t1h:.1}")), + ("UUU", "1.2".to_owned()), + ("VEC", "200".to_owned()), + ("VVV", "-0.5".to_owned()), + ("WSD", "2.1".to_owned()), + ]; + let items: Vec<_> = values + .into_iter() + .map(|(category, value)| { + json!({"baseDate":p.base_date(),"baseTime":p.base_time(),"category":category, + "nx":grid.nx(),"ny":grid.ny(),"obsrValue":value}) + }) + .collect(); + serde_json::to_vec(&json!({"response":{"header":{"resultCode":"00","resultMsg":"NORMAL_SERVICE"}, + "body":{"dataType":"JSON","items":{"item":items},"pageNo":1,"numOfRows":999,"totalCount":items.len()}}})) + .unwrap() +} +/// One complete acquisition (pages in order) of a Current partition. +async fn publish( + store: &CatalogStore>, + grid: Grid, + p: Publication, + pages: &[Vec], +) { + let limits = CatalogLimits::default(); + let n = pages.len() as u32; + let mut records = Vec::new(); + let mut members = Vec::new(); + for (i, page) in pages.iter().enumerate() { + let record = RawRecord::new( + "data-go-kr", + "ultra-srt-ncst", + &grid.provider_key(), + p.period(), + (schedule::to_ms(p) + 45 * 60_000) as u64, + 200, + "application/json", + (n > 1).then_some(Pagination { + page: i as u32 + 1, + pages: n, + complete: true, + }), + page.clone().into(), + &limits.raw, + ) + .unwrap(); + members.push(GroupMember { + envelope: record.envelope.clone(), + catalogs: vec![ + CatalogId::for_record(&record.envelope.identity, &p.partition()).unwrap(), + ], + }); + records.push(record); + } + store + .publish( + GroupDeclaration::new(members, &limits).unwrap(), + records, + deadline(), + ) + .await + .unwrap(); +} +/// A peer holding `PARTITIONS` hourly Current partitions for each of `grids`. +async fn seeded(grids: &[Grid]) -> Peer { + let peer = Peer::persistent(); + let store = CatalogStore::new(peer.transport(), CatalogLimits::default()).unwrap(); + for &grid in grids { + for (h, p) in hourly(PARTITIONS).into_iter().enumerate() { + publish( + &store, + grid, + p, + &[current_page(grid, p, 15. + (h % 10) as f64)], + ) + .await; + } + } + peer +} +fn fcs(doc: &Doc) -> f64 { + match doc.get("fcsDate") { + Some(Val::Date(ms)) => *ms, + other => panic!("fcsDate {other:?}"), + } +} +async fn drained(probe: &Probe, within: Duration) -> usize { + let until = Instant::now() + within; + while probe.in_flight() != 0 && Instant::now() < until { + tokio::time::sleep(Duration::from_millis(5)).await; + } + probe.in_flight() +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn overlapped_lookups_read_every_partition_once_inside_the_gate() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60)]).await; + let probe = Arc::new(Probe::default()); + probe.delay_ms.store(10, SeqCst); + let (source, _) = source(&peer, &probe, GATE); + let started = Instant::now(); + let docs = source + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap(); + let elapsed = started.elapsed(); + assert_eq!( + docs.len(), + PARTITIONS, + "one Current Doc per hourly partition" + ); + assert!(docs.windows(2).all(|w| fcs(&w[0]) < fcs(&w[1]))); + let reads = probe.catalog_reads.lock().unwrap().clone(); + let mut once = reads.clone(); + once.sort(); + once.dedup(); + assert_eq!((reads.len(), once.len()), (PARTITIONS, PARTITIONS)); + assert_eq!( + source.forecast_cache_stats().parse_acquisitions, + PARTITIONS as u64 + ); + let peak = probe.all.peak.load(SeqCst); + assert!(peak <= GATE, "the process gate bounds every read: {peak}"); + let lookups = probe.catalogs.peak.load(SeqCst); + let sequential = Duration::from_millis(PARTITIONS as u64 * CHAIN * 10); + eprintln!( + "cold read: {PARTITIONS} partitions at 10 ms, peak lookups {lookups}, peak reads {peak}, \ + {elapsed:?} (sequential estimate {sequential:?})" + ); + assert!( + lookups >= 8, + "partition lookups must overlap: peak {lookups}" + ); + assert!( + elapsed <= sequential / 3, + "{elapsed:?} for a sequential estimate of {sequential:?}" + ); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn jittered_overlapped_reads_equal_one_operation_at_a_time() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60)]).await; + let (serial, _) = source(&peer, &Arc::new(Probe::default()), 1); + let expected = serial + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap(); + assert_eq!(expected.len(), PARTITIONS); + let probe = Arc::new(Probe::default()); + probe.jitter.store(0x9E37_79B9_7F4A_7C15, SeqCst); + let (source, _) = source(&peer, &probe, GATE); + let docs = source + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap(); + same( + &docs_json(&docs), + &docs_json(&expected), + "jittered overlapped read", + ); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn the_first_failing_partition_in_order_decides_the_answer() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60)]).await; + let parts = ascending(PARTITIONS); + let probe = Arc::new(Probe::default()); + probe.delay_ms.store(5, SeqCst); + // The earlier partition fails late; a later one fails at once. + probe.fault(&parts[20], Duration::from_millis(150), Error::Transport); + probe.fault( + &parts[25], + Duration::ZERO, + Error::Corrupt("injected later partition"), + ); + let (source, _) = source(&peer, &probe, GATE); + let error = source + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap_err(); + assert!( + error.contains("Transport") && !error.contains("Corrupt"), + "{error}" + ); + assert_eq!(drained(&probe, Duration::from_millis(500)).await, 0); + assert_eq!(source.forecast_cache_stats().mapped_entries, 0); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn a_catalog_vanished_after_listing_fails_the_view_as_before() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60)]).await; + let parts = ascending(PARTITIONS); + let probe = Arc::new(Probe::default()); + probe.fault(&parts[20], Duration::ZERO, Error::NotFound); + let (source, _) = source(&peer, &probe, GATE); + let error = source + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap_err(); + assert!(error.contains("incomplete catalog"), "{error}"); + assert_eq!(drained(&probe, Duration::from_millis(500)).await, 0); + assert_eq!(source.forecast_cache_stats().mapped_entries, 0); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn the_owner_deadline_drops_every_lookup_in_flight() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60)]).await; + let probe = Arc::new(Probe::default()); + // 1.2 s per partition: far more than the eight-second owner bound in total, each lookup + // inside its own three-second bound. + probe.delay_ms.store(400, SeqCst); + let (source, _) = source(&peer, &probe, GATE); + let started = Instant::now(); + let error = source + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap_err(); + assert!(started.elapsed() >= Duration::from_secs(7), "{error}"); + assert_eq!( + drained(&probe, Duration::from_millis(500)).await, + 0, + "no lookup outlives its owner" + ); + let until = Instant::now() + Duration::from_secs(2); + while source.forecast_cache_stats().active_workspace_logical_bytes != 0 + && Instant::now() < until + { + tokio::time::sleep(Duration::from_millis(10)).await; + } + let stats = source.forecast_cache_stats(); + assert_eq!( + (stats.mapped_entries, stats.active_workspace_logical_bytes), + (0, 0) + ); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn a_lookup_that_never_answers_times_out_and_stops_the_others() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60)]).await; + let parts = ascending(PARTITIONS); + let probe = Arc::new(Probe::default()); + probe.delay_ms.store(10, SeqCst); + probe.fault(&parts[20], Duration::from_secs(30), Error::Transport); + let (source, _) = source(&peer, &probe, GATE); + let error = source + .grid_answer(Family::Current, grid(60), NOW, deadline()) + .await + .unwrap_err(); + assert!(error.contains("Timeout"), "{error}"); + assert_eq!(drained(&probe, Duration::from_millis(500)).await, 0); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn two_cold_keys_share_the_gate_without_starving_another_reader() { + let _serial = S3_PEERS.lock().await; + let peer = seeded(&[grid(60), grid(61)]).await; + let mut expected = Vec::new(); + for nx in [60, 61] { + let (plain, _) = source(&peer, &Arc::new(Probe::default()), GATE); + expected.push( + plain + .grid_answer(Family::Current, grid(nx), NOW, deadline()) + .await + .unwrap(), + ); + } + let probe = Arc::new(Probe::default()); + probe.delay_ms.store(10, SeqCst); + let (source, transport) = source(&peer, &probe, GATE); + let builds: Vec<_> = [60, 61] + .into_iter() + .map(|nx| { + let source = source.clone(); + tokio::spawn(async move { + let docs = source + .grid_answer(Family::Current, grid(nx), NOW, deadline()) + .await; + (docs, Instant::now()) + }) + }) + .collect(); + tokio::time::sleep(Duration::from_millis(50)).await; + let asked = Instant::now(); + let foreign = transport + .get_control("index/v2/foreign/absent.json", 1024) + .await; + let answered = Instant::now(); + assert!(matches!(foreign, Err(Error::NotFound)), "{foreign:?}"); + for (build, expected) in builds.into_iter().zip(&expected) { + let (docs, finished) = build.await.unwrap(); + same( + &docs_json(&docs.unwrap()), + &docs_json(expected), + "concurrent cold key", + ); + assert!( + answered < finished, + "another reader waited for a whole cold build" + ); + } + assert!(answered - asked < Duration::from_millis(250)); + let peak = probe.all.peak.load(SeqCst); + assert!(peak <= GATE, "{peak}"); +} + +#[tokio::test(flavor = "multi_thread", worker_threads = 2)] +async fn a_partition_above_four_mebibytes_is_refused_for_capacity() { + let _serial = S3_PEERS.lock().await; + let peer = Peer::persistent(); + let store = CatalogStore::new(peer.transport(), CatalogLimits::default()).unwrap(); + let latest = hourly(1)[0]; + // Distinct 1 MiB pages (equal pages would share one member identity). + let pages: Vec> = (b'a'..=b'd').map(|b| vec![b; 1024 * 1024]).collect(); + publish(&store, grid(62), latest, &pages).await; + let mut above = pages.clone(); + above.push(b"e".to_vec()); + publish(&store, grid(63), latest, &above).await; + let (source, _) = source(&peer, &Arc::new(Probe::default()), GATE); + let at = source + .grid_answer(Family::Current, grid(62), NOW, deadline()) + .await; + assert!( + at.as_ref().err().is_none_or(|e| !e.contains("Capacity")), + "exactly 4 MiB is admitted: {at:?}" + ); + let above = source + .grid_answer(Family::Current, grid(63), NOW, deadline()) + .await + .unwrap_err(); + assert!(above.contains("Capacity"), "{above}"); +} From 85a1a09b16dcb4ca6ade1262df72128b2a066f39 Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 06:22:47 +0900 Subject: [PATCH 03/16] Keep an exact cached weight in each Doc (#2849) The fold re-weighed the whole retained collection on every store and the whole Doc on every bounded field set, so storing n Docs walked about n^2 Docs (256 Docs: 67,840 walks). - A Doc keeps its heap_weight in a Weight cell (0 = unknown; a real weight is at least 64). try_set stores the exact new weight from the stored key, value and Vec capacity after its unchanged projected check; set, remove and clones start unknown; a failed push leaves it unknown. Weight compares equal and Debug prints the previous form. - checked_store_with_limit and every caller now read cached weights: storing 256 Docs walks 768 Docs, 32 field sets walk once. - The logical weight of the same data grows by 8 bytes per Doc and per stored field (Doc carries the cell); limits and their arithmetic are unchanged. Tests: cached weights equal an independent full walk after random sets, refused sets, removes and clones; collection admission equals a full recomputation at limit - 1, limit and limit + 1; a walk counter shows linear stores and field sets (Red on the base: 67,840 walks). Co-Authored-By: Claude Opus 5.5 --- server2/src/domestic/kma/source/doc.rs | 264 ++++++++++++++++++++++--- 1 file changed, 242 insertions(+), 22 deletions(-) diff --git a/server2/src/domestic/kma/source/doc.rs b/server2/src/domestic/kma/source/doc.rs index af016c4c3..435da01f1 100644 --- a/server2/src/domestic/kma/source/doc.rs +++ b/server2/src/domestic/kma/source/doc.rs @@ -4,6 +4,7 @@ //! `{"$date": ms}` like every `KmaStore` answer. Key order never reaches a response (the readers //! project fixed fields) but answers keep it, as the S15 store contract requires. use crate::gateway::OrderedJson; +use std::sync::atomic::{AtomicUsize, Ordering}; /// The scalar parseInt semantics used by bounded grid/RSS builders, without allocating a /// bit vector proportional to an untrusted hexadecimal string. Significant hex values beyond @@ -148,9 +149,52 @@ impl From for Val { } } +#[cfg(test)] +thread_local! { + /// Docs whose fields `heap_weight` walked on this thread (tests only). + static WALKS: std::cell::Cell = const { std::cell::Cell::new(0) }; +} + +/// The backing allocations of one stored value (a Doc's cached weight is reused). +fn value_weight(v: &Val) -> Result { + use super::forecast_cache::{add, vector}; + Ok(match v { + Val::Str(s) => super::forecast_cache::allocation(s.capacity())?, + Val::Doc(d) => d.heap_weight()?, + Val::Arr(a) => { + let mut n = vector(a)?; + for v in a { + n = add(n, value_weight(v)?)?; + } + n + } + _ => 0, + }) +} +/// The exact `heap_weight` of a Doc once known; 0 is unknown (a real weight is at least 64). +/// A clone owns other capacities, so it starts unknown; the cache never affects equality. +/// Retained views share their Docs across threads, hence the atomic. +#[derive(Default)] +struct Weight(AtomicUsize); +impl Clone for Weight { + fn clone(&self) -> Self { + Self::default() + } +} +impl PartialEq for Weight { + fn eq(&self, _: &Self) -> bool { + true + } +} + /// An insertion-ordered document. -#[derive(Debug, Clone, Default, PartialEq)] -pub struct Doc(Vec<(String, Val)>); +#[derive(Clone, Default, PartialEq)] +pub struct Doc(Vec<(String, Val)>, Weight); +impl std::fmt::Debug for Doc { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.debug_tuple("Doc").field(&self.0).finish() + } +} impl Doc { /// Fallible cache-path copy; callers own an admitted parse/fold workspace. pub(super) fn checked_clone(&self) -> Result { @@ -206,47 +250,54 @@ impl Doc { .checked_mul(std::mem::size_of::<(String, Val)>()) .ok_or(Error::Capacity)?, )?; + let current = self.heap_weight()?; let projected = add( - add(self.heap_weight()? - old, extra)?, + add(current - old, extra)?, add(root - before, if is_new { allocation(k.len())? } else { 0 })?, )?; if projected > 8 * 1024 * 1024 { return Err(Error::Capacity); } let value = clone_val(v, 0)?; - if let Some((_, slot)) = self.0.iter_mut().find(|(key, _)| key == k) { + let stored = value_weight(&value)?; + // From the first mutation until the exact delta is stored, the weight is unknown: a + // failed push can leave a grown capacity behind. + *self.1.0.get_mut() = 0; + let weight = if let Some((_, slot)) = self.0.iter_mut().find(|(key, _)| key == k) { + let replaced = value_weight(slot)?; *slot = value; + add(current - replaced, stored)? } else { reserve(&mut self.0, 1)?; self.0.push((copied(k)?, value)); - } + let key = allocation(self.0.last().map_or(0, |(key, _)| key.capacity()))?; + add( + add(current, stored)?, + add(key, super::forecast_cache::vector(&self.0)? - before)?, + )? + }; + *self.1.0.get_mut() = weight; Ok(()) } - /// Backing allocations only: the containing Vec/Val already charges inline headers. + /// Backing allocations only: the containing Vec/Val already charges inline headers. Known + /// after the first walk or an exact `try_set`, until an unchecked change. pub(super) fn heap_weight(&self) -> Result { use super::forecast_cache::{add, allocation, vector}; - fn value(v: &Val) -> Result { - Ok(match v { - Val::Str(s) => allocation(s.capacity())?, - Val::Doc(d) => d.heap_weight()?, - Val::Arr(a) => { - let mut n = vector(a)?; - for v in a { - n = add(n, value(v)?)?; - } - n - } - _ => 0, - }) + let known = self.1.0.load(Ordering::Relaxed); + if known != 0 { + return Ok(known); } + #[cfg(test)] + WALKS.with(|w| w.set(w.get() + 1)); let mut n = vector(&self.0)?; for (k, v) in &self.0 { - n = add(n, add(allocation(k.capacity())?, value(v)?)?)?; + n = add(n, add(allocation(k.capacity())?, value_weight(v)?)?)?; } + self.1.0.store(n, Ordering::Relaxed); Ok(n) } pub fn new() -> Self { - Self(Vec::new()) + Self::default() } pub fn with(mut self, k: &str, v: Val) -> Self { self.set(k, v); @@ -260,6 +311,7 @@ impl Doc { } /// `$set` of one field: replaced in place, or appended. pub fn set(&mut self, k: &str, v: Val) { + *self.1.0.get_mut() = 0; match self.0.iter_mut().find(|(key, _)| key == k) { Some((_, slot)) => *slot = v, None => self.0.push((k.to_owned(), v)), @@ -267,6 +319,7 @@ impl Doc { } /// `$unset` / `delete`. pub fn remove(&mut self, k: &str) { + *self.1.0.get_mut() = 0; self.0.retain(|(key, _)| key != k); } pub fn keys(&self) -> impl Iterator { @@ -315,7 +368,7 @@ impl Row { super::forecast_cache::reserve(&mut fields, 32)?; Ok(Self { template, - own: Doc(fields), + own: Doc(fields, Weight::default()), }) } pub(super) fn heap_weight(&self) -> Result { @@ -537,4 +590,171 @@ mod tests { f64::INFINITY ); } + struct Rng(u64); + impl Rng { + fn next(&mut self, bound: u64) -> u64 { + self.0 ^= self.0 << 13; + self.0 ^= self.0 >> 7; + self.0 ^= self.0 << 17; + self.0 % bound + } + } + /// Any value, with varied string capacities, nested Docs and (rejected by `try_set`) arrays. + fn any_value(rng: &mut Rng, depth: usize) -> Val { + match rng.next(if depth < 2 { 7 } else { 5 }) { + 0 => Val::Num(rng.next(1000) as f64), + 1 => { + let mut s = String::with_capacity(rng.next(200) as usize); + for _ in 0..rng.next(40) { + s.push('x'); + } + Val::Str(s) + } + 2 => Val::Date(rng.next(1_000_000) as f64), + 3 => Val::Null, + 4 => Val::Bool(rng.next(2) == 0), + 5 => { + let mut d = Doc::new(); + for i in 0..rng.next(5) { + d.set(&format!("n{i}"), any_value(rng, depth + 1)); + } + Val::Doc(d) + } + _ => Val::Arr( + (0..rng.next(4)) + .map(|_| any_value(rng, depth + 1)) + .collect(), + ), + } + } + /// An independent full walk of the backing allocations: the oracle of every Doc weight. + fn fresh(doc: &Doc) -> usize { + use super::super::forecast_cache::{allocation, vector}; + fn value(v: &Val) -> usize { + match v { + Val::Str(s) => allocation(s.capacity()).unwrap(), + Val::Doc(d) => fresh(d), + Val::Arr(a) => vector(a).unwrap() + a.iter().map(value).sum::(), + _ => 0, + } + } + vector(&doc.0).unwrap() + + doc + .0 + .iter() + .map(|(k, v)| allocation(k.capacity()).unwrap() + value(v)) + .sum::() + } + #[test] + fn doc_weights_equal_a_full_walk_after_every_change() { + let mut rng = Rng(0x9E37_79B9_7F4A_7C15); + for _ in 0..300 { + let mut doc = Doc::new(); + for _ in 0..60 { + let key = format!("k{}", rng.next(40)); + match rng.next(7) { + // Refused sets (arrays, a 33rd field) must leave a correct weight too. + 0..=2 => { + let _ = doc.try_set(&key, &any_value(&mut rng, 0)); + } + 3 => doc.set(&key, any_value(&mut rng, 0)), + 4 => doc.remove(&key), + 5 => doc = doc.clone(), + _ => doc = doc.checked_clone().unwrap_or_else(|_| doc.clone()), + } + assert_eq!(doc.heap_weight().unwrap(), fresh(&doc)); + } + } + } + #[test] + fn collection_admission_equals_a_full_recomputation_at_every_limit() { + use super::super::forecast_cache::allocation; + fn scalar(rng: &mut Rng) -> Val { + loop { + let v = any_value(rng, 1); + if !matches!(v, Val::Arr(_)) { + break v; + } + } + } + let mut rng = Rng(0x2545_F491_4F6C_DD1D); + for _ in 0..300 { + let mut docs = Vec::new(); + for _ in 0..rng.next(12) { + let mut d = Doc::new(); + for i in 0..rng.next(6) { + d.try_set(&format!("f{i}"), &scalar(&mut rng)).unwrap(); + } + docs.push(d); + } + let mut doc = Doc::new(); + for i in 0..rng.next(6) { + doc.try_set(&format!("g{i}"), &scalar(&mut rng)).unwrap(); + } + let index = (!docs.is_empty() && rng.next(2) == 0) + .then(|| rng.next(docs.len() as u64) as usize); + for (delta, admitted) in [(-1_isize, false), (0, true), (1, true)] { + let mut target = docs.clone(); + let n = target.len() + usize::from(index.is_none()); + let exact = allocation(target.capacity().max(n) * std::mem::size_of::()) + .unwrap() + + target + .iter() + .enumerate() + .filter(|(i, _)| Some(*i) != index) + .map(|(_, d)| fresh(d)) + .sum::() + + fresh(&doc); + let before = target.clone(); + let result = checked_store_with_limit( + &mut target, + index, + doc.clone(), + exact.saturating_add_signed(delta), + ); + assert_eq!(result.is_ok(), admitted, "limit {delta:+} of {exact}"); + if !admitted { + assert_eq!(target, before); + } else if let Some(i) = index { + assert_eq!(target[i], doc); + } else { + assert_eq!(target.last(), Some(&doc)); + } + } + } + } + #[test] + fn stores_and_field_sets_walk_each_doc_a_bounded_number_of_times() { + fn walks() -> usize { + WALKS.with(std::cell::Cell::get) + } + fn store(n: usize) -> usize { + let start = walks(); + let mut docs = Vec::new(); + for i in 0..n { + let coord = Doc::new() + .with("mx", Val::Num(60.)) + .with("my", Val::Num(127.)); + let mut d = Doc::new(); + d.try_set("mCoord", &Val::Doc(coord)).unwrap(); + d.try_set("fcsDate", &Val::Date(i as f64)).unwrap(); + d.try_set("data", &Val::str(format!("value {i}"))).unwrap(); + checked_store(&mut docs, None, d).unwrap(); + } + walks() - start + } + let (small, large) = (store(64), store(256)); + assert!( + large <= 8 * 256, + "storing 256 Docs walked {large} Docs (64 Docs: {small})" + ); + let start = walks(); + let mut wide = Doc::new(); + for i in 0..32 { + wide.try_set(&format!("f{i}"), &Val::Num(i as f64)).unwrap(); + } + let sets = walks() - start; + eprintln!("Doc walks: 64 stores {small}, 256 stores {large}, 32 field sets {sets}"); + assert!(sets <= 2, "32 field sets walked the Doc {sets} times"); + } } From de76f37adb54f8fa5dca3099aafaebabbff2959f Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 06:33:06 +0900 Subject: [PATCH 04/16] Return the owner workspace before waking the next owner (#2849) Workspace declared its owner permit before its 192 MiB byte lease, so a retiring owner released the slot first. Tokio wakes the next owner inside that release and ByteBudget::reserve refuses rather than waits, so an owner woken on another worker could fail with Capacity while the old lease was still counted ("forecast cache: raw storage: Capacity", the four failures of base CI run 39243883911 and one local full-suite failure that passed alone). Declare the lease first: struct fields drop in declaration order. No size, owner, queue or waiter limit changes. Test: a waker registered by the next owner records the workspace in use at its wake-up; on the old order it saw 201,326,592 bytes, now 0. Co-Authored-By: Claude Opus 5.5 --- .../src/domestic/kma/source/forecast_cache.rs | 39 ++++++++++++++++++- 1 file changed, 38 insertions(+), 1 deletion(-) diff --git a/server2/src/domestic/kma/source/forecast_cache.rs b/server2/src/domestic/kma/source/forecast_cache.rs index 2a392ddba..14dba3737 100644 --- a/server2/src/domestic/kma/source/forecast_cache.rs +++ b/server2/src/domestic/kma/source/forecast_cache.rs @@ -241,9 +241,11 @@ impl Clone for Cache { Self(self.0.clone()) } } +/// Fields drop in declaration order: the bytes return before the owner slot wakes the next +/// owner, whose reservation refuses rather than waits. pub(super) struct Workspace { - _slot: OwnedSemaphorePermit, _bytes: ByteLease, + _slot: OwnedSemaphorePermit, } impl Cache { pub(super) fn new(reader: Reader) -> Result { @@ -939,6 +941,41 @@ mod tests { } } #[test] + fn an_owner_hand_off_returns_the_workspace_before_waking_the_next_owner() { + use std::future::Future; + use std::task::{Context, Wake, Waker}; + /// The workspace in use when the next owner is woken, inside the slot release. + struct Observe(Arc, Mutex>); + impl Wake for Observe { + fn wake(self: Arc) { + self.wake_by_ref(); + } + fn wake_by_ref(self: &Arc) { + *self.1.lock().unwrap() = Some(self.0.used()); + } + } + let owners = Arc::new(Semaphore::new(1)); + let budget = ByteBudget::new(WORKSPACE).unwrap(); + let workspace = Workspace { + _slot: owners.clone().try_acquire_owned().unwrap(), + _bytes: budget.reserve(WORKSPACE).unwrap(), + }; + let observe = Arc::new(Observe(budget.clone(), Mutex::new(None))); + let waker = Waker::from(observe.clone()); + let mut next = Box::pin(owners.clone().acquire_owned()); + assert!( + next.as_mut() + .poll(&mut Context::from_waker(&waker)) + .is_pending() + ); + drop(workspace); + assert_eq!( + *observe.1.lock().unwrap(), + Some(0), + "the woken owner must find the previous workspace returned" + ); + } + #[test] fn freshness_clips_monotonic_wall_minute_and_future_equality() { let mut view = empty(); let now = view.wall; From 8946cecd899228b8585bfc2c16de3fd6f1b20321 Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 06:46:17 +0900 Subject: [PATCH 05/16] Compare grid row text without copying it (#2849) A profile of the empty-cache build after the previous changes put about 200 of 1,150 build_view samples in Row::get string copies, their allocation and frees (find_or_create per item, complete per expected time and row), and 45 in js_number of the grid coordinate per item. - Row::str_ref borrows the string Row::get reads (own value, or the template string unless it needs the value layer's canonical form). - find_or_create and valid compare date and time through it; complete compares a row's date + time with the expected stamp without building it; row_at stays where a set needs the owned stamp. - raw_items_checked formats the coordinate once per acquisition and compares the publication without a per-item string. Tests: rows found exactly as through Row::get (own, template, numeric and stand-in values; written before the change); str_ref and the borrowed stamp comparison equal the copied reads. The isolated smoke keeps 13/13 golden Docs and the reference HTTP body. Co-Authored-By: Claude Opus 5.5 --- server2/src/domestic/kma/source/doc.rs | 16 ++++ server2/src/domestic/kma/source/grid.rs | 112 ++++++++++++++++++++---- 2 files changed, 109 insertions(+), 19 deletions(-) diff --git a/server2/src/domestic/kma/source/doc.rs b/server2/src/domestic/kma/source/doc.rs index 435da01f1..2762d86f6 100644 --- a/server2/src/domestic/kma/source/doc.rs +++ b/server2/src/domestic/kma/source/doc.rs @@ -410,6 +410,22 @@ impl Row { _ => String::new(), } } + /// The string [`Self::get`] reads, without copying it: a template string is borrowed unless + /// it needs the value layer's canonical form ([`Val::str`]). + pub(super) fn str_ref(&self, k: &str) -> Option> { + use std::borrow::Cow; + match self.own.get(k) { + Some(Val::Str(s)) => Some(Cow::Borrowed(s)), + Some(_) => None, + None => match self.template.iter().find(|(name, _)| *name == k) { + Some((_, Tmpl::Str(s))) if s.as_bytes().contains(&0xF4) => { + Some(Cow::Owned(crate::domestic::kma::js::canon_str(s))) + } + Some((_, Tmpl::Str(s))) => Some(Cow::Borrowed(s)), + _ => None, + }, + } + } pub fn set(&mut self, k: &str, v: Val) { self.own.set(k, v); } diff --git a/server2/src/domestic/kma/source/grid.rs b/server2/src/domestic/kma/source/grid.rs index 20ec74ee8..2aa04e581 100644 --- a/server2/src/domestic/kma/source/grid.rs +++ b/server2/src/domestic/kma/source/grid.rs @@ -250,9 +250,12 @@ fn fields(family: Family, at: &(String, String), slot: &Slot) -> Vec<&'static st } list } +/// The row's `date` and `time` strings, as [`Row::get`] reads them, equal these. +fn row_is(row: &Row, date: &str, time: &str) -> bool { + row.str_ref("date").as_deref() == Some(date) && row.str_ref("time").as_deref() == Some(time) +} fn valid(row: &Row, family: Family, at: &(String, String), slot: &Slot) -> bool { - row.get("date").as_ref().and_then(Val::as_str) == Some(at.0.as_str()) - && row.get("time").as_ref().and_then(Val::as_str) == Some(at.1.as_str()) + row_is(row, &at.0, &at.1) && fields(family, at, slot) .into_iter() .all(|f| accepts(f, row.get(f).as_ref())) @@ -280,6 +283,12 @@ fn canonical(family: Family, publication: &str) -> String { fn row_at(row: &Row) -> String { row.text("date") + &row.text("time") } +/// `row_at(row) == key` without building the row's stamp. +fn row_at_is(row: &Row, key: &str) -> bool { + let date = row.str_ref("date").unwrap_or_default(); + let time = row.str_ref("time").unwrap_or_default(); + key.len() == date.len() + time.len() && key.starts_with(&*date) && key.ends_with(&*time) +} /// `trailing(product, slot, row)`. fn trailing(family: Family, slot: &Slot, row: &Row, times: &[(String, String)]) -> bool { let Some(last) = times.last() else { @@ -292,10 +301,10 @@ fn trailing(family: Family, slot: &Slot, row: &Row, times: &[(String, String)]) fn complete(family: Family, slot: &Slot, rows: &[Row], times: &[(String, String)]) -> bool { times.iter().all(|at| { let key = format!("{}{}", at.0, at.1); - rows.iter().any(|r| row_at(r) == key) + rows.iter().any(|r| row_at_is(r, &key)) && rows .iter() - .filter(|r| row_at(r) == key) + .filter(|r| row_at_is(r, &key)) .all(|r| valid(r, family, at, slot)) }) } @@ -329,6 +338,9 @@ fn raw_items_checked( slots .try_reserve(times.len()) .map_err(|_| crate::storage::Error::Capacity)?; + // The same for every item: the coordinate text and, once seen, the echoed publication. + let nx = crate::gateway::response::js_number(coord.mx); + let ny = crate::gateway::response::js_number(coord.my); let mut echoed: Option = None; for item in items { let part = |k| item.get(k).unwrap_or("undefined"); @@ -337,20 +349,24 @@ fn raw_items_checked( if date.len().checked_add(time.len()) != Some(12) { return Ok(false); } - let mut publication = String::new(); - publication - .try_reserve_exact(12) - .map_err(|_| crate::storage::Error::Capacity)?; - publication.push_str(date); - publication.push_str(time); - if !ids.contains(&publication) - || echoed.as_ref().is_some_and(|p| p != &publication) - || Some(crate::gateway::response::js_number(coord.mx)).as_deref() != item.get("nx") - || Some(crate::gateway::response::js_number(coord.my)).as_deref() != item.get("ny") + // `date + time`, compared without building it. + let publication = |p: &str| p.len() == 12 && p.starts_with(date) && p.ends_with(time); + if !ids.iter().any(|id| publication(id)) + || echoed.as_deref().is_some_and(|p| !publication(p)) + || Some(nx.as_str()) != item.get("nx") + || Some(ny.as_str()) != item.get("ny") { return Ok(false); } - echoed.get_or_insert(publication); + if echoed.is_none() { + let mut first = String::new(); + first + .try_reserve_exact(12) + .map_err(|_| crate::storage::Error::Capacity)?; + first.push_str(date); + first.push_str(time); + echoed = Some(first); + } let category = item.get("category").unwrap_or("undefined"); let at = (part("fcstDate"), part("fcstTime")); if !times.iter().any(|t| t.0 == at.0 && t.1 == at.1) { @@ -542,10 +558,7 @@ fn find_or_create<'a>( time: &str, limits: Option<&mut RowLimits>, ) -> Result<&'a mut Row, crate::storage::Error> { - if let Some(i) = list.iter().position(|r| { - r.get("date").as_ref().and_then(Val::as_str) == Some(date) - && r.get("time").as_ref().and_then(Val::as_str) == Some(time) - }) { + if let Some(i) = list.iter().position(|r| row_is(r, date, time)) { return Ok(&mut list[i]); } let row = if let Some(limits) = limits { @@ -1168,6 +1181,67 @@ impl GridDocs { mod bounded_tests { use super::*; #[test] + fn rows_are_found_by_their_date_and_time_as_get_reads_them() { + let mut rows = vec![Row::new(CURRENT_TEMPLATE); 4]; + rows[0].set("date", Val::str("20260924")); + rows[0].set("time", Val::str("1000")); + // rows[1] keeps the template's empty date and time. + rows[2].set("date", Val::Num(20260924.)); + rows[2].set("time", Val::str("1000")); + rows[3].set("date", Val::checked_str("\u{10F800}").unwrap()); + rows[3].set("time", Val::str("1100")); + let canonical = rows[3].text("date"); + let found = |rows: &mut Vec, date: &str, time: &str| { + let n = rows.len(); + find_or_create(rows, CURRENT_TEMPLATE, date, time, None) + .unwrap() + .set("mark", Val::Num(1.)); + let at = rows.iter().position(|r| r.has_own("mark")).unwrap(); + rows[at].delete("mark"); + (at, rows.len() - n) + }; + assert_eq!(found(&mut rows, "20260924", "1000"), (0, 0)); + assert_eq!(found(&mut rows, "", ""), (1, 0)); + assert_eq!(found(&mut rows, &canonical, "1100"), (3, 0)); + // A raw stand-in key never equals its canonical stored form; a number is not text. + assert_eq!(found(&mut rows, "\u{10F800}", "1100"), (4, 1)); + assert_eq!(found(&mut rows, "20260924", "1100"), (5, 1)); + } + #[test] + fn borrowed_row_text_equals_the_copied_reads() { + const STAND_IN: &[(&str, Tmpl)] = &[ + ("date", Tmpl::Str("\u{10F800}")), + ("time", Tmpl::Str("0900")), + ("mx", Tmpl::Num(1.)), + ]; + let mut rows = vec![Row::new(CURRENT_TEMPLATE), Row::new(STAND_IN)]; + rows[0].set("date", Val::str("2026092")); + rows[0].set("time", Val::str("41500")); + let mut number = Row::new(STAND_IN); + number.set("date", Val::Num(1.)); + rows.push(number); + for row in &rows { + for key in ["date", "time", "mx", "pubDate", "absent"] { + assert_eq!( + row.str_ref(key).as_deref(), + row.get(key).as_ref().and_then(Val::as_str), + "{key}" + ); + } + for stamp in [ + "202609241500", + "20260924", + "1500", + "", + "\u{10F800}0900", + &crate::domestic::kma::js::canon_str("\u{10F800}0900"), + "0900", + ] { + assert_eq!(row_at_is(row, stamp), row_at(row) == stamp, "{stamp:?}"); + } + } + } + #[test] fn canonicalization_mismatch_still_respects_the_item_count_row_reservation() { const ITEMS: usize = 64; let raw = "\u{10F800}"; From 79d798c5bdf3b1a77b5d058cf56f02f6c372e9c4 Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 07:04:01 +0900 Subject: [PATCH 06/16] Report when cut cold builds actually finish (#2849) A cold or aged request cut by the 3-second native deadline leaves its forecast owners building until their 8-second bound, so a 502 alone does not show how far the build was from fitting. - The smoke example waits, outside the request timing, until the owners started by a cold or aged request are idle and records views_ready_ms; the S3 counters then include the whole build. - cold_build_matrix.py reports the ready time (median, p95, runs that were not ready after 10 s) and the mapped views per cell. Test: summary of ready times and not-ready runs (written first). Co-Authored-By: Claude Opus 5.5 --- server2/examples/domestic_warm_cache_smoke.rs | 20 ++++++++++++++++++- server2/tools/cold_build_matrix.py | 19 +++++++++++++++--- server2/tools/test_cold_build_matrix.py | 20 +++++++++++++++---- 3 files changed, 51 insertions(+), 8 deletions(-) diff --git a/server2/examples/domestic_warm_cache_smoke.rs b/server2/examples/domestic_warm_cache_smoke.rs index 5ef70b2d5..dbb6c89e6 100644 --- a/server2/examples/domestic_warm_cache_smoke.rs +++ b/server2/examples/domestic_warm_cache_smoke.rs @@ -748,6 +748,24 @@ async fn http(endpoint: &str, manifest: &Path, phases: &[&str]) { } .await; let elapsed = start.elapsed().as_secs_f64() * 1000.; + // Outside the request timing: an answer cut by the 3-second deadline leaves its owners + // building (until their 8-second bound). Wait until they are idle, so the record shows + // when the views were ready and the counters hold their whole reads. + let views_ready_ms = if phase == "cold" || phase == "aged" { + let until = start + Duration::from_secs(10); + loop { + let state = source.forecast_cache_stats(); + if state.active_owners == 0 && state.queued_keys == 0 && state.admitted_keys == 0 { + break Some(start.elapsed().as_secs_f64() * 1000.); + } + if Instant::now() >= until { + break None; + } + tokio::time::sleep(Duration::from_millis(5)).await; + } + } else { + None + }; let after = status(endpoint).await; let cache_after = source.forecast_cache_stats(); let outcome = match result { @@ -794,7 +812,7 @@ async fn http(endpoint: &str, manifest: &Path, phases: &[&str]) { } println!( "{}", - json!({"mode":"normal-native-direct-HTTP","phase":phase,"deadline_seconds":3,"client_timeout_seconds":10,"elapsed_ms":elapsed,"outcome":outcome,"status_before":before,"status_after":after,"forecast_cache_before":cache_before,"forecast_cache_after":cache_after,"provider_stub_invocations":denied_after[0],"denied_observation_web_total":denied_after[1],"denied_observation_asos_total":denied_after[2],"denied_observation_delta":{"aggregate":denied_delta[0],"web":denied_delta[1],"asos":denied_delta[2]},"provider_external_calls":0,"external_provider_guard":"injected Off methods return Transport without an HTTP client","geocoder_stub_invocations":geo.0.load(Ordering::SeqCst),"source_prewarmed":false,"native_latency_pass":false,"baseline_context":"original native baseline aggregate cold196/warm additional0; family split previously not measured"}) + json!({"mode":"normal-native-direct-HTTP","phase":phase,"deadline_seconds":3,"client_timeout_seconds":10,"elapsed_ms":elapsed,"views_ready_ms":views_ready_ms,"outcome":outcome,"status_before":before,"status_after":after,"forecast_cache_before":cache_before,"forecast_cache_after":cache_after,"provider_stub_invocations":denied_after[0],"denied_observation_web_total":denied_after[1],"denied_observation_asos_total":denied_after[2],"denied_observation_delta":{"aggregate":denied_delta[0],"web":denied_delta[1],"asos":denied_delta[2]},"provider_external_calls":0,"external_provider_guard":"injected Off methods return Transport without an HTTP client","geocoder_stub_invocations":geo.0.load(Ordering::SeqCst),"source_prewarmed":false,"native_latency_pass":false,"baseline_context":"original native baseline aggregate cold196/warm additional0; family split previously not measured"}) ); // Stop after the first actual failure; preserve it and retire owned work before root // diagnosis. No later warm success can turn a failed cold request into acceptance. diff --git a/server2/tools/cold_build_matrix.py b/server2/tools/cold_build_matrix.py index f2f584e09..998ea999a 100644 --- a/server2/tools/cold_build_matrix.py +++ b/server2/tools/cold_build_matrix.py @@ -5,7 +5,8 @@ and run each binary's `http` (fresh process: cold, warm1, warm2) and `aged` (cold, then a rebuild after the 30-second freshness) modes, interleaved. The peer delays every GET/HEAD/LIST by the modeled milliseconds; seeding runs without delay. Bodies are kept -per run and compared with the reference hash. Works on Linux and macOS; no provider, +per run and compared with the reference hash. A cold or aged answer cut by the 3-second +deadline leaves its owners building; the example reports when they were idle (views ready). Works on Linux and macOS; no provider, credential or AWS access. """ import argparse @@ -72,7 +73,8 @@ def phase_rows(stdout_text, labels, classify): before, after = record['forecast_cache_before'], record['forecast_cache_after'] rows.append({'phase': record['phase'], 'status': outcome.get('http_status'), 'transport_error': outcome.get('transport_error'), - 'elapsed_ms': record['elapsed_ms'], 'sha256': outcome.get('sha256'), + 'elapsed_ms': record['elapsed_ms'], 'views_ready_ms': record.get('views_ready_ms'), + 'mapped': after.get('mapped_entries'), 'sha256': outcome.get('sha256'), 'bytes': outcome.get('bytes'), 'forecast_io': forecast, 'other_io_operations': sum(unknown.values()), 'parses': after['parse_acquisitions'] - before['parse_acquisitions'], @@ -90,6 +92,10 @@ def summarize(rows, reference): for (binary, mode, delay, phase), group in sorted(groups.items()): ok = [r for r in group if r['status'] == 200] times = [r['elapsed_ms'] for r in group] + # Cold and aged answers leave owners building after a cut answer: when the views were ready. + rebuilt = phase in ('cold', 'aged') + ready = [r['views_ready_ms'] for r in group if rebuilt and r.get('views_ready_ms') is not None] + mapped = [r['mapped'] for r in group if r.get('mapped') is not None] summary.append({ 'binary': binary, 'mode': mode, 'delay_ms': delay, 'phase': phase, 'runs': len(group), 'status_counts': {str(s): sum(1 for r in group if r['status'] == s) @@ -98,6 +104,10 @@ def summarize(rows, reference): 'min_ms': min(times), 'max_ms': max(times), 'ok_median_ms': statistics.median([r['elapsed_ms'] for r in ok]) if ok else None, 'hash_mismatches': sum(1 for r in ok if r['sha256'] != reference), + 'ready_runs': len(ready), 'not_ready_runs': sum(1 for r in group if rebuilt and r.get('views_ready_ms') is None), + 'ready_median_ms': statistics.median(ready) if ready else None, + 'ready_p95_ms': percentile(ready, 0.95) if ready else None, + 'mapped_median': statistics.median(mapped) if mapped else None, 'forecast_io_median': {c: statistics.median(r['forecast_io'][c] for r in group) for c in IO_CLASSES}, }) return summary @@ -150,6 +160,8 @@ def child(binary, endpoint, mode, manifest, directory): def main(): + # A stopped run still reaps its children and peer (the `finally` blocks below). + signal.signal(signal.SIGTERM, lambda *_: sys.exit(143)) parser = argparse.ArgumentParser(description=__doc__) parser.add_argument('--binary', type=parse_binary, action='append', required=True, help='NAME=PATH of a copied domestic_warm_cache_smoke executable; first one seeds') @@ -216,8 +228,9 @@ def main(): (output/'matrix.json').write_text(json.dumps({'inputs': inputs, 'rows': rows, 'summary': summary, 'problems': found, 'peer_exit': peer.returncode}, indent=2)+'\n') for s in summary: + ready = '' if s['ready_median_ms'] is None else f" views ready {s['ready_median_ms']:.0f} ms ({s['ready_runs']}/{s['runs']}, {s['mapped_median']} mapped)" print(f"{s['binary']:>10} {s['mode']:>4} {s['delay_ms']:>3}ms {s['phase']:>5} status {s['status_counts']}" - f" median {s['median_ms']:.0f} ms p95 {s['p95_ms']:.0f} ms forecast GET {s['forecast_io_median']}") + f" median {s['median_ms']:.0f} ms p95 {s['p95_ms']:.0f} ms{ready} forecast GET {s['forecast_io_median']}") for problem in found: print('PROBLEM', problem) return 1 if found else 0 diff --git a/server2/tools/test_cold_build_matrix.py b/server2/tools/test_cold_build_matrix.py index 9e01384dc..7e76bd561 100644 --- a/server2/tools/test_cold_build_matrix.py +++ b/server2/tools/test_cold_build_matrix.py @@ -19,16 +19,16 @@ } -def record(phase, status=200, sha=REFERENCE, elapsed=100.0, ops=None, parses=(0, 0)): +def record(phase, status=200, sha=REFERENCE, elapsed=100.0, ops=None, parses=(0, 0), ready=None, mapped=7): after = {'OP GET index/v2/data-go-kr/vilage-fcst/k/20260924-0500.json': 2, 'OP GET index/v2/groups/g1.json': 3, 'OP GET raw/v2/data-go-kr/vilage-fcst/a.raw.gz': 4, 'OP LIST index/v2/data-go-kr/vilage-fcst/k/202609': 1, 'OP GET raw/v2/data-go-kr/forecast-zone/z.raw.gz': 5, 'OP GET index/v2/kasi/unknown.json': 6} after.update(ops or {}) outcome = {'http_status': status, 'sha256': sha, 'bytes': 42549} if status else {'transport_error': 'timed out'} - return {'phase': phase, 'elapsed_ms': elapsed, 'outcome': outcome, 'status_before': {}, 'status_after': after, - 'forecast_cache_before': {'parse_acquisitions': parses[0], 'folds': 0}, - 'forecast_cache_after': {'parse_acquisitions': parses[1], 'folds': 7}} + return {'phase': phase, 'elapsed_ms': elapsed, 'views_ready_ms': ready, 'outcome': outcome, 'status_before': {}, + 'status_after': after, 'forecast_cache_before': {'parse_acquisitions': parses[0], 'folds': 0}, + 'forecast_cache_after': {'parse_acquisitions': parses[1], 'folds': 7, 'mapped_entries': mapped}} def rows_of(binary, mode, delay, run, records): @@ -74,6 +74,18 @@ def test_summary_keeps_statuses_times_and_answer_identity(self): self.assertEqual(summary[('cand', 'cold')]['hash_mismatches'], 1) self.assertEqual(d2['forecast_io_median']['GET_raw'], 4) + def test_ready_times_report_how_long_the_views_really_took(self): + rows = [] + for run, (status, ready, mapped) in enumerate([(502, 3400.0, 7), (502, 3600.0, 7), (502, None, 2)], 1): + rows += rows_of('c', 'aged', 10, run, [record('cold', status=status, elapsed=3002.0, sha='x', ready=ready, + mapped=mapped)]) + [s] = matrix.summarize(rows, REFERENCE) + self.assertEqual((s['ready_runs'], s['ready_median_ms'], s['ready_p95_ms']), (2, 3500.0, 3600.0)) + self.assertEqual(s['not_ready_runs'], 1, 'owners still busy after 10 s are counted, not dropped') + self.assertEqual(s['mapped_median'], 7) + [warm] = matrix.summarize(rows_of('c', 'http', 0, 1, [record('warm1')]), REFERENCE) + self.assertEqual((warm['ready_runs'], warm['not_ready_runs'], warm['ready_median_ms']), (0, 0, None)) + def test_problems_are_harness_integrity_not_measured_failures(self): complete = rows_of('c', 'http', 0, 1, [record('cold'), record('warm1'), record('warm2')]) measured_502 = rows_of('d2', 'http', 10, 1, [record('cold', status=502, sha='x')]) From 885c26bed173b8eb52fbc19cab827c9c076fc8bb Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 07:22:01 +0900 Subject: [PATCH 07/16] Measure the aged rebuild after a cut cold request (#2849) At 10 and 20 ms both builds missed the 3-second deadline on the cold request, and the example stopped the aged run there, so the rebuild in a warm process (forecast views stale after 30 seconds) was never measured. That rebuild is the common empty-cache case: about 2,230 forecast S3 operations and about 20 others, against about 1,400 other operations in a fresh process. - An aged run still makes its rebuild request after a cut cold one; the run stays failed and the matrix accepts that order only there. - The matrix counts unlabelled S3 operations and returned bytes separately (it had summed both into one operation count) and reports their median per cell. Co-Authored-By: Claude Opus 5.5 --- server2/examples/domestic_warm_cache_smoke.rs | 4 +++- server2/tools/cold_build_matrix.py | 7 +++++-- server2/tools/test_cold_build_matrix.py | 13 ++++++++++--- 3 files changed, 18 insertions(+), 6 deletions(-) diff --git a/server2/examples/domestic_warm_cache_smoke.rs b/server2/examples/domestic_warm_cache_smoke.rs index dbb6c89e6..28776ceca 100644 --- a/server2/examples/domestic_warm_cache_smoke.rs +++ b/server2/examples/domestic_warm_cache_smoke.rs @@ -816,7 +816,9 @@ async fn http(endpoint: &str, manifest: &Path, phases: &[&str]) { ); // Stop after the first actual failure; preserve it and retire owned work before root // diagnosis. No later warm success can turn a failed cold request into acceptance. - if !complete { + // The aged rebuild still runs after a cut cold request: the cold owners finish in the + // background, and the run stays failed. + if !complete && !(phase == "cold" && phases.contains(&"aged")) { break; } } diff --git a/server2/tools/cold_build_matrix.py b/server2/tools/cold_build_matrix.py index 998ea999a..c216773d0 100644 --- a/server2/tools/cold_build_matrix.py +++ b/server2/tools/cold_build_matrix.py @@ -76,7 +76,8 @@ def phase_rows(stdout_text, labels, classify): 'elapsed_ms': record['elapsed_ms'], 'views_ready_ms': record.get('views_ready_ms'), 'mapped': after.get('mapped_entries'), 'sha256': outcome.get('sha256'), 'bytes': outcome.get('bytes'), 'forecast_io': forecast, - 'other_io_operations': sum(unknown.values()), + 'other_io_operations': sum(v for k, v in unknown.items() if k.startswith('OP ')), + 'other_io_bytes': sum(v for k, v in unknown.items() if k.startswith('BODYOUT ')), 'parses': after['parse_acquisitions'] - before['parse_acquisitions'], 'folds': after['folds'] - before['folds']}) return rows @@ -109,6 +110,7 @@ def summarize(rows, reference): 'ready_p95_ms': percentile(ready, 0.95) if ready else None, 'mapped_median': statistics.median(mapped) if mapped else None, 'forecast_io_median': {c: statistics.median(r['forecast_io'][c] for r in group) for c in IO_CLASSES}, + 'other_io_median': statistics.median(r['other_io_operations'] for r in group), }) return summary @@ -125,7 +127,8 @@ def problems(rows, exits, reference): found.append(f'{where}: phases {list(phases)}, exit {code}') continue failed = [r for r in mine if r['status'] != 200] - if failed and failed[0] is not mine[-1]: + # Only the aged rebuild runs after a cut cold request (the example's rule). + if failed and failed[0] is not mine[-1] and not (mode == 'aged' and failed[0]['phase'] == 'cold'): found.append(f'{where}: continued after a failed {failed[0]["phase"]}') if not failed and (code != 0 or len(phases) < len(MODES[mode])): found.append(f'{where}: exit {code} after {list(phases)} all 200') diff --git a/server2/tools/test_cold_build_matrix.py b/server2/tools/test_cold_build_matrix.py index 7e76bd561..718b86f8e 100644 --- a/server2/tools/test_cold_build_matrix.py +++ b/server2/tools/test_cold_build_matrix.py @@ -23,7 +23,8 @@ def record(phase, status=200, sha=REFERENCE, elapsed=100.0, ops=None, parses=(0, after = {'OP GET index/v2/data-go-kr/vilage-fcst/k/20260924-0500.json': 2, 'OP GET index/v2/groups/g1.json': 3, 'OP GET raw/v2/data-go-kr/vilage-fcst/a.raw.gz': 4, 'OP LIST index/v2/data-go-kr/vilage-fcst/k/202609': 1, - 'OP GET raw/v2/data-go-kr/forecast-zone/z.raw.gz': 5, 'OP GET index/v2/kasi/unknown.json': 6} + 'OP GET raw/v2/data-go-kr/forecast-zone/z.raw.gz': 5, 'OP GET index/v2/kasi/unknown.json': 6, + 'BODYOUT GET index/v2/kasi/unknown.json': 900} after.update(ops or {}) outcome = {'http_status': status, 'sha256': sha, 'bytes': 42549} if status else {'transport_error': 'timed out'} return {'phase': phase, 'elapsed_ms': elapsed, 'views_ready_ms': ready, 'outcome': outcome, 'status_before': {}, @@ -55,6 +56,7 @@ def test_phase_rows_separate_forecast_io_from_support_and_other_reads(self): [row] = rows_of('cand', 'http', 10, 1, [record('cold', parses=(10, 735))]) self.assertEqual(row['forecast_io'], {'LIST': 1, 'GET_catalog': 2, 'GET_descriptor': 3, 'GET_raw': 4}) self.assertEqual(row['other_io_operations'], 6, 'unlabelled reads are kept, not hidden') + self.assertEqual(row['other_io_bytes'], 900, 'returned bytes are not operations') self.assertEqual((row['parses'], row['folds']), (725, 7)) self.assertEqual((row['status'], row['sha256'], row['bytes']), (200, REFERENCE, 42549)) [failed] = rows_of('cand', 'http', 10, 1, [record('cold', status=None)]) @@ -73,6 +75,7 @@ def test_summary_keeps_statuses_times_and_answer_identity(self): self.assertEqual(d2['hash_mismatches'], 0, 'a failed answer is not an identity mismatch') self.assertEqual(summary[('cand', 'cold')]['hash_mismatches'], 1) self.assertEqual(d2['forecast_io_median']['GET_raw'], 4) + self.assertEqual(d2['other_io_median'], 6) def test_ready_times_report_how_long_the_views_really_took(self): rows = [] @@ -96,12 +99,16 @@ def test_problems_are_harness_integrity_not_measured_failures(self): 'all 200 but failed exit': (rows_of('c', 'aged', 0, 1, [record('cold'), record('aged')]), 101), 'timeout after 200': (rows_of('c', 'aged', 0, 1, [record('cold')]), 'TIMEOUT'), 'wrong body': (rows_of('c', 'aged', 0, 1, [record('cold'), record('aged', sha='e' * 64)]), 0), - 'continued after failure': (rows_of('c', 'aged', 0, 1, [record('cold', status=502), record('aged')]), 101), + 'continued after failure': (rows_of('c', 'http', 0, 1, [record('cold', status=502), record('warm1')]), 101), 'phase order': (rows_of('c', 'aged', 0, 1, [record('aged'), record('cold')]), 0), } for name, (rows, code) in cases.items(): with self.subTest(name): - self.assertTrue(matrix.problems(rows, {('c', 'aged', 0, 1): code}, REFERENCE), name) + mode = rows[0]['mode'] if rows else 'aged' + self.assertTrue(matrix.problems(rows, {('c', mode, 0, 1): code}, REFERENCE), name) + # An aged rebuild after a cut cold request is the measured scenario, not a problem. + cut = rows_of('c', 'aged', 10, 1, [record('cold', status=502, sha='x'), record('aged', status=502, sha='y')]) + self.assertEqual(matrix.problems(cut, {('c', 'aged', 10, 1): 101}, REFERENCE), []) if __name__ == '__main__': From 54aad5935a0bfb6bb0f6f670677827e6b112c02f Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 08:05:00 +0900 Subject: [PATCH 08/16] Keep the matrix report when a run stops early (#2849) The first complete local matrix ran every cell but lost its report: the final latency reset failed with "Can't assign requested address" (local ports exhausted at that moment) and the tool exited before writing matrix.json. The reset was unnecessary because the peer stops right after. An exception inside the run loop now ends the loop, and the report keeps every finished run with a "stopped early" problem (exit 1). The reset is gone. Co-Authored-By: Claude Opus 5.5 --- server2/tools/cold_build_matrix.py | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/server2/tools/cold_build_matrix.py b/server2/tools/cold_build_matrix.py index c216773d0..bce36dbd0 100644 --- a/server2/tools/cold_build_matrix.py +++ b/server2/tools/cold_build_matrix.py @@ -189,7 +189,7 @@ def main(): (output/'inputs.json').write_text(json.dumps(inputs, indent=2)+'\n') peer = subprocess.Popen([sys.executable, 'tests/storage/catalog_peer.py', '--persistent'], cwd=SERVER2, stdout=subprocess.PIPE, stderr=(output/'peer.stderr').open('w'), text=True) - rows, exits = [], {} + rows, exits, stopped = [], {}, None try: ready, _, _ = select.select([peer.stdout], [], [], 5) if not ready: @@ -218,7 +218,9 @@ def main(): 'phases': {r['phase']: [r['status'], round(r['elapsed_ms'])] for r in rows if (r['binary'], r['mode'], r['delay_ms'], r['run']) == (name, mode, delay, run)}}), flush=True) - latency(endpoint, 0) + except Exception as error: + # Keep every finished run: the report below still covers them. + stopped = repr(error) finally: peer.terminate() try: @@ -227,7 +229,7 @@ def main(): peer.kill() peer.wait() summary = summarize(rows, args.reference) - found = problems(rows, exits, args.reference) + found = problems(rows, exits, args.reference) + ([f'stopped early: {stopped}'] if stopped else []) (output/'matrix.json').write_text(json.dumps({'inputs': inputs, 'rows': rows, 'summary': summary, 'problems': found, 'peer_exit': peer.returncode}, indent=2)+'\n') for s in summary: From ea26a5ab0a2043833e70f09e99fc35aa19ec4ea9 Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 08:54:29 +0900 Subject: [PATCH 09/16] Document the empty-cache read path and its local evidence (#2849) - Architecture D2 section: ordered read-ahead of 12 partition lookups, forecast store admission 12/12 with 4 MiB records and 1 MiB controls per lookup (72.75 MiB in flight over all views, D2 82.125 MiB), linear Doc accounting, the owner hand-off order, local evidence and the remaining gap to the 2.5-second goal. - Operator guide: new limits, the hand-off note, the base-versus- candidate latency matrix procedure; D2 run figures labelled as such. The native verification guide links the procedure. - Architecture diagram: D2 card and forecast sources at 8946cecd; the cold-read sequence is bound to the implementation (Archify finalize and visual check pass for both). - Intent rev 3, spec rev 5 and plan carry the dated amendments (process- wide memory bound, owner hand-off scope); selected evidence under docs/evidence/tasks/issue-2849-cold-build-speed. No code change: server2/ is unchanged by this commit. Co-Authored-By: Claude Opus 5.5 --- .../diagrams/server2-cold-read.html | 1913 +++++++++++++---- .../diagrams/server2-cold-read.sequence.json | 49 +- docs/architecture/diagrams/server2.html | 3 +- docs/architecture/diagrams/server2.json | 11 +- docs/architecture/server2.md | 49 + .../verification.md | 124 ++ docs/operations/server2-domestic-cache.md | 25 +- .../operations/server2-native-verification.md | 2 + intent/issue-2849-cold-build-speed.md | 6 +- plans/issue-2849-cold-build-speed.md | 7 +- specs/issue-2849-cold-build-speed.md | 5 +- 11 files changed, 1726 insertions(+), 468 deletions(-) create mode 100644 docs/evidence/tasks/issue-2849-cold-build-speed/verification.md diff --git a/docs/architecture/diagrams/server2-cold-read.html b/docs/architecture/diagrams/server2-cold-read.html index 0f307fce2..5a3b4dca0 100644 --- a/docs/architecture/diagrams/server2-cold-read.html +++ b/docs/architecture/diagrams/server2-cold-read.html @@ -3,9 +3,9 @@ - + - Proposed empty-cache forecast build: ordered concurrent partition lookups Diagram + Empty-cache forecast build: ordered concurrent partition lookups Diagram - + +
- - Proposed empty-cache forecast build: ordered concurrent partition lookups + + Empty-cache forecast build: ordered concurrent partition lookups A sequence diagram generated by Archify. @@ -5030,7 +5245,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Build key (workspace held) @@ -5038,7 +5253,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + LIST partitions by month @@ -5046,7 +5261,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Sorted partition ids @@ -5054,7 +5269,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Start lookups 1..12 in order @@ -5062,7 +5277,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Per lookup: catalog, descriptor, raw @@ -5070,7 +5285,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + At most 12 operations in flight @@ -5078,7 +5293,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Objects, decoded and verified @@ -5086,7 +5301,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Lookup n ready (any finish order) @@ -5094,7 +5309,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Partition order; caps; first error wins @@ -5102,7 +5317,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + build_view on blocking thread @@ -5110,7 +5325,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - + Same Docs, linear accounting @@ -5120,18 +5335,18 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups - Overlapped reads, ordered results + Overlapped reads, ordered results - Fold + Fold Cache owner · one flight per view · Sequence participant - + @@ -5142,7 +5357,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups Partition reader · ordered consumer · Sequence participant - + @@ -5153,7 +5368,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups Forecast store · admission 12 lookups · Sequence participant - + @@ -5164,7 +5379,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups Process S3 gate · 12 permits, unchanged · Sequence participant - + @@ -5175,7 +5390,7 @@

Proposed empty-cache forecast build: ordered concurrent partition lookups S3 records · authoritative · Sequence participant - +

+ Find Archify useful? A star on GitHub helpsStar - +
D2 forecast memory
  • Grid / RSS / Mid complete views; other owners still run
    • +
  • 12 partition lookups read ahead, consumed in order
  • 128 MiB retained; 48 MiB per entry; logical, not RSS
  • Epoch plus active writer fence; no stale generation install
  • Local CPU / queue limits; global integration remains open
    • diff --git a/docs/architecture/diagrams/server2.json b/docs/architecture/diagrams/server2.json index 1e5180f65..74aa3ffdc 100644 --- a/docs/architecture/diagrams/server2.json +++ b/docs/architecture/diagrams/server2.json @@ -8,7 +8,7 @@ "locale": "en", "repository": { "url": "https://github.com/WizardFactory/TodayWeather", - "revision": "f1a0e0940f14341b62138f8bf17f568f1c061cfb", + "revision": "8946cecd899228b8585bfc2c16de3fd6f1b20321", "provider": "github", "link_mode": "web" } @@ -153,13 +153,13 @@ { "path": "server2/src/domestic/kma/source/forecast_cache.rs", "line": 21, - "end_line": 321, - "label": "Forecast limits and fresh generation lookup" + "end_line": 618, + "label": "Limits, lookup and ordered partition read-ahead" }, { "path": "server2/src/domestic/kma/source/forecast_cache.rs", - "line": 856, - "end_line": 901, + "line": 874, + "end_line": 921, "label": "Actual writer lifetime invalidates generation" }, { @@ -308,6 +308,7 @@ "title": "D2 forecast memory", "items": [ "Grid / RSS / Mid complete views; other owners still run", + "12 partition lookups read ahead, consumed in order", "128 MiB retained; 48 MiB per entry; logical, not RSS", "Epoch plus active writer fence; no stale generation install", "Local CPU / queue limits; global integration remains open" diff --git a/docs/architecture/server2.md b/docs/architecture/server2.md index bc0ac6f41..c0419e14e 100644 --- a/docs/architecture/server2.md +++ b/docs/architecture/server2.md @@ -4136,3 +4136,52 @@ per request; no valid-zone recovery is claimed. Cold observation stubs are denie These are local source/cache results, not complete API parity, host p95 or an eligible rollback release. See the [operator guide](../operations/server2-domestic-cache.md) and [selected verification](../evidence/tasks/issue-2819-domestic-warm-cache/verification.md). + +### D2 empty-cache reads (#2849, local candidate) + +An empty forecast cache rebuilds a view from every partition in its lookback; the +Seoul fixture town needs about 700 partition lookups (about 2,220 forecast GETs). +D2 read them one at a time through a forecast store that admitted two lookups, so +one request grew by about 2 s per millisecond of S3 latency. The +[cold-read sequence](diagrams/server2-cold-read.html) +([editable source](diagrams/server2-cold-read.sequence.json)) shows the change. + +- A view build keeps up to 12 partition lookups (`READ_AHEAD`) in flight and + consumes them in ascending partition order. Retained acquisitions, the scope + caps (1,024 partitions, 2,048 acquisitions, 8,192 pages, 1 MiB pages, 32 MiB raw) + and the first error therefore equal the sequential read; an error, a cap or the + owner deadline drops the lookups still in flight. +- The forecast store admits 12 lookups and 12 raw loads (a raw load beyond its + permits is refused, not queued) and bounds each lookup to 4 MiB of records and + 1 MiB of catalog and descriptor bytes. With one compressed body per load, its + in-flight bytes over all views are at most 12 × (4 + 1 + 1.0625) MiB = 72.75 MiB, + below D2's 2 × (32 + 8 + 1.0625) MiB = 82.125 MiB; one view may now hold all of + it (D2: 41.06 MiB). A partition above 4 MiB is a `Capacity` error; fixture + partitions decode to at most about 0.2 MiB. The 12-permit process S3 gate is + unchanged and shared, so a cold build can occupy it while it reads. +- Retained-Doc accounting is linear: a Doc keeps its exact weight once known + (bounded field sets maintain it; other changes and clones start unknown), so a + store no longer re-walks the collection. The same data weighs 8 bytes more per + Doc and per stored field. Grid row reads compare date and time without copying. +- A retiring owner returns its 192 MiB workspace before its slot wakes the next + owner. D2 released the slot first, and an owner woken on another worker could + fail with `forecast cache: raw storage: Capacity` under load. + +Owner, queue, waiter, workspace, freshness and lookback limits are unchanged. Local +evidence (macOS, owned loopback peer with modeled per-operation latency): 130 +partitions at 10 ms take 0.55 s with 12 lookups in flight against a 3.9 s +sequential estimate; the fold of `short` falls from 1,171 to 687 ms and `shortest` +from 418 to 297 ms with all 13 golden Docs unchanged. An empty-cache request at 0 ms +takes 1.10 s instead of 1.78 s in a fresh process and 1.03 s instead of 1.52 s in a +running server whose views went stale. At a modeled 10 ms the candidate's views are +ready after 3.1 s in a running server (one of five such requests answered inside +3 s) and after 4.7 s in a fresh process, while D2's owners stop at their 8-second +bound with at most one of seven views; at 20 ms the running-server rebuild needs +5.4 s. Through +the 12-permit process gate, a fresh request's 3,628 S3 operations cannot finish in +under about 3.0 s at 10 ms, and a running-server rebuild's 2,245 in under about +1.9 s, so the 2.5-second goal needs fewer S3 operations per view or more S3 +concurrency, both separate decisions. These are not host p95, real S3/TLS or +capacity results. See the +[operator guide](../operations/server2-domestic-cache.md#measure-empty-cache-builds-at-modeled-s3-latency) +and [selected verification](../evidence/tasks/issue-2849-cold-build-speed/verification.md). diff --git a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md new file mode 100644 index 000000000..8689ab784 --- /dev/null +++ b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md @@ -0,0 +1,124 @@ +# Empty-cache forecast build speed: selected local verification + +Scope: #2849 on the D2 branch (PR #2841 head `307defeb706886217ab67ea858dc7c7b0435752f`). +Ordered concurrent partition lookups, forecast store admission and per-lookup bounds, +an exact cached Doc weight, borrowed grid row reads and the owner hand-off order. Local +pre-merge evidence on macOS arm64 (10 cores) with the owned loopback S3 peer and +modeled per-operation latency; it is not a Seoul host, real S3/TLS, p95 capacity or +production result. Raw logs, receipts and copied executables stay in the ignored task +record. + +## Candidate and input identities + +| Input | Identity | +| --- | --- | +| Implementation commits | `7df3bc30` harness, `62595a92` reads and store limits, `85a1a09b` Doc weight, `de76f37a` owner hand-off, `8946cecd` row reads, `79d798c5` / `885c26be` / `54aad593` harness ready times, aged rebuild and report keeping | +| Candidate `server2/` tree (`54aad593`) | `21d72d19f5bf2be4ef6eec171c09644299c6aa2d` | +| Candidate example (final example; product code of `54aad593`) | `cc165e3045bdc6ed844be0a59533722e86baa1bb151f8c8840b4bfc52c1db5e5` | +| D2 + harness example (`307defeb` product code with the same final example) | `f54744301e13a9567f423d77d124dc7cd79ac817feeb56024b5058ec2e93258c` | +| D2 smoke runner | `8627e144ae742da1291c101d88559451989c113f2fe19bf5464dcbcc45ec9cc6` | +| Matrix tool (`54aad593`) | `1da1ac083483d0ce1cd9c407571e54b668b84402c24e1b629351bbb676db46fe` | +| Loopback peer | `66aa32d8ef2fef5237d6b5824eb745966cc127668f6c58069389c5735415d9de` | +| Original fixture manifest (730 acquisitions / 851 pages) | `11606b79c26365e4ba8a5a906d5801f717845f853bafc971c2f099d27b7bbe3f` | + +## Behavior checks + +Each change was test-first where it has observable behavior, and the tests fail on the +D2 code for the intended reason: + +| Check | D2 (Red) | Candidate | +| --- | --- | --- | +| 130 hourly partitions at 10 ms per operation, 12-permit gate | 1 lookup in flight | 12 lookups in flight, 12 reads at most, 0.55 s against a 3.9 s sequential estimate | +| Partition of exactly 4 MiB / 4 MiB + 1 byte | both admitted | 4 MiB admitted, + 1 byte is `Capacity` | +| Forecast store limits | 2 lookups / 2 raw loads, 32 MiB, 8 MiB | 12 / 12, 4 MiB, 1 MiB | +| Storing 64 / 256 Docs; 32 bounded field sets | 4,672 / 67,840 Doc walks; 32 | 192 / 768; 1 | +| Next owner woken by a hand-off | sees 201,326,592 workspace bytes still counted | sees 0 | + +Characterization tests pass on D2 and on the candidate: the first failing partition in +partition order decides the answer; a catalog vanished after LIST still fails the view +with `Corrupt("incomplete catalog")`; the owner deadline and a never-answering lookup +leave no lookup in flight and no view mapped; two cold keys share the gate without +starving another reader; jittered overlapped reads equal one operation at a time; +scope totals fail at the same partition as the D2 per-acquisition checks in 3,000 +random cases; cached weights equal an independent full walk after random changes; store +admission equals a full recomputation at limit − 1, limit and limit + 1; rows are +found exactly as through `Row::get`. + +## Output equality and fold time + +The isolated smoke on the final candidate example (seed, diagnostic, HTTP) exited 0: +seed 730 / 851, diagnostic 725 acquisitions / 845 pages with 13/13 golden Docs in every +phase, warm forecast I/O, parse and fold deltas 0. Fresh native HTTP: cold 200 in +1,295 ms, warm 200 in 21 / 20 ms, all bodies 42,549 bytes with SHA-256 +`a6462aba8ad9ec34d8efdcab4ccd2f37b00339a301fd17caa7c1e5485d45b283`. + +Fold time per view, median of 5 diagnostic runs at 0 ms, with one uncommitted timing +patch (two lines printing the blocking `build_view` time) applied to D2 + harness +(`7df3bc30`) and to the final candidate tree (`54aad593`), 13/13 Docs in all 10 runs: + +| View | D2 + harness | Candidate | Change | +| --- | --- | --- | --- | +| Short | 1,170.9 ms | 687.4 ms | −41.3 % | +| Shortest | 418.3 ms | 296.9 ms | −29.0 % | +| RSS | 35.9 ms | 29.0 ms | −19.2 % | + +An earlier run on the `8946cecd` tree gave 1,148.9 → 677.4, 410.3 → 287.6 and 35.3 → 28.3 ms. + +## Empty-cache requests at modeled S3 latency + +Harness: `server2/tools/cold_build_matrix.py` with the owned peer's latency control, +one seeded corpus per execution, 5 interleaved runs per cell, D2 product code and the +candidate built with the same final example (`f54744301e13a9567f423d77d124dc7cd79ac817feeb56024b5058ec2e93258c` +and `cc165e3045bdc6ed844be0a59533722e86baa1bb151f8c8840b4bfc52c1db5e5`). The 0 and 10 ms +cells come from one execution and the 20 ms cells from another, both without harness +problems; every 200 body equals the reference. An earlier complete execution lost +11 runs to local port exhaustion and is kept only in the task record: bursts of up +to about 24,000 TIME_WAIT sockets came from other activity on the host at times not +aligned with the runs, while a run of this harness alone stayed near 300. "Running server" is the `aged` request: +views stale after 30 seconds in a warm process, about 2,245 S3 operations; a fresh +process makes about 3,628. Times are medians (p95 in parentheses); "ready" is when +the owners started by the request were idle, measured outside the request timing. + +| Modeled delay | Request | D2 + harness | Candidate | +| --- | --- | --- | --- | +| 0 ms | fresh process | 200 in 1,784 ms (2,195) | 200 in 1,096 ms (1,413) | +| 0 ms | running server | 200 in 1,516 ms (1,606) | 200 in 1,026 ms (1,160) | +| 10 ms | fresh process | 502 at 3.0 s; owners stop at the 8 s bound with 1 of 7 views | 502 at 3.0 s; 7/7 views ready at 4.66 s (4.75) | +| 10 ms | running server | 502 at 3.0 s; 0 of 7 views | 7/7 views ready at 3.12 s (3.14); 1 of 5 answered 200 inside 3 s, 4 answered 502 | +| 20 ms | fresh process | 502 at 3.0 s; 2 of 7 views | 502 at 3.0 s; 6 of 7 views by 8.02 s | +| 20 ms | running server | 502 at 3.0 s; 0 of 7 views | 502 at 3.0 s; 7/7 views ready at 5.41 s | + +The goal of a 2.5 s p95 at a modeled 10 ms is not met locally; the running-server +rebuild is 0.6 s above it and 0.1 s above the 3-second deadline. Through the +unchanged 12-permit process S3 gate, 2,245 operations at 10 ms need at least +2,245 × 10 ms ÷ 12 ≈ 1.9 s and 3,628 need ≈ 3.0 s before any fold work, so the +remaining gap needs fewer S3 operations per view or more S3 concurrency. + +## Tests and gates on the candidate + +On the candidate `server2/` tree: `cargo fmt --check` and all-target Clippy with +warnings denied pass; the placement gate passes for `ColdBuildSpeed2849.json`; the +peer self-check (with its latency control), 6 matrix-tool tests and 6 D2 runner tests +pass; the 8 cold-read integration tests and 63 source unit tests pass. The whole +workspace with 4 test threads and `--no-fail-fast`: 1,112 passed, 6 ignored, 1 failed. +The failure, `runtime_services::inventory::factory_national_prose_reader_survives_factory_reconstruction`, +fails the same way on the D2 head `307defeb` and passes on its merge base `c1ae9082`: +it is pre-existing in D2 and unrelated to this change (two owned flights panic during +`/v000903/nation/KR`). With that one test skipped by name, the workspace passes: +1,112 passed, 6 ignored, 0 failed across 30 test binaries. `tools/test_placement.py` did not run here: its self-tests call +`rustc +1.99.0`, which needs the rustup proxy this host lacks. + +Base observations: D2 CI run `39243883911` failed 4 `domestic` tests with +`forecast cache: raw storage: Capacity`, the owner hand-off defect fixed here. With +the default 10 local test threads the base fails 30 `domestic` tests while seeding +the loopback peers (host contention), so base and candidate are compared with 4 +threads: base 173 passed, candidate 181 passed (8 new), none failed. + +## Limits + +The latency is modeled on loopback: no TLS, connection setup or S3 variance, and the +local CPU is faster than the Seoul t3.small. The Seoul host matrix has not run; it +waits for AK's launch confirmation. The process S3 gate (12) is unchanged and shared, +so one cold build can hold all its permits while it reads. Logical weights of the same +data grow by 8 bytes per Doc and per stored field. Real-partition sizes are taken from +the fixture (at most about 0.2 MiB decoded against the new 4 MiB bound). diff --git a/docs/operations/server2-domestic-cache.md b/docs/operations/server2-domestic-cache.md index dcb153873..148c5a69c 100644 --- a/docs/operations/server2-domestic-cache.md +++ b/docs/operations/server2-domestic-cache.md @@ -15,8 +15,10 @@ Freshness is at most 30 seconds and clips at the relevant minute, day, month, pr |2 active owners + 8 queued keys|Ten admitted keys, 192 MiB logical workspace per owner ; 8-second owner deadline starts at admission, including queue time| |128 waiting callers / local CPU 2|Bounded per-Source demand; each caller keeps its own deadline| |4995 comparison indices|At most 39,960 requested payload bytes on 64-bit plus charged allocation allowance; fallible growth and actual Vec capacity check| +|12 partition lookups per build (#2849)|Consumed in partition order, so acquisitions, scope caps and the first error equal a sequential read; an error, cap or owner deadline drops the rest| +|Forecast store 12 lookups / 12 raw loads|4 MiB of records and 1 MiB of catalog/descriptor bytes per lookup: at most 72.75 MiB in flight over all views (D2: 82.125 MiB). A larger partition is a `Capacity` error. The 12-permit process S3 gate is unchanged and shared| -A caller or owner timeout does not forcibly stop an already running blocking closure. Its workspace and permits remain owned until the actual closure retires. +A caller or owner timeout does not forcibly stop an already running blocking closure. Its workspace and permits remain owned until the actual closure retires. A retiring owner returns its workspace before its slot wakes the next owner (#2849); D2 released the slot first, and the woken owner could fail with `forecast cache: raw storage: Capacity` under load. These are logical admission limits, not an allocator/RSS or total process CPU guarantee. Existing catalog/raw gates remain. D2/F2 must be reconciled with the shared process resource owner in the integrated candidate; this branch alone does not establish that global claim. @@ -33,12 +35,31 @@ python3 -B tools/domestic_warm_cache_smoke.py \ --build-variant release --modes seed diagnostic http ``` -Use a new output directory. The runner owns a persistent IPv4 loopback S3 peer and separate seed, diagnostic and native HTTP children. It verifies their input identities, captures complete counters and reaps its children. No live endpoint or provider credentials are required. The Off provider reports denied observation stub calls separately from external network calls. A diagnostic Source run uses 60 seconds to inspect all 13 golden datasets; the separate unprimed Gateway -> DirectRoutes -> KmaBackend HTTP flow retains its normal 3-second deadline. +Use a new output directory. The runner owns a persistent IPv4 loopback S3 peer and separate seed, diagnostic and native HTTP children; the example's S3 transport admits 12 requests at once, the server's process gate (it admitted 4 before #2849). It verifies their input identities, captures complete counters and reaps its children. No live endpoint or provider credentials are required. The Off provider reports denied observation stub calls separately from external network calls. A diagnostic Source run uses 60 seconds to inspect all 13 golden datasets; the separate unprimed Gateway -> DirectRoutes -> KmaBackend HTTP flow retains its normal 3-second deadline. A passing run requires the original seed of 730 acquisitions / 851 pages (including one zone-support acquisition) and the diagnostic selection of 725 forecast acquisitions / 845 pages and all 13 expected Doc views. Every warm forecast LIST/catalog/descriptor/raw GET/returned byte, parse and fold delta must be 0. The complete classified label universe is exactly those 13 plus zone-support; missing or unknown labels fail. Cold HTTP must be 200; both warm responses must have identical bytes. Provider/geocoder counters, final owner/queue/workspace/waiter state and process retirement are checked. Never accept 502 as a successful partial response or prime the HTTP Source with the diagnostic Source. +## Measure empty-cache builds at modeled S3 latency + +This compares two builds of the same example, for example the D2 product code and a candidate, on one seeded corpus. Build each at its own commit in its own clean target (a target shared between worktrees of the same package can report the second build fresh and reuse the first one's binary), copy and hash both executables, then run: + +```sh +cd server2 +python3 -B tools/cold_build_matrix.py \ + --binary base=/absolute/path/to/copied/base_smoke \ + --binary candidate=/absolute/path/to/copied/candidate_smoke \ + --output /absolute/path/to/new/ignored/matrix-run \ + --delays 0 10 20 --runs 5 +``` + +The tool starts one persistent loopback peer, seeds the original corpus without delay, then sets the peer's latency control so every GET, HEAD and LIST waits the modeled milliseconds (PUT does not). For each delay and run it starts every binary in turn in `http` mode (fresh process: cold, warm1, warm2) and in `aged` mode (cold, then a rebuild after the 30-second view freshness, i.e. an empty forecast cache in a warm process). It keeps each run's bodies, compares every 200 body with the reference SHA-256 and reports status, median and p95 time, forecast LIST/catalog/descriptor/raw counts and, for cold and aged requests, when the views were ready, in `matrix.json`. A 502 after about 3 s is the unchanged native deadline and is recorded as a result; the owners of a cut answer keep building up to their 8-second bound, so the ready time and the number of mapped views show how far the build really was from the deadline. An `http` run then stops; an `aged` run still makes its rebuild request after the cold one was cut, because the forecast views of a running server go stale after 30 seconds and that rebuild (with about 20 other S3 operations instead of about 1,400 in a fresh process) is the common empty-cache case. Exit 1 means a harness problem (missing phases, a failed child after successful answers, a wrong body), never a slow answer. + +The delay is modeled on loopback: it has no TLS, connection setup or real S3 variance, and the host CPU decides the fold time. It is not a host p95 or capacity qualification. The selected local result of #2849 is in its [verification record](../evidence/tasks/issue-2849-cold-build-speed/verification.md). + ## Read the actual retained result +These are the figures of the D2 base run (#2819), kept as recorded. Since #2849 the same data weighs 8 bytes more per Doc and per stored field (each Doc carries its cached weight), and the example's S3 admission is 12. + The selected optimized executable is SHA-256 `f131044392694657919864caee1a95539359c736d4f0e6225127235a8069d68b`, built on the task's exact runtime source above base `c1ae9082`. The current runner is `a9b1e1a194188e3fb31c325b0fdd128f5b566cd58d2bfe6b0c3cdc1282272a84`. The retained original fixture manifest is `11606b79c26365e4ba8a5a906d5801f717845f853bafc971c2f099d27b7bbe3f`. - Actual whole runner and all 3 children exited 0. Diagnostic 13/13 Docs match; cold 1958.88 ms and warm 3.75 / 3.79 ms. diff --git a/docs/operations/server2-native-verification.md b/docs/operations/server2-native-verification.md index d7ae98814..a4ca1b171 100644 --- a/docs/operations/server2-native-verification.md +++ b/docs/operations/server2-native-verification.md @@ -596,3 +596,5 @@ optional counter visible. Never accept a 502 or weaken the original corpus. The [selected receipt](../evidence/tasks/issue-2819-domestic-warm-cache/verification.md) records actual current results and original failures. This does not qualify host latency, global resource integration, full API parity or production recovery. +Empty-cache build time at modeled S3 latency (#2849) has its own base-versus-candidate +procedure in the operator guide, [measure empty-cache builds](server2-domestic-cache.md#measure-empty-cache-builds-at-modeled-s3-latency). diff --git a/intent/issue-2849-cold-build-speed.md b/intent/issue-2849-cold-build-speed.md index 11996d122..bc7154cfe 100644 --- a/intent/issue-2849-cold-build-speed.md +++ b/intent/issue-2849-cold-build-speed.md @@ -3,7 +3,7 @@ | Field | Recorded value | | --- | --- | | Task / stage / owner | `issue-2849-cold-build-speed` / intent / main (Claude Sonnet 5.5, Anthropic) | -| Date / revision | 2026-10-22 KST, revision 2 (amendment below) | +| Date / revision | 2026-10-22 KST, revision 3 (amendments below) | | Source / authority | AK, 2026-10-22: implement per SDLC after the #2849 investigation; keep the EC2 host time limit until implementation completes. Issues #2849 (revised body), #2850. | | Base | `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head, branch `fix/domestic-warm-cache-2819`); this task's branch `fix/cold-build-speed-2849` | | Endpoint | `pre-merge` as the intended constraint; delegation of external writes is **pending** (see Authority) | @@ -26,7 +26,7 @@ Affected: every first request for a town whose forecast views are not cached (re An empty-cache forecast request completes inside the unchanged 3 s native deadline with identical output, bounded memory and no new runtime mode. Goal on the measured host class: empty-cache p95 ≤ 2.5 s at a modeled S3 delay of 10 ms. If the bounded iterations cannot reach that, report the measured remaining gap; never relax the deadline or the gate. - **AC1 — ordered concurrent reads.** A view build looks up its partitions with bounded concurrency while consuming results in partition order. Acquisitions, order, exclusion counts and the first error equal the sequential read. With a delayed transport double the build time follows operations × delay ÷ concurrency (at least 4× faster than the sequential read for 120+ partitions at the same delay). Timeout, corruption, missing catalog and capacity paths return the same typed errors; a cancelled build leaves no installed partial view and no running lookup beyond the S06 blocking closures that already outlive their caller. -- **AC2 — identical output and limits.** All 13 view Docs equal their goldens; the HTTP bodies of the cold, warm and empty-cache-in-warm-process requests equal the reference; every capacity limit keeps its exact boundary behavior (existing ±1 tests stay green); the forecast store's in-flight read memory, summed over all views of the process, stays below D2's bound. +- **AC2 — identical output and limits.** All 13 view Docs equal their goldens; the HTTP bodies of the cold, warm and empty-cache-in-warm-process requests equal the reference; every capacity limit keeps its exact boundary behavior (existing ±1 tests stay green); the forecast store's in-flight read memory, summed over all views of the process, stays below D2's bound; a build that obtains an owner slot always obtains its workspace (no `Capacity` left behind by the previous owner's hand-off). - **AC3 — linear fold accounting.** Retained-Doc accounting no longer re-walks the whole collection per store or the whole Doc per field set, and the grid collector's row lookup no longer copies strings per visited row; a deterministic operation-count test shows linear growth and the local fold time of `short` and `shortest` falls against the D2 baseline on the same corpus with unchanged output. - **AC4 — Seoul t3.small evidence.** The candidate and D2-as-published are measured with the same harness on the Seoul t3.small (Unlimited) host at modeled S3 delays 0, 10 and 20 ms (empty-cache request, fresh process and warm process), bodies identical, and the gap to 2.5 s is stated. - **AC5 — contract, documentation and placement.** No new runtime flag or mode; all added paths are under the declared `server2/` subdirectories plus the declared documents; the D2 architecture section, the operator guide and the diagram describe the new read concurrency and limits; the placement gate passes; unrelated files are untouched. @@ -55,3 +55,5 @@ An empty-cache forecast request completes inside the unchanged 3 s native deadli PROCEED for local stages (investigation → build → local self-verification). NEEDS_HUMAN for external writes and the AWS launch; unaffected work continues. Amendment 2026-10-22 (revision 2, before any code): AC2's memory clause read "in-flight read memory stays within the previous per-view bound". The forecast catalog store is one instance shared by every view, and D2 already let two owners read at once, so its bound is process-wide; with overlapped lookups one view may now use more than one sequential D2 lookup did. The clause now compares the store's in-flight bytes over all views with D2's. Found while planning, when the raw store's refuse-rather-than-wait admission and the per-load compressed buffer were added to the arithmetic. No other criterion changes. + +Amendment 2026-10-22 (revision 3, during build): the D2 owner `Workspace` releases its owner slot before its workspace bytes. A waiting owner woken on another worker can reserve before the bytes return and fails with `Capacity` (`forecast cache: raw storage: Capacity`): the 4 failures of base CI run 39243883911 and 1 in this task's first full local run carry exactly that error. The fix (bytes before slot) and a deterministic regression test join the scope in `forecast_cache.rs`, which is already declared; AC2 gains the hand-off clause. Reason: the defect fails cold requests under load and makes every CI result of this change unreadable. diff --git a/plans/issue-2849-cold-build-speed.md b/plans/issue-2849-cold-build-speed.md index b18988807..e59a4363c 100644 --- a/plans/issue-2849-cold-build-speed.md +++ b/plans/issue-2849-cold-build-speed.md @@ -1,6 +1,6 @@ # Plan: empty-cache forecast build speed (issue #2849 follow-through) -Consumes [intent](../intent/issue-2849-cold-build-speed.md) revision 2, [spec](../specs/issue-2849-cold-build-speed.md) revision 4 and the design of 2026-10-22 (iteration 3: [sequence](../docs/architecture/diagrams/server2-cold-read.html), [editable source](../docs/architecture/diagrams/server2-cold-read.sequence.json); the written design is in the ignored task record). Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head), branch `fix/cold-build-speed-2849`, endpoint `pre-merge` as the intended constraint with external writes pending AK's authority record. Owner: main (Claude Opus 5.5; earlier stages by Claude Sonnet 5.5, both Anthropic). Execution notebook: `.planning/2026-10-22-issue-2849-uncached-forecast-build-speed/` of the coordinating workspace. +Consumes [intent](../intent/issue-2849-cold-build-speed.md) revision 3, [spec](../specs/issue-2849-cold-build-speed.md) revision 5 and the design of 2026-10-22 (iteration 4: [sequence](../docs/architecture/diagrams/server2-cold-read.html), [editable source](../docs/architecture/diagrams/server2-cold-read.sequence.json); the written design is in the ignored task record). Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head), branch `fix/cold-build-speed-2849`, endpoint `pre-merge` as the intended constraint with external writes pending AK's authority record. Owner: main (Claude Opus 5.5; earlier stages by Claude Sonnet 5.5, both Anthropic). Execution notebook: `.planning/2026-10-22-issue-2849-uncached-forecast-build-speed/` of the coordinating workspace. ## Placement declaration (server2) @@ -11,7 +11,7 @@ Intended `server2/` paths: | Path | Why | | --- | --- | | `server2/config/tasks/ColdBuildSpeed2849.json` (new) | task placement declaration | -| `server2/src/domestic/kma/source/forecast_cache.rs` | `READ_AHEAD`, ordered concurrent `read_partitions`, unit tests | +| `server2/src/domestic/kma/source/forecast_cache.rs` | `READ_AHEAD`, ordered concurrent `read_partitions`, owner hand-off order (R5), unit tests | | `server2/src/domestic/kma/source/records.rs` | `forecast_lookup` (`Looked`, `Counted`) replaces `forecast_acquisitions`; `ForecastScope::admit` | | `server2/src/domestic/kma/source/mod.rs` | forecast store admission 12/12 and per-lookup output 4 MiB / controls 1 MiB | | `server2/src/domestic/kma/source/doc.rs` | cached exact `Doc` weight (`Weight` newtype), `Row::str_is`, accounting tests | @@ -45,7 +45,7 @@ Excluded and untouched: legacy `server/`, the process S3 gate (`gateway/runtime. | S2 | Same user asks again | repeat request after S1 | warm hit, zero forecast LIST/GET, parse and fold | n/a | AC2 | existing D2 tests, smoke | | S3 | Maintainer verifies equality locally | seed, diagnostic and http modes of the isolated smoke on the candidate | 13/13 Docs equal their goldens, hashes equal, warm deltas 0 | any Doc or hash difference fails the run | AC2 | smoke | | S4 | Operator compares D2 and the candidate | run the matrix at 0, 10, 20 ms for both binaries, fresh process and aged cache, locally and on the Seoul host | table of status, time, hash and S3 operation counts; the gap to 2.5 s is stated | host launch not confirmed: the host column is recorded as not run, never inferred | AC4 | matrix, host run | -| S5 | A different town builds at the same time (2 owners) and other S3 users run | two cold keys plus a foreign S3 operation through the same gate | all complete; the foreign operation waits at most one gate round; no deadline relaxation | queue overflow keeps the existing typed refusal | AC1 AC2 | T-R1.7 | +| S5 | A different town builds at the same time (2 owners) and other S3 users run | two cold keys plus a foreign S3 operation through the same gate | all complete; the foreign operation waits at most one gate round; an owner hand-off never fails for workspace capacity; no deadline relaxation | queue overflow keeps the existing typed refusal | AC1 AC2 | T-R1.7 | | S6 | Maintainer reads the D2 documents | open architecture section, operator guide, diagram | read concurrency, admission (lookups = raw loads = 12), the process-wide in-flight bound (72.75 MiB, D2 82.125 MiB) and the evidence limits are stated; links resolve | stale statement found: fix before completion | AC5 | doc review, link check, Archify | | S7 | Maintainer checks that the fold no longer re-weighs everything per store | operation-count tests; fold timing of `short`/`shortest` on base and candidate at 0 ms; goldens | walks grow linearly; store results equal the old recomputation; fold time down ≥ 25 %; Docs identical | stale weight, accept/reject difference or a gain below target is reported with numbers, never relaxed silently | AC2 AC3 | T-R3.1–T-R3.4, fold timing, smoke | @@ -57,6 +57,7 @@ Each cycle follows the `tdd` skill (Red, Green, post-refactor check) and ends in 1. **Harness and test aids** (`catalog_peer.py` latency control + self-check, example gate/`aged` mode, `cold_build_matrix.py` + pure tests). Red: the pure tests and the peer self-check fail before the code exists. This step must precede R1 so that D2-as-published and the candidate use one harness. 2. **R1 and R2.** Red tests in `forecast_cold_read.rs` first: peak concurrent catalog lookups ≥ 8, elapsed ≤ ⅓ of the sequential estimate for ≥ 120 partitions, 4 MiB+1 partition returns `Capacity`; characterization tests for first-error precedence, scope-cap partition, jitter equality and cancellation (these pass on the base and must stay green). Green: `forecast_lookup`/`Looked`/`Counted`, `ForecastScope::admit`, `read_partitions` with `buffered(READ_AHEAD)`, store limits. 3. **R3a cached weight.** Red: a `#[cfg(test)]` counter of full weight walks shows quadratic growth on the base; cached-equals-recomputed and store-decision-versus-oracle tests are written first and pass on the base. Green: `Weight` cache in `Doc`, exact delta maintenance in `try_set`, `checked_store_with_limit` over cached weights. +3b. **R5 owner hand-off.** Red: a waker registered by the next owner observes the workspace budget at its wake-up and sees the previous 192 MiB lease still counted. Green: declare the lease before the owner permit. Then rerun the whole `domestic` binary with 4 threads. 4. **R3b borrowed row lookup.** Red: `Row::str_is` is absent; equality tests against `Row::get` (own, template, missing, non-string, `0xF4` canonicalization). Green: `str_is` and `find_or_create`. Then re-profile and remove further per-read copies only where the profile and equality tests justify it (R3.3, R3.4). 5. **Documentation and diagrams.** D2 architecture section, operator guide, `server2.json` card, rebind `server2-cold-read` to the implementation commit; Archify `finalize` and `visual-check` for both sources; declaration file; documentation assessment. 6. **Verification and evidence.** Full self-verification (below), selected evidence under `docs/evidence/tasks/issue-2849-cold-build-speed/`, then the Seoul host matrix when AK confirms the launch. diff --git a/specs/issue-2849-cold-build-speed.md b/specs/issue-2849-cold-build-speed.md index 693850682..9d9a73a21 100644 --- a/specs/issue-2849-cold-build-speed.md +++ b/specs/issue-2849-cold-build-speed.md @@ -1,6 +1,6 @@ # Empty-cache forecast build speed (issue #2849 follow-through) -Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841, D2). Intent: `intent/issue-2849-cold-build-speed.md` revision 2 (AC1–AC5). Evidence: investigation of the same task (local sweep, profile, 2026-10-21 EC2 record). Revision 4, 2026-10-22 (revision 2 amended decision D3; revision 3 refined R2.2/D1 with the control-byte bound; revision 4 corrects the R2.2 memory comparison to the process-wide store bound, adds the raw admission constraint to R2.1 and states the logical-weight shift; acceptance follows intent revision 2). Status: complete; decisions D1–D5 below are made for design, none blocks it. +Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841, D2). Intent: `intent/issue-2849-cold-build-speed.md` revision 3 (AC1–AC5). Evidence: investigation of the same task (local sweep, profile, 2026-10-21 EC2 record). Revision 5, 2026-10-22 (revision 2 amended decision D3; revision 3 refined R2.2/D1 with the control-byte bound; revision 4 corrected the R2.2 memory comparison to the process-wide store bound, added the raw admission constraint to R2.1 and the logical-weight shift; revision 5 adds R5, the owner hand-off order, following intent revision 3). Status: complete; decisions D1–D5 below are made for design, none blocks it. ## Problem and outcome @@ -42,6 +42,8 @@ Excluded: retention, SSD tier and warm-up (#2850); packs or rollups (#2707); the 3. The grid collector's row lookup (`find_or_create`) compares `date` and `time` without allocating strings; any other per-read string copy in the hot collector path is removed if it keeps results identical. 4. Local fold time of `short` and `shortest` on the 730-acquisition corpus falls by at least 25% against the base with no output change (stretch is set by the AC4 gap). +**R5 — Owner hand-off (AC2).** A retiring owner returns its 192 MiB workspace lease before it releases its owner slot, so the owner woken by that release always obtains its workspace; no build fails with `Capacity` because the previous owner's lease was still counted. The owner, queue, waiter and workspace sizes do not change. + **R4 — Evidence and documentation (AC4, AC5).** 1. A repeatable harness reports empty-cache time at modeled delays 0, 10 and 20 ms, fresh-process and warm-process, with body hash and S3 operation counts, for the candidate and for D2 as published, locally and on the Seoul t3.small. 2. The D2 architecture section, the operator guide and the diagram state the new read concurrency, the store admission and the in-flight bound. No new runtime setting or mode: the constants live in code with the same justification as the existing `LOOKUPS`. @@ -73,6 +75,7 @@ Excluded: retention, SSD tier and warm-up (#2850); packs or rollups (#2707); the | --- | --- | --- | | AC1 | integration over the owned S06 peer | counting/delaying transport wrapper: peak in-flight lookups ≥ 8 and elapsed ≤ ⅓ of the sequential estimate for ≥120 synthetic partitions; result equality against the 13 goldens; fault injection (missing, corrupt, timeout, over-cap) compares error and partition of failure; cancellation test drops the build mid-read and checks no install and no leaked in-flight count | | AC2 | existing suites + goldens | existing exact-boundary and D2 tests stay green; diagnostic mode (13 Docs) and HTTP body hashes; a 4 MiB+1 partition returns `Capacity`; the forecast store limits are checked (lookups = raw loads = `READ_AHEAD`, 4 MiB, 1 MiB) | +| AC2 (R5) | unit | a waker that observes the workspace budget when the next owner is woken sees the previous lease already returned | | AC3 | unit + local timing | test-only counter of `heap_weight` calls shows linear growth in Doc count and field count; equality tests of borrowed row lookup against the old accessor; local fold timing against base binary | | AC4 | harness on host | latency-injected matrix on Seoul t3.small (EC2) and locally; body hash equality; operation counts | | AC5 | review + gates | placement gate, artifact policy checker, doc/diagram review, no new flags (grep), clean checkout links | From af08acc4d013584e8fdedd0d9fa335e0c55c1a9b Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 08:56:38 +0900 Subject: [PATCH 10/16] Point the plan at the implementation-bound design (#2849) Co-Authored-By: Claude Opus 5.5 --- plans/issue-2849-cold-build-speed.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/plans/issue-2849-cold-build-speed.md b/plans/issue-2849-cold-build-speed.md index e59a4363c..324975daf 100644 --- a/plans/issue-2849-cold-build-speed.md +++ b/plans/issue-2849-cold-build-speed.md @@ -1,6 +1,6 @@ # Plan: empty-cache forecast build speed (issue #2849 follow-through) -Consumes [intent](../intent/issue-2849-cold-build-speed.md) revision 3, [spec](../specs/issue-2849-cold-build-speed.md) revision 5 and the design of 2026-10-22 (iteration 4: [sequence](../docs/architecture/diagrams/server2-cold-read.html), [editable source](../docs/architecture/diagrams/server2-cold-read.sequence.json); the written design is in the ignored task record). Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head), branch `fix/cold-build-speed-2849`, endpoint `pre-merge` as the intended constraint with external writes pending AK's authority record. Owner: main (Claude Opus 5.5; earlier stages by Claude Sonnet 5.5, both Anthropic). Execution notebook: `.planning/2026-10-22-issue-2849-uncached-forecast-build-speed/` of the coordinating workspace. +Consumes [intent](../intent/issue-2849-cold-build-speed.md) revision 3, [spec](../specs/issue-2849-cold-build-speed.md) revision 5 and the design of 2026-10-22 (iteration 5, diagram bound to the implementation: [sequence](../docs/architecture/diagrams/server2-cold-read.html), [editable source](../docs/architecture/diagrams/server2-cold-read.sequence.json); the written design is in the ignored task record). Base `307defeb706886217ab67ea858dc7c7b0435752f` (PR #2841 head), branch `fix/cold-build-speed-2849`, endpoint `pre-merge` as the intended constraint with external writes pending AK's authority record. Owner: main (Claude Opus 5.5; earlier stages by Claude Sonnet 5.5, both Anthropic). Execution notebook: `.planning/2026-10-22-issue-2849-uncached-forecast-build-speed/` of the coordinating workspace. ## Placement declaration (server2) From 207b176dd5017c7b58c7e4f3b7d65a799a62b96b Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 11:03:00 +0900 Subject: [PATCH 11/16] Treat a hung child or a missing aged rebuild as a matrix problem (#2849) A cut cold request excused any later exit, so a child that hung after a 502, or an aged run without its rebuild, passed as a measurement. Timeouts and signals are now always problems and the aged mode must record both phases. Review finding CX-2852-001. Co-Authored-By: Claude Opus 5.5 --- server2/tools/cold_build_matrix.py | 8 ++++++++ server2/tools/test_cold_build_matrix.py | 5 +++++ 2 files changed, 13 insertions(+) diff --git a/server2/tools/cold_build_matrix.py b/server2/tools/cold_build_matrix.py index bce36dbd0..51886f7ce 100644 --- a/server2/tools/cold_build_matrix.py +++ b/server2/tools/cold_build_matrix.py @@ -126,7 +126,15 @@ def problems(rows, exits, reference): if not phases or phases != MODES[mode][:len(phases)]: found.append(f'{where}: phases {list(phases)}, exit {code}') continue + # A hung or killed child is never a measured result. + if code == 'TIMEOUT' or (isinstance(code, int) and code < 0): + found.append(f'{where}: child {code} after {list(phases)}') + continue failed = [r for r in mine if r['status'] != 200] + # The aged mode answers its rebuild even after a cut cold request. + if mode == 'aged' and len(phases) < len(MODES[mode]): + found.append(f'{where}: phases {list(phases)}, exit {code}') + continue # Only the aged rebuild runs after a cut cold request (the example's rule). if failed and failed[0] is not mine[-1] and not (mode == 'aged' and failed[0]['phase'] == 'cold'): found.append(f'{where}: continued after a failed {failed[0]["phase"]}') diff --git a/server2/tools/test_cold_build_matrix.py b/server2/tools/test_cold_build_matrix.py index 718b86f8e..77c8c83c9 100644 --- a/server2/tools/test_cold_build_matrix.py +++ b/server2/tools/test_cold_build_matrix.py @@ -101,6 +101,11 @@ def test_problems_are_harness_integrity_not_measured_failures(self): 'wrong body': (rows_of('c', 'aged', 0, 1, [record('cold'), record('aged', sha='e' * 64)]), 0), 'continued after failure': (rows_of('c', 'http', 0, 1, [record('cold', status=502), record('warm1')]), 101), 'phase order': (rows_of('c', 'aged', 0, 1, [record('aged'), record('cold')]), 0), + # A cut cold request never excuses a hung or killed child, or a missing aged rebuild. + 'timeout after a cut aged cold': (rows_of('c', 'aged', 0, 1, [record('cold', status=502, sha='x')]), 'TIMEOUT'), + 'aged rebuild missing after a cut cold': (rows_of('c', 'aged', 0, 1, [record('cold', status=502, sha='x')]), 101), + 'timeout after a cut http cold': (rows_of('c', 'http', 0, 1, [record('cold', status=502, sha='x')]), 'TIMEOUT'), + 'signal after a cut http cold': (rows_of('c', 'http', 0, 1, [record('cold', status=502, sha='x')]), -9), } for name, (rows, code) in cases.items(): with self.subTest(name): From b7aaf689feb2a66722a29e5ea0cf845236003784 Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 11:13:14 +0900 Subject: [PATCH 12/16] State what the cached Doc weight removes and what remains (#2849) Full Doc walks grow linearly with stores, but each store still reads every retained Doc's cached weight. The architecture text and the cold-read diagram said the accounting was linear. Review finding CX-2852-002; diagram regenerated with Archify 3.2.0 (all gates pass). Co-Authored-By: Claude Opus 5.5 --- docs/architecture/diagrams/server2-cold-read.html | 12 ++++++------ .../diagrams/server2-cold-read.sequence.json | 4 ++-- docs/architecture/server2.md | 11 +++++++---- 3 files changed, 15 insertions(+), 12 deletions(-) diff --git a/docs/architecture/diagrams/server2-cold-read.html b/docs/architecture/diagrams/server2-cold-read.html index 5a3b4dca0..ca094b9ce 100644 --- a/docs/architecture/diagrams/server2-cold-read.html +++ b/docs/architecture/diagrams/server2-cold-read.html @@ -5324,11 +5324,11 @@

    Empty-cache forecast build: ordered concurrent partition lookups

    - + - - Same Docs, linear accounting + + Same Docs, cached Doc weights @@ -5399,15 +5399,15 @@

    Empty-cache forecast build: ordered concurrent partition lookups

    authoritative     - - Fold · blocking, linear accounting · Sequence participant + + Fold · blocking, cached Doc weights · Sequence participant Fold - blocking, linear accounting + blocking, cached Doc weights diff --git a/docs/architecture/diagrams/server2-cold-read.sequence.json b/docs/architecture/diagrams/server2-cold-read.sequence.json index 0d7d7b3ba..8a64060e6 100644 --- a/docs/architecture/diagrams/server2-cold-read.sequence.json +++ b/docs/architecture/diagrams/server2-cold-read.sequence.json @@ -104,7 +104,7 @@ "id": "fold", "type": "backend", "label": "Fold", - "sublabel": "blocking, linear accounting", + "sublabel": "blocking, cached Doc weights", "sources": [ { "path": "server2/src/domestic/kma/source/forecast_cache.rs", @@ -219,7 +219,7 @@ "from": "fold", "to": "owner", "y": 468, - "label": "Same Docs, linear accounting", + "label": "Same Docs, cached Doc weights", "variant": "return" } ], diff --git a/docs/architecture/server2.md b/docs/architecture/server2.md index c0419e14e..fc4d27e92 100644 --- a/docs/architecture/server2.md +++ b/docs/architecture/server2.md @@ -4159,10 +4159,13 @@ one request grew by about 2 s per millisecond of S3 latency. The it (D2: 41.06 MiB). A partition above 4 MiB is a `Capacity` error; fixture partitions decode to at most about 0.2 MiB. The 12-permit process S3 gate is unchanged and shared, so a cold build can occupy it while it reads. -- Retained-Doc accounting is linear: a Doc keeps its exact weight once known - (bounded field sets maintain it; other changes and clones start unknown), so a - store no longer re-walks the collection. The same data weighs 8 bytes more per - Doc and per stored field. Grid row reads compare date and time without copying. +- A Doc keeps its exact weight once known (bounded field sets maintain it; other + changes and clones start unknown), so a store sums one cached weight per + retained Doc instead of walking every Doc's fields: full Doc walks now grow + linearly with the stores (768 for 256 stores; D2 67,840). The per-store sum + still reads every retained Doc's cached weight. The same data weighs 8 bytes + more per Doc and per stored field. Grid row reads compare date and time + without copying. - A retiring owner returns its 192 MiB workspace before its slot wakes the next owner. D2 released the slot first, and an owner woken on another worker could fail with `forecast cache: raw storage: Capacity` under load. From 7eadefb6ddc8a828417bdec0a1f6c6844df5621f Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 11:16:38 +0900 Subject: [PATCH 13/16] Port the factory prose reconstruction fixture from #2851 (#2849) runtime_services::inventory::factory_national_prose_reader_survives_factory_reconstruction fails on the D2 head 307defeb and passes on its merge base. Once the owner hand-off fix let the domestic tests pass, CI on this stack reached that test and failed there. The test file is taken unchanged from 0c163912 (PR #2851, commits 24fb0fbc and 0c163912; test only): each reconstruction phase prepares its weather once and ends detached owners and pools at its runtime boundary. Locally runtime_services passes 48/48 on this branch with it. Co-Authored-By: Claude Opus 5.5 --- server2/config/tasks/ColdBuildSpeed2849.json | 7 +- server2/tests/runtime_services/inventory.rs | 215 +++++++++++++------ 2 files changed, 152 insertions(+), 70 deletions(-) diff --git a/server2/config/tasks/ColdBuildSpeed2849.json b/server2/config/tasks/ColdBuildSpeed2849.json index b9128ec88..c7987597f 100644 --- a/server2/config/tasks/ColdBuildSpeed2849.json +++ b/server2/config/tasks/ColdBuildSpeed2849.json @@ -2,9 +2,9 @@ "task": "ColdBuildSpeed2849", "stable_task": "issue-2849-cold-build-speed", "issue": "https://github.com/WizardFactory/TodayWeather/issues/2849", - "status": "local implementation under the canonical SDLC stages; external writes pending the pre-merge authority record", + "status": "pre-merge under the canonical SDLC stages (AK delegation 2026-10-22): PR #2852 stacked on #2841; no merge or deployment", "base": "307defeb706886217ab67ea858dc7c7b0435752f", - "scope": "Empty-cache D2 forecast view build: ordered concurrent partition lookups (READ_AHEAD 12) with forecast store admission 12/12, 4 MiB output and 1 MiB controls per lookup; exact cached Doc weight and borrowed row lookup in the fold; latency control of the owned loopback peer, aged smoke mode and a base-versus-candidate matrix tool. No process S3 gate, owner/waiter, lookback, retention, freshness, provider, mode, timer or production/merge change.", + "scope": "Empty-cache D2 forecast view build: ordered concurrent partition lookups (READ_AHEAD 12) with forecast store admission 12/12, 4 MiB output and 1 MiB controls per lookup; exact cached Doc weight and borrowed row lookup in the fold; latency control of the owned loopback peer, aged smoke mode and a base-versus-candidate matrix tool. No process S3 gate, owner/waiter, lookback, retention, freshness, provider, mode, timer or production/merge change. Correction: the factory prose reconstruction test fixture of D2 is ported unchanged from PR #2851 (test only) so the stacked CI reaches a verdict.", "server2_paths": [ "server2/config/tasks/ColdBuildSpeed2849.json", "server2/src/domestic/kma/source/forecast_cache.rs", @@ -21,7 +21,8 @@ "server2/tools/domestic_warm_cache_smoke.py", "server2/tools/test_domestic_warm_cache_smoke.py", "server2/tools/cold_build_matrix.py", - "server2/tools/test_cold_build_matrix.py" + "server2/tools/test_cold_build_matrix.py", + "server2/tests/runtime_services/inventory.rs" ], "outside": [ { diff --git a/server2/tests/runtime_services/inventory.rs b/server2/tests/runtime_services/inventory.rs index ae384acb8..37ae68b7c 100644 --- a/server2/tests/runtime_services/inventory.rs +++ b/server2/tests/runtime_services/inventory.rs @@ -692,78 +692,159 @@ async fn populated_warning_http_survives_shared_service_reconstruction() { // Keep virtual request time fixed while real loopback S3/network I/O is polled; // this isolates factory reader wiring from cold-weather wall-clock cost. The // separate real-clock inventory and late-read controls retain deadline behavior. -#[tokio::test] -async fn factory_national_prose_reader_survives_factory_reconstruction() { - let _ = server2::domestic::kma::source::towns(); - let peer = Peer::new(); - let mut expected = None; - for phase in 0..2 { - let services = services(&peer); - ready(&services).await; - if phase == 0 { - expected = Some(populate(&services).await.1); - } - tokio::time::pause(); - let router = services.public_router(std::sync::Arc::new(server2::SharedState::new( - &server2::Config::default(), - ))); - let phase_started = std::time::Instant::now(); - for version in ["v000903", "v000901"] { - let mut proved = false; - for cold_to_warm_attempt in 0..4 { - use tower::ServiceExt; - let request = axum::http::Request::builder() - .uri(format!("/{version}/nation/KR")) - .header("accept-language", "ko") - .body(axum::body::Body::empty()) - .unwrap(); - let mut response = Box::pin(router.clone().oneshot(request)); - let response = std::future::poll_fn(|cx| { - assert!( - phase_started.elapsed() < Duration::from_secs(15), - "factory fixture did not complete" - ); - match std::future::Future::poll(response.as_mut(), cx) { - std::task::Poll::Ready(result) => std::task::Poll::Ready(result.unwrap()), - std::task::Poll::Pending => { - // A runnable task prevents automatic paused-time advancement. - cx.waker().wake_by_ref(); - std::task::Poll::Pending +#[test] +fn factory_national_prose_reader_survives_factory_reconstruction() { + // Other parallel tests may replace the process panic hook. Retain this + // fixture's failure reason while preserving the original panic result. + let result = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| { + let _ = server2::domestic::kma::source::towns(); + // Reuse connections within one factory to reduce peer handler-release races. + // Each phase's runtime ends its detached owners and pool before replacement; + // the peer retains canonical S3 state across that memory-loss boundary. + let peer = Peer::persistent(); + let mut expected = None; + for phase in 0..2 { + let runtime = tokio::runtime::Builder::new_current_thread() + .enable_all() + .build() + .unwrap(); + runtime.block_on(async { + let services = services(&peer); + ready(&services).await; + if phase == 0 { + expected = Some(populate(&services).await.1); + } + tokio::time::pause(); + let router = services.public_router(std::sync::Arc::new(server2::SharedState::new( + &server2::Config::default(), + ))); + let phase_started = std::time::Instant::now(); + let virtual_before = tokio::time::Instant::now(); + // Both API versions share these canonical weather inputs. Prepare once + // per phase so version conversion checks do not repeat cold setup work. + let version = "v000903"; + // Prepare weather through this same factory/router, one city at a time. + // A cold 15-city fanout can reject keys before detached owners finish; + // that is separate from the national prose reader wiring checked below. + // The first pass can start missing-publication owners which invalidate + // their canonical view. The second reads after those one-shot claims. + for _pass in 0..2 { + for city in server2::nation::CITIES { + use tower::ServiceExt; + let city_path: String = city + .bytes() + .map(|byte| match byte { + b'/' => "/".to_owned(), + _ if byte.is_ascii_alphanumeric() => (byte as char).to_string(), + _ => format!("%{byte:02X}"), + }) + .collect(); + let request = axum::http::Request::builder() + .uri(format!("/{version}/kma/addr/{city_path}")) + .header("accept-language", "ko") + .body(axum::body::Body::empty()) + .unwrap(); + let mut response = Box::pin(router.clone().oneshot(request)); + let response = std::future::poll_fn(|cx| { + assert!( + phase_started.elapsed() < Duration::from_secs(15), + "city preparation did not complete: phase {phase}, {city}, pass {_pass}" + ); + match std::future::Future::poll(response.as_mut(), cx) { + std::task::Poll::Ready(result) => { + std::task::Poll::Ready(result.unwrap()) + } + std::task::Poll::Pending => { + cx.waker().wake_by_ref(); + std::task::Poll::Pending + } + } + }) + .await; + let status = response.status(); + let bytes = axum::body::to_bytes(response.into_body(), 2 << 20) + .await + .unwrap(); + assert_eq!( + status, + 200, + "city setup: {phase}, {version}, {city}: {}", + String::from_utf8_lossy(&bytes[..bytes.len().min(2048)]) + ); + } + } + for version in ["v000903", "v000901"] { + let mut proved = false; + for cold_to_warm_attempt in 0..4 { + use tower::ServiceExt; + let request = axum::http::Request::builder() + .uri(format!("/{version}/nation/KR")) + .header("accept-language", "ko") + .body(axum::body::Body::empty()) + .unwrap(); + let mut response = Box::pin(router.clone().oneshot(request)); + let response = std::future::poll_fn(|cx| { + assert!( + phase_started.elapsed() < Duration::from_secs(15), + "factory fixture did not complete" + ); + match std::future::Future::poll(response.as_mut(), cx) { + std::task::Poll::Ready(result) => std::task::Poll::Ready(result.unwrap()), + std::task::Poll::Pending => { + // A runnable task prevents automatic paused-time advancement. + cx.waker().wake_by_ref(); + std::task::Poll::Pending + } + } + }) + .await; + let status = response.status(); + let bytes = axum::body::to_bytes(response.into_body(), 2 << 20) + .await + .unwrap(); + if status == 500 { + let body = std::str::from_utf8(&bytes).unwrap(); + assert!( + body.contains(""getWeather""), + "unexpected factory child error: {body}" + ); + println!( + "FACTORY_PROSE_WARMUP phase={phase} version={version} attempt={cold_to_warm_attempt} child500" + ); + continue; } + assert_eq!(status, 200); + let value: Value = serde_json::from_slice(&bytes).unwrap(); + assert_eq!( + value.get("forecastNarrative"), + expected.as_ref(), + "factory must attach exact stored prose, phase {phase}, {version}" + ); + super::inventory_nation::assert_response(&value, expected.as_ref().unwrap()); + println!( + "FACTORY_PROSE_READY phase={phase} version={version} attempt={cold_to_warm_attempt} elapsed_ms={}", + phase_started.elapsed().as_millis() + ); + proved = true; + break; } - }) - .await; - let status = response.status(); - let bytes = axum::body::to_bytes(response.into_body(), 2 << 20) - .await - .unwrap(); - if status == 500 { - let body = std::str::from_utf8(&bytes).unwrap(); assert!( - body.contains(""getWeather""), - "unexpected factory child error: {body}" + proved, + "factory fixture must produce a strict positive nation response: phase {phase}, {version}" ); - println!( - "FACTORY_PROSE_WARMUP phase={phase} version={version} attempt={cold_to_warm_attempt} child500" - ); - continue; } - assert_eq!(status, 200); - let value: Value = serde_json::from_slice(&bytes).unwrap(); - assert_eq!( - value.get("forecastNarrative"), - expected.as_ref(), - "factory must attach exact stored prose, phase {phase}, {version}" - ); - super::inventory_nation::assert_response(&value, expected.as_ref().unwrap()); - proved = true; - break; - } - assert!( - proved, - "factory fixture must produce a strict positive nation response: phase {phase}, {version}" - ); + assert_eq!(tokio::time::Instant::now(), virtual_before); + tokio::time::resume(); + }); } - tokio::time::resume(); + })); + if let Err(payload) = result { + let reason = payload + .downcast_ref::() + .map(String::as_str) + .or_else(|| payload.downcast_ref::<&str>().copied()) + .unwrap_or("non-string panic"); + eprintln!("factory national prose fixture failed: {reason}"); + std::panic::resume_unwind(payload); } } From 982055d9107ac850970262dd587b6aab7b0ad9bd Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 12:54:25 +0900 Subject: [PATCH 14/16] Record the Seoul t3.small empty-cache matrix (#2849) On one Spot t3.small (2 vCPUs) with the loopback peer, no binary answered an empty-cache request inside 3 s at 0, 10 or 20 ms. A running server's views are ready after 4.6 / 5.3 / 6.4 s with the candidate and 6.7 / 8.2 / 8.3 s with D2, whose owners stop at 8 s with few views. The 0 ms floor is parse and fold CPU; a 24-permit gate variant cut the 10/20 ms times to 4.8 / 5.3 s without lowering it. Also documents the matrix tool's stricter problem rule (CX-2852-001) and the test fixture ported from #2851 in the plan. Co-Authored-By: Claude Opus 5.5 --- .../diagrams/server2-cold-read.html | 6 +- .../diagrams/server2-cold-read.sequence.json | 6 +- docs/architecture/server2.md | 18 ++++- .../verification.md | 80 +++++++++++++++---- docs/operations/server2-domestic-cache.md | 4 +- plans/issue-2849-cold-build-speed.md | 1 + 6 files changed, 90 insertions(+), 25 deletions(-) diff --git a/docs/architecture/diagrams/server2-cold-read.html b/docs/architecture/diagrams/server2-cold-read.html index ca094b9ce..323f58454 100644 --- a/docs/architecture/diagrams/server2-cold-read.html +++ b/docs/architecture/diagrams/server2-cold-read.html @@ -5630,12 +5630,12 @@

    Preserved

    -

    Local evidence only

    +

    Loopback evidence

    • 130 partitions at 10 ms per operation: 0.55 s with 12 lookups in flight, 3.9 s sequential.
      • -
    • Request at a modeled 10 ms: views ready after 3.1 s in a running server (D2: none within its 8 s owner bound); the 3 s deadline is still missed.
      • -
    • Seoul t3.small, real S3 and TLS latency are not yet measured.
      • +
    • Local, modeled 10 ms: views ready after 3.1 s in a running server (D2: none within its 8 s owner bound); the 3 s deadline is still missed.
      • +
    • Seoul t3.small: views ready after 4.6 s even at 0 ms (D2: about 3 of 7 by its 8 s bound); fold CPU sets the floor. Real S3 and TLS are not measured.
    diff --git a/docs/architecture/diagrams/server2-cold-read.sequence.json b/docs/architecture/diagrams/server2-cold-read.sequence.json index 8a64060e6..7ba4cb94e 100644 --- a/docs/architecture/diagrams/server2-cold-read.sequence.json +++ b/docs/architecture/diagrams/server2-cold-read.sequence.json @@ -244,11 +244,11 @@ }, { "dot": "slate", - "title": "Local evidence only", + "title": "Loopback evidence", "items": [ "130 partitions at 10 ms per operation: 0.55 s with 12 lookups in flight, 3.9 s sequential.", - "Request at a modeled 10 ms: views ready after 3.1 s in a running server (D2: none within its 8 s owner bound); the 3 s deadline is still missed.", - "Seoul t3.small, real S3 and TLS latency are not yet measured." + "Local, modeled 10 ms: views ready after 3.1 s in a running server (D2: none within its 8 s owner bound); the 3 s deadline is still missed.", + "Seoul t3.small: views ready after 4.6 s even at 0 ms (D2: about 3 of 7 by its 8 s bound); fold CPU sets the floor. Real S3 and TLS are not measured." ] } ] diff --git a/docs/architecture/server2.md b/docs/architecture/server2.md index fc4d27e92..c9b33a66d 100644 --- a/docs/architecture/server2.md +++ b/docs/architecture/server2.md @@ -4137,7 +4137,7 @@ These are local source/cache results, not complete API parity, host p95 or an eligible rollback release. See the [operator guide](../operations/server2-domestic-cache.md) and [selected verification](../evidence/tasks/issue-2819-domestic-warm-cache/verification.md). -### D2 empty-cache reads (#2849, local candidate) +### D2 empty-cache reads (#2849) An empty forecast cache rebuilds a view from every partition in its lookback; the Seoul fixture town needs about 700 partition lookups (about 2,220 forecast GETs). @@ -4184,7 +4184,19 @@ bound with at most one of seven views; at 20 ms the running-server rebuild needs the 12-permit process gate, a fresh request's 3,628 S3 operations cannot finish in under about 3.0 s at 10 ms, and a running-server rebuild's 2,245 in under about 1.9 s, so the 2.5-second goal needs fewer S3 operations per view or more S3 -concurrency, both separate decisions. These are not host p95, real S3/TLS or -capacity results. See the +concurrency, both separate decisions. + +On the Seoul t3.small (2 vCPUs, Unlimited; same loopback peer on the same host, so +the peer shares the CPUs) no binary answered an empty-cache request inside 3 s at +0, 10 or 20 ms, in 20 fresh-process and 10 running-server runs per cell. Views +were ready in a running server after 4.6 / 5.3 / 6.4 s with the candidate and +6.7 / 8.2 / 8.3 s with D2 (D2's owners stop at their 8 s bound with a median of 3.5, 1 and +0.5 of 7 views mapped); +in a fresh process after 5.7 / 6.6 / 8.7 s and 7.7 / 8.2 / 8.4 s. Even at 0 ms +the candidate needs 4.6 s, so on this host class parse and fold CPU, not S3 +concurrency, sets the floor. An uncommitted variant with a 24-permit gate and +read-ahead measured 4.6 / 4.8 / 5.3 s; the largest resident set of any process +stayed about 88 MiB for all three. These are loopback measurements, not real +S3/TLS, p95 capacity or production results. See the [operator guide](../operations/server2-domestic-cache.md#measure-empty-cache-builds-at-modeled-s3-latency) and [selected verification](../evidence/tasks/issue-2849-cold-build-speed/verification.md). diff --git a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md index 8689ab784..5b9950627 100644 --- a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md +++ b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md @@ -3,9 +3,9 @@ Scope: #2849 on the D2 branch (PR #2841 head `307defeb706886217ab67ea858dc7c7b0435752f`). Ordered concurrent partition lookups, forecast store admission and per-lookup bounds, an exact cached Doc weight, borrowed grid row reads and the owner hand-off order. Local -pre-merge evidence on macOS arm64 (10 cores) with the owned loopback S3 peer and -modeled per-operation latency; it is not a Seoul host, real S3/TLS, p95 capacity or -production result. Raw logs, receipts and copied executables stay in the ignored task +pre-merge evidence with the owned loopback S3 peer and modeled per-operation latency, +on macOS arm64 (10 cores) and on one Seoul t3.small; it is not a real S3/TLS, p95 +capacity or production result. Raw logs, receipts and copied executables stay in the ignored task record. ## Candidate and input identities @@ -20,6 +20,8 @@ record. | Matrix tool (`54aad593`) | `1da1ac083483d0ce1cd9c407571e54b668b84402c24e1b629351bbb676db46fe` | | Loopback peer | `66aa32d8ef2fef5237d6b5824eb745966cc127668f6c58069389c5735415d9de` | | Original fixture manifest (730 acquisitions / 851 pages) | `11606b79c26365e4ba8a5a906d5801f717845f853bafc971c2f099d27b7bbe3f` | +| SM3 static musl examples: D2 + harness / candidate / `gate24` | `dddbc035a5277d08cc330c8e03b37f926e0a619873351317baaca7a5dd805859` / `ca42aa82cb6bdf4371db5ec4d4b9f5b8aef60f2513d7dee153fd42ef31e1c311` / `408a0cf2ed98e438b9219b0afa2a6e74c5a5e2a84aba509cb286cd6a97cdf116` | +| SM3 host package / retrieved results archive | `1104f185e4e5fc6c2de1890832f6e7d97a8cb152250e238f741b4a3bb1c1109a` / `84c2064a51396c120fba8b16f3e30f9f6fb5e1bee9cedf63738e66ca8272297f` | ## Behavior checks @@ -94,19 +96,70 @@ unchanged 12-permit process S3 gate, 2,245 operations at 10 ms need at least 2,245 × 10 ms ÷ 12 ≈ 1.9 s and 3,628 need ≈ 3.0 s before any fold work, so the remaining gap needs fewer S3 operations per view or more S3 concurrency. +## Seoul t3.small host (SM3) + +One task-owned, role-less Spot t3.small (Unlimited, 2 vCPUs, 1.9 GiB, Amazon Linux +2023 kernel 6.18) in ap-northeast-2d, SSH from the operator address only, egress +revoked before the workload, a 4-hour termination timer; 2026-10-22 02:08–03:51 UTC, +then terminated with its security group and root volume deleted (read back). The +workload ran under a systemd unit with 1,536 MiB memory and no swap. Static musl +x86-64 builds of the same three sources: D2 + harness (`307defeb` product code with +the final example), the candidate (`54aad593`), and an uncommitted measurement +variant `gate24` (the candidate with the process gate, `READ_AHEAD` and the example +gate at 24 and an idle connection pool of 32). The packaged peer copy accepted 32 +connections (tracked default 16) so the variant is not refused; the other two keep +at most 16 open. The matrix tool is the `207b176d` version. Matrix: 20 fresh-process +`http` runs and 10 `aged` runs per binary and delay, interleaved, no harness problem. +The Python peer runs on the same two vCPUs as the server, so these times include its +CPU; real S3 would not. + +No request of any binary was answered inside the 3 s deadline at 0, 10 or 20 ms +(0 of 270 cold requests and 0 of 90 aged rebuilds), so no body could be compared on +the host; the same Linux builds returned the reference body inside an emulated +amd64 container during qualification. Views ready (median, p95 in parentheses), +mapped views of 7 where fewer: + +| Delay | Request | D2 + harness | Candidate | gate24 variant | +| --- | --- | --- | --- | --- | +| 0 ms | running server | 6.73 s (7.02), 3.5 of 7 | 4.63 s (4.73) | 4.58 s (4.71) | +| 10 ms | running server | 8.15 s (9.46), 1 of 7 | 5.32 s (5.45) | 4.77 s (4.93) | +| 20 ms | running server | 8.28 s (8.29), 0.5 of 7 | 6.44 s (6.68) | 5.28 s (5.43) | +| 0 ms | fresh process | 7.65 s (7.93), 3 of 7 | 5.73 s (5.88) | 5.55 s (5.67) | +| 10 ms | fresh process | 8.24 s (9.93), 3 of 7 | 6.58 s (6.70) | 5.75 s (5.93) | +| 20 ms | fresh process | 8.36 s (8.39), 2 of 7 | 8.71 s (8.93), 6 of 7 | 6.28 s (6.39) | + +D2's times are its owners stopping at the 8-second bound with the views shown; D2 +read fewer objects for the same reason (1,875 / 1,402 / 739 forecast operations +against the candidate's 2,227). The candidate's floor at 0 ms, 4.6 s in a running +server, is parse and fold CPU on this host class (about 4.5 times the local 1.03 s), +not S3 concurrency: the 2.5-second goal is not met on t3.small at any modeled +delay. A 24-permit gate removes most of the latency-dependent part (10 ms: 5.32 → +4.77 s; 20 ms: 6.44 → 5.28 s) and does not lower the floor. The largest resident +set of any process (server, peer or tool) was 78.8 MiB for D2, 87.5 MiB for the +candidate and 88.1 MiB for `gate24` in the per-binary memory runs; the unit's +`memory.peak` (1.46 GiB) includes the page cache of 2.4 GiB of written run output +and is not a process size. CloudWatch showed at most 74 % average CPU per 5 minutes +and no surplus credits charged at the final snapshot; the host cost is estimated at +about USD 0.10 (Spot, surplus credits, root volume, public IPv4 and the result +download), not an invoice. + ## Tests and gates on the candidate On the candidate `server2/` tree: `cargo fmt --check` and all-target Clippy with warnings denied pass; the placement gate passes for `ColdBuildSpeed2849.json`; the peer self-check (with its latency control), 6 matrix-tool tests and 6 D2 runner tests -pass; the 8 cold-read integration tests and 63 source unit tests pass. The whole -workspace with 4 test threads and `--no-fail-fast`: 1,112 passed, 6 ignored, 1 failed. -The failure, `runtime_services::inventory::factory_national_prose_reader_survives_factory_reconstruction`, -fails the same way on the D2 head `307defeb` and passes on its merge base `c1ae9082`: -it is pre-existing in D2 and unrelated to this change (two owned flights panic during -`/v000903/nation/KR`). With that one test skipped by name, the workspace passes: -1,112 passed, 6 ignored, 0 failed across 30 test binaries. `tools/test_placement.py` did not run here: its self-tests call -`rustc +1.99.0`, which needs the rustup proxy this host lacks. +pass; the 8 cold-read integration tests and 63 source unit tests pass. The D2 test +`runtime_services::inventory::factory_national_prose_reader_survives_factory_reconstruction` +fails on the D2 head `307defeb` and passes on its merge base `c1ae9082` (two owned +flights panic during `/v000903/nation/KR`); its fixture is ported unchanged from +PR #2851 (`0c163912`, test only), after which `runtime_services` passes 48/0. At +`7eadefb6` the whole workspace with 4 test threads and `--no-fail-fast` passed +1,111 tests with 6 ignored and failed 2 `domestic::source_s3` tests with +`address_unavailable`: these tests alone leave about 33,500 loopback TIME_WAIT +sockets on macOS, the D2 base peaks at the same count and fails the same way when +run back to back, and the `domestic` binary rerun alone passes 181/0. PR CI at +`7eadefb6` (Linux) passes every check. `tools/test_placement.py` did not run here: +its self-tests call `rustc +1.99.0`, which needs the rustup proxy this host lacks. Base observations: D2 CI run `39243883911` failed 4 `domestic` tests with `forecast cache: raw storage: Capacity`, the owner hand-off defect fixed here. With @@ -116,9 +169,8 @@ threads: base 173 passed, candidate 181 passed (8 new), none failed. ## Limits -The latency is modeled on loopback: no TLS, connection setup or S3 variance, and the -local CPU is faster than the Seoul t3.small. The Seoul host matrix has not run; it -waits for AK's launch confirmation. The process S3 gate (12) is unchanged and shared, +The latency is modeled on loopback: no TLS, connection setup or S3 variance, and on +the Seoul host the peer shares the server's two vCPUs. The process S3 gate (12) is unchanged and shared, so one cold build can hold all its permits while it reads. Logical weights of the same data grow by 8 bytes per Doc and per stored field. Real-partition sizes are taken from the fixture (at most about 0.2 MiB decoded against the new 4 MiB bound). diff --git a/docs/operations/server2-domestic-cache.md b/docs/operations/server2-domestic-cache.md index 148c5a69c..fc0b7558a 100644 --- a/docs/operations/server2-domestic-cache.md +++ b/docs/operations/server2-domestic-cache.md @@ -52,9 +52,9 @@ python3 -B tools/cold_build_matrix.py \ --delays 0 10 20 --runs 5 ``` -The tool starts one persistent loopback peer, seeds the original corpus without delay, then sets the peer's latency control so every GET, HEAD and LIST waits the modeled milliseconds (PUT does not). For each delay and run it starts every binary in turn in `http` mode (fresh process: cold, warm1, warm2) and in `aged` mode (cold, then a rebuild after the 30-second view freshness, i.e. an empty forecast cache in a warm process). It keeps each run's bodies, compares every 200 body with the reference SHA-256 and reports status, median and p95 time, forecast LIST/catalog/descriptor/raw counts and, for cold and aged requests, when the views were ready, in `matrix.json`. A 502 after about 3 s is the unchanged native deadline and is recorded as a result; the owners of a cut answer keep building up to their 8-second bound, so the ready time and the number of mapped views show how far the build really was from the deadline. An `http` run then stops; an `aged` run still makes its rebuild request after the cold one was cut, because the forecast views of a running server go stale after 30 seconds and that rebuild (with about 20 other S3 operations instead of about 1,400 in a fresh process) is the common empty-cache case. Exit 1 means a harness problem (missing phases, a failed child after successful answers, a wrong body), never a slow answer. +The tool starts one persistent loopback peer, seeds the original corpus without delay, then sets the peer's latency control so every GET, HEAD and LIST waits the modeled milliseconds (PUT does not). For each delay and run it starts every binary in turn in `http` mode (fresh process: cold, warm1, warm2) and in `aged` mode (cold, then a rebuild after the 30-second view freshness, i.e. an empty forecast cache in a warm process). It keeps each run's bodies, compares every 200 body with the reference SHA-256 and reports status, median and p95 time, forecast LIST/catalog/descriptor/raw counts and, for cold and aged requests, when the views were ready, in `matrix.json`. A 502 after about 3 s is the unchanged native deadline and is recorded as a result; the owners of a cut answer keep building up to their 8-second bound, so the ready time and the number of mapped views show how far the build really was from the deadline. An `http` run then stops; an `aged` run still makes its rebuild request after the cold one was cut, because the forecast views of a running server go stale after 30 seconds and that rebuild (with about 20 other S3 operations instead of about 1,400 in a fresh process) is the common empty-cache case. Exit 1 means a harness problem (missing phases, an `aged` run without its rebuild, a timed-out or killed child, a failed child after successful answers, a wrong body), never a slow answer. -The delay is modeled on loopback: it has no TLS, connection setup or real S3 variance, and the host CPU decides the fold time. It is not a host p95 or capacity qualification. The selected local result of #2849 is in its [verification record](../evidence/tasks/issue-2849-cold-build-speed/verification.md). +The delay is modeled on loopback: it has no TLS, connection setup or real S3 variance, and the host CPU decides the fold time. It is not a host p95 or capacity qualification. The selected local and Seoul t3.small results of #2849 are in its [verification record](../evidence/tasks/issue-2849-cold-build-speed/verification.md). ## Read the actual retained result diff --git a/plans/issue-2849-cold-build-speed.md b/plans/issue-2849-cold-build-speed.md index 324975daf..36c4518e7 100644 --- a/plans/issue-2849-cold-build-speed.md +++ b/plans/issue-2849-cold-build-speed.md @@ -19,6 +19,7 @@ Intended `server2/` paths: | `server2/src/domestic/kma/source/items.rs`, `rss.rs` (conditional) | only if the profile of the new baseline shows a remaining shared per-read copy; unchanged otherwise | | `server2/tests/domestic.rs`, `server2/tests/domestic/forecast_cold_read.rs` (new) | delayed/counting transport double, ordered-concurrency, fault, cap and cancellation tests | | `server2/tests/storage/catalog_peer.py` | runtime `latency` control of the loopback peer for the measurement harness, with its own loopback self-check | +| `server2/tests/runtime_services/inventory.rs` | correction 2026-10-22: D2 factory prose reconstruction fixture ported unchanged from PR #2851 (`0c163912`, test only) so stacked CI reaches a verdict | | `server2/examples/domestic_warm_cache_smoke.rs` | transport gate 4 → 12 (the product's `S3_IN_FLIGHT`), `aged` mode (cold, then a request after the 30 s freshness bound) | | `server2/tools/domestic_warm_cache_smoke.py` (+ its test only if affected) | the runner records the example's S3 transport admission (`s3_transport_admission`), which becomes 12 | | `server2/tools/cold_build_matrix.py`, `server2/tools/test_cold_build_matrix.py` (new) | repeatable base-versus-candidate matrix at modeled S3 delays, with pure report-check tests | From af1caa4adec060bc5a498d8f85d58a0ee7dfa2dc Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 12:59:38 +0900 Subject: [PATCH 15/16] Narrow the Seoul host conclusions to what the data shows (#2849) Only the Linux candidate and gate24 builds returned the reference body during qualification; the D2 build did not. D2's owners did not all stop at the 8 s bound: at 0 ms two rebuilds failed early without a logged cause. The 4.6 s at 0 ms is a floor of a setup in which the loopback peer shares the two vCPUs, not a measured parse and fold time. Review findings CX-2852-003, -004 and -005. Co-Authored-By: Claude Opus 5.5 --- .../diagrams/server2-cold-read.html | 2 +- .../diagrams/server2-cold-read.sequence.json | 2 +- docs/architecture/server2.md | 13 +++++---- .../verification.md | 28 ++++++++++++------- 4 files changed, 27 insertions(+), 18 deletions(-) diff --git a/docs/architecture/diagrams/server2-cold-read.html b/docs/architecture/diagrams/server2-cold-read.html index 323f58454..dcabe7976 100644 --- a/docs/architecture/diagrams/server2-cold-read.html +++ b/docs/architecture/diagrams/server2-cold-read.html @@ -5635,7 +5635,7 @@

    Loopback evidence

    • 130 partitions at 10 ms per operation: 0.55 s with 12 lookups in flight, 3.9 s sequential.
    • Local, modeled 10 ms: views ready after 3.1 s in a running server (D2: none within its 8 s owner bound); the 3 s deadline is still missed.
      • -
    • Seoul t3.small: views ready after 4.6 s even at 0 ms (D2: about 3 of 7 by its 8 s bound); fold CPU sets the floor. Real S3 and TLS are not measured.
      • +
    • Seoul t3.small: views ready after 4.6 s even at 0 ms (D2: about 3 of 7 views); host CPU, shared with the loopback peer, sets the floor. Real S3 and TLS are not measured.
    diff --git a/docs/architecture/diagrams/server2-cold-read.sequence.json b/docs/architecture/diagrams/server2-cold-read.sequence.json index 7ba4cb94e..970974015 100644 --- a/docs/architecture/diagrams/server2-cold-read.sequence.json +++ b/docs/architecture/diagrams/server2-cold-read.sequence.json @@ -248,7 +248,7 @@ "items": [ "130 partitions at 10 ms per operation: 0.55 s with 12 lookups in flight, 3.9 s sequential.", "Local, modeled 10 ms: views ready after 3.1 s in a running server (D2: none within its 8 s owner bound); the 3 s deadline is still missed.", - "Seoul t3.small: views ready after 4.6 s even at 0 ms (D2: about 3 of 7 by its 8 s bound); fold CPU sets the floor. Real S3 and TLS are not measured." + "Seoul t3.small: views ready after 4.6 s even at 0 ms (D2: about 3 of 7 views); host CPU, shared with the loopback peer, sets the floor. Real S3 and TLS are not measured." ] } ] diff --git a/docs/architecture/server2.md b/docs/architecture/server2.md index c9b33a66d..9c761ef60 100644 --- a/docs/architecture/server2.md +++ b/docs/architecture/server2.md @@ -4189,12 +4189,13 @@ concurrency, both separate decisions. On the Seoul t3.small (2 vCPUs, Unlimited; same loopback peer on the same host, so the peer shares the CPUs) no binary answered an empty-cache request inside 3 s at 0, 10 or 20 ms, in 20 fresh-process and 10 running-server runs per cell. Views -were ready in a running server after 4.6 / 5.3 / 6.4 s with the candidate and -6.7 / 8.2 / 8.3 s with D2 (D2's owners stop at their 8 s bound with a median of 3.5, 1 and -0.5 of 7 views mapped); -in a fresh process after 5.7 / 6.6 / 8.7 s and 7.7 / 8.2 / 8.4 s. Even at 0 ms -the candidate needs 4.6 s, so on this host class parse and fold CPU, not S3 -concurrency, sets the floor. An uncommitted variant with a 24-permit gate and +were ready (owners idle) in a running server after 4.6 / 5.3 / 6.4 s with the +candidate and 6.7 / 8.2 / 8.3 s with D2, whose owners mapped a median of only 3.5, +1 and 0.5 of 7 views (two of its 0 ms rebuilds failed early without a logged +cause); in a fresh process after 5.7 / 6.6 / 8.7 s and 7.7 / 8.2 / 8.4 s. Even at +0 ms the candidate needs 4.6 s with the server, peer and loopback HTTP on the same +two vCPUs, which points to CPU rather than S3 concurrency; parse and fold alone were +not timed on the host. An uncommitted variant with a 24-permit gate and read-ahead measured 4.6 / 4.8 / 5.3 s; the largest resident set of any process stayed about 88 MiB for all three. These are loopback measurements, not real S3/TLS, p95 capacity or production results. See the diff --git a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md index 5b9950627..e3a3f08e7 100644 --- a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md +++ b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md @@ -115,9 +115,11 @@ CPU; real S3 would not. No request of any binary was answered inside the 3 s deadline at 0, 10 or 20 ms (0 of 270 cold requests and 0 of 90 aged rebuilds), so no body could be compared on -the host; the same Linux builds returned the reference body inside an emulated -amd64 container during qualification. Views ready (median, p95 in parentheses), -mapped views of 7 where fewer: +the host. During qualification in an emulated amd64 container the Linux candidate and +`gate24` builds returned the reference body; the D2 build answered no request with +200 there either, so its Linux body is not verified. Views ready (median, p95 in +parentheses) is when the owners started by the request went idle; mapped views of 7 +where fewer: | Delay | Request | D2 + harness | Candidate | gate24 variant | | --- | --- | --- | --- | --- | @@ -128,13 +130,19 @@ mapped views of 7 where fewer: | 10 ms | fresh process | 8.24 s (9.93), 3 of 7 | 6.58 s (6.70) | 5.75 s (5.93) | | 20 ms | fresh process | 8.36 s (8.39), 2 of 7 | 8.71 s (8.93), 6 of 7 | 6.28 s (6.39) | -D2's times are its owners stopping at the 8-second bound with the views shown; D2 -read fewer objects for the same reason (1,875 / 1,402 / 739 forecast operations -against the candidate's 2,227). The candidate's floor at 0 ms, 4.6 s in a running -server, is parse and fold CPU on this host class (about 4.5 times the local 1.03 s), -not S3 concurrency: the 2.5-second goal is not met on t3.small at any modeled -delay. A 24-permit gate removes most of the latency-dependent part (10 ms: 5.32 → -4.77 s; 20 ms: 6.44 → 5.28 s) and does not lower the floor. The largest resident +D2's owners went idle with only the views shown mapped and read fewer objects +(1,875 / 1,402 / 739 forecast operations against the candidate's 2,227). At 10 and +20 ms they reached the 8-second owner bound; at 0 ms they went idle earlier, and two +of D2's ten 0 ms running-server rebuilds failed early (502 after 2.21 and 2.37 s, +with 2 and 4 views mapped). The info-level log records no cause for these early +stops: they are consistent with the owner hand-off defect fixed here, but that is +not confirmed. The candidate and `gate24` had no early failure. The candidate's +0 ms time, 4.6 s in a running server (about 4.5 times the local 1.03 s), is a floor +of this setup, in which the server, the Python peer and loopback HTTP share the two +vCPUs; it points to CPU rather than S3 concurrency, but parse and fold time alone +was not separated on the host. The 2.5-second goal is not met on t3.small at any +modeled delay. A 24-permit gate removes most of the latency-dependent part (10 ms: +5.32 → 4.77 s; 20 ms: 6.44 → 5.28 s) and does not lower the 0 ms time. The largest resident set of any process (server, peer or tool) was 78.8 MiB for D2, 87.5 MiB for the candidate and 88.1 MiB for `gate24` in the per-binary memory runs; the unit's `memory.peak` (1.46 GiB) includes the page cache of 2.4 GiB of written run output From bd7122ae55fa87106b607e67c0b38f5e733219b2 Mon Sep 17 00:00:00 2001 From: hwanjjang Date: Thu, 22 Oct 2026 14:11:11 +0900 Subject: [PATCH 16/16] Correct the D2 operation series and the one 10 ms answer (#2849) The fresh-process and running-server D2 operation counts were given as one series, D2's 10 ms owners were said to reach the 8 s bound although two stayed active until 9.46 s, and the one local 10 ms 200 took a client-measured 3.003 s, not under 3 s. Additional review finding GK-2852-001 and reviewer notes. Co-Authored-By: Claude Opus 5.5 --- docs/architecture/server2.md | 4 ++-- .../tasks/issue-2849-cold-build-speed/verification.md | 10 ++++++---- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/docs/architecture/server2.md b/docs/architecture/server2.md index 9c761ef60..6e02e0aae 100644 --- a/docs/architecture/server2.md +++ b/docs/architecture/server2.md @@ -4177,8 +4177,8 @@ sequential estimate; the fold of `short` falls from 1,171 to 687 ms and `shortes from 418 to 297 ms with all 13 golden Docs unchanged. An empty-cache request at 0 ms takes 1.10 s instead of 1.78 s in a fresh process and 1.03 s instead of 1.52 s in a running server whose views went stale. At a modeled 10 ms the candidate's views are -ready after 3.1 s in a running server (one of five such requests answered inside -3 s) and after 4.7 s in a fresh process, while D2's owners stop at their 8-second +ready after 3.1 s in a running server (one of five such requests answered 200, at +a client-measured 3.003 s) and after 4.7 s in a fresh process, while D2's owners stop at their 8-second bound with at most one of seven views; at 20 ms the running-server rebuild needs 5.4 s. Through the 12-permit process gate, a fresh request's 3,628 S3 operations cannot finish in diff --git a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md index e3a3f08e7..09cd420dc 100644 --- a/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md +++ b/docs/evidence/tasks/issue-2849-cold-build-speed/verification.md @@ -86,7 +86,7 @@ the owners started by the request were idle, measured outside the request timing | 0 ms | fresh process | 200 in 1,784 ms (2,195) | 200 in 1,096 ms (1,413) | | 0 ms | running server | 200 in 1,516 ms (1,606) | 200 in 1,026 ms (1,160) | | 10 ms | fresh process | 502 at 3.0 s; owners stop at the 8 s bound with 1 of 7 views | 502 at 3.0 s; 7/7 views ready at 4.66 s (4.75) | -| 10 ms | running server | 502 at 3.0 s; 0 of 7 views | 7/7 views ready at 3.12 s (3.14); 1 of 5 answered 200 inside 3 s, 4 answered 502 | +| 10 ms | running server | 502 at 3.0 s; 0 of 7 views | 7/7 views ready at 3.12 s (3.14); 1 of 5 answered 200 (client-measured 3.003 s), 4 answered 502 | | 20 ms | fresh process | 502 at 3.0 s; 2 of 7 views | 502 at 3.0 s; 6 of 7 views by 8.02 s | | 20 ms | running server | 502 at 3.0 s; 0 of 7 views | 502 at 3.0 s; 7/7 views ready at 5.41 s | @@ -130,9 +130,11 @@ where fewer: | 10 ms | fresh process | 8.24 s (9.93), 3 of 7 | 6.58 s (6.70) | 5.75 s (5.93) | | 20 ms | fresh process | 8.36 s (8.39), 2 of 7 | 8.71 s (8.93), 6 of 7 | 6.28 s (6.39) | -D2's owners went idle with only the views shown mapped and read fewer objects -(1,875 / 1,402 / 739 forecast operations against the candidate's 2,227). At 10 and -20 ms they reached the 8-second owner bound; at 0 ms they went idle earlier, and two +D2's owners went idle with only the views shown mapped and read fewer objects: +1,875 / 1,402 / 739 forecast operations per fresh-process request and 1,876 / 1,471 / +773 per running-server rebuild, against the candidate's 2,227. At 10 and 20 ms they +went idle at or after the 8-second owner bound (two 10 ms rebuilds only at 9.46 s); +at 0 ms they went idle earlier, and two of D2's ten 0 ms running-server rebuilds failed early (502 after 2.21 and 2.37 s, with 2 and 4 views mapped). The info-level log records no cause for these early stops: they are consistent with the owner hand-off defect fixed here, but that is