Skip to content

Commit 159d72e

Browse files
msoginclaude
andauthored
GLOOK-54: repair the model's JSON, and bust the proxy cache when repair can't (#73)
* diag(project-insights): log the parse-failure window /api/project-insights has been returning 500 on roughly one report a week since 2026-08-25 — five so far — and nobody has been able to say why, because the log records content_chars and never the content: [project-insights] report=da2fa78f finish_reason=stop prompt_chars=203278 content_chars=14280 llm_projects=0 FAILURE="json parse: Expected double-quoted property name in JSON at position 2318" Not truncation (finish_reason=stop, 14k of a 32k budget) and not a cached failure (insights.ts already refuses to persist one). Data-dependent: three reports fail while six of the same output size succeed, and the two live failures break at position 2298 and 2318 — close enough to suggest a structural artifact rather than randomness. Logs a 300-char window either side of V8's reported offset, plus the head and tail, which is where provider artifacts live: a prose preamble, a trailing comma, an unterminated string. Verified the `position (\d+)` regex against V8's actual message format — and note that JSON.parse('{"a":1,}') produces exactly this error family, so a trailing comma is the leading hypothesis for the window to confirm or kill. Diagnostics only: no behaviour change, and deliberately console.warn rather than err.message, because route.ts serialises err.message into the 500 body and raw model output must not reach the client. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> * GLOOK-54: repair the model's JSON, and bust the proxy cache when repair can't The Top Projects card had been broken for weeks by ONE character. The diagnostics added in the previous commit caught it: …"RPS-10766","RPS-10768"], }, <- trailing comma before } {"name":"Video/Audio Processing", … The model closes a jira_keys array, emits a comma, then a brace. JSON forbids that, so JSON.parse reports "Expected double-quoted property name" at the brace — it is looking for the next key. Not truncation (finish_reason=stop, 14k of a 32k budget); the rest of the 14,268-char response is well-formed. Reloading never helped because the AI Proxy re-serves cached completions. That was measured, not assumed — a prompt asking for a random hex string: identical #1 2431ms -> a3f9c2e7b1d4 identical #2 224ms -> a3f9c2e7b1d4 same value, 10x faster => CACHED message nonce 1866ms -> a3f9c21b7e4d different value => salt works extraBody nonce 38ms -> a3f9c2e7b1d4 same value => salt IGNORED So the salt has to go in the user message. A nonce in smartling_additional_properties is ignored by the proxy, and putting it there would have shipped a retry that silently re-served the same broken JSON. Three parts: - src/lib/llm-json.ts: parseModelJson() strips provider fences, and on a failed parse strips commas that sit before } or ]. The stripper SCANS string literals rather than pattern-matching, because this payload is full of Jira summaries and commit messages that can contain ", }" — a bare replace(/,\s*([}\]])/g,'$1') corrupts them silently. Same hazard as GLOOK-41's outsideStringLiterals, but JSON escapes a quote with a backslash where SQL doubles it, so the scanner tracks escapes instead. Repair is only attempted after a clean parse fails, so valid output is never touched, and `repaired` is reported so a drift in model behaviour stays visible. - insights.ts retries once with a salt when repair cannot help. That covers artifacts repair cannot fix — report c28781b4 failed with "Unexpected token 'r'", i.e. prose, not a comma. - The retry is bounded by a 10-minute per-report marker on globalThis (matching the progress and stop-signal stores). Successes are cached, so the model is normally called about once per report — but failures are deliberately NOT cached (incident 2026-08-03), so every page load re-enters this path. Today that is cheap because the proxy serves the cached completion in ~200ms; a salted retry is a deliberate cache miss costing a full ~200k-char generation, and da2fa78f logged 15 failure calls in one day. Without the marker, one broken report buys a fresh generation per page load. ModelJsonError carries the position, window, head and tail for logging but keeps model output OUT of `message`, because route.ts serialises err.message into the 5xx body and this payload contains internal commit text. There is a test asserting exactly that. Honest scope: repair is the part that can be promised — the artifact is characterised and the bytes are in hand. Whether a fresh generation avoids the comma is unknown; the retry is a safety net, not a guarantee. The 2026-08-03 invariant is preserved: a truncated completion is still never repaired and never cached, with a test pinning it. 129 suites / 1276 tests; tsc --noEmit and npm run build clean. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> * GLOOK-54: stop leaking model output into the 500 body, and stop wasting the retry Review found the confidentiality property this PR claimed — and certified with a test — was false, and that the test could not fail. V8 has two SyntaxError shapes and only one is content-free: Expected double-quoted property name in JSON at position 35 Unexpected token 'I', "INTERNAL-COMMIT-TEXT" is not valid JSON ModelJsonError interpolated V8's message into super(), so the second shape put model bytes into .message — which route.ts serialises into the 500 body, and this payload carries commit messages and Jira summaries. The guard test passed only because its fixture failed at position 35, the one shape that carries no snippet. Verified by execution: a position-0 fixture leaks. `message` is now fixed text. V8's own message moves to a `detail` field alongside window/head/tail, under the same rule: logs only. The same fact had broken the diagnostics. `/position (\d+)/` matches only the positional shape, so for "Unexpected token" the position was -1 and the window empty — and insights.ts guarded its window log on `position >= 0`. That is exactly the prose-preamble case (report c28781b4) the window logging was added for, so the diagnostic was missing precisely where it was needed. The window now falls back to the head of the document, and the log prints unconditionally. Three more, all found by review: - Truncation was never excluded from the retry. finishReason gated nothing, so a finish_reason=length body reached mayRetry and spent the report's one regeneration re-sending a prompt the salt had made STRICTLY LONGER at the same token limit — re-truncating with near-certainty. A permanently oversized report bought a doomed ~200k-char generation every cooldown window, indefinitely. Now a truncated completion is never repaired, never retried, never cached, stated as a rule rather than left as an accident of the current repair only deleting characters. - Emptiness was tested on the RAW content, so a fence-only completion — the artifact stripJsonFences exists for — skipped 'empty completion', failed as a parse error, and bought a regeneration. Now tested on the stripped text. - The retry's request shared a try/catch with its parse, so a 429, timeout or auth expiry became `json parse after salted retry: <provider message>`: wrong in errors.log, a second route for provider text into the 500 body, and it consumed the cooldown for something that was never a JSON problem. It also logged the FIRST attempt's bytes, because the reassignments never ran. The await is now outside the parse. - The cooldown marker was never cleared on success. A retry that succeeded but attributed 0 projects is served uncached, so the next load re-entered, got the proxy's cached broken completion, found mayRetry() false, and turned the card into a 500 for the rest of the window — with a good generation already discarded. Cleared on any usable generation, and the store is pruned so it cannot grow one entry per failing report forever. The doc comment now says the bound is PER PROCESS. This ships as a container image with GHCR publishing and a compose file, so the real ceiling is N regenerations per window across N replicas, reset on deploy; a true global bound needs the marker persisted, which is noted on the ticket rather than done here. Tests: the guard is now parameterised over all three V8 shapes including the two that leak, and asserts message equality rather than absence. Added: no retry on truncation (with call counts pinned on the pre-existing truncation tests too), fence-only treated as empty, a transport failure labelled as transport and carrying no provider text, and the cooldown cleared after a usable generation so a later failure can still retry. 129 suites / 1284 tests; tsc --noEmit and npm run build clean. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> --------- Co-authored-by: msogin <msogin@users.noreply.github.com> Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent 165b65a commit 159d72e

4 files changed

Lines changed: 602 additions & 12 deletions

File tree

Lines changed: 146 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,146 @@
1+
import {
2+
parseModelJson,
3+
stripTrailingCommas,
4+
stripJsonFences,
5+
ModelJsonError,
6+
} from '@/lib/llm-json';
7+
8+
/**
9+
* GLOOK-54. The Top Projects card was broken for weeks by ONE character: the
10+
* model closed a `jira_keys` array, emitted `,`, then `}`. The real captured
11+
* bytes, from the app log:
12+
*
13+
* …"RPS-10766","RPS-10768"],
14+
* },
15+
* {"name":"Video/Audio Processing", …
16+
*/
17+
18+
const REAL_ARTIFACT = `{
19+
"projects": [
20+
{
21+
"name": "Media Studio",
22+
"jira_keys": ["RPS-10766","RPS-10768"],
23+
},
24+
{"name":"Video/Audio Processing", "jira_keys":["RPS-10683"]}
25+
]
26+
}`;
27+
28+
describe('the real 2026-09-16 artifact', () => {
29+
it('fails a plain JSON.parse with the signature we saw in production', () => {
30+
let msg = '';
31+
try { JSON.parse(REAL_ARTIFACT); } catch (e) { msg = (e as Error).message; }
32+
expect(msg).toMatch(/Expected double-quoted property name/);
33+
});
34+
35+
it('parses after repair, and says it repaired', () => {
36+
const { value, repaired } = parseModelJson<{ projects: any[] }>(REAL_ARTIFACT);
37+
expect(repaired).toBe(true);
38+
expect(value.projects).toHaveLength(2);
39+
expect(value.projects[0].jira_keys).toEqual(['RPS-10766', 'RPS-10768']);
40+
});
41+
});
42+
43+
describe('stripTrailingCommas is literal-aware', () => {
44+
it('does NOT touch a comma-brace sequence inside a string', () => {
45+
// The payload is full of Jira summaries and commit messages. A naive
46+
// replace(/,\s*([}\]])/g, '$1') corrupts these silently, which is the whole
47+
// reason this scans literals instead of pattern-matching.
48+
const json = '{"summary":"refactor, } and cleanup, ] too","n":1}';
49+
expect(stripTrailingCommas(json)).toBe(json);
50+
expect(parseModelJson<any>(json).value.summary).toBe('refactor, } and cleanup, ] too');
51+
});
52+
53+
it('survives an escaped quote before a comma-brace', () => {
54+
// `\"` must not read as the end of the literal, or the scanner loses track
55+
// of whether it is inside a string.
56+
const json = '{"msg":"he said \\"done, }\\" loudly","n":1}';
57+
expect(stripTrailingCommas(json)).toBe(json);
58+
expect(parseModelJson<any>(json).value.msg).toBe('he said "done, }" loudly');
59+
});
60+
61+
it('handles a trailing backslash at the very end without overrunning', () => {
62+
expect(() => stripTrailingCommas('{"a":"b\\')).not.toThrow();
63+
});
64+
65+
it('strips in objects and arrays, including nested and multiple', () => {
66+
expect(stripTrailingCommas('{"a":[1,2,],}')).toBe('{"a":[1,2],}'.replace(',}', '}'));
67+
expect(parseModelJson<any>('{"a":[1,2,],}').value).toEqual({ a: [1, 2] });
68+
expect(parseModelJson<any>('[{"a":1,},{"b":2,},]').value).toEqual([{ a: 1 }, { b: 2 }]);
69+
});
70+
71+
it('keeps legitimate commas between members', () => {
72+
const json = '{"a":1,"b":2}';
73+
expect(stripTrailingCommas(json)).toBe(json);
74+
});
75+
76+
it('preserves whitespace shape around a removed comma', () => {
77+
expect(parseModelJson<any>('{"a":1 , \n }').value).toEqual({ a: 1 });
78+
});
79+
});
80+
81+
describe('well-formed output is never modified', () => {
82+
it('reports repaired=false and returns the parsed value', () => {
83+
const { value, repaired } = parseModelJson<any>('{"projects":[{"name":"x"}]}');
84+
expect(repaired).toBe(false);
85+
expect(value.projects[0].name).toBe('x');
86+
});
87+
88+
it('strips provider code fences', () => {
89+
expect(stripJsonFences('```json\n{"a":1}\n```')).toBe('{"a":1}');
90+
expect(parseModelJson<any>('```json\n{"a":1}\n```').value).toEqual({ a: 1 });
91+
});
92+
});
93+
94+
describe('unrepairable output', () => {
95+
it('raises ModelJsonError carrying the diagnostic window', () => {
96+
// 'r' is the shape report c28781b4 failed with — prose, not a comma.
97+
const raw = 'reasoning: the projects are as follows {"projects":[]}';
98+
let err: ModelJsonError | null = null;
99+
try { parseModelJson(raw); } catch (e) { err = e as ModelJsonError; }
100+
expect(err).toBeInstanceOf(ModelJsonError);
101+
expect(err!.head).toContain('reasoning');
102+
expect(err!.tail).toContain('projects');
103+
});
104+
105+
/**
106+
* V8 has two SyntaxError shapes and only one is content-free:
107+
*
108+
* Expected double-quoted property name in JSON at position 35
109+
* Unexpected token 'I', "INTERNAL-COMMIT-TEXT" is not valid JSON
110+
*
111+
* The first version of this guard used a fixture that failed at position 35,
112+
* so it only ever saw the safe shape and could not fail. These use the
113+
* leaking shape deliberately.
114+
*/
115+
it.each([
116+
['position 0 — V8 embeds the whole input', 'INTERNAL-COMMIT-TEXT'],
117+
['prose preamble — V8 embeds the first chars', 'INTERNAL-COMMIT-TEXT then {"projects":[]}'],
118+
['positional shape', '{"summary":"INTERNAL-COMMIT-TEXT", oops}'],
119+
])('keeps model output OUT of err.message (%s)', (_label, raw) => {
120+
// route.ts serialises err.message into the 5xx body, and this payload
121+
// carries commit messages and Jira summaries.
122+
let err: ModelJsonError | null = null;
123+
try { parseModelJson(raw); } catch (e) { err = e as ModelJsonError; }
124+
expect(err!.message).toBe('model JSON unparseable after repair');
125+
expect(err!.message).not.toContain('INTERNAL-COMMIT-TEXT');
126+
// Still available for the log, via detail/window rather than message.
127+
expect(`${err!.detail} ${err!.window}`).toContain('INTERNAL-COMMIT-TEXT');
128+
});
129+
130+
it('never leaves the window empty, even for the shape with no position', () => {
131+
// `/position (\d+)/` does not match "Unexpected token …", so position is
132+
// -1. That IS the prose-preamble case the window logging was added for, so
133+
// an empty window would omit the diagnostic exactly where it is needed.
134+
let err: ModelJsonError | null = null;
135+
try { parseModelJson('Here is the JSON: {"projects":[]}'); } catch (e) { err = e as ModelJsonError; }
136+
expect(err!.position).toBe(-1);
137+
expect(err!.window).not.toBe('');
138+
expect(err!.window).toContain('Here is the JSON');
139+
});
140+
141+
it('reports a usable position for the log window', () => {
142+
let err: ModelJsonError | null = null;
143+
try { parseModelJson('{"a":1 "b":2}'); } catch (e) { err = e as ModelJsonError; }
144+
expect(err!.position).toBeGreaterThan(0);
145+
});
146+
});

‎src/lib/__tests__/unit/project-insights-failure.test.ts‎

Lines changed: 160 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -52,6 +52,9 @@ beforeEach(() => {
5252
mockExecute.mockReset();
5353
mockCreate.mockReset();
5454
routeQueries();
55+
// The salted-retry cooldown lives on globalThis so it survives HMR; clear it
56+
// so each test starts eligible to retry.
57+
(globalThis as any).__glookInsightsRetryAt?.clear();
5558
});
5659

5760
it('does NOT cache when the completion is truncated (finish_reason=length)', async () => {
@@ -62,6 +65,11 @@ it('does NOT cache when the completion is truncated (finish_reason=length)', asy
6265

6366
await expect(getProjectInsights()).rejects.toThrow(/truncat|json parse|generation/i);
6467
expect(cacheWrites()).toHaveLength(0);
68+
// Exactly one call: a truncated body must never buy a salted regeneration.
69+
// The salt is appended, so the retry prompt is strictly LONGER at the same
70+
// token limit and re-truncates — spending the report's one regeneration on
71+
// the single case it cannot help.
72+
expect(mockCreate).toHaveBeenCalledTimes(1);
6573
});
6674

6775
it('does NOT cache when the completion is empty', async () => {
@@ -89,3 +97,155 @@ it('caches a complete, parseable generation', async () => {
8997
expect(res.projects).toHaveLength(1);
9098
expect(cacheWrites()).toHaveLength(1);
9199
});
100+
101+
/**
102+
* GLOOK-54: the Top Projects card was broken for weeks by ONE trailing comma
103+
* in an otherwise perfect 14,268-char response, and reloading never helped
104+
* because the AI Proxy re-serves the identical cached completion (measured:
105+
* 2431ms first call, 224ms and byte-identical on the second).
106+
*/
107+
describe('GLOOK-54 — malformed model JSON', () => {
108+
const TRAILING_COMMA =
109+
'{"projects":[{"name":"Media Studio","jira_keys":["AAA-1"],},{"name":"Other","jira_keys":["AAA-1"]}]}';
110+
111+
const userMessageOf = (call: any) =>
112+
call[0].messages.find((m: any) => m.role === 'user').content;
113+
114+
it('repairs a trailing comma instead of failing the card', async () => {
115+
mockCreate.mockResolvedValue({
116+
choices: [{ finish_reason: 'stop', message: { content: TRAILING_COMMA } }],
117+
});
118+
const out = await getProjectInsights();
119+
expect(out.available).toBe(true);
120+
// Repaired output is a real success, so it SHOULD be cached.
121+
expect(cacheWrites()).toHaveLength(1);
122+
// One call only: repair must not spend a regeneration.
123+
expect(mockCreate).toHaveBeenCalledTimes(1);
124+
});
125+
126+
it('retries ONCE with a salt when repair cannot help', async () => {
127+
mockCreate
128+
.mockResolvedValueOnce({ choices: [{ finish_reason: 'stop', message: { content: 'reasoning: here goes {"projects":[]}' } }] })
129+
.mockResolvedValueOnce({
130+
choices: [{ finish_reason: 'stop', message: { content: '{"projects":[{"name":"Fresh","jira_keys":["AAA-1"]}]}' } }],
131+
});
132+
133+
const out = await getProjectInsights();
134+
expect(out.available).toBe(true);
135+
expect(mockCreate).toHaveBeenCalledTimes(2);
136+
137+
// The salt must be in the USER MESSAGE. Measured on 2026-09-16: a nonce in
138+
// smartling_additional_properties does NOT bust the proxy cache (38ms,
139+
// identical bytes), so putting it there would re-serve the same bad JSON.
140+
const first = userMessageOf(mockCreate.mock.calls[0]);
141+
const second = userMessageOf(mockCreate.mock.calls[1]);
142+
expect(second).not.toBe(first);
143+
expect(second).toMatch(/<!-- retry .+ -->/);
144+
expect(second.startsWith(first)).toBe(true); // payload unchanged, salt appended
145+
});
146+
147+
it('does not cache when even the salted retry fails', async () => {
148+
mockCreate.mockResolvedValue({
149+
choices: [{ finish_reason: 'stop', message: { content: 'not json at all' } }],
150+
});
151+
await expect(getProjectInsights()).rejects.toThrow(/json parse/i);
152+
expect(cacheWrites()).toHaveLength(0);
153+
expect(mockCreate).toHaveBeenCalledTimes(2); // original + one salted retry
154+
});
155+
156+
it('will not spend a second regeneration while the cooldown holds', async () => {
157+
// Failures are NOT cached on our side, so every page load re-enters this
158+
// path. Without the cooldown one broken report buys a full ~200k-char
159+
// generation per load — da2fa78f logged 15 in a day.
160+
mockCreate.mockResolvedValue({
161+
choices: [{ finish_reason: 'stop', message: { content: 'not json at all' } }],
162+
});
163+
164+
await expect(getProjectInsights()).rejects.toThrow();
165+
expect(mockCreate).toHaveBeenCalledTimes(2); // first load: original + retry
166+
167+
mockCreate.mockClear();
168+
await expect(getProjectInsights()).rejects.toThrow(/cooldown/i);
169+
expect(mockCreate).toHaveBeenCalledTimes(1); // second load: no retry
170+
});
171+
172+
it('still refuses to cache a truncated completion', async () => {
173+
// GLOOK-54 must not weaken the 2026-08-03 invariant: repair is for
174+
// malformed output, never for a severed one.
175+
mockCreate.mockResolvedValue({
176+
choices: [{ finish_reason: 'length', message: { content: '{"projects":[{"name":"x","jira_keys":["AAA' } }],
177+
});
178+
await expect(getProjectInsights()).rejects.toThrow();
179+
expect(cacheWrites()).toHaveLength(0);
180+
});
181+
});
182+
183+
describe('GLOOK-54 review follow-ups', () => {
184+
it('does not retry a truncated completion, and says so', async () => {
185+
mockCreate.mockResolvedValue({
186+
choices: [{ finish_reason: 'length', message: { content: '{"projects":[{"name":"x","jira_keys":["AAA-1"],' } }],
187+
});
188+
await expect(getProjectInsights()).rejects.toThrow(/truncated completion/i);
189+
expect(mockCreate).toHaveBeenCalledTimes(1);
190+
expect(cacheWrites()).toHaveLength(0);
191+
});
192+
193+
it('treats a fence-only completion as empty rather than buying a regeneration', async () => {
194+
// Emptiness is tested on the STRIPPED content. Against raw content this
195+
// slipped past `empty completion`, failed as a parse error, and spent a
196+
// salted retry on a response with nothing in it.
197+
mockCreate.mockResolvedValue({
198+
choices: [{ finish_reason: 'stop', message: { content: '```json\n```' } }],
199+
});
200+
await expect(getProjectInsights()).rejects.toThrow(/empty completion/i);
201+
expect(mockCreate).toHaveBeenCalledTimes(1);
202+
});
203+
204+
it('labels a transport failure on the retry as transport, not as a parse error', async () => {
205+
// One try/catch around both the request and the parse turned a 429 or a
206+
// timeout into `json parse after salted retry: <provider message>` — wrong
207+
// in errors.log, and a second route for provider text into the 500 body.
208+
mockCreate
209+
.mockResolvedValueOnce({ choices: [{ finish_reason: 'stop', message: { content: 'prose, not json' } }] })
210+
.mockRejectedValueOnce(Object.assign(new Error('429 rate limited by PROVIDER-INTERNAL-DETAIL'), { name: 'RateLimitError' }));
211+
212+
const err = await getProjectInsights().catch((e) => e as Error);
213+
expect(err.message).toMatch(/salted retry request failed/i);
214+
expect(err.message).not.toMatch(/json parse/i);
215+
// Provider text must not ride out to the client via err.message.
216+
expect(err.message).not.toContain('PROVIDER-INTERNAL-DETAIL');
217+
});
218+
219+
it('clears the cooldown after a usable generation, so a later failure can still retry', async () => {
220+
// A retry that succeeded but attributed 0 projects is served UNCACHED, so
221+
// the next load re-enters. With the marker left set, that load found
222+
// mayRetry() false and turned the card into a 500 for the rest of the
223+
// window — having already discarded a good generation.
224+
mockCreate
225+
.mockResolvedValueOnce({ choices: [{ finish_reason: 'stop', message: { content: 'prose, not json' } }] })
226+
.mockResolvedValueOnce({
227+
choices: [{ finish_reason: 'stop', message: { content: '{"projects":[{"name":"Fresh","jira_keys":["AAA-1"]}]}' } }],
228+
});
229+
await expect(getProjectInsights()).resolves.toMatchObject({ available: true });
230+
expect(mockCreate).toHaveBeenCalledTimes(2);
231+
232+
// Same report fails again immediately: the retry budget must be available.
233+
mockCreate.mockClear();
234+
mockCreate.mockResolvedValue({
235+
choices: [{ finish_reason: 'stop', message: { content: 'prose, not json' } }],
236+
});
237+
await expect(getProjectInsights()).rejects.toThrow(/json parse after salted retry/i);
238+
expect(mockCreate).toHaveBeenCalledTimes(2); // not suppressed by a stale marker
239+
});
240+
241+
it('keeps V8 error text out of the thrown message on the cooldown path', async () => {
242+
mockCreate.mockResolvedValue({
243+
choices: [{ finish_reason: 'stop', message: { content: 'INTERNAL-COMMIT-TEXT not json' } }],
244+
});
245+
await expect(getProjectInsights()).rejects.toThrow();
246+
mockCreate.mockClear();
247+
const err = await getProjectInsights().catch((e) => e as Error);
248+
expect(err.message).toMatch(/cooldown/i);
249+
expect(err.message).not.toContain('INTERNAL-COMMIT-TEXT');
250+
});
251+
});

0 commit comments

Comments
 (0)