Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 15 additions & 0 deletions .changeset/15484-rest-log-declared-level-seam.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
---
"@objectstack/rest": patch
---

`packages/rest`'s fault logging gains a **declared level seam**, `OS_REST_LOG`, with the **shipped default unchanged**. At the default — and an unset or unrecognised value *is* the default — a reported fault still prints the whole `Error`: message, `cause` chain and stack frames, exactly as before. ⛔ No wire byte moves, no published payload gains a key, and no existing log line changes shape.

What is new is that the loud/quiet choice is now **declared and machine-read** instead of implicit in whether an author happened to pass `error` or `error.message`:

- **`OS_REST_LOG`** accepts `debug` / `info` / `warn` / `error` / `silent` — deliberately the same vocabulary and the same `'info'` default as `@objectstack/objectql`'s `OS_REGISTRY_LOG`, so the two are one logging contract with two populations rather than a second ad-hoc environment variable. Documented for operators in this package's README.
- **`scripts/check-rest-log-declared.mjs`** enforces it: the seam is located by its environment read (never a hardcoded path), the vocabulary is read from `REST_LOG_LEVELS` rather than copied, the two seams' vocabularies are held equal, a harness declaration must name a level the seam actually recognises — an unrecognised one resolves to the default *silently* — and every inline vitest project must carry its own declaration, because a root-level `env` is inert for project runs.
- **The shipped default is gated, not just documented.** Lowering `REST_LOG_DEFAULT_LEVEL` to `error` or `silent` is a finding, because at those levels this package stops reporting faults it is the only reporter of.

**Why the default does not move.** Measured on one green `packages/rest` run: 2,095 indented `at ` frame lines, 36.7% of captured output, 100% of them arriving through this one shim. They are not dead weight. When a 5xx is withheld from the client, the log is the only copy of the driver text, and that text lives on `error.cause` — printed only because a whole `Error` object, not a summary, reaches `console.error`. Four assertions across `rest-5xx-message-sanitization.test.ts` and `rest-expected-error-logging.test.ts` pin that by asserting the **identity** of the error that arrives, one of them carrying an explicit do-not-delete warning aimed at exactly this repair.

Operators: nothing to do. A deployment that wants the REST layer quieter can now say so — `OS_REST_LOG=error` drops the warning half, `silent` drops both — but doing so discards diagnostics that have no second copy anywhere, and the README says so at the seam.
13 changes: 13 additions & 0 deletions .github/workflows/lint.yml
Original file line number Diff line number Diff line change
Expand Up @@ -3762,6 +3762,19 @@ jobs:
- name: Declared registry log level
run: node scripts/check-registry-log-declared.mjs --self-test && node scripts/check-registry-log-declared.mjs

# The same defect one package down (#15484). `packages/rest`'s own fault
# logging hands whole `Error` objects to `console.error`, and Node prints
# the stack and the `[cause]` chain with them — 2,095 indented `at ` frame
# lines on one green run, 36.7% of the captured output, all of it through
# one shim. ⛔ Those frames are READ (four assertions pin the identity of
# the error that arrives, #5437 / #4886 / #5489), so the ruled repair was a
# DECLARED level, not a quieter product. This holds the two halves that rot
# silently: a harness declaration that is deleted or typo'd to a level the
# seam does not recognise (it resolves to the DEFAULT, silently), and the
# shipped default itself being lowered to quieten a log. Self-test first.
- name: Declared REST fault-log level
run: node scripts/check-rest-log-declared.mjs --self-test && node scripts/check-rest-log-declared.mjs

# Live-server database isolation (#10382). CI provisions ONE Postgres and
# ONE MySQL for the whole temporal-conformance job and points every live
# leg at them, and every live suite in the repo issues a `drop` when it
Expand Down
27 changes: 21 additions & 6 deletions docs/audits/2026-09-test-log-volume-census.md
Original file line number Diff line number Diff line change
Expand Up @@ -27,9 +27,12 @@ total volume than the five heaviest suites already were. See

- **No urgency, no correctness impact.** This is CI log volume. The earlier
reading said so and nothing here changes it.
- **No seam was added, and none is recommended.** The two candidates — an env
read in the kernel logger, a level field on `BootOptions` — both touch
published surface, and choosing between them is not a measurement.
- **No seam was added by this document, and neither candidate it listed is
recommended.** The two candidates — an env read in the kernel logger, a level
field on `BootOptions` — both touch published surface, and choosing between
them is not a measurement. ⚠️ A different seam was later ruled and built for
a different population: `OS_REST_LOG`, on `packages/rest`'s own fault logging
(#15484). See the closing section — that is not one of these two.
- **"A reader of a production boot log may well want every one of these
lines."** Test-environment noise and production observability are two ends of
one switch. Nothing here is an argument for lowering the engine's boot INFO
Expand Down Expand Up @@ -416,6 +419,18 @@ point does the combined population cross back toward parity, let alone toward
`console` being the majority — it stays firmly structured-dominated (77.1%)
throughout.

**No seam was added.** Per triage's ruling, this document is the measurement
only; which of the two candidate seams (if either) to build is triage's call,
made with this table in hand.
**No seam was added by this document, and the reservation it held is now
DISCHARGED.** This document was the measurement only, and it reserved to triage
「which of the two candidate seams (if either) to build」. The maintainer decided
it in decision batch #49, item 2 (2026-09-05, recorded on #15484): option **A**,
a declared level seam on `packages/rest`'s `logError`, in the `OS_REGISTRY_LOG`
shape, **with the shipped default unchanged**.

⇒ The seam that was built against that ruling is `OS_REST_LOG`
(`packages/rest/src/log.ts`, `REST_LOG_LEVELS`), enforced by
`scripts/check-rest-log-declared.mjs`. ⛔ It is a DECLARATION, not a quieter
product: at the shipped default a reported fault still prints the whole `Error`
— message, `cause` chain and frames — for every real caller, and suppression is
only ever something a harness declares. The two candidates this document listed
(an env read in the kernel logger, a level field on `BootOptions`) remain
unbuilt; neither was chosen.
1 change: 1 addition & 0 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -158,6 +158,7 @@
"examples:live-imports": "node scripts/check-examples-live-imports.mjs --list",
"check:test-source-alias": "node scripts/check-test-source-alias.mjs --self-test && node scripts/check-test-source-alias.mjs",
"check:registry-log-declared": "node scripts/check-registry-log-declared.mjs --self-test && node scripts/check-registry-log-declared.mjs",
"check:rest-log-declared": "node scripts/check-rest-log-declared.mjs --self-test && node scripts/check-rest-log-declared.mjs",
"check:refd-timer-probe": "node scripts/check-refd-timer-probe.mjs --self-test && node scripts/check-refd-timer-probe.mjs",
"check:type-source-resolution": "node scripts/check-type-source-resolution.mjs --self-test && node scripts/check-type-source-resolution.mjs",
"check:undeclared-dep-imports": "node scripts/check-undeclared-dep-imports.mjs --self-test && node scripts/check-undeclared-dep-imports.mjs",
Expand Down
23 changes: 23 additions & 0 deletions packages/rest/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -97,6 +97,29 @@ Plus metadata and discovery routes:
| `caching.etag` | `boolean` | `true` | Emits `ETag` header. |
| `caching.lastModified` | `boolean` | `true` | Emits `Last-Modified`. |

### Environment

| Variable | Values | Default | Notes |
|:---|:---|:---|:---|
| `OS_REST_LOG` | `debug` \| `info` \| `warn` \| `error` \| `silent` | `info` | Level for this package's own fault logging. |

`OS_REST_LOG` declares how loud the REST layer is about faults **it reports
itself** — the `[REST] …` lines written when a request fails. It is the same
vocabulary, and the same shipped default, as `@objectstack/objectql`'s
`OS_REGISTRY_LOG`; an unrecognised value falls back to the default rather than
silencing anything.

At the default a reported fault prints the **whole** `Error`: its message, its
`cause` chain and its stack frames. That is deliberate and it is the reason to
leave it alone. When a 5xx is withheld from the client, the log is the only
place the underlying driver text exists, and that text travels on `error.cause`
— it is printed only because a whole `Error`, not a summary, reaches the
console. Lowering the level to `error` or `silent` discards diagnostics that
have no second copy anywhere.

⇒ Prefer declaring a quieter level in a **test harness** (`vitest.config.ts`'s
`env` block) over exporting it for a running server.

## HTTP semantics

- JSON envelope: `{ success, data, error?, meta? }`.
Expand Down
92 changes: 90 additions & 2 deletions packages/rest/src/log.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,8 +9,96 @@
* is the "two spellings of one thing" shape this repo pays for repeatedly. It
* is deliberately NOT re-exported from the package index: an internal shim, not
* a logging API.
*
* ── The declared level seam (#15484) ──────────────────────────────────────
*
* Every fault this package reports goes through `logError`, and `logError`
* hands its varargs — an `Error` object among them — straight to
* `console.error`, which Node formats with the error's full stack and its
* `[cause]` chain. Measured on one green `packages/rest` run: 2,095 indented
* `at ` frame lines, 36.7% of the captured output, and 100% of them arrive
* through this file (1,197 from `error-response.ts`, 841 from
* `rest-server.ts`, 57 from `cause` chains).
*
* ⛔ That volume is NOT a defect and the frames are NOT dead weight. They are
* read, and the repo pins that they are read: at `logWithheldServerFault` the
* client is told nothing and the log is the operator's only copy of the driver
* text — which lives on `error.cause` and is printed only because a whole
* `Error` is passed; at `logUnexpectedRouteError` the frames are the only
* location diagnostic a bare `TypeError` has. Four assertions across
* `rest-5xx-message-sanitization.test.ts` and `rest-expected-error-logging.test.ts`
* hold that, by asserting the IDENTITY of the `Error` reaching `console.error`
* (#5437 / #4886 / #5489). ⛔ Do not "quieten" this shim by formatting the
* `Error` down to a string or a summary — that is the repair those pins exist
* to stop, and it deletes from the LOG what was deliberately withheld from the
* CLIENT.
*
* So the seam is a DECLARATION, not a quieter product: `OS_REST_LOG` names a
* level, exactly as `OS_REGISTRY_LOG` does for `@objectstack/objectql`'s
* `SchemaRegistry`, with the same five-level vocabulary and the same shipped
* `'info'` default. ⛔ The shipped default is unchanged and must stay
* unchanged: a reported fault keeps printing the full `Error` — message,
* `cause` chain and frames — for every real caller. Suppression is only ever
* something a HARNESS opts into, declared where a gate can read it
* (`scripts/check-rest-log-declared.mjs`), never the product's default.
*
* An operator learns the variable from `packages/rest/README.md`, from this
* block, and from `docs/audits/2026-09-test-log-volume-census.md`; an
* unrecognised value falls back to the default rather than silently silencing
* anything, which is the same failure direction `OS_REGISTRY_LOG` chose.
*/

/**
* The levels `OS_REST_LOG` accepts — deliberately the same vocabulary as
* `@objectstack/objectql`'s `REGISTRY_LOG_LEVELS`, so the two declarations are
* one contract with two populations rather than two ad-hoc environment
* variables. Ordered loudest-first; `scripts/check-rest-log-declared.mjs`
* READS this array rather than copying it.
*/
export const REST_LOG_LEVELS = ['debug', 'info', 'warn', 'error', 'silent'] as const;

/** One of {@link REST_LOG_LEVELS}. */
export type RestLogLevel = (typeof REST_LOG_LEVELS)[number];

/**
* The SHIPPED default — what every real caller gets when `OS_REST_LOG` is
* unset or unrecognised. ⛔ Never lower this to quieten a log: at any level
* below `'warn'` this package stops reporting faults it is the only reporter
* of. `rest-log-declared-level-seam.test.ts` pins it.
*/
export const REST_LOG_DEFAULT_LEVEL: RestLogLevel = 'info';

/** Emission threshold per level: a site emits when its own rank <= the level's. */
const LEVEL_RANK: Readonly<Record<RestLogLevel, number>> = {
debug: 4, info: 3, warn: 2, error: 1, silent: 0,
};

/** `logError`'s rank, and `logWarn`'s — a site speaks while the level reaches it. */
const ERROR_RANK = LEVEL_RANK.error;
const WARN_RANK = LEVEL_RANK.warn;

/**
* The level in force right now.
*
* Read from the environment on every call, not memoised at module load: a
* harness that declares the level through vitest's `env` block, and a test that
* restores the shipped default around one assertion, both have to be observed
* by a module that may already be imported. This is a fault path — it runs once
* per reported fault, never per request.
*/
export function restLogLevel(): RestLogLevel {
const raw = String((globalThis as any).process?.env?.OS_REST_LOG ?? '').toLowerCase();
return (REST_LOG_LEVELS as readonly string[]).includes(raw)
? (raw as RestLogLevel)
: REST_LOG_DEFAULT_LEVEL;
}

// Node-safe logger — avoids importing 'console' which is absent from ES2020 lib typings.
export const logError = (...args: unknown[]) => (globalThis as any).console?.error(...args);
export const logWarn = (...args: unknown[]) => ((globalThis as any).console?.warn ?? (globalThis as any).console?.error)?.(...args);
export const logError = (...args: unknown[]) => {
if (LEVEL_RANK[restLogLevel()] < ERROR_RANK) return;
(globalThis as any).console?.error(...args);
};
export const logWarn = (...args: unknown[]) => {
if (LEVEL_RANK[restLogLevel()] < WARN_RANK) return;
((globalThis as any).console?.warn ?? (globalThis as any).console?.error)?.(...args);
};
Loading
Loading