|
| 1 | +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. |
| 2 | + |
| 3 | +/** |
| 4 | + * [#14656] A DECLARED CAPABILITY ABSENCE is reported once per route per |
| 5 | + * process, at `warn`, naming the missing service — driven through the REAL |
| 6 | + * dispatcher and the REAL REST envelope writer. |
| 7 | + * |
| 8 | + * ## The ruling this pins |
| 9 | + * |
| 10 | + * Maintainer ruling 2026-09-03 (decision batch #23, verbatim reply 「同意」 to |
| 11 | + * this card's **B + C**): |
| 12 | + * |
| 13 | + * > A **declared capability absence** — a 5xx the platform chose because the |
| 14 | + * > deployment did not install an optional service (the `NOT_IMPLEMENTED` / |
| 15 | + * > `SERVICE_UNAVAILABLE` family answering a configuration fact) — is a |
| 16 | + * > configuration fact, not a fault: it is reported **once per route per |
| 17 | + * > process**, at `warn`, naming the missing service, and then stays quiet for |
| 18 | + * > that route. Everything else that reaches `logServerFault` keeps the shipped |
| 19 | + * > per-request `error` line. |
| 20 | + * |
| 21 | + * ## What was measured before it |
| 22 | + * |
| 23 | + * On a stock showcase boot (#14656 comment, 2026-09-04), `GET /api/v1/ai/*` — |
| 24 | + * the cloud-only AI service's declared `501 NOT_IMPLEMENTED` — printed one |
| 25 | + * `error`-level line **per request**, and Studio opens it unprompted. The |
| 26 | + * channel #14310 had just built to mean "an operator must look" was being |
| 27 | + * trained into noise by a deployment that is working exactly as configured. |
| 28 | + * |
| 29 | + * ## Why these four assertions and not others |
| 30 | + * |
| 31 | + * 1. **The second, different route.** The ruling names the global "first N" |
| 32 | + * throttle as "the shape that hides the second route", so a test showing |
| 33 | + * the first route going quiet is worth less than one showing a second one |
| 34 | + * still speaking. Both routes here answer the SAME code and the SAME |
| 35 | + * message from the SAME slot, so only the route can be discriminating. |
| 36 | + * 2. **The undeclared fault control.** Same process, same door, N requests — |
| 37 | + * N `error` lines. Without it, "quiet" and "broken" are the same colour. |
| 38 | + * 3. **The two doors, on one fixture envelope.** The ruling puts the predicate |
| 39 | + * in one place *because* a per-door spelling is what this repo has paid to |
| 40 | + * repair twice. Here the envelope the dispatcher really answers is read off |
| 41 | + * the wire and handed to the OTHER door (`sendError`, `@objectstack/types` |
| 42 | + * — the exit every nested-envelope 5xx in `packages/rest` takes), and both |
| 43 | + * must classify it the same way. ⚠️ The two lines are not byte-identical |
| 44 | + * and are not asserted to be: the dispatcher names its route and the |
| 45 | + * envelope writer has none to name. What must agree is the VERDICT — the |
| 46 | + * level, and that the line names the missing service. |
| 47 | + * 4. **The wire does not move.** The ruling's own condition is «if any |
| 48 | + * response byte moves, stop and report», so the bytes are captured rather |
| 49 | + * than asserted to be unchanged: the `the wire does not move` block below |
| 50 | + * runs green on `origin/main` at this branch's base too, which is what |
| 51 | + * makes it a before/after measurement instead of a claim. |
| 52 | + */ |
| 53 | + |
| 54 | +import { describe, it, expect, vi } from 'vitest'; |
| 55 | + |
| 56 | +// Each test re-executes the dispatcher's module graph (see `boot` below), which |
| 57 | +// the default 5s budget does not cover on a shared box — measured: the FIRST |
| 58 | +// test paid 5s+ and timed out while the rest ran in ~1.4s each off vitest's |
| 59 | +// transform cache. The cost is the price of the per-test isolation the ruling's |
| 60 | +// "per process" key needs, so the budget is raised rather than the isolation |
| 61 | +// dropped. |
| 62 | +vi.setConfig({ testTimeout: 30_000 }); |
| 63 | + |
| 64 | +function makeFakeServer() { |
| 65 | + const handlers: Record<string, (req: any, res: any) => any> = {}; |
| 66 | + const rec = (verb: string) => (path: string, handler: any) => { |
| 67 | + handlers[`${verb} ${path}`] = handler; |
| 68 | + }; |
| 69 | + return { |
| 70 | + handlers, |
| 71 | + server: { |
| 72 | + get: rec('GET'), |
| 73 | + post: rec('POST'), |
| 74 | + put: rec('PUT'), |
| 75 | + delete: rec('DELETE'), |
| 76 | + patch: rec('PATCH'), |
| 77 | + }, |
| 78 | + }; |
| 79 | +} |
| 80 | + |
| 81 | +function makeRes() { |
| 82 | + const res: any = { |
| 83 | + statusCode: undefined as number | undefined, |
| 84 | + body: undefined as any, |
| 85 | + status(c: number) { res.statusCode = c; return res; }, |
| 86 | + header() { return res; }, |
| 87 | + json(b: any) { res.body = b; return res; }, |
| 88 | + end() { return res; }, |
| 89 | + }; |
| 90 | + return res; |
| 91 | +} |
| 92 | + |
| 93 | +/** |
| 94 | + * Boot the real plugin over a fake transport, with a spied kernel logger — |
| 95 | + * in a FRESH module graph. |
| 96 | + * |
| 97 | + * ⚠️ `vi.resetModules()` is the load-bearing line, not boilerplate. The dedupe |
| 98 | + * registry is module state in `@objectstack/types` (that IS the ruling's "per |
| 99 | + * process" half), so without a reset the first test to touch a route would |
| 100 | + * silence it for every later test in this file, and their colour would depend |
| 101 | + * on execution order. Resetting gives each test its own process-equivalent, |
| 102 | + * which is also the only honest way to pin a per-process rule. |
| 103 | + * |
| 104 | + * `@objectstack/types` is aliased to its SOURCE for this package |
| 105 | + * (`packages/runtime/vitest.config.ts`), so the reset reaches the registry and |
| 106 | + * an edit to `packages/types/src` is visible here without a rebuild. |
| 107 | + * |
| 108 | + * Both doors are imported INSIDE this window so the dispatcher and `sendError` |
| 109 | + * share one registry — a two-door pin over two registries would prove nothing. |
| 110 | + */ |
| 111 | +async function boot(services: Record<string, any>) { |
| 112 | + vi.resetModules(); |
| 113 | + const [{ createDispatcherPlugin }, { sendError }] = await Promise.all([ |
| 114 | + import('./dispatcher-plugin.js'), |
| 115 | + import('@objectstack/types'), |
| 116 | + ]); |
| 117 | + const logger = { info: vi.fn(), warn: vi.fn(), error: vi.fn(), debug: vi.fn() }; |
| 118 | + const kernel = { |
| 119 | + getService: (n: string) => services[n], |
| 120 | + getServiceAsync: async (n: string) => services[n], |
| 121 | + }; |
| 122 | + const { server, handlers } = makeFakeServer(); |
| 123 | + const ctx: any = { |
| 124 | + getKernel: () => kernel, |
| 125 | + getService: (n: string) => (n === 'http.server' ? server : undefined), |
| 126 | + environmentId: undefined, |
| 127 | + logger, |
| 128 | + hook: () => { }, |
| 129 | + on: () => { }, |
| 130 | + }; |
| 131 | + const plugin = createDispatcherPlugin({ prefix: '/api/v1', securityHeaders: false }); |
| 132 | + await plugin.start?.(ctx); |
| 133 | + return { handlers, logger, sendError }; |
| 134 | +} |
| 135 | + |
| 136 | +const FAULT_PREFIX = '[5xx]'; |
| 137 | +const lines = (spy: { mock: { calls: any[][] } }) => |
| 138 | + spy.mock.calls.filter((c) => String(c[0]).startsWith(FAULT_PREFIX)); |
| 139 | + |
| 140 | +const REQ = { body: {}, query: {}, headers: {}, params: {} }; |
| 141 | + |
| 142 | +/** The analytics door, which throws and therefore answers an UNDECLARED 500. */ |
| 143 | +const throwingAnalytics = (message: string) => ({ |
| 144 | + analytics: { |
| 145 | + query: async () => { throw new Error(message); }, |
| 146 | + getMeta: async () => ({ cubes: [] }), |
| 147 | + generateSql: async () => ({ sql: null }), |
| 148 | + }, |
| 149 | +}); |
| 150 | + |
| 151 | +describe('#14656 — the dispatcher door', () => { |
| 152 | + it('reports a declared 501 ONCE across N requests, at warn, naming the missing service', async () => { |
| 153 | + const { handlers, logger } = await boot({}); |
| 154 | + |
| 155 | + for (const _ of [0, 1, 2, 3, 4]) { |
| 156 | + await handlers['GET /api/v1/notifications']({ ...REQ }, makeRes()); |
| 157 | + } |
| 158 | + |
| 159 | + expect(lines(logger.error), 'a configuration fact is not a fault').toHaveLength(0); |
| 160 | + const warned = lines(logger.warn); |
| 161 | + expect(warned, 'five requests, one line').toHaveLength(1); |
| 162 | + |
| 163 | + const [message, meta] = warned[0]; |
| 164 | + // `serviceUnavailableMessage('notification')` — the same remedy |
| 165 | + // sentence discovery publishes for that slot, which is what "naming the |
| 166 | + // missing service" means here: the line says WHICH package to install. |
| 167 | + expect(String(message)).toContain('@objectstack/service-messaging'); |
| 168 | + expect(String(message)).toContain('reported once per route per process'); |
| 169 | + expect(meta).toMatchObject({ |
| 170 | + status: 501, |
| 171 | + code: 'NOT_IMPLEMENTED', |
| 172 | + method: 'GET', |
| 173 | + path: '/api/v1/notifications', |
| 174 | + }); |
| 175 | + }); |
| 176 | + |
| 177 | + it('a SECOND, DIFFERENT route still reports — the dedupe key is the route', async () => { |
| 178 | + const { handlers, logger } = await boot({}); |
| 179 | + |
| 180 | + await handlers['GET /api/v1/notifications']({ ...REQ }, makeRes()); |
| 181 | + await handlers['GET /api/v1/notifications']({ ...REQ }, makeRes()); |
| 182 | + await handlers['POST /api/v1/notifications/read']({ ...REQ, body: { ids: ['n1'] } }, makeRes()); |
| 183 | + await handlers['POST /api/v1/notifications/read']({ ...REQ, body: { ids: ['n1'] } }, makeRes()); |
| 184 | + |
| 185 | + const warned = lines(logger.warn); |
| 186 | + expect(warned, 'one line per route, not one line per process').toHaveLength(2); |
| 187 | + expect(warned.map((c) => `${(c[1] as any).method} ${(c[1] as any).path}`)).toEqual([ |
| 188 | + 'GET /api/v1/notifications', |
| 189 | + 'POST /api/v1/notifications/read', |
| 190 | + ]); |
| 191 | + // Same slot, same code, same prose — so nothing but the route could |
| 192 | + // have told the two apart. |
| 193 | + expect((warned[0][1] as any).code).toBe('NOT_IMPLEMENTED'); |
| 194 | + expect((warned[1][1] as any).code).toBe('NOT_IMPLEMENTED'); |
| 195 | + expect(lines(logger.error)).toHaveLength(0); |
| 196 | + }); |
| 197 | + |
| 198 | + it('an UNDECLARED 500 on the same door is still loud, once per request', async () => { |
| 199 | + const { handlers, logger } = await boot(throwingAnalytics('still-loud-per-request')); |
| 200 | + |
| 201 | + for (const _ of [0, 1, 2]) { |
| 202 | + await handlers['POST /api/v1/analytics/query']( |
| 203 | + { body: { cube: 'x', measures: ['count'] }, query: {} }, |
| 204 | + makeRes(), |
| 205 | + ); |
| 206 | + } |
| 207 | + |
| 208 | + expect(lines(logger.error), 'the #14310 rule is untouched for faults').toHaveLength(3); |
| 209 | + expect(lines(logger.warn)).toHaveLength(0); |
| 210 | + }); |
| 211 | + |
| 212 | + it('a declared absence and a fault coexist in one process without either changing the other', async () => { |
| 213 | + const { handlers, logger } = await boot(throwingAnalytics('coexist')); |
| 214 | + |
| 215 | + await handlers['GET /api/v1/notifications']({ ...REQ }, makeRes()); |
| 216 | + await handlers['POST /api/v1/analytics/query']({ body: { cube: 'x', measures: ['count'] }, query: {} }, makeRes()); |
| 217 | + await handlers['GET /api/v1/notifications']({ ...REQ }, makeRes()); |
| 218 | + await handlers['POST /api/v1/analytics/query']({ body: { cube: 'x', measures: ['count'] }, query: {} }, makeRes()); |
| 219 | + |
| 220 | + expect(lines(logger.warn)).toHaveLength(1); |
| 221 | + expect(lines(logger.error)).toHaveLength(2); |
| 222 | + }); |
| 223 | +}); |
| 224 | + |
| 225 | +describe('#14656 — both doors read ONE predicate, on one fixture envelope', () => { |
| 226 | + it('the envelope the dispatcher answers is classified identically by the REST envelope writer', async () => { |
| 227 | + const { handlers, logger, sendError } = await boot({}); |
| 228 | + |
| 229 | + // ── Door 1: the runtime dispatcher, on the real route ────────────── |
| 230 | + const res = makeRes(); |
| 231 | + await handlers['GET /api/v1/notifications']({ ...REQ }, res); |
| 232 | + |
| 233 | + const fixture = { |
| 234 | + status: res.statusCode as number, |
| 235 | + code: res.body.error.code as string, |
| 236 | + message: res.body.error.message as string, |
| 237 | + }; |
| 238 | + expect(fixture).toMatchObject({ status: 501, code: 'NOT_IMPLEMENTED' }); |
| 239 | + |
| 240 | + const dispatcherWarned = lines(logger.warn); |
| 241 | + expect(dispatcherWarned, 'door 1 demoted it').toHaveLength(1); |
| 242 | + expect(lines(logger.error)).toHaveLength(0); |
| 243 | + |
| 244 | + // ── Door 2: `sendError`, the exit every nested-envelope 5xx takes ── |
| 245 | + // It takes no logger (it is reached from ~50 sites that have none), so |
| 246 | + // its channel is `console`. The CHANNEL differs; the VERDICT must not. |
| 247 | + const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => { }); |
| 248 | + const errorSpy = vi.spyOn(console, 'error').mockImplementation(() => { }); |
| 249 | + try { |
| 250 | + sendError(makeRes(), fixture.status, fixture.code as any, fixture.message); |
| 251 | + |
| 252 | + const restWarned = lines(warnSpy); |
| 253 | + expect(restWarned, 'door 2 must not disagree with door 1 about the same envelope').toHaveLength(1); |
| 254 | + expect(lines(errorSpy), 'door 2 must not keep the fault line the other door dropped').toHaveLength(0); |
| 255 | + |
| 256 | + // Both lines name the missing service and both declare the |
| 257 | + // suppression — the two halves of "reported once, naming what is |
| 258 | + // absent" that a per-door spelling would drift on first. |
| 259 | + for (const line of [String(dispatcherWarned[0][0]), String(restWarned[0][0])]) { |
| 260 | + expect(line.startsWith(FAULT_PREFIX)).toBe(true); |
| 261 | + expect(line).toContain('@objectstack/service-messaging'); |
| 262 | + expect(line).toContain('reported once per route per process'); |
| 263 | + } |
| 264 | + } finally { |
| 265 | + warnSpy.mockRestore(); |
| 266 | + errorSpy.mockRestore(); |
| 267 | + } |
| 268 | + }); |
| 269 | +}); |
| 270 | + |
| 271 | +describe('#14656 — the wire does not move', () => { |
| 272 | + /** |
| 273 | + * ⚠️ This block is written to be RUNNABLE AT THIS BRANCH'S BASE. It names |
| 274 | + * no `warn`, no count and nothing else this card introduces, so running it |
| 275 | + * on `origin/main` and here answers one question: did any response byte |
| 276 | + * move? The ruling's condition — «if any response byte moves, stop and |
| 277 | + * report» — is a measurement, and this is the instrument. |
| 278 | + */ |
| 279 | + it('answers the same bytes it answered before this change, on every request', async () => { |
| 280 | + const { handlers } = await boot({}); |
| 281 | + |
| 282 | + const seen: string[] = []; |
| 283 | + for (const _ of [0, 1, 2]) { |
| 284 | + const res = makeRes(); |
| 285 | + await handlers['GET /api/v1/notifications']({ ...REQ }, res); |
| 286 | + seen.push(`${res.statusCode} ${JSON.stringify(res.body)}`); |
| 287 | + } |
| 288 | + |
| 289 | + // Identical on every request: the dedupe changes what is LOGGED, never |
| 290 | + // what is ANSWERED — a caller cannot tell the first request from the |
| 291 | + // hundredth. |
| 292 | + expect(new Set(seen).size, 'the answer must not depend on how many times it was asked').toBe(1); |
| 293 | + expect(seen[0]).toBe( |
| 294 | + '501 {"success":false,"error":{"code":"NOT_IMPLEMENTED",' |
| 295 | + + '"message":"Install @objectstack/service-messaging to enable",' |
| 296 | + + '"httpStatus":501}}', |
| 297 | + ); |
| 298 | + }); |
| 299 | + |
| 300 | + it('answers the same bytes for a fault, too', async () => { |
| 301 | + const { handlers } = await boot(throwingAnalytics('wire-unchanged-for-faults')); |
| 302 | + |
| 303 | + const res = makeRes(); |
| 304 | + await handlers['POST /api/v1/analytics/query']( |
| 305 | + { body: { cube: 'x', measures: ['count'] }, query: {} }, |
| 306 | + res, |
| 307 | + ); |
| 308 | + |
| 309 | + expect(`${res.statusCode} ${JSON.stringify(res.body)}`).toBe( |
| 310 | + '500 {"success":false,"error":{"code":"INTERNAL_ERROR","message":"wire-unchanged-for-faults","httpStatus":500}}', |
| 311 | + ); |
| 312 | + }); |
| 313 | +}); |
0 commit comments