Skip to content

qa: full log-volume census — structured logger is 77.1% of test output, not ~45% - #14989

Merged
os-musk merged 12 commits into
mainfrom
claude/issue-13986-structured-logger-volume-census
Sep 3, 2026
Merged

qa: full log-volume census — structured logger is 77.1% of test output, not ~45%#14989
os-musk merged 12 commits into
mainfrom
claude/issue-13986-structured-logger-volume-census

Conversation

@os-musk

@os-musk os-musk commented Sep 3, 2026

Copy link
Copy Markdown
Collaborator

Part of #13986

PM seat note on the reference keyword. This line read Fixes #13986 when the PR was opened; it is Part of now. Triage's ruling on the card requires the fork to come back to this card after the measurement, so a closing keyword would delete the fork's home the moment this merges. Verbatim, from comment 5489397004, ruling item ③: 「⇒ 实施者跑完测量后,⛔ 不得自行选缝。报 fork 回分诊,附测量结果。届时按正典四棱重估」. Nothing else in this PR changed.

What this is

Triage's ruling on this card (comment 5489397004): "the deliverable is the
unmeasured half, not another seam"
and "after running the measurement, do
not pick a seam yourself — report a fork back to triage with the results."

This PR is exactly that: the measurement, and nothing else. No seam was
added.
Which of the two candidate seams (if either) to build is left for
triage, with the numbers below in hand.

The measurement

scripts/qa/log-volume-census.mjs runs every one of the 72 workspace
packages' own test script unchanged, captures combined stdout+stderr, and
classifies every line as structured (the engine logger's fixed
TIMESTAMP LEVEL … / JSON head), reporter (vitest's own closed
vocabulary), or console (the complement — everything else). All 72
packages measured, all green.

console structured reporter total
all 72 packages 17,428 61,980 993 80,401

structured share of total: 77.1% — comparable to the card's own ~45%
framing (its console bucket absorbed what this instrument tracks
separately as reporter).

The ratio does not hold, and not toward more noise — it moved to 77.1%
structured, for two compounding reasons:

  1. Two commits landed on main between the card's reading and this one —
    b79ddf17d (test(dogfood): declare OS_REGISTRY_LOG=warn in the suite's own vitest harness #13985) and 5e2c04da7 (test(objectql,verify,runtime): declare OS_REGISTRY_LOG=warn in each suite's own vitest harness #14016) — each declaring
    OS_REGISTRY_LOG=warn in a suite's vitest harness. That alone takes the
    same five suites the card measured from ~45% to 86.6% structured,
    by cutting a [Registry] debug-console.log population. Reproduced here
    as a control before trusting anything else: packages/rest, the one
    suite of the five nothing touched, moved only +5.8% on console.
  2. Extending to the other 67 packages pulls that back down to 77.1%, not
    further: that population's own structured share (57.7%) is lower than the
    five heaviest suites', but it's also a minority of total volume (30.3%
    of all lines), and most of it barely writes anything at all — 35 of 72
    packages under 30 lines total, 22 of those exactly 13 (pure reporter
    boilerplate, nothing else). Structured lines need a kernel boot; a lot of
    packages/services/*, packages/triggers/* and thin plugins/* suites
    never construct one.

A finding relevant to which seam triage picks (not a choice)

The premise re-verification found new ObjectKernel() — no config — appears
78 times across 55 files (verified at 54a972905, this branch merged
with origin/main at 99b4deba4), not only in packages/verify's harness.
packages/objectql/src/kernel-factory.ts:35 has the identical shape, and
objectql alone contributes 18.3% of the structured total measured here. A
BootOptions field on packages/verify's harness would quiet only suites
that boot through that harness — not objectql's, nor most of the other ~53
call sites — without each being found and updated individually. An env-level
default read at the kernel/logger construction point (NO_COLOR's existing
pattern in the same file is the precedent) would cover all 78 call sites
without touching any of them. Doesn't choose a seam; changes what each one
would actually cost to reach the population it's meant to quiet.

Full per-package table, method, limits, the mechanism verification
(packages/core/src/logger.ts writing straight to process.stdout/stderr,
never through console), and the complete Zone-2-D premise re-verification
are all in docs/audits/2026-09-test-log-volume-census.md.

Not superseded

#13517 covers the console population and is untouched by this — the two
cards measure different writers, as the original finding said.

Scope

  • No production code touched. scripts/qa/log-volume-census.mjs (the
    instrument) and docs/audits/2026-09-test-log-volume-census.md (the
    reading) only.
  • packages/spec measured read-only — its own test script run, stdout
    captured, nothing under it edited.
  • No changeset: this PR publishes nothing from any released package. The
    skip-changeset label is on and verified by read-back (documentation,
    size/l, skip-changeset) — the author's own read-back attempts hit the
    shared GraphQL rate-limit bucket and could not confirm it at the time.

Generated by Claude Code

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
Extends Batch 1's ledger (23 packages, driven under the shared verify
lock) with 9 more: driver-sqlite-wasm, driver-turso, formula, lint,
mcp, metadata, metadata-core, metadata-fs, metadata-protocol.

Also: end-to-end control for the OS_LOG_LEVEL premise re-verification
(Zone 2 D) — resolveLogLevel() confirmed sensitive to its input, and a
repo-wide grep confirms it is read nowhere outside packages/cli (one
non-hit is a self-test fixture string in dispatch-gates.mjs).

Doc's method/mechanism/reproduction/premise sections carried over from
a prior attempt's draft, independently re-verified against source
(packages/core/src/logger.ts, packages/verify/src/harness.ts) before
being kept — every file:line citation checked out exactly.

Provisional structured share (console+structured) at 32/72: ~84%,
already far from the five-suite ~45%, in the direction the earlier
reading's own explanation predicts. Not the final number — continuing.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
+13 packages this batch: observability, platform-objects,
embedder-openai, knowledge-memory, knowledge-ragflow,
plugin-approvals, plugin-audit, plugin-auth, plugin-dev, plugin-email,
plugin-hono-server, plugin-pinyin-search, plugin-reports.

plugin-auth is the first non-trivial plugins/ package: 4,840 lines
(2,149 structured / 2,678 console) — most plugins so far are near-
silent (13 reporter lines only, no kernel boot in their own test
script).

Provisional structured share (console+structured) at 45/72: ~80%.
27 remain, all services/*, triggers/*, spec, sdui-parser, and the
qa/http-conformance + qa/downstream-contract pair.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
+10 packages this batch: plugin-security, plugin-sharing,
plugin-webhooks, downstream-contract, http-conformance, sdui-parser,
service-analytics, service-automation, service-cache, service-cluster.

17 remain: service-cluster-redis, service-datasource, service-i18n,
service-job, service-knowledge, service-messaging, service-package,
service-queue, service-realtime, service-settings, service-sms,
service-storage, spec, trigger-api, trigger-record-change,
trigger-schedule, types.

Provisional structured share (console+structured) at 55/72: ~79%,
holding steady across three checkpoints now (84% -> 80% -> 79%).

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
+13 packages this batch: service-cluster-redis, service-datasource,
service-i18n, service-job, service-knowledge, service-messaging,
service-package, service-queue, service-realtime, service-settings,
service-sms, service-storage, spec.

4 remain: trigger-api, trigger-record-change, trigger-schedule, types.

packages/spec measured read-only (its own `test` script run and
stdout captured, nothing edited under it — domain:spec's package
stays untouched); 481s of the 480s budget, exit 0.

Provisional structured share (console+structured) at 68/72: ~78%.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
… hold

All 72 workspace packages with a test script measured, all green.
Final totals: 61,980 structured / 17,428 console / 993 reporter /
80,401 total lines — structured share of total 77.1% (comparable to
the earlier five-suite framing, whose own `console` bucket absorbed
what this instrument tracks separately as `reporter`).

The five-suite ~45% figure does not hold, and not toward more noise:
it moved to 77.1% structured, decomposed in "The answer" section as
two effects — (1) two commits (#13985, #14016) that landed on main
between the earlier reading and this one already took the original
five suites from ~45% to 86.6% structured on their own, by cutting a
`[Registry]` debug-console population; (2) extending to the other 67
packages pulls that back down to 77.1% (not further), since that
population's own structured share (57.7%) is lower than the five
heaviest suites' but is also a minority (30.3%) of total test-run
volume, and most of it (35/72 packages under 30 lines total, 22 of
those exactly 13 -- pure reporter boilerplate) never boots a kernel at
all.

No seam added -- per triage's ruling (comment 5489397004), this
document is the measurement; which seam (if either) to build is
triage's call.

Merged origin/main (dispatch-gates warned STALE TREE, 19 commits
behind) -- no relevant file (logger.ts, harness.ts, log-level.ts,
vitest configs, package.json test scripts) changed across that range,
so the merge does not invalidate any measurement already taken.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
@github-actions github-actions Bot added size/l documentation Improvements or additions to documentation labels Sep 3, 2026
@os-musk os-musk added skip-changeset PR has no user-facing published change; bypasses the changeset gate and removed documentation Improvements or additions to documentation size/l labels Sep 3, 2026 — with Claude
…ess.ts

Relevant to the fork this card hands back to triage: a BootOptions
field on packages/verify's harness would only quiet suites that boot
through that harness, not the ~60 other files (85 call sites) that
construct a kernel directly -- including packages/objectql's own
kernel-factory.ts, which alone accounts for 18.3% of the structured
lines measured. Does not choose a seam; changes what each seam would
cost to actually reach the population it's meant to quiet.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
Review found three citation defects in
docs/audits/2026-09-test-log-volume-census.md — the measurement itself
(72-row table, arithmetic) was independently reproduced and is untouched.

1. `new ObjectKernel(` repo-wide count: re-ran the exact grep command on
   this branch merged with origin/main and got 78 occurrences across 55
   files, not 85/62. Corrected the number and the two downstream figures
   that depend on it (~53 remaining call sites, "all 78 call sites"),
   and stamped the ref it was verified against so a future drift is
   reproducible instead of silent.
2. `scripts/pm/dispatch-gates.mjs:14461` is blank on this tree; the real
   self-test-fixture line is 14478. Corrected and ref-stamped (this file
   is edited often).
3. `packages/core/src/logger.ts:350-395` — the quoted block actually
   starts at 349, not 350 (content verbatim-correct, only the start line
   was off by one; end line shifts by the same one to 394).

Re-resolved the other eight citations the reviewer already checked
(logger.ts:180/236, harness.ts:96-313/384, kernel.ts:87,
log-level.ts:53, kernel-factory.ts:35, and the 72/72
disableConsoleIntercept:true claim) against this branch's merged tree —
none of them moved.

Part of #13986

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
origin/main moved again (99b4deb) between the first fix commit and the
gate sweep. Re-verified all three corrected citations plus the eight
already-checked ones against that tree — nothing moved — and updated the
inline ref stamps from 48d4422 to 0de50b8 (this branch's HEAD after
merging origin/main a second time) so they point at the tree the numbers
were actually last confirmed on.

Part of #13986

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68
@os-musk
os-musk marked this pull request as ready for review September 3, 2026 18:21

os-musk commented Sep 3, 2026

Copy link
Copy Markdown
Collaborator Author

Review FAIL cleared — all three citations corrected, and the PM seat re-measured them independently

Independent review FAILed this PR on three citation defects. The fix round corrected them, and this seat then re-ran the three measurements itself on the branch head 54a972905 rather than accepting the fix report:

# was now independently re-measured here
1 new ObjectKernel( 85 times across 62 files 78 across 55 grep -rn 'new ObjectKernel(' --include='*.ts' packages examples78 lines, 55 files. Exact match.
2 the OS_LOG_LEVEL hit at dispatch-gates.mjs:14461 :14478 sed -n '14461p' | cat -A$, i.e. blank; :14478 is the self-test-fixture string. Confirmed.
3 the write block at logger.ts:350-395 :349-394 sed -n '349p'const isErrorLevel = level === 'error' || level === 'fatal';. Confirmed.

The fix round did more than the three it was asked for, correctly. Two further numbers in the same paragraph were derived from the wrong count and would have silently survived a narrow fix: the "~60 remaining call sites" estimate is now ~53, and "all 85 call sites" is now all 78. Neither was in the review's finding list; catching them is the difference between fixing a symptom and fixing the paragraph.

And the actual repair is not the number — it is the ref. Each corrected figure now carries the commit it was verified against (verified at 0de50b83a), which is exactly what the failing claim lacked: it had its own repro command and no stamp, so nobody could tell which tree it was true of. The other eight citations the reviewer had checked at 357c7e3d5 were re-resolved on the final merged tree; none had moved.

Everything the review passed stayed untouched, as instructed: the 72-row census table (arithmetically reconciled row by row, 61,980 / 80,401 = 77.1%), the instrument scripts/qa/log-volume-census.mjs, and the three-package spot-check that reproduced two of three on every field.

Gates: 25 commands derived off the merge base with no path arguments — 24 exit 0, one (check-test-completeness.mjs) exit 3 PREREQUISITE NOT MET by its own design (it grades a saved CI turbo-test log that does not exist locally; recorded as NOT MEASURED, never as a pass). check-governed-merges --test: NOT governed. skip-changeset unchanged and correct. Part of #13986 unchanged — that keyword is load-bearing: this card still owes its seam fork to triage, and a closing keyword would delete the fork's home.

Landing state, stated precisely. Marked ready. ⛔ Auto-merge is deliberately NOT armed yet: 33 of 34 check runs are green or skipped, but Lint & Repo Gates is still in_progress, and this seat's enqueue bar is every check run green or skipped — an in-progress check is not a green one. That gate is also the one that matters most here, since this PR is entirely a documentation edit and Lint & Repo Gates is where the repo's doc gates run. It will be armed once that check reports.


Generated by Claude Code

@os-musk
os-musk added this pull request to the merge queue Sep 3, 2026
Merged via the queue into main with commit 6e6efac Sep 3, 2026
36 checks passed
@os-musk
os-musk deleted the claude/issue-13986-structured-logger-volume-census branch September 3, 2026 19:22
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

documentation Improvements or additions to documentation size/l skip-changeset PR has no user-facing published change; bypasses the changeset gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants