|
| 1 | +// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license. |
| 2 | +// |
| 3 | +// [#15484] The declared fault-log level seam on this package's console shim. |
| 4 | +// |
| 5 | +// The card this closes measured 2,095 indented `at ` stack-frame lines on one |
| 6 | +// green `packages/rest` run — 36.7% of the captured output — and attributed |
| 7 | +// 100% of them to `logError` handing whole `Error` objects to `console.error`, |
| 8 | +// which Node formats with the full stack and the `[cause]` chain. |
| 9 | +// |
| 10 | +// The ruling on it (decision batch #49, item 2) bought a DECLARATION, not a |
| 11 | +// quieter product: 「a declared level seam on `logError`, shipped default |
| 12 | +// unchanged」. So the property this file exists to hold is the one that is |
| 13 | +// easiest to lose by accident and impossible to notice afterwards: |
| 14 | +// |
| 15 | +// ⛔ THE SHIPPED DEFAULT PRINTS THE WHOLE `Error`. |
| 16 | +// |
| 17 | +// That matters because at `logWithheldServerFault` the client is told nothing |
| 18 | +// and the log is the operator's ONLY copy of the driver text — and that text |
| 19 | +// lives on `error.cause`, so it is printed only because an `Error` OBJECT, not |
| 20 | +// a string, reaches `console.error` (#5437 / #8136). A "quieten the logs" |
| 21 | +// change that lowers the default, or formats the error down to its message, |
| 22 | +// deletes from the LOG exactly what was deliberately withheld from the CLIENT, |
| 23 | +// and every existing assertion about the WIRE answer stays green while it does. |
| 24 | +// |
| 25 | +// ⚠️ This file asserts on the fault log, so it DECLARES the level it depends on |
| 26 | +// instead of inheriting it from `vitest.config.ts`. That is the pattern any |
| 27 | +// future test asserting on this shim should copy: see the measured note in the |
| 28 | +// root `env` block of that config for why the suite's own value is the shipped |
| 29 | +// default and not a quieter one. |
| 30 | + |
| 31 | +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; |
| 32 | +import { |
| 33 | + logError, |
| 34 | + logWarn, |
| 35 | + restLogLevel, |
| 36 | + REST_LOG_LEVELS, |
| 37 | + REST_LOG_DEFAULT_LEVEL, |
| 38 | + type RestLogLevel, |
| 39 | +} from './log.js'; |
| 40 | + |
| 41 | +let errorSpy: ReturnType<typeof vi.spyOn>; |
| 42 | +let warnSpy: ReturnType<typeof vi.spyOn>; |
| 43 | +let saved: string | undefined; |
| 44 | + |
| 45 | +/** Set the seam for one assertion; `undefined` means "as shipped — nothing declared". */ |
| 46 | +function at(level: string | undefined): void { |
| 47 | + if (level === undefined) delete process.env.OS_REST_LOG; |
| 48 | + else process.env.OS_REST_LOG = level; |
| 49 | +} |
| 50 | + |
| 51 | +beforeEach(() => { |
| 52 | + saved = process.env.OS_REST_LOG; |
| 53 | + errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); |
| 54 | + warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); |
| 55 | +}); |
| 56 | +afterEach(() => { |
| 57 | + if (saved === undefined) delete process.env.OS_REST_LOG; |
| 58 | + else process.env.OS_REST_LOG = saved; |
| 59 | + errorSpy.mockRestore(); |
| 60 | + warnSpy.mockRestore(); |
| 61 | +}); |
| 62 | + |
| 63 | +describe('[#15484] the shipped default is unchanged — a reported fault prints the whole Error', () => { |
| 64 | + it('with NOTHING declared, logError hands console.error the identical argument list', () => { |
| 65 | + at(undefined); |
| 66 | + const cause = new Error('SQLITE_ERROR: no such table: sys_metadata'); |
| 67 | + const boom = new Error('Failed to delete customization overlay', { cause }); |
| 68 | + |
| 69 | + logError('[REST] Unhandled error:', boom); |
| 70 | + |
| 71 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 72 | + const args = errorSpy.mock.calls[0]; |
| 73 | + expect(args).toHaveLength(2); |
| 74 | + expect(args[0]).toBe('[REST] Unhandled error:'); |
| 75 | + // Identity, not shape: Node prints the frames and the `[cause]` chain |
| 76 | + // only because the Error OBJECT itself is what arrives here. |
| 77 | + expect(args[1]).toBe(boom); |
| 78 | + expect((args[1] as Error).cause).toBe(cause); |
| 79 | + }); |
| 80 | + |
| 81 | + it('an UNRECOGNISED value falls back to the default rather than silencing anything', () => { |
| 82 | + at('quiet'); |
| 83 | + expect(restLogLevel()).toBe(REST_LOG_DEFAULT_LEVEL); |
| 84 | + logError('[REST] Unhandled error:', new Error('boom')); |
| 85 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 86 | + }); |
| 87 | + |
| 88 | + it('an empty declaration is not a silencing declaration', () => { |
| 89 | + at(''); |
| 90 | + expect(restLogLevel()).toBe(REST_LOG_DEFAULT_LEVEL); |
| 91 | + logError('[REST] Unhandled error:', new Error('boom')); |
| 92 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 93 | + }); |
| 94 | + |
| 95 | + it('the declared default is loud enough for BOTH sites — the ⛔ that must not be lowered', () => { |
| 96 | + at(undefined); |
| 97 | + logError('e'); |
| 98 | + logWarn('w'); |
| 99 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 100 | + expect(warnSpy).toHaveBeenCalledTimes(1); |
| 101 | + }); |
| 102 | +}); |
| 103 | + |
| 104 | +describe('[#15484] the level ladder — suppression is only ever what a harness declares', () => { |
| 105 | + it('silent stops both sites', () => { |
| 106 | + at('silent'); |
| 107 | + logError('e', new Error('boom')); |
| 108 | + logWarn('w'); |
| 109 | + expect(errorSpy).not.toHaveBeenCalled(); |
| 110 | + expect(warnSpy).not.toHaveBeenCalled(); |
| 111 | + }); |
| 112 | + |
| 113 | + it('error keeps the fault and drops the warning', () => { |
| 114 | + at('error'); |
| 115 | + logError('e', new Error('boom')); |
| 116 | + logWarn('w'); |
| 117 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 118 | + expect(warnSpy).not.toHaveBeenCalled(); |
| 119 | + }); |
| 120 | + |
| 121 | + it.each(['warn', 'info', 'debug'] as const)('%s keeps both sites, Error identity intact', (level) => { |
| 122 | + at(level); |
| 123 | + const boom = new Error('boom'); |
| 124 | + logError('e', boom); |
| 125 | + logWarn('w'); |
| 126 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 127 | + expect(errorSpy.mock.calls[0][1]).toBe(boom); |
| 128 | + expect(warnSpy).toHaveBeenCalledTimes(1); |
| 129 | + }); |
| 130 | + |
| 131 | + it('every declared level is honoured by restLogLevel', () => { |
| 132 | + for (const level of REST_LOG_LEVELS) { |
| 133 | + at(level); |
| 134 | + expect(restLogLevel()).toBe(level); |
| 135 | + } |
| 136 | + }); |
| 137 | + |
| 138 | + it('the level is read per call, so a harness declaration made after import is observed', () => { |
| 139 | + at('silent'); |
| 140 | + logError('e'); |
| 141 | + expect(errorSpy).not.toHaveBeenCalled(); |
| 142 | + at('info'); |
| 143 | + logError('e'); |
| 144 | + expect(errorSpy).toHaveBeenCalledTimes(1); |
| 145 | + }); |
| 146 | + |
| 147 | + it('an UPPERCASE declaration is honoured, not silently defaulted', () => { |
| 148 | + at('SILENT'); |
| 149 | + expect(restLogLevel()).toBe('silent' satisfies RestLogLevel); |
| 150 | + }); |
| 151 | +}); |
| 152 | + |
| 153 | +describe('[#15484] one logging contract, two populations', () => { |
| 154 | + it('OS_REST_LOG accepts exactly the vocabulary OS_REGISTRY_LOG accepts', () => { |
| 155 | + // The ruling asked for 「one logging contract, not a second ad-hoc env |
| 156 | + // var」, so the two seams share one vocabulary. ⚠️ The EQUALITY is held |
| 157 | + // by `scripts/check-rest-log-declared.mjs`, which reads both arrays out |
| 158 | + // of their own sources, and NOT here: `@objectstack/objectql` does not |
| 159 | + // re-export `REGISTRY_LOG_LEVELS` from its package index, so importing |
| 160 | + // it here yields `undefined` and an assertion that cannot fail honestly. |
| 161 | + // What this pin holds is the literal vocabulary, so a level added or |
| 162 | + // renamed here has to be a deliberate edit in two places. |
| 163 | + expect([...REST_LOG_LEVELS].sort()).toEqual(['debug', 'error', 'info', 'silent', 'warn']); |
| 164 | + }); |
| 165 | + |
| 166 | + it('the shipped default matches the engine seam it is modelled on', () => { |
| 167 | + expect(REST_LOG_DEFAULT_LEVEL).toBe('info'); |
| 168 | + }); |
| 169 | +}); |
0 commit comments