Skip to content

Commit 2049b6a

Browse files
os-zhuangclaude
andauthored
feat(observability): admin-gated per-request Server-Timing via X-OS-Debug-Timing (#2408) (#3163)
* feat(observability): admin-gated per-request Server-Timing via X-OS-Debug-Timing (#2408) Adds the per-request gating from the perf-tuning design so an operator can pull a single request's `Server-Timing` breakdown on a live environment without turning the header on for every user. Until now perf-tuning was global-only (`serverTiming` option / `OS_SERVER_TIMING`), which discloses internal phase durations — a mild backend-fingerprinting surface — to every caller. This wires up the second gating path the issue describes: - **Disclosure gate** (`@objectstack/observability`): a request-scoped `AsyncLocalStorage` gate, separate from the pure `PerfTiming` collector so the collector keeps its "only measures, never decides to emit" invariant. Pinned to a `Symbol.for` registry key like the collector store so the middleware (which seeds it) and the dispatcher (which opens it) share one store across ESM/CJS module copies. - **Hono middleware**: always registered unless `serverTiming: false`. Runs the collector when timing is global OR the request carries `X-OS-Debug-Timing: 1`; emits the header only when the gate is open. Zero collector overhead (one header read) when neither applies. - **Dispatcher**: after resolving the execution context, opens the gate for admin/service/system principals (`isSystem`, `principalKind` service/system, posture PLATFORM_ADMIN/TENANT_ADMIN). Ordinary callers get no header even if they send the debug header. - **Env alias**: `OS_PERF_TIMING=1` now also enables global mode, matching the issue's naming; `OS_SERVER_TIMING=true` still works. Tests cover the gate primitive, the middleware's per-request/global/hard-off paths, and the admin predicate. Existing global-mode behavior is unchanged. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011upHdyr5AnNc6dWAu63qxD * docs(observability): document the admin-gated per-request Server-Timing path (#2408) Updates the Server-Timing section for the new gating: the global mode (`serverTiming` / `OS_SERVER_TIMING` / `OS_PERF_TIMING`) plus the per-request `X-OS-Debug-Timing: 1` path that returns timing only to an admin/service identity, and the `serverTiming: false` hard-off. Keeps the go-live checklist in sync. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011upHdyr5AnNc6dWAu63qxD * chore(changeset): perf-timing per-request gating (#2408) Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011upHdyr5AnNc6dWAu63qxD --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent beaf2de commit 2049b6a

10 files changed

Lines changed: 426 additions & 53 deletions

File tree

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
---
2+
"@objectstack/observability": minor
3+
"@objectstack/plugin-hono-server": minor
4+
"@objectstack/runtime": minor
5+
---
6+
7+
feat(observability): admin-gated per-request `Server-Timing` via `X-OS-Debug-Timing` (#2408)
8+
9+
Perf-tuning mode was previously global-only (`serverTiming` option /
10+
`OS_SERVER_TIMING`), which discloses internal phase durations — a mild
11+
backend-fingerprinting surface — to every caller. This adds the per-request
12+
gating path from the design so an operator can pull a single request's
13+
`Server-Timing` breakdown on a live environment without turning the header on
14+
for everyone.
15+
16+
- **observability**: a request-scoped disclosure gate (`runWithPerfDisclosure`,
17+
`allowPerfDisclosure`, `isPerfDisclosureAllowed`, `PerfDisclosureGate`) kept
18+
separate from the pure `PerfTiming` collector and pinned to its own
19+
`Symbol.for` store so the middleware and dispatcher share it across module
20+
copies.
21+
- **plugin-hono-server**: the Server-Timing middleware is registered by default
22+
(unless `serverTiming: false`). It runs the collector when timing is global
23+
**or** the request sends `X-OS-Debug-Timing: 1`, and emits the header only
24+
when the gate is open. `OS_PERF_TIMING=1` now also enables global mode.
25+
- **runtime**: after resolving the execution context, the dispatcher opens the
26+
gate for admin/service/system principals, so ordinary callers never receive
27+
the header even if they send the debug header.
28+
29+
Existing global-mode behavior is unchanged.

docs/OBSERVABILITY.md

Lines changed: 32 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -238,27 +238,45 @@ usual culprit behind an inexplicably slow list), 18ms in **3** business hooks,
238238
and 7ms serializing the response. `db` and `hooks` are aggregates — one member
239239
carrying the summed duration and the event count, not one member per query.
240240

241-
This is **off by default**: the header discloses internal phase durations,
242-
which is helpful for profiling but also lets a caller fingerprint the backend.
243-
Treat it as a perf-tuning toggle you flip in staging (or briefly in production
244-
behind an allowlist), not a default-on header.
241+
The header discloses internal phase durations, which is helpful for profiling
242+
but also lets a caller fingerprint the backend, so disclosure is **gated**.
243+
There are two ways to turn it on:
245244

246-
Enable it on the Hono server plugin:
245+
**Global** — every response carries the header. Flip this in staging, or
246+
briefly on a production environment under active investigation:
247247

248248
```ts
249249
new HonoServerPlugin({ serverTiming: true });
250250
```
251251

252252
…or, for the default `os serve` server (which constructs the plugin for you),
253-
via the environment:
253+
via the environment (`OS_PERF_TIMING=1` and the older `OS_SERVER_TIMING=true`
254+
are equivalent):
254255

255256
```bash
256-
OS_SERVER_TIMING=true os serve
257+
OS_PERF_TIMING=1 os serve
257258
```
258259

259-
When enabled, every response carries `total` (the whole request, measured by
260-
an outer middleware) plus the sub-phases the request path records out of the
261-
box:
260+
**Per-request** — available by default (unless hard-disabled below), with **no
261+
redeploy**: the caller sends the request header
262+
263+
```
264+
X-OS-Debug-Timing: 1
265+
```
266+
267+
and the `Server-Timing` header comes back **only** when the request resolves an
268+
**admin/service identity** (a platform/tenant admin, a service token, or an
269+
internal system call). An ordinary user who sends the header gets nothing back —
270+
they can never pull timings, so this is safe to leave available on a live
271+
environment. This is the path to reach for when diagnosing "why is *this* request
272+
slow?" against a running environment.
273+
274+
To hard-disable both paths (no middleware registered at all), set
275+
`serverTiming: false` explicitly.
276+
277+
When timing is emitted, every response carries `total` (the whole request,
278+
measured by an outer middleware) plus the sub-phases the request path records
279+
out of the box:
262280

263281
| Member | Recorded by | Meaning |
264282
|:---|:---|:---|
@@ -316,5 +334,7 @@ countServerTiming('db', queryMs, 'queries'); // → db;dur=<sum>;desc="<n> queri
316334
- [ ] Log records include `requestId` field; cross-checked one against the
317335
response `X-Request-Id` header.
318336
- [ ] Alerts wired: error rate, p95 latency per route.
319-
- [ ] (Optional) `Server-Timing` verified in DevTools when `serverTiming` /
320-
`OS_SERVER_TIMING=true` is enabled, and confirmed **absent** by default.
337+
- [ ] (Optional) `Server-Timing` verified in DevTools with global mode
338+
(`serverTiming: true` / `OS_PERF_TIMING=1`) on, confirmed **absent** for a
339+
normal request, and confirmed the per-request `X-OS-Debug-Timing: 1` header
340+
returns timing **only** to an admin/service caller.

packages/observability/src/index.ts

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -52,5 +52,9 @@ export {
5252
startServerTiming,
5353
measureServerTiming,
5454
countServerTiming,
55+
runWithPerfDisclosure,
56+
allowPerfDisclosure,
57+
isPerfDisclosureAllowed,
5558
type ServerTimingMark,
59+
type PerfDisclosureGate,
5660
} from './perf-timing.js';

packages/observability/src/perf-timing.test.ts

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,10 @@ import {
1010
startServerTiming,
1111
measureServerTiming,
1212
countServerTiming,
13+
runWithPerfDisclosure,
14+
allowPerfDisclosure,
15+
isPerfDisclosureAllowed,
16+
type PerfDisclosureGate,
1317
} from './perf-timing.js';
1418

1519
describe('formatServerTiming', () => {
@@ -208,3 +212,61 @@ describe('ambient collector', () => {
208212
expect(t.marks().map((m) => m.name)).toContain('after-await');
209213
});
210214
});
215+
216+
describe('disclosure gate', () => {
217+
it('isPerfDisclosureAllowed() is false with no active gate', () => {
218+
expect(isPerfDisclosureAllowed()).toBe(false);
219+
});
220+
221+
it('allowPerfDisclosure() is a no-op with no active gate (does not throw)', () => {
222+
allowPerfDisclosure();
223+
expect(isPerfDisclosureAllowed()).toBe(false);
224+
});
225+
226+
it('reflects the seeded state inside runWithPerfDisclosure', () => {
227+
const closed: PerfDisclosureGate = { allowed: false };
228+
runWithPerfDisclosure(closed, () => {
229+
expect(isPerfDisclosureAllowed()).toBe(false);
230+
});
231+
const open: PerfDisclosureGate = { allowed: true };
232+
runWithPerfDisclosure(open, () => {
233+
expect(isPerfDisclosureAllowed()).toBe(true);
234+
});
235+
});
236+
237+
it('allowPerfDisclosure() opens a closed gate the caller still holds', async () => {
238+
const gate: PerfDisclosureGate = { allowed: false };
239+
await runWithPerfDisclosure(gate, async () => {
240+
await new Promise((r) => setTimeout(r, 1));
241+
allowPerfDisclosure(); // after an await — same ALS scope
242+
});
243+
// The caller reads its own reference once the scope settles.
244+
expect(gate.allowed).toBe(true);
245+
});
246+
247+
it('leaves the gate closed when disclosure is never granted', async () => {
248+
const gate: PerfDisclosureGate = { allowed: false };
249+
await runWithPerfDisclosure(gate, async () => {
250+
await new Promise((r) => setTimeout(r, 1));
251+
});
252+
expect(gate.allowed).toBe(false);
253+
});
254+
255+
it('pins the gate store to a global-registry symbol (shared across module copies)', () => {
256+
const key = Symbol.for('@objectstack/observability:perf-disclosure-gate');
257+
expect((globalThis as Record<symbol, unknown>)[key]).toBeDefined();
258+
});
259+
260+
it('is independent of the timing collector scope', () => {
261+
// A collector can be active without a gate, and vice versa.
262+
const t = new PerfTiming();
263+
runWithPerfTiming(t, () => {
264+
expect(isPerfDisclosureAllowed()).toBe(false);
265+
});
266+
const gate: PerfDisclosureGate = { allowed: true };
267+
runWithPerfDisclosure(gate, () => {
268+
expect(currentPerfTiming()).toBeUndefined();
269+
expect(isPerfDisclosureAllowed()).toBe(true);
270+
});
271+
});
272+
});

packages/observability/src/perf-timing.ts

Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -283,3 +283,64 @@ export async function measureServerTiming<T>(
283283
export function countServerTiming(name: string, dur: number, unit?: string): void {
284284
store.getStore()?.count(name, dur, unit);
285285
}
286+
287+
// --- Disclosure gate (WHO may see the timing) -------------------------
288+
289+
/**
290+
* Per-request disclosure gate — the policy counterpart to the collector.
291+
*
292+
* The {@link PerfTiming} collector only MEASURES; whether the measured
293+
* `Server-Timing` header is returned to the client is a separate decision. When
294+
* perf-tuning is turned on GLOBALLY (env flag / plugin option) the operator has
295+
* opted the whole environment in, so the gate opens up front and every response
296+
* carries the header. When it is turned on PER-REQUEST — the caller sends an
297+
* `X-OS-Debug-Timing` header — the header must stay withheld until the request
298+
* proves an admin/service identity: phase durations are a mild
299+
* backend-fingerprinting surface, so an ordinary user must never be able to pull
300+
* them just by sending a header. The request path flips the gate open with
301+
* {@link allowPerfDisclosure} once it has resolved a privileged principal.
302+
*
303+
* Keeping this out of {@link PerfTiming} preserves the collector's invariant
304+
* ("it only measures, it never decides whether to emit").
305+
*/
306+
export interface PerfDisclosureGate {
307+
/** Whether the collected timing may be disclosed to the client. */
308+
allowed: boolean;
309+
}
310+
311+
/**
312+
* The disclosure gate lives in its OWN global-registry-pinned
313+
* `AsyncLocalStorage`, for the same cross-module-copy reason as the collector
314+
* store above: the middleware seeds the gate and the dispatcher (a different
315+
* package, possibly a different module copy) flips it open — both must see the
316+
* one store.
317+
*/
318+
const GATE_KEY = Symbol.for('@objectstack/observability:perf-disclosure-gate');
319+
const globalGate = globalThis as unknown as Record<symbol, AsyncLocalStorage<PerfDisclosureGate> | undefined>;
320+
const gateStore: AsyncLocalStorage<PerfDisclosureGate> =
321+
globalGate[GATE_KEY] ?? (globalGate[GATE_KEY] = new AsyncLocalStorage<PerfDisclosureGate>());
322+
323+
/**
324+
* Run `fn` with `gate` as the ambient disclosure gate for the async call chain.
325+
* The caller keeps its reference to `gate` and reads `gate.allowed` after `fn`
326+
* settles to decide whether to emit the header.
327+
*/
328+
export function runWithPerfDisclosure<T>(gate: PerfDisclosureGate, fn: () => T): T {
329+
return gateStore.run(gate, fn);
330+
}
331+
332+
/**
333+
* Open the ambient disclosure gate — the request has proven it may see its own
334+
* `Server-Timing` header (admin/service identity). A no-op when no gate is
335+
* active (perf-tuning off, or already-global mode with no gate to flip), so the
336+
* call site stays branch-free.
337+
*/
338+
export function allowPerfDisclosure(): void {
339+
const g = gateStore.getStore();
340+
if (g) g.allowed = true;
341+
}
342+
343+
/** Whether the ambient disclosure gate is open. `false` when none is active. */
344+
export function isPerfDisclosureAllowed(): boolean {
345+
return gateStore.getStore()?.allowed ?? false;
346+
}

packages/plugins/plugin-hono-server/src/hono-plugin.test.ts

Lines changed: 22 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -210,36 +210,40 @@ describe('HonoServerPlugin', () => {
210210
});
211211

212212
it('should disable CORS when cors option is false', async () => {
213+
corsConfigCapture.last = undefined;
214+
213215
const plugin = new HonoServerPlugin({
214216
cors: false
215217
});
216218

217219
await plugin.init(context as PluginContext);
218220

219-
const serverInstance = (HonoHttpServer as any).mock.instances[0];
220-
const rawApp = serverInstance.getRawApp();
221-
222-
// CORS middleware should NOT be registered
223-
expect(rawApp.use).not.toHaveBeenCalled();
221+
// CORS middleware must NOT be configured. (Assert on the CORS config,
222+
// not the raw `use` count: the perf-timing middleware registers its
223+
// own `use('*')` by default to catch the `X-OS-Debug-Timing` header.)
224+
expect(corsConfigCapture.last).toBeUndefined();
224225
});
225226

226227
it('should disable CORS when CORS_ENABLED env is false', async () => {
227228
const originalEnv = process.env.OS_CORS_ENABLED;
228229
process.env.OS_CORS_ENABLED = 'false';
230+
corsConfigCapture.last = undefined;
229231

230-
const plugin = new HonoServerPlugin();
231-
await plugin.init(context as PluginContext);
232-
233-
const serverInstance = (HonoHttpServer as any).mock.instances[0];
234-
const rawApp = serverInstance.getRawApp();
235-
236-
expect(rawApp.use).not.toHaveBeenCalled();
237-
238-
// Restore environment
239-
if (originalEnv !== undefined) {
240-
process.env.OS_CORS_ENABLED = originalEnv;
241-
} else {
242-
delete process.env.OS_CORS_ENABLED;
232+
try {
233+
const plugin = new HonoServerPlugin();
234+
await plugin.init(context as PluginContext);
235+
236+
// CORS not configured — see the note above re: the perf-timing
237+
// middleware's own `use('*')`.
238+
expect(corsConfigCapture.last).toBeUndefined();
239+
} finally {
240+
// Restore environment even if the assertion fails, so a leaked
241+
// `OS_CORS_ENABLED=false` can't disable CORS in later tests.
242+
if (originalEnv !== undefined) {
243+
process.env.OS_CORS_ENABLED = originalEnv;
244+
} else {
245+
delete process.env.OS_CORS_ENABLED;
246+
}
243247
}
244248
});
245249

0 commit comments

Comments
 (0)