Skip to content

Log tracebacks for client error responses - #985

Open
ramantehlan wants to merge 9 commits into
mainfrom
raman/age-2148-log-tracebacks-for-trueforge-for-422-424-400-errors
Open

ramantehlan wants to merge 9 commits into
mainfrom
raman/age-2148-log-tracebacks-for-trueforge-for-422-424-400-errors

Conversation

@ramantehlan

@ramantehlan ramantehlan commented Oct 7, 2026 •

Copy link
Copy Markdown
Contributor

Closes AGE-2148.

Problem

Errors leaving the server as a non-2xx response produced only the one-line access log (method, path, status, duration_ms). A 400, 422 or 424 could not be traced back to the code that raised it.

The reported case: a saved agent gets an exchanged token with no provider integrations, the model lookup fails, and the request exits non-2xx with nothing in the log but the status.

Three paths were silent:

  1. createAppErrorHandler logged only when an HTTPException was >= 500. Every thrown client error was dropped - 27 thrown 422s, 9 thrown 424s, 9 thrown 400s, plus ZodError and InvalidCronError. A test even asserted this ('does not error-log a client HTTP exception').
  2. 22 route catch-blocks caught a real error and returned c.json({...}, 400|422|424) directly, never reaching the error handler.
  3. OpenAPI request validation returned its 400 from the defaultHook without throwing, so it bypassed the handler too. This is the largest source of silent 400s.

Change

New packages/trueforge/src/http/requestErrorLog.ts owns the policy:

logRequestError({ logger, c, status, error, message });

It logs { method, path, status, ...extractErrorLogFields(error) } - reusing the existing helper, which already walks cause and carries stack. Level by status:

Status Level Why
>= 500 error unchanged
401 / 403 / 404 debug routine auth and not-found; the stack adds nothing and hosted logs would flood
everything else 4xx warn the ticket's 400 / 422 / 424

Call sites:

  • createAppErrorHandler on all four branches (ZodError, InvalidCronError, HTTPException, unhandled).
  • zodValidationHook became createZodValidationHook(logger) and logs Request validation failed before returning the prettified 400.
  • The 22 catch-and-convert sites in src/apis/*.ts.

logger is threaded into the four router deps that had none (AgentsRouterDeps, ModelProvidersRouterDeps, WebSearchProvidersRouterDeps, AgentImportRouterDeps).

The 403 / 404 / 409 branches in route handlers are deliberately untouched - those are expected control flow with no traceback worth keeping.

Verification

pnpm run typecheck clean, 77 suites / 675 tests pass, eslint and prettier clean on the changed files.

Live against a standalone server, the reported case:

POST /api/v1/agents  {"manifest":{"model":{"name":"nosuch/model"}, ...}}
-> 422 {"error":{"message":"Unknown model \"nosuch/model\" — provider not configured"}}
warn Client API error {"method":"POST","path":"/api/v1/agents","status":422,"error":"Unknown model \"nosuch/model\" — provider not configured"}
Error: Unknown model "nosuch/model" — provider not configured
    at getModelDetails (src/runtime/sessionResources.ts:86:11)
    at async validateAgentSpec (src/runtime/sessionResources.ts:286:20)
    at async validateManifest (src/apis/agents.ts:85:3)
    at async createHandler (src/apis/agents.ts:126:22)

Before this change that request logged only info request {... "status":422 ...}.

Also confirmed live:

  • GET /api/v1/agents?page_token=garbage -> 400 with an InvalidPageTokenError traceback through PageToken.ts (catch-and-convert path).
  • A malformed body -> 400 with warn Request validation failed naming manifest.model (validation-hook path).
  • An unknown route -> 404 with no extra line, since notFound() raises no error.

Tests

  • tests/unit/appErrorHandler.test.ts rewritten; the old case asserted the bug.
  • tests/unit/http/requestErrorLog.test.ts covers the level-selection rule and the cause chain.
  • tests/unit/zodErrorResponse.test.ts covers the validation hook.

Note

A ZodError logs zod's raw JSON issue array as its error field, because that is what Error.message holds. The field path and reason are both present, just verbose. Prettifying would mean teaching extractErrorLogFields about zod in trueforge-core, which felt out of scope here.


Note

Low Risk
Observability and error-path refactors only; HTTP status codes and response bodies stay the same for converted routes, with slightly more warn-level log volume for 4xx.

Overview
Non-2xx API responses now emit structured logs with method, path, status, the error message chain, and a stack so 400/422/424 failures can be traced past the access log alone.

Central error handling: createAppErrorHandler logs every branch (ZodError, InvalidCronError, HTTPException, unhandled) at error for 5xx, warn for most 4xx, and debug for routine 401/403/404. OpenAPI validation’s zodValidationHook throws ZodError instead of returning 400 directly so the same handler builds the envelope and writes the log line.

Route handlers: Catch blocks that used to return c.json({ error }, 4xx) now rethrow HTTPException with the original error as cause (agents, sessions, turns, schedules, MCP/model/sandbox/web-search providers, import, etc.). Shared client-facing strings live in clientErrorMessages.ts.

Core logging: extractErrorLogFields prefers the deepest cause stack when errors are wrapped at API boundaries, so logged tracebacks point at the origin throw site. Unit tests cover cause chains, cycles, and the error handler log levels.

Reviewed by Cursor Bugbot for commit 7f33462. Bugbot is set up for automated code reviews on this repo. Configure here.

Errors leaving the server as a non-2xx response produced only the
one-line access log, so a 400, 422 or 424 could not be traced to the
code that raised it. Three paths were silent: the app error handler
skipped every HTTPException below 500, 22 route catch-blocks converted
a caught error into a 4xx without logging it, and OpenAPI request
validation returned its 400 from the defaultHook without ever throwing.

Add logRequestError as the single owner of the policy. It logs the
method, path, status and error chain with its stack, at error level for
5xx, debug for routine 401/403/404 rejections, and warn for everything
else. Call it from the error handler, from the validation hook, and at
each catch-and-convert site.

Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
@changeset-bot

changeset-bot Bot commented Oct 7, 2026 •

Copy link
Copy Markdown

🦋 Changeset detected

Latest commit: 7f33462

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 2 packages
Name Type
@truefoundry/trueforge-core Patch
@truefoundry/trueforge Patch

Not sure what this means? Click here to learn what changesets are.

Click here if you're a maintainer who wants to add another changeset to this PR

@cursor cursor Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cursor Bugbot has reviewed your changes using default effort and found 2 potential issues.

Fix All in Cursor

❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.

Reviewed by Cursor Bugbot for commit 303a258. Configure here.

Comment thread packages/trueforge/src/apis/turns.ts Outdated
Comment thread packages/trueforge/src/apis/sandboxProviders.ts Outdated
…acebacks-for-trueforge-for-422-424-400-errors

Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
Bugbot review on #985 found client errors that still bypassed the new
logging. getTurnExecutionError maps turn-start failures to 400/404/422
and returns them directly, so the unknown-model 422 raised while
starting a turn - the exact case in the ticket - was still silent on
both the turn and schedule-run routes. The Daytona permission 422, the
SandboxError download path and both sandbox-secret sync responses were
unlogged for the same reason.

Call logRequestError at each, passing the mapped status so the level
rule still applies.

Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
Comment thread packages/trueforge/tests/unit/apis/webSearchProviders.test.ts Outdated
Comment thread packages/trueforge/src/apis/webSearchProviders.ts Outdated
The 22 catch-and-convert sites each had to remember to log, and four
routers had to grow a logger they otherwise had no use for. Instead they
now rethrow as HTTPException with the caught error as cause, and the
OpenAPI validation hook throws its ZodError rather than answering
directly, so createAppErrorHandler is the single place that builds the
error envelope and writes the log line.

A rethrow captures the boundary, not the throw site, so
extractErrorLogFields gains cause_stack: the stack of the deepest cause
that carries one. The unknown-model 422 still names sessionResources.ts
and a bad page token still names PageToken.ts.

Router tests that asserted the JSON envelope now mount through the real
error handler, since the envelope is the handler's to produce.

Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
Signed-off-by: Raman Tehlan <ramantehlan@gmail.com>
@@ -0,0 +1,5 @@
---

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why are there 2 change sets


async function createRouters(): Promise<{
settingsRouter: ReturnType<typeof createSettingsRouter>;
settingsRouter: ReturnType<typeof mountWithErrorHandler>;

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why do we need to do this. and why just settings router


export const zodValidationHook: Hook<unknown, object, string, Response | undefined> = (result, c) => {
/** Throws so the app error handler owns both the response and its log line. */
export const zodValidationHook: Hook<unknown, object, string, Response | undefined> = result => {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

where is this used exactly?

export function getDaytonaAuthorizationErrorMessage(error: unknown): string | undefined {
if (isDaytonaAuthError(error)) {
return 'Sandbox provider rejected the API key — check the credentials';
return SANDBOX_PROVIDER_API_KEY_REJECTED;

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why are we only replacing some specific errors with constants? this function itself is about getting error messages, and not everything was replaced here.
If its just used here why use constants?

return;
}
if (QUIET_CLIENT_ERROR_STATUSES.has(status)) {
params.logger.debug(message, fields);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@chiragjn what is the expectation here? The issue is about logging tracebacks, I assume we don't want debug logs?
However why do we want to log 400s as errors?

return c.json({ error: { message: error.message } }, error.status);
}
params.logger.error('Unhandled error', extractErrorLogFields(error));
logError(500, 'Unhandled error');

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why are we not extracting error fields

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants