Repository navigation
fix(server): parse JSON after auth, answer bad bodies with 4xx and cap daily log files - #750
aliasunder wants to merge 12 commits into
Conversation
Limit JSON parsing to authenticated MCP posts. Treat non-form setup requests as missing fields and cover malformed consent and MCP bodies over HTTP. Implemented-By: codex · gpt-6.1-sol
Return public client errors with their 4xx status and a fixed response. Limit request metadata in both error handlers and retain full stacks for server failures. Implemented-By: codex · gpt-6.1-sol
Disable a failed file sink across the root logger and its children. Keep every original console line and emit one warning when setup, append, or daily size lookup fails. Implemented-By: codex · gpt-6.1-sol
Limit daily files to 25 MB by default, preserving existing file sizes across restarts and keeping console output after the cap. Add LOG_MAX_DAILY_MB across deployment settings, generated CLI settings, and documentation, with none as the off switch. Implemented-By: codex · gpt-6.1-sol
…te-limit' into worktree-unauthenticated-log-disk-flood
Ship-Check: pr-review · gpt-6.1-sol
| describe("JSON parser placement", () => { | ||
| it.each([ | ||
| { label: "authenticated MCP", path: "/mcp" }, | ||
| { label: "public registration", path: "/register" }, | ||
| ])("answers malformed $label JSON with 400", async ({ path }) => { | ||
| const server = await startServer(await freePort(), { MCP_AUTH_TOKEN: TOKEN_A }) | ||
| onTestFinished(server.cleanup) | ||
| const response = await fetch(`http://127.0.0.1:${server.port}${path}`, { | ||
| method: "POST", | ||
| headers: { "content-type": "application/json", authorization: `Bearer ${TOKEN_A}` }, | ||
| body: "{", | ||
| }) | ||
|
|
||
| expect({ status: response.status, body: await response.json() }).toEqual({ | ||
| status: 400, | ||
| body: { error: "invalid request body" }, | ||
| }) | ||
| expect(server.stderr()).not.toContain('"message":"unhandled_error"') | ||
| }) | ||
|
|
||
| it("rejects tokenless malformed MCP JSON before parsing or logging a request", async () => { | ||
| const server = await startServer(await freePort()) | ||
| onTestFinished(server.cleanup) | ||
| const response = await fetch(`http://127.0.0.1:${server.port}/mcp`, { | ||
| method: "POST", | ||
| headers: { "content-type": "application/json" }, | ||
| body: "{", | ||
| }) | ||
|
|
||
| expect(response.status).toBe(401) | ||
| expect(await response.json()).toEqual({ | ||
| error: "invalid_token", | ||
| error_description: "Missing Authorization header", | ||
| }) | ||
| expect(server.stderr()).not.toContain('"message":"unhandled_error"') | ||
| expect(server.stdout()).not.toContain('"message":"mcp_request"') | ||
| }) | ||
|
|
||
| it("rejects malformed JSON consent as an invalid form without an unhandled error", async () => { | ||
| const server = await startServer(await freePort()) | ||
| onTestFinished(server.cleanup) | ||
| const response = await fetch(`http://127.0.0.1:${server.port}/oauth/decide`, { | ||
| method: "POST", | ||
| headers: { "content-type": "application/json" }, | ||
| body: "{", | ||
| }) | ||
|
|
||
| expect({ | ||
| status: response.status, | ||
| cacheControl: response.headers.get("cache-control"), | ||
| body: await response.text(), | ||
| }).toEqual({ status: 400, cacheControl: "no-store", body: "Invalid form submission." }) | ||
| expect(server.stderr()).not.toContain('"message":"unhandled_error"') | ||
| }) | ||
| }) |
There was a problem hiding this comment.
Test the JSON-body contract on /token and /revoke after the parser move
Medium severity · tests · medium confidence
The PR description states that JSON bodies to /token, /authorize and /revoke now get the SDK's OAuth 400, but no test exercises that path even though removing the app-wide parser changed what those handlers receive (an unparsed body instead of a parsed object). If an SDK handler dereferences the missing body, the response regresses to a 500 unhandled_error with a full stack on an unauthenticated endpoint — the exact log-flood pattern this PR removes elsewhere.
Failure scenario: A client or script POSTs to /token with content-type: application/json and a JSON body (a client that defaults to JSON rather than OAuth's form encoding): if the SDK's token or client-auth handler reads req.body directly, Express answers 500 and logs unhandled_error with a full stack; an unauthenticated sender can repeat this at the 5/min limiter to fill the log with stack traces, contradicting the PR's stated SDK-400 outcome.
Suggested fix
Add a case to the new "JSON parser placement" describe that POSTs content-type application/json with a JSON body to /token (and /revoke) and asserts the exact status and body the SDK returns (e.g. 400 with an invalid_request OAuth error). The assertion locks the documented 400 or exposes the 500.umm-actually · z-ai/glm-5.3-flash
|
Cap client-controlled fields in the OAuth warn logs
Pre-existing: the OAuth endpoints log client-controlled values without the 256-code-point cap this PR applies to the rejection paths: oauth_consent_expired logs the raw request_id form field (which the urlencoded parser accepts up to its 100 KB body limit), oauth_rate_limited logs the attacker-chosen request path, and oauth-provider.ts's oauth_resource_rejected logs the full resource href. Because the new daily file cap pauses file logging once 25 MB is reached, oversized lines from these sibling rejection paths can consume the day's entire budget, dropping that day's legitimate logs, and each line breaks the short-rejection line contract the PR establishes. Failure scenario: An unauthenticated client POSTs /oauth/decide with request_id filled to ~100 KB five times per minute (the limiter's budget); each miss emits an oauth_consent_expired warn carrying the full 100 KB field, so roughly 250 requests in under an hour burn the day's 25 MB file-log budget and file logging pauses for the rest of the day; alternatively, sustained over-limit requests to /token spam oauth_rate_limited warns whose path field is attacker-sized, at unlimited rate. Suggested fixPass these values through the new capLogField helper before logging: requestId: capLogField(requestId) in the consent handler's child logger and warn, path: capLogField(requestPath) in the limiter handler, and cap resource.href in oauth-provider.ts's oauth_resource_rejected.umm-actually · z-ai/glm-5.3-flash |
|
umm-actually re-reviewed at 4 new finding(s) posted (9 tracked finding(s) across all runs). Context notes
umm-actually · z-ai/glm-5.3-flash |
Ship-Check: code-quality · gpt-6.1-sol
Ship-Check: test-audit · gpt-6.1-sol
…nauthenticated-log-disk-flood
Move the terminal request-error policy into one shared factory and mount it in the full and setup apps. Move its unit tests beside the shared module and retain both apps’ response and logging checks. Implemented-By: codex · gpt-6.1-sol
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
| const transports = new Map<string, StreamableHTTPServerTransport>() | ||
|
|
||
| router.post("/mcp", bearerAuth, async (req: Request, res: Response) => { | ||
| router.post("/mcp", bearerAuth, express.json(), async (req: Request, res: Response) => { |
There was a problem hiding this comment.
Cap the client-supplied mcp-session-id in mcp-router logs
Low severity · subtle bugs · medium confidence
The PR's new capLogField helper bounds sessionId/path/clientIp in the error middleware, but mcp-router.ts still logs the raw client-controlled mcp-session-id header (up to the header size limit) in mcp_request, mcp_response and session_closed lines. An authenticated client can therefore keep writing arbitrarily large log lines, the exact pattern the PR caps elsewhere.
Failure scenario: A client holding a valid bearer token sends POST /mcp with an mcp-session-id header of ~100 KB; each request emits an mcp_request/mcp_response warn or info line carrying the full header, so repeated calls consume the day's 25 MB file-log budget on oversized lines and crowd out legitimate logs.
Suggested fix
Pass the header through capLogField at the route boundaries: const sessionId = capLogField(headerAsString(req.headers["mcp-session-id"])) in the POST/GET/DELETE handlers, matching http-error-middleware.ts.umm-actually · z-ai/glm-5.3-flash
Restore the boot-sync restart paragraph and correct the matching setup claim. Reuse grapheme-safe code-point truncation for capped log fields. Accept every whole daily cap of at least one megabyte. Warn and use the default for negative or non-number log retention. Shorten the comment explaining the CLI TypeScript library constraint. Implemented-By: codex · gpt-6.1-sol
| logDay.date = today | ||
| // An exact-cap file still needs its limit notice; an over-cap file already | ||
| // has one or predates this cap, so restarting must not append another. | ||
| logDay.capped = logDay.bytes > maxDailyBytes |
There was a problem hiding this comment.
Treat a notice-terminated day as capped when re-deriving on restart
Medium severity · subtle bugs · high confidence
On rollover the sink re-derives the capped state from file size alone, but the limit notice (~160 bytes) usually lands the file just under the cap, so a same-day restart computes capped=false and resumes writing after the notice. The day's file then ends with log lines after the first notice and a second notice once the cap trips again, breaking the one-notice-per-day contract stated in SECURITY.md and the code's own restart comment.
Failure scenario: The day's file sits at 24,999,000 of the 25,000,000-byte cap; the next ~2 KB info line trips the limit, so the sink appends only the ~160-byte file_log_daily_limit_reached notice and stops (file now ~24,999,160 bytes, under the cap). The container restarts the same day during a deploy; the sink stats the file, sees the size is under the cap, sets capped=false, and appends further lines after the notice until the cap trips again — the file ends with two notices and lines after the first one, while SECURITY.md promises one limit notice and writes resume only at midnight.
Suggested fix
On rollover, also treat the day as capped when the on-disk file ends with the limit notice (bounded read of the final line), e.g. `logDay.capped = logDay.bytes > maxDailyBytes || fileEndsWithDailyLimitNotice(logPath)`, and add a logger test covering a restart after a small line tripped the cap.umm-actually · z-ai/glm-5.3-flash
| const retentionDays = parseInt(envValue, 10) | ||
| return Number.isNaN(retentionDays) ? undefined : retentionDays | ||
|
|
||
| if (!Number.isNaN(retentionDays) && retentionDays >= 0) return retentionDays | ||
|
|
||
| process.stdout.write( | ||
| consoleWarningLine("invalid LOG_RETENTION_DAYS; using default", { | ||
| retentionDays: DEFAULT_RETENTION_DAYS, | ||
| }), | ||
| ) | ||
| return DEFAULT_RETENTION_DAYS |
There was a problem hiding this comment.
Parse LOG_RETENTION_DAYS as strictly as LOG_MAX_DAILY_MB
Low severity · subtle bugs · high confidence
Pre-existing: parseRetentionDays accepts any parseInt prefix — 1e1 parses as 1, 0.5 as 0, 90abc as 90 — while this PR's sibling LOG_MAX_DAILY_MB parser validates strictly with WHOLE_MEGABYTES and warns on malformed values. The same malformed-value contract the PR establishes for one log variable is silently absent for the other, so a mistyped retention value truncates to its numeric prefix with no warning.
Failure scenario: An operator sets LOG_RETENTION_DAYS=0.5 intending half a day (or 1e1 intending ten): parseInt yields 0 and 1, so the next startup or midnight prune deletes every log file except today's (or keeps only one day), silently destroying up to 89 days of retained logs — while the identical malformed value on LOG_MAX_DAILY_MB produces an 'invalid LOG_MAX_DAILY_MB; using default' warning and the documented default.
Suggested fix
Validate with the same pattern as parseMaxDailyBytes (e.g. `/^\d+$/` plus a range check), warn via consoleWarningLine, and fall back to DEFAULT_RETENTION_DAYS on failure.umm-actually · z-ai/glm-5.3-flash
| const parseMaxDailyBytes = (envValue: string | undefined): number => { | ||
| if (envValue === undefined) return DEFAULT_MAX_DAILY_MB * BYTES_PER_MB | ||
| if (envValue.toLowerCase() === "none") return Number.POSITIVE_INFINITY | ||
|
|
||
| const maxDailyMb = Number(envValue) | ||
| const maxDailyBytes = maxDailyMb * BYTES_PER_MB | ||
| const validLimit = WHOLE_MEGABYTES.test(envValue) && maxDailyMb >= 1 | ||
|
|
||
| if (validLimit) return maxDailyBytes | ||
|
|
||
| process.stdout.write( | ||
| consoleWarningLine("invalid LOG_MAX_DAILY_MB; using default", { | ||
| maxDailyMb: DEFAULT_MAX_DAILY_MB, | ||
| }), | ||
| ) | ||
| return DEFAULT_MAX_DAILY_MB * BYTES_PER_MB | ||
| } |
There was a problem hiding this comment.
Warn when LOG_MAX_DAILY_MB is large enough to be non-finite
Low severity · subtle bugs · medium confidence
parseMaxDailyBytes accepts any digit-only string whose Number() times 1,000,000 the test pins at 'non-finite byte count' — for a 400-digit value Number() is Infinity, so the cap silently behaves as disabled (identical to none) with no warning, while every other malformed value produces an 'invalid LOG_MAX_DAILY_MB; using default' line. An operator who fat-fingers a huge value gets no signal that the cap is off; the runtime hazard is bounded (Infinity comparisons are safe), so this is a diagnosability gap, not a crash.
Failure scenario: LOG_MAX_DAILY_MB=999... (400 nines) is set to 'disable the cap'; a runaway auth-failure flood grows the day's file unbounded on a small /data volume, and nothing in the logs explains why the cap the operator believes is configured never engaged.
Suggested fix
Reject maxDailyBytes values that are not finite numbers (or exceed a sane ceiling) in the same warning branch, instead of letting Infinity pass the validLimit check.umm-actually · z-ai/glm-5.3-flash
Summary
A malformed request body was parsed before any token check, answered 500, and logged at
errorwith a full stack and the raw request path, so requests without credentials could write a kilobyte or more of log per request. With a full log disk, every log call threw and the server stopped answering. This change parses JSON only onPOST /mcpafter the token check, answers request-body errors with their own 4xx and a shortwarnline, caps the logged path, session ID and client IP, keeps the server running when file logging fails, and caps each day's log file.Stacked on #749 (consent-form rate limit), which also changes
/oauth/decide.Changes
server.ts,mcp-core/mcp-router.ts): the app-wideexpress.json()is gone;POST /mcpmounts its own afterbearerAuth, so a body without a valid token is answered 401 without being parsed.POST /setupanswers a non-form body with its missing-fields 400;/oauth/decidealready reads a missing body as an invalid form (fix(oauth): rate-limit consent form submissions #749).server.ts,setup/setup-server.ts, a new guard insrc/utils/): a body-parser error (status400–499 withexpose: true) is answered with its own status and{"error":"invalid request body"}, and logged once atwarnasrequest_body_rejectedwithout a stack. Other errors keep the 500 and the full stack. Loggedpath,sessionIdandclientIpare capped at 256 code points.src/logger.ts): a failed append, first-write size lookup, prune, or log-folder creation at startup turns file logging off with one console warning instead of throwing; console logging continues. A restart resumes file logging.src/logger.ts, newLOG_MAX_DAILY_MB, default 25,noneturns it off): each day's file stops at the cap with onefile_log_daily_limit_reachedline, the count survives a restart, and old files are also pruned at each day rollover. Documented in the deploy guides,.env.examplefiles, README,DEPLOY.md,server.jsonand the CLI's generated env blocks;DOCKERHUB.mdregenerated (24,992 bytes)./token,/authorizeand/revokenow get the SDK's OAuth 400; those endpoints take form-encoded bodies, as OAuth specifies.Verification
npm test: 7,642 passed, 2 skipped.npm run build,npm run lint(no errors),npx knip, markdownlint and Prettier pass.🤖 Generated with Claude Code