[1395490241lhj-code]

Summary

P0 diagnostics for Kitchen AI. Render production logs show /api/ai-conversation failures that come back as HTTP 200 with an in-stream provider_unavailable error. Today's ai_conversation_failed log line carries only resultCode: provider_unavailable, so a 400, 413, 429, timeout and 5xx all look the same in production.

This PR only adds failure diagnostic metadata to the existing ai_conversation_completed / ai_conversation_failed log lines.

Commit	What
27c9aad	adds the diagnostic fields
e6cc48c	GitHub "Update branch" merge of main @ 1a3d3b9 (PR #35); no functional change to this PR
966dc97	makes the extraction exception-safe and the logged status accurate (S1/S2 from review, see below)

Fields now logged

Field	When	Value
provider, attempt	always (existing)	provider that answered or failed last; 1-based attempt
primaryProvider	always	provider the request asked for first
timeoutMs	always	SDK deadline configured for the final attempt
requestSizeBytes	always	UTF-8 byte length of JSON.stringify(messages); see the note below the table
fallbackReason	primary failed transiently and the fallback ran	normalized error code of the primary failure
status	final failure	HTTP status the error itself carries (err.response.status, else the SDK's err.status), integer 100–599. Omitted for transport errors, SDK timeouts and mid-stream errors that have no HTTP status. No synthetic 502/504
reason	final failure	normalized error code; see the code-normalization list below
timeoutSource	final failure	server_sdk_deadline (our SDK deadline; status is omitted), upstream_response (a real upstream 504), otherwise omitted
upstreamRequestId	final failure	first value that matches ^[A-Za-z0-9_-]{8,128}$; see the order below. Malformed values are skipped, never logged. Omitted when none matches

requestSizeBytes counts messages only. It excludes tool definitions and model parameters, so it is not the full provider request size.

Error codes (reason, fallbackReason) are normalized like this:

• a string matching ^[A-Za-z0-9][A-Za-z0-9_.-]{0,63}$, or a finite number, is kept as is;
• anything else becomes unrecognized, including objects, arrays, symbols, BigInt and unreadable fields;
• an SDK timeout with no code becomes ECONNABORTED;
• no code at all becomes upstream_error.

upstreamRequestId candidates are checked in this order:

1. x-groq-id, x-request-id and x-trace-id, taken from err.response.headers or the SDK's err.headers;
2. then err.requestID.

All field names were already in the logger allowlist (src/server/observability/logger.js is unchanged).

What is read, and what is not

The diagnostics read only these fields of the thrown error:

• status and response.status;
• code and type, on the error itself and on its body (error / response.data.error), plus response.data.code;
• constructor.name;
• the three request-id headers and requestID.

They never read:

• the error's message / detail / body text;
• prompts, conversation messages, tool results or user inventory (only their byte count);
• API keys, tokens or Authorization values.

Limitation (format check, not an allowlist). Error codes and request ids are third-party values. They are checked for shape only: short, anchored, bounded character classes. They are not checked against a list of known values. So a short identifier-shaped string that an upstream returns as its code or request id would be logged verbatim, including something that looks like a key. In the tested scenarios, a fake key in the error message, the prompt, inventory text and the upstream message never reach stdout. That is not a guarantee against an arbitrarily hostile upstream code.

Review fixes in 966dc97

• S1, exception safety. Before this commit, the route's catch called the shared getUpstreamAiErrorInfo(err). That helper String()s arbitrary codes and reads properties without guards. An error whose code JSON-parses to an object with a non-callable toString, or a throwing getter, made the async handler reject: Express 4 does not catch that, and server.js has no unhandledRejection handler. The paths affected were no-fallback, the fallback attempt itself, and mid-stream.
  • The fix is a route-local conversationFailureInfo(err). It reads every field through a guarded accessor, so throwing getters and Proxy traps read as unreadable. It never stringifies non-primitive codes. An outer try/catch returns { reason: 'unrecognized' } as a last resort.
  • The shared helper and every other route are unchanged.
• S2, status accuracy. The shared helper invents 502 when there is no status and 504 for SDK timeouts. Those values were being logged as if they were upstream statuses. Now status is only what the error carries.

What does not change

• Provider selection, models, fallback rules (isTransientProviderFailure, visibleEvents gating), timeouts, rate limits, auth and business logic
• Stream events and HTTP status returned to clients
• The production model-call policy

The only control-flow edit is in the existing catch block. It stores conversationFailureInfo(err) before the same continue / error-event path that runs today.

Known limitations, tracked separately

• R1, pre-existing, not changed by this PR. On the gemini-primary-with-fallback path, isTransientProviderFailure still runs String(err.code) before any event is written. The same malformed code still makes that path reject, exactly as on main before this PR. Fixing it touches fallback determination and is out of scope here.
• R2. Format-checked codes and ids; see the limitation above.
• S3, not done. When the fallback ran, only the primary's normalized code is kept as fallbackReason. Its status, timeout source and request id are not logged.

Production context (not resolved by this PR)

Render service kitchenmanager, 2026-10-20 15:43–15:44 America/Toronto: 13 /api/ai-conversation requests, 9 succeeded and 4 failed. Groq failed twice (54 ms, 58 ms) and Gemini failed twice (171 ms, 178 ms), right after successful model calls. Every failure returned HTTP 200 with in-stream provider_unavailable.

The root cause is not confirmed. Leading hypotheses are an incompatible continuation request after multi-step tool calls, or an immediate upstream rejection. This PR exists to tell those apart. Separately, /api/ai-chat logs show repeated Gemini upstream HTTP 503s. That should not be assumed to be the same cause.

Independence

• Up to date with main @ 1a3d3b9 via "Update branch". It does not depend on PR Kitchen AI Phase 1a: tonight recipe recommendations with deterministic kitchen facts #32 or PR fix: improve Kitchen AI reliability and conversation scrolling #33.
• The diagnostics no longer match 20a0de2 on PR fix: improve Kitchen AI reliability and conversation scrolling #33's branch, because this PR adds the S1/S2 hardening. PR fix: improve Kitchen AI reliability and conversation scrolling #33's duplicate diagnostics commit has to be reconciled separately after this PR lands.

Test plan

Regression tests were written first. On e6cc48c 8 of them fail: 4 route throws (S1) and 4 synthetic 502/504 statuses (S2). With 966dc97 all of them pass. Locally on Node v26.12.0, with dependencies installed from this branch's lockfile:

• test/ai-conversation-stream.test.mjs: 43/43. That is 14 diagnostics tests, 10 of them new, using the real openai SDK error classes.

• ai-server-routes 124/124, ai-conversation-lifecycle 2/2, ai-conversation-turn-limit 21/21

• full npm test: 2013/2013

• npm audit --omit=dev --audit-level=high: 0 vulnerabilities; git diff --cached --check clean

• Behaviour diff against main across 17 scenarios:

  • success, validation 400, fallback success and fallback failure;
  • SDK timeout, connection error, real 400/413/429/503/504 and mid-stream failure;
  • malformed codes on four paths, throwing getters and client abort.

  HTTP status, NDJSON events, provider call count and throw/no-throw are identical to main in all 17. No sensitive test string appears in the logs.

• The extracted helper was fuzzed with 31 hostile inputs (proxies, a revoked proxy, throwing getters, symbol/BigInt/object codes): 0 throws, and every field value was safe.

• Two independent read-only reviews: no blockers. The second review's request-id and comment findings are addressed in 966dc97.

• CI run 39534978344 on 966dc97, which checked out ee9a747, the merge of 966dc97 into 1a3d3b9:

  • test (22): Node 22.23.3, 2013/2013
  • test (24): Node 24.22.0, 2013/2013
  • both jobs passed the recipe pack validations and the production npm audit, with 0 vulnerabilities

• After an approved deploy: confirm the new fields show up on the next production ai_conversation_failed line

🤖 Generated with Claude Code