Skip to content

Commit 5897552

Browse files
baozhoutaoclaude
andauthored
fix(rest): route expected 4xx through one shared handleRouteError, not "[REST] Unhandled error" (#4886) (#5394)
The metadata routes had 29 catch blocks logging every thrown error unconditionally. Studio's designer probes GET /meta/:type/:name?state=draft on every panel, and "no draft exists" is the overwhelmingly common answer, so the structured { code: 'NO_DRAFT', status: 404 } printed a full stack trace per panel -- 45 in one browsing session, burying real errors and misreporting severity. The wire answer was already a correct, clean 404. The data routes already consulted isExpectedDataStatus / isExpectedQueryRejection but in four open-coded spellings across 12 sites, and the latter's docblock records an earlier lap of the same drift (the filter and sort codes shipped without joining the list). Both families now decide through one predicate behind one door: - resolveErrorResponse() -- split out of sendError so the logging decision reads the exact status/body the client gets, not a second opinion that can drift - isExpectedRouteError() -- the union of the three conditions: expected lifecycle statuses, the client-caused 400 query-rejection vocabulary, and VALIDATION_FAILED. Deliberately NOT "any 4xx": mapDataError degrades an unrecognised error to an un-coded 400, which is where a real handler bug lands, so that stays loud. - handleRouteError() -- resolve once, log only genuine faults, then send - logUnexpectedRouteError() -- the verdict alone, for the CRUD catches that must keep their own responder (one rewrites 400 to 404 on the wire) isExpectedDataStatus and isExpectedQueryRejection now have no other callers, so the families cannot drift apart again. No wire responses change; this only decides whether the log line is printed. Two operator-visible log deltas beyond the metadata fix: the transactional batch route judged on status >= 500 alone and so swallowed the un-coded 400 (a handler TypeError inside a batch transaction used to vanish, and now prints), and updateMany/deleteMany/clone/global-search/public-form stop logging normal 404s, 403s and query rejections. Claude-Session: https://claude.ai/code/session_01VkPSGsX9o17MsGv3Lbxu2w Co-authored-by: Claude <noreply@anthropic.com>
1 parent ccba1bb commit 5897552

3 files changed

Lines changed: 414 additions & 98 deletions

File tree

Lines changed: 51 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,51 @@
1+
---
2+
"@objectstack/rest": patch
3+
---
4+
5+
fix(rest): expected 4xx no longer logged as "[REST] Unhandled error" with a stack (#4886)
6+
7+
Opening Studio flooded the server log with stack traces. The designer probes
8+
`GET /meta/:type/:name?state=draft` on every panel to decide whether to show
9+
"unsaved draft" state, and "no draft exists" is the overwhelmingly common
10+
answer — true of every artifact nobody is currently editing. `getMetaItem`
11+
throws a structured `{ code: 'NO_DRAFT', status: 404 }`, the client got a clean
12+
404 and handled it fine, but the route logged it anyway:
13+
14+
```
15+
[REST] Unhandled error: Error: [no_draft] No pending draft exists for app/showcase_app.
16+
at _ObjectStackProtocolImplementation.getMetaItem (…) { code: 'NO_DRAFT', status: 404 }
17+
```
18+
19+
**45 of these in one browsing session** — by far the dominant entry in the log,
20+
which is how a genuine 500 goes unnoticed, and it misreports severity: nothing
21+
was broken.
22+
23+
The metadata routes had 29 catch blocks logging unconditionally. The data
24+
routes already consulted `isExpectedDataStatus` / `isExpectedQueryRejection`
25+
but in four different open-coded spellings across 12 sites, and
26+
`isExpectedQueryRejection`'s docblock records an earlier lap of exactly this
27+
drift (the filter and sort codes shipped without joining the list, so every
28+
rejection they produced was logged as unhandled too).
29+
30+
Both families now decide through one predicate behind one door,
31+
`handleRouteError(res, error, object?)`: it resolves the response once — the
32+
same structured-status passthrough or `mapDataError` envelope `sendError`
33+
already produced — logs only when that resolved response is a genuine fault,
34+
then sends it. `isExpectedDataStatus` and `isExpectedQueryRejection` have no
35+
other callers left, so the two families cannot drift apart again.
36+
37+
Expected now means an explicitly recognised client or lifecycle outcome:
38+
403/404/409/502/503, the client-caused 400 query-rejection vocabulary, and
39+
`VALIDATION_FAILED`. It deliberately does **not** mean "any 4xx" —
40+
`mapDataError` degrades an error it recognised nothing about to an un-coded
41+
400, and that bucket is where a real handler bug lands, so it stays loud.
42+
43+
**No wire responses change** — every status and body is byte-for-byte what it
44+
was; this only decides whether the log line is printed. Two operator-visible
45+
log deltas beyond the metadata fix:
46+
47+
- the cross-object transactional batch route judged on `status >= 500` alone,
48+
which also swallowed that un-coded 400 — a handler `TypeError` inside a batch
49+
transaction used to vanish, and now prints;
50+
- `updateMany` / `deleteMany` / clone / global search / the public-form routes
51+
stop logging normal 404s, 403s and query rejections.
Lines changed: 233 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,233 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
//
3+
// [#4886] Expected 4xx must not be logged as "[REST] Unhandled error".
4+
//
5+
// The metadata routes logged EVERY thrown error unconditionally — 29 catch
6+
// blocks doing `logError("[REST] Unhandled error:", error); sendError(...)`.
7+
// Studio's designer probes `GET /meta/:type/:name?state=draft` on every panel
8+
// to decide whether to show "unsaved draft" state, and "no draft exists" is the
9+
// overwhelmingly common answer, so `getMetaItem` throwing its structured
10+
// `{ code: 'NO_DRAFT', status: 404 }` printed a full stack trace per panel —
11+
// 45 in one browsing session. The wire answer was always a correct, clean 404;
12+
// only the logging was wrong.
13+
//
14+
// The data routes already consulted `isExpectedDataStatus` /
15+
// `isExpectedQueryRejection` — but in four different open-coded spellings, and
16+
// `isExpectedQueryRejection`'s docblock records an earlier lap of the same
17+
// drift (the filter and sort codes shipped without joining the list). Both
18+
// families now decide through ONE predicate behind ONE door
19+
// (`handleRouteError`), which is what these tests pin.
20+
//
21+
// Both directions are pinned deliberately, and they are NOT symmetric:
22+
// - the "quiet" tests go RED if the fix is reverted (the unconditional log
23+
// comes back);
24+
// - the "loud" tests stay GREEN under a revert — they exist to catch the
25+
// OPPOSITE overreach, a predicate widened to "any 4xx is expected", which
26+
// would silence the un-coded 400 that `mapDataError` degrades an
27+
// unrecognised error (a handler `TypeError`) to.
28+
29+
import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest';
30+
import { RestServer } from './rest-server';
31+
32+
const META_ITEM = '/api/v1/meta/:type/:name';
33+
const DATA_LIST = '/api/v1/data/:object';
34+
35+
function createMockServer() {
36+
return {
37+
get: vi.fn(), post: vi.fn(), put: vi.fn(), delete: vi.fn(), patch: vi.fn(), use: vi.fn(),
38+
listen: vi.fn().mockResolvedValue(undefined), close: vi.fn().mockResolvedValue(undefined),
39+
};
40+
}
41+
42+
function makeRes() {
43+
const res: any = { statusCode: 200, body: undefined };
44+
res.status = vi.fn((c: number) => { res.statusCode = c; return res; });
45+
res.json = vi.fn((b: any) => { res.body = b; return res; });
46+
res.header = vi.fn(() => res);
47+
res.setHeader = vi.fn(); res.write = vi.fn(); res.end = vi.fn(); res.send = vi.fn();
48+
return res;
49+
}
50+
51+
/** The exact error `metadata-protocol`'s `getMetaItem` throws for a draft probe. */
52+
function noDraftError(target: string) {
53+
return Object.assign(
54+
new Error(`[no_draft] No pending draft exists for ${target}.`),
55+
{ code: 'NO_DRAFT', status: 404 },
56+
);
57+
}
58+
59+
function setup(protocolOverrides: Record<string, unknown> = {}) {
60+
const protocol: any = {
61+
getDiscovery: vi.fn().mockResolvedValue({
62+
version: 'v0', endpoints: { data: '', metadata: '', ui: '', auth: '/auth' },
63+
}),
64+
getMetaTypes: vi.fn().mockResolvedValue([]),
65+
getMetaItems: vi.fn().mockResolvedValue([{ name: 'showcase_account' }]),
66+
getMetaItem: vi.fn().mockResolvedValue({}),
67+
findData: vi.fn().mockResolvedValue([]),
68+
...protocolOverrides,
69+
};
70+
const rest = new RestServer(
71+
createMockServer() as any,
72+
protocol,
73+
{ api: { requireAuth: false } } as any,
74+
);
75+
// A resolved session — meta routes are behind an unconditional auth gate.
76+
(rest as any).resolveExecCtx = async () => ({ userId: 'u1' });
77+
rest.registerRoutes();
78+
return { rest, protocol };
79+
}
80+
81+
function findRoute(rest: any, method: string, path: string) {
82+
const route = rest.getRoutes().find((r: any) => r.method === method && r.path === path);
83+
if (!route) throw new Error(`${method} ${path} route not registered`);
84+
return route;
85+
}
86+
87+
async function callMetaItem(rest: any, params: any, query: any = {}) {
88+
const res = makeRes();
89+
await findRoute(rest, 'GET', META_ITEM).handler(
90+
{ method: 'GET', params, query, headers: {} }, res,
91+
);
92+
return res;
93+
}
94+
95+
async function callDataList(rest: any, object: string) {
96+
const res = makeRes();
97+
await findRoute(rest, 'GET', DATA_LIST).handler(
98+
{ method: 'GET', params: { object }, query: {}, headers: {} }, res,
99+
);
100+
return res;
101+
}
102+
103+
let errorSpy: ReturnType<typeof vi.spyOn>;
104+
105+
/** Only the "[REST] Unhandled error" channel — other console.error noise is not this test's business. */
106+
const unhandledLogs = () => errorSpy.mock.calls.filter((c) => c[0] === '[REST] Unhandled error:');
107+
108+
beforeEach(() => { errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); });
109+
afterEach(() => { errorSpy.mockRestore(); });
110+
111+
describe('metadata routes — expected 4xx respond without an "Unhandled error" log (#4886)', () => {
112+
it('NO_DRAFT from the designer draft probe logs NOTHING and still 404s cleanly', async () => {
113+
const { rest } = setup({
114+
getMetaItem: vi.fn().mockRejectedValue(noDraftError('app/showcase_app')),
115+
});
116+
117+
const res = await callMetaItem(rest, { type: 'app', name: 'showcase_app' }, { state: 'draft' });
118+
119+
// The whole point: no stack trace for the overwhelmingly common answer.
120+
expect(unhandledLogs()).toHaveLength(0);
121+
// ...and the wire answer is byte-for-byte what it always was.
122+
expect(res.statusCode).toBe(404);
123+
expect(res.body).toEqual({
124+
error: '[no_draft] No pending draft exists for app/showcase_app.',
125+
code: 'NO_DRAFT',
126+
});
127+
});
128+
129+
it('stays quiet across the sibling expected statuses, not just 404', async () => {
130+
// 403 RBAC denial / 409 conflict / 503 provisioning are all normal
131+
// outcomes `isExpectedDataStatus` already named for the data family.
132+
for (const status of [403, 404, 409, 502, 503]) {
133+
const { rest } = setup({
134+
getMetaItem: vi.fn().mockRejectedValue(
135+
Object.assign(new Error('expected'), { code: 'SOME_CODE', status }),
136+
),
137+
});
138+
const res = await callMetaItem(rest, { type: 'object', name: 'showcase_account' });
139+
expect(res.statusCode).toBe(status);
140+
}
141+
expect(unhandledLogs()).toHaveLength(0);
142+
});
143+
144+
it('a VALIDATION_FAILED 400 is also expected (client-caused, body already explains it)', async () => {
145+
const { rest } = setup({
146+
getMetaItem: vi.fn().mockRejectedValue(
147+
Object.assign(new Error('bad'), { code: 'VALIDATION_FAILED', status: 400 }),
148+
),
149+
});
150+
151+
const res = await callMetaItem(rest, { type: 'object', name: 'showcase_account' });
152+
153+
expect(unhandledLogs()).toHaveLength(0);
154+
expect(res.statusCode).toBe(400);
155+
});
156+
});
157+
158+
describe('metadata routes — genuine faults keep the loud log (#4886)', () => {
159+
it('a 500 still logs the full error object', async () => {
160+
const boom = Object.assign(new Error('driver exploded'), { status: 500 });
161+
const { rest } = setup({ getMetaItem: vi.fn().mockRejectedValue(boom) });
162+
163+
const res = await callMetaItem(rest, { type: 'object', name: 'showcase_account' });
164+
165+
expect(unhandledLogs()).toHaveLength(1);
166+
// The error itself is logged, not a summary — the stack is the point here.
167+
expect(unhandledLogs()[0][1]).toBe(boom);
168+
expect(res.statusCode).toBe(500);
169+
});
170+
171+
it('an UNRECOGNISED error (handler bug) stays loud even though it maps to 400', async () => {
172+
// This is the case a blanket "any 4xx is expected" predicate would
173+
// wrongly silence: `mapDataError` degrades anything it recognises
174+
// nothing about to an UN-CODED 400, and that is where a real handler
175+
// bug lands. Silencing it would be the mirror-image of #4886.
176+
const bug = new TypeError('Cannot read properties of undefined (reading \'name\')');
177+
const { rest } = setup({ getMetaItem: vi.fn().mockRejectedValue(bug) });
178+
179+
const res = await callMetaItem(rest, { type: 'object', name: 'showcase_account' });
180+
181+
expect(unhandledLogs()).toHaveLength(1);
182+
expect(unhandledLogs()[0][1]).toBe(bug);
183+
expect(res.statusCode).toBe(400);
184+
expect(res.body?.code).toBeUndefined();
185+
});
186+
});
187+
188+
describe('both route families share ONE verdict — the anti-drift pin (#4886)', () => {
189+
it('the same structured 404 is silent on a metadata route AND a data route', async () => {
190+
const meta = setup({ getMetaItem: vi.fn().mockRejectedValue(noDraftError('object/showcase_account')) });
191+
const metaRes = await callMetaItem(meta.rest, { type: 'object', name: 'showcase_account' });
192+
const afterMeta = unhandledLogs().length;
193+
194+
const data = setup({ findData: vi.fn().mockRejectedValue(noDraftError('object/showcase_account')) });
195+
const dataRes = await callDataList(data.rest, 'showcase_account');
196+
const afterData = unhandledLogs().length;
197+
198+
expect(metaRes.statusCode).toBe(404);
199+
expect(dataRes.statusCode).toBe(404);
200+
expect(afterMeta).toBe(0);
201+
expect(afterData).toBe(0);
202+
});
203+
204+
it('the same unrecognised fault is loud on a metadata route AND a data route', async () => {
205+
const bug = new TypeError('boom');
206+
207+
const meta = setup({ getMetaItem: vi.fn().mockRejectedValue(bug) });
208+
await callMetaItem(meta.rest, { type: 'object', name: 'showcase_account' });
209+
expect(unhandledLogs()).toHaveLength(1);
210+
211+
const data = setup({ findData: vi.fn().mockRejectedValue(bug) });
212+
await callDataList(data.rest, 'showcase_account');
213+
expect(unhandledLogs()).toHaveLength(2);
214+
});
215+
216+
it('a client-caused query rejection is silent on the data list route (the earlier drift lap)', async () => {
217+
// `isExpectedQueryRejection`'s docblock: the filter and sort codes
218+
// shipped WITHOUT joining the expected list, so every rejection they
219+
// produced was ALSO logged as an unhandled error. Same shape, and now
220+
// the same single predicate for every family.
221+
const { rest } = setup({
222+
findData: vi.fn().mockRejectedValue(
223+
Object.assign(new Error('Unknown filter operator'), { code: 'INVALID_FILTER', status: 400 }),
224+
),
225+
});
226+
227+
const res = await callDataList(rest, 'showcase_account');
228+
229+
expect(unhandledLogs()).toHaveLength(0);
230+
expect(res.statusCode).toBe(400);
231+
expect(res.body?.code).toBe('INVALID_FILTER');
232+
});
233+
});

0 commit comments

Comments
 (0)