From bb540e1e9ad9cefcc3f16a0b20244534a4351d43 Mon Sep 17 00:00:00 2001 From: doudouOUC Date: Mon, 18 May 2026 23:25:10 +0800 Subject: [PATCH 1/5] fix(serve): auth device-flow follow-up for #4255 review threads MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Fold-in for the 5 review comments posted ~20 min after #4255 merged (deepseek-v4-pro / DeepSeek). All 5 are real, observable gaps; this commit addresses them in a single follow-up: 1. **stderr audit for raw poll() errors** (Critical) — `qwenDeviceFlowProvider.poll()`'s catch block previously dropped raw `err.message` on the floor; only the static `upstream_error` hint reached SSE/HTTP. `start()` already used `writeStderrLine(...)` for this; symmetrize so on-call has a breadcrumb at 3 AM (WAF block vs. proxy 503 vs. JSON parse). 2. **runPollTick poll() Promise.race timeout** (Critical) — `provider.poll()` only had `entry.cancelController.signal` for cooperative cancellation; a non-abortable provider could pin the per-providerId singleton until the sweeper expired the entry (10 min default). Add `DEVICE_FLOW_POLL_TIMEOUT_MS = 30_000` and race the same shape used by `doStart` (#1) and persist (#2). 3. **GET clientId-gated userCode/verificationUri/initiatorClientId** — `GET /workspace/auth/device-flow/:id` previously echoed all fields to any bearer holder; the POST take-over response (round-12 #6) already gated `initiatorClientId` on caller-clientId match. Symmetrize: only the original starter (matched by `X-Qwen-Client-Id`) sees `userCode` / `verificationUri` / `verificationUriComplete` / `initiatorClientId`. Anonymous and different-clientId callers see only the public envelope. 4. **cancellerClientId first-writer-wins** — two SDK clients racing `cancel()` on the same persist-in-flight entry would overwrite attribution; the second cancel is functionally a no-op on the entry (already marked `cancelRequestedDuringPersist`) but its id silently took over the SSE event's `originatorClientId`. Guard with `if (entry.cancellerClientId === undefined)`. 5. **`not_found_or_evicted` into `DaemonAuthDeviceFlowErrorKind`** — SDK synthesizes this errorKind from a daemon 404, but the typed union didn't list it; SDK consumers' exhaustive switches couldn't narrow it as a known literal (fell into the `(string & {})` fallback arm). Add the literal so it's compile-time recognized. Tests: - `deviceFlow.test.ts` +2 (poll timeout race; cancellerClientId first-writer-wins) - `server.test.ts` +1 (GET clientId gating: matching / anonymous / different) - existing 665 cli serve + 384 sdk tests still green - typecheck clean across cli + core + sdk + webui - eslint --max-warnings 0 clean on touched files Refs: #4175, #4255 🤖 Generated with [Qwen Code](https://github.com/QwenLM/qwen-code) --- .../cli/src/serve/auth/deviceFlow.test.ts | 124 ++++++++++++++++++ packages/cli/src/serve/auth/deviceFlow.ts | 63 +++++++-- .../src/serve/auth/qwenDeviceFlowProvider.ts | 13 ++ packages/cli/src/serve/server.test.ts | 61 ++++++++- packages/cli/src/serve/server.ts | 31 ++++- packages/sdk-typescript/src/daemon/events.ts | 10 ++ 6 files changed, 283 insertions(+), 19 deletions(-) diff --git a/packages/cli/src/serve/auth/deviceFlow.test.ts b/packages/cli/src/serve/auth/deviceFlow.test.ts index a1ac9448a1e..9bfafd4ee32 100644 --- a/packages/cli/src/serve/auth/deviceFlow.test.ts +++ b/packages/cli/src/serve/auth/deviceFlow.test.ts @@ -16,6 +16,7 @@ import { DEVICE_FLOW_MAX_EXPIRES_IN_SEC, DEVICE_FLOW_MAX_INTERVAL_MS, DEVICE_FLOW_PERSIST_TIMEOUT_MS, + DEVICE_FLOW_POLL_TIMEOUT_MS, DEVICE_FLOW_SLOW_DOWN_BUMP_MS, DEVICE_FLOW_START_TIMEOUT_MS, DEVICE_FLOW_TERMINAL_GRACE_MS, @@ -122,6 +123,13 @@ class FakeProvider implements DeviceFlowProvider { * `DeviceFlowProvider.poll()` `@remarks` sanitization contract by * throwing raw IdP detail. PR #4255 fold-in 8 #1. */ pollThrowsWith: Error | undefined; + /** Test hook: when `true`, `poll()` returns a Promise that NEVER + * resolves and ignores the supplied `signal`. Models a misbehaving + * provider whose underlying I/O isn't abortable — registry's + * authoritative `Promise.race` against `DEVICE_FLOW_POLL_TIMEOUT_MS` + * is the only thing that can rescue the await. PR #4255 follow-up + * review thread (deepseek-v4-pro). */ + pollHangs = false; /** Most recent `opts.signal` observed by `poll`. Test hook for the * abort-mid-poll assertion: after `registry.cancel(...)`, this * signal MUST report `.aborted === true` so the upstream HTTP @@ -168,6 +176,12 @@ class FakeProvider implements DeviceFlowProvider { this.pollThrowsWith = undefined; throw err; } + if (this.pollHangs) { + // Never resolves, ignores `signal`. Registry's Promise.race + // timeout is the only path out. + await new Promise(() => {}); + throw new Error('unreachable'); + } if (opts.signal.aborted) return { kind: 'pending' }; if (this.pollScript.length === 0) { return { kind: 'pending' }; @@ -667,6 +681,59 @@ describe('DeviceFlowRegistry — authoritative timeouts (fold-in 7)', () => { } }); + it('poll() that hangs past POLL_TIMEOUT_MS surfaces as upstream_error and aborts the entry signal (follow-up review)', async () => { + // PR #4255 follow-up review thread (deepseek-v4-pro): runPollTick + // now races provider.poll() against DEVICE_FLOW_POLL_TIMEOUT_MS so + // a non-abortable provider can no longer pin the per-providerId + // singleton waiting for sweeper-level expiry. Aborts the signal + // first so cooperative providers tear down cleanly; reject + // surfaces in the catch as the bounded `upstream_error` hint. + const provider = new FakeProvider(); + provider.pollHangs = true; + const built = buildRegistry(provider); + const { registry, env, events, auditLines } = built; + try { + const { view } = await registry.start({ providerId: 'qwen-oauth' }); + // Trigger the first poll tick. + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + // Let runPollTick reach the await. + await flushAsync(); + expect(provider.pollCount).toBe(1); + // Race timer hasn't fired yet — entry is still pending. + expect(registry.get(view.deviceFlowId)?.status).toBe('pending'); + // Advance clock past POLL_TIMEOUT_MS; race timer fires, aborts + // the entry signal, and rejects the wrapper promise. + env.clock.tick(DEVICE_FLOW_POLL_TIMEOUT_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // Signal must be aborted so cooperative providers can abandon + // their in-flight fetch. + expect(provider.lastPollSignal?.aborted).toBe(true); + // The catch block surfaces a bounded upstream_error to SSE. + const failed = events.find( + (e) => + e.emission.type === 'failed' && + e.emission.data.deviceFlowId === view.deviceFlowId, + ); + expect(failed).toBeDefined(); + if (failed && failed.emission.type === 'failed') { + expect(failed.emission.data.errorKind).toBe('upstream_error'); + expect(failed.emission.data.hint).toContain( + 'see daemon audit log for details', + ); + } + // Audit captures the raw timeout error for the operator. + const auditFailure = auditLines.find( + (line) => + line['status'] === 'failed' && line['errorKind'] === 'upstream_error', + ); + expect(auditFailure).toBeDefined(); + } finally { + registry.dispose(); + } + }); + it('persist() that hangs past PERSIST_TIMEOUT_MS maps to persist_failed (#2)', async () => { const provider = new FakeProvider(); // Single poll tick returns success whose persist() never resolves. @@ -940,6 +1007,63 @@ describe('DeviceFlowRegistry — persist failure paths (fold-in 10 #1)', () => { } }); + it('cancellerClientId is first-writer-wins across concurrent cancel() calls during persist', async () => { + // PR #4255 follow-up review thread (deepseek-v4-pro): two SDK + // clients racing `cancel()` on the same persist-in-flight entry + // must NOT silently overwrite attribution. The first cancel that + // observes `persistInFlight` is the one that drove the transition; + // the persist-resolution event should be attributed to it. The + // second cancel is functionally a no-op on the entry (it's already + // marked `cancelRequestedDuringPersist`); its caller still appears + // in the audit trail through the `audit.record(...)` path but + // does not overwrite the SSE event's `originatorClientId`. + const provider = new FakeProvider(); + let rejectPersist!: (err: Error) => void; + const persistPromise = new Promise<{ expiresAt?: number }>( + (_resolve, reject) => { + rejectPersist = reject; + }, + ); + provider.pollScript = [ + { + kind: 'success', + persist: () => persistPromise, + }, + ]; + const built = buildRegistry(provider); + const { registry, env, events } = built; + try { + const { view } = await registry.start({ providerId: 'qwen-oauth' }); + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // First canceller wins. + const first = registry.cancel(view.deviceFlowId, 'sdk-A'); + expect(first).toEqual({ alreadyTerminal: false }); + // Second canceller observes `persistInFlight` already set; the + // entry is still marked `cancelRequestedDuringPersist`. Its id + // MUST NOT overwrite the first-writer's attribution. + const second = registry.cancel(view.deviceFlowId, 'sdk-B'); + expect(second).toEqual({ alreadyTerminal: false }); + // Persist now fails — the registry emits `cancelled` with + // `originatorClientId = entry.cancellerClientId` (sdk-A). + rejectPersist(new Error('aborted: cancel during persist')); + await flushAsync(); + const snapshot = registry.get(view.deviceFlowId); + expect(snapshot?.status).toBe('cancelled'); + const cancelledEvent = events.find( + (e) => + e.emission.type === 'cancelled' && + e.emission.data.deviceFlowId === view.deviceFlowId, + ); + expect(cancelledEvent).toBeDefined(); + // First-writer-wins: sdk-A drove the transition. + expect(cancelledEvent?.clientId).toBe('sdk-A'); + } finally { + registry.dispose(); + } + }); + it('records lost_success_after_timeout when persist resolves AFTER the registry timeout (round-12 #8)', async () => { // PR #4255 round-12 #8 (Cy_ZH): pins the split-brain detector // for non-conforming providers. fold-in 9 #7 added an diff --git a/packages/cli/src/serve/auth/deviceFlow.ts b/packages/cli/src/serve/auth/deviceFlow.ts index 104d76c7b2a..132c609be75 100644 --- a/packages/cli/src/serve/auth/deviceFlow.ts +++ b/packages/cli/src/serve/auth/deviceFlow.ts @@ -50,6 +50,21 @@ export const DEVICE_FLOW_PERSIST_TIMEOUT_MS = 30_000; * PR #4255 review fold-in 3 (#2). */ export const DEVICE_FLOW_START_TIMEOUT_MS = 30_000; +/** + * Hard ceiling on a single `provider.poll()` tick. Symmetric with + * `DEVICE_FLOW_START_TIMEOUT_MS` and `DEVICE_FLOW_PERSIST_TIMEOUT_MS`, + * which already bound their respective phases. PR #4255 follow-up + * review thread (deepseek-v4-pro): a hung IdP token endpoint (TCP + * established, no response) without this would block the registry's + * poll-tick promise indefinitely. The entry's `cancelController.signal` + * is the cooperative path; this race makes the timeout authoritative + * regardless of provider cooperation. The sweeper would still evict + * the entry once `expiresAt` is past, but until then the per-provider + * singleton stays occupied with no other recovery short of daemon + * restart. 30s is the same generosity the start/persist phases use + * and is well over a healthy IdP's polling round-trip. + */ +export const DEVICE_FLOW_POLL_TIMEOUT_MS = 30_000; /** * Operator-safe upper bound on the IdP-provided `expires_in`. RFC * 8628 §6.1 calls 5–30 minutes "reasonable"; 1 hour is the practical @@ -916,7 +931,15 @@ export class DeviceFlowRegistry { // `originatorClientId` was always `entry.initiatorClientId`, // which broke any SSE consumer that suppresses self-emitted // events to avoid double-handling. - if (cancellerClientId) { + // PR #4255 follow-up review thread (deepseek-v4-pro): first-writer- + // wins. Two SDK clients racing `cancel()` on the same persist-in- + // flight entry must NOT silently overwrite attribution — the second + // caller's `cancel()` is functionally a no-op (the entry is already + // marked `cancelRequestedDuringPersist`), so the persist-resolution + // event should be attributed to whoever actually drove the + // transition first. Subsequent callers stay in the audit trail + // through their own `audit.record(...)` line below. + if (cancellerClientId && entry.cancellerClientId === undefined) { entry.cancellerClientId = cancellerClientId; } try { @@ -1011,14 +1034,36 @@ export class DeviceFlowRegistry { entry.lastPolledAt = now; let result: DeviceFlowPollResult; let rawProviderError: string | undefined; + // PR #4255 follow-up review thread (deepseek-v4-pro): bound + // `provider.poll()` with the same `Promise.race` shape used by + // `doStart` / persist. The cooperative `entry.cancelController.signal` + // path covers well-behaved providers; this race makes the timeout + // authoritative even when a provider ignores `signal`. A hung IdP + // token endpoint without this would otherwise block the poll-tick + // promise indefinitely (occupying the per-provider singleton until + // sweeper / daemon restart). The rejecting timer aborts the signal + // first so cooperative providers can still tear down cleanly. + let pollTimer: ReturnType | undefined; try { - result = await provider.poll( - { - deviceCode: entry.deviceCode, - pkceVerifier: entry.pkceVerifier, - }, - { signal: entry.cancelController.signal }, - ); + result = await new Promise((resolve, reject) => { + pollTimer = this.schedule(DEVICE_FLOW_POLL_TIMEOUT_MS, () => { + try { + entry.cancelController.abort(new Error('device-flow poll timeout')); + } catch { + // best-effort + } + reject(new Error('device-flow poll timeout')); + }); + provider + .poll( + { + deviceCode: entry.deviceCode!, + pkceVerifier: entry.pkceVerifier, + }, + { signal: entry.cancelController.signal }, + ) + .then(resolve, reject); + }); } catch (err: unknown) { // PR #4255 fold-in 9 review thread #1 (refines fold-in 8 #1): // a non-conforming provider that violates the `@remarks` @@ -1037,6 +1082,8 @@ export class DeviceFlowRegistry { errorKind: 'upstream_error', hint: 'provider.poll() failed; see daemon audit log for details', }; + } finally { + if (pollTimer !== undefined) this.clearScheduled(pollTimer); } // PR #4255 round-12 #1 (gpt-5.5 review CzSpN): also re-check // `this.disposed` after the await. `dispose()` clears diff --git a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts index ed86236cbd2..d5fc3b406f4 100644 --- a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts +++ b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts @@ -199,6 +199,19 @@ export class QwenOAuthDeviceFlowProvider implements DeviceFlowProvider { err instanceof QwenOAuthPollError ? mapRfc8628OAuthCode(err.oauthError) : 'upstream_error'; + // PR #4255 follow-up review thread (deepseek-v4-pro): mirror the + // `start()` path's stderr audit — `poll()` failures (non-RFC-8628, + // non-`authorization_pending` / `slow_down` throws like JSON + // parse errors, WAF HTML, proxy 503) previously had no operator + // breadcrumb; SSE/HTTP only carried the static `upstream_error` + // hint. Without raw detail in stderr the on-call has no way to + // distinguish WAF block from network reset from malformed JSON + // at 3 AM. The truncator caps the kept prefix below container + // log-aggregator per-line limits. + const detail = err instanceof Error ? err.message : String(err); + writeStderrLine( + `[serve] qwen device-flow poll failed (raw, errorKind=${errorKind}): ${truncateForStderr(detail)}`, + ); return { kind: 'error', errorKind, diff --git a/packages/cli/src/serve/server.test.ts b/packages/cli/src/serve/server.test.ts index 01b3d9c778b..cfeb7f3ab1f 100644 --- a/packages/cli/src/serve/server.test.ts +++ b/packages/cli/src/serve/server.test.ts @@ -4415,10 +4415,10 @@ describe('auth device-flow routes', () => { it('GET /workspace/auth/device-flow/:id is strict-gated; GET /workspace/auth/status is read-only', async () => { // The two GETs have ASYMMETRIC auth posture by design: // - `GET /workspace/auth/device-flow/:id` returns `userCode` for - // pending entries, which is shoulder-surf-able if a peer process - // on the same host can read it. fold-in (round-4 #1) added - // `mutate({strict:true})` to close the info-disclosure - // asymmetry vs. the strict POST/DELETE. + // pending entries (only when caller's clientId matches the + // initiator — see follow-up review thread test below). fold-in + // (round-4 #1) added `mutate({strict:true})` to close the + // info-disclosure asymmetry vs. the strict POST/DELETE. // - `GET /workspace/auth/status` intentionally redacts userCode // (lists only deviceFlowId/providerId/expiresAt) so it stays // bearer-only (passthrough on loopback no-token default). @@ -4434,4 +4434,57 @@ describe('auth device-flow routes', () => { .set('Host', `127.0.0.1:${baseOpts.port}`); expect(status.status).toBe(200); }); + + it('GET /workspace/auth/device-flow/:id only echoes userCode/verificationUri/initiatorClientId to caller matching the initiator', async () => { + // PR #4255 follow-up review thread (deepseek-v4-pro): the GET + // response shape is symmetrized with the POST take-over response. + // An anonymous caller, or a caller identifying as a different + // client, only sees the public envelope (status/timestamps/error + // fields) — never the verification code or the initiator id. + const { app } = buildApp({ token: 'tkn' }); + const post = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-A') + .send({ providerId: 'qwen-oauth' }); + const id = post.body.deviceFlowId as string; + expect(typeof id).toBe('string'); + + const matchingCaller = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-A'); + expect(matchingCaller.status).toBe(200); + expect(matchingCaller.body.deviceFlowId).toBe(id); + expect(matchingCaller.body.userCode).toBe('USER-1'); + expect(matchingCaller.body.verificationUri).toBe( + 'https://idp.example/verify', + ); + expect(matchingCaller.body.initiatorClientId).toBe('sdk-A'); + + const anonymousCaller = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`); + expect(anonymousCaller.status).toBe(200); + expect(anonymousCaller.body.deviceFlowId).toBe(id); + expect(anonymousCaller.body).not.toHaveProperty('userCode'); + expect(anonymousCaller.body).not.toHaveProperty('verificationUri'); + expect(anonymousCaller.body).not.toHaveProperty('verificationUriComplete'); + expect(anonymousCaller.body).not.toHaveProperty('initiatorClientId'); + + const differentCaller = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-B'); + expect(differentCaller.status).toBe(200); + expect(differentCaller.body.deviceFlowId).toBe(id); + expect(differentCaller.body).not.toHaveProperty('userCode'); + expect(differentCaller.body).not.toHaveProperty('verificationUri'); + expect(differentCaller.body).not.toHaveProperty('verificationUriComplete'); + expect(differentCaller.body).not.toHaveProperty('initiatorClientId'); + }); }); diff --git a/packages/cli/src/serve/server.ts b/packages/cli/src/serve/server.ts index b6f1258ef47..c2932506fbf 100644 --- a/packages/cli/src/serve/server.ts +++ b/packages/cli/src/serve/server.ts @@ -736,7 +736,9 @@ export function createServeApp( }); return; } - res.status(200).json(toDeviceFlowStateBody(view)); + const clientId = parseClientIdHeader(req, res); + if (clientId === null) return; + res.status(200).json(toDeviceFlowStateBody(view, clientId)); }, ); @@ -1763,6 +1765,7 @@ function toDeviceFlowStartResponseBody( function toDeviceFlowStateBody( view: DeviceFlowPublicView, + callerClientId?: string, ): Record { const body: Record = { deviceFlowId: view.deviceFlowId, @@ -1772,15 +1775,29 @@ function toDeviceFlowStateBody( }; if (view.errorKind) body['errorKind'] = view.errorKind; if (view.hint) body['hint'] = view.hint; - if (view.userCode) body['userCode'] = view.userCode; - if (view.verificationUri) body['verificationUri'] = view.verificationUri; - if (view.verificationUriComplete) { - body['verificationUriComplete'] = view.verificationUriComplete; - } if (view.expiresAt !== undefined) body['expiresAt'] = view.expiresAt; if (view.intervalMs !== undefined) body['intervalMs'] = view.intervalMs; if (view.lastPolledAt !== undefined) body['lastPolledAt'] = view.lastPolledAt; - if (view.initiatorClientId) { + // PR #4255 follow-up review thread (deepseek-v4-pro): symmetrize with + // the POST take-over response shape — only echo `userCode` / + // `verificationUri` / `verificationUriComplete` / `initiatorClientId` + // back to the original starter (matched by `X-Qwen-Client-Id`). An + // anonymous GET caller, or a caller identifying as a different client, + // sees only the public envelope (`status` / `errorKind` / `hint` / + // timestamps). Bearer-token gated already (the route uses + // `mutate({ strict: true })`), so the blast radius was small, but + // multi-client setups sharing a single daemon token could otherwise + // enumerate other clients' verification codes. + const callerIsInitiator = + view.initiatorClientId !== undefined && + callerClientId !== undefined && + callerClientId === view.initiatorClientId; + if (callerIsInitiator) { + if (view.userCode) body['userCode'] = view.userCode; + if (view.verificationUri) body['verificationUri'] = view.verificationUri; + if (view.verificationUriComplete) { + body['verificationUriComplete'] = view.verificationUriComplete; + } body['initiatorClientId'] = view.initiatorClientId; } return body; diff --git a/packages/sdk-typescript/src/daemon/events.ts b/packages/sdk-typescript/src/daemon/events.ts index 02548240846..12fc98e8781 100644 --- a/packages/sdk-typescript/src/daemon/events.ts +++ b/packages/sdk-typescript/src/daemon/events.ts @@ -199,6 +199,16 @@ export type DaemonAuthDeviceFlowErrorKind = * exchange succeeded but the daemon couldn't durably store credentials * (EACCES, EROFS, ENOSPC, etc.). Distinct from `upstream_error`. */ | 'persist_failed' + /** SDK-synthesized when the daemon's GET returns 404 inside + * `DaemonAuthFlow.awaitCompletion`. Surfaced from `getDeviceFlowOrSynthetic404` + * rather than the daemon — three reachable causes: (a) the flow expired + * past the 5-min terminal grace window and the sweeper reaped it, (b) the + * daemon was restarted and lost the in-memory registry, (c) the + * `deviceFlowId` was wrong / spoofed. PR #4255 follow-up review thread + * (deepseek-v4-pro): added to the typed union so SDK consumers' exhaustive + * switches narrow it as a known literal instead of falling into the + * `(string & {})` fallback arm. */ + | 'not_found_or_evicted' | (string & {}); export interface DaemonAuthDeviceFlowStartedData { From 0048a357dd0a65ce589b924415dce48cdbdae5cb Mon Sep 17 00:00:00 2001 From: doudouOUC Date: Tue, 19 May 2026 00:04:29 +0800 Subject: [PATCH 2/5] fix(serve): address Copilot review on #4291 follow-up MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three real findings from the Copilot review on the follow-up PR (#4291), plus a documentation-level clarification: C1+C2 (Critical, qwenDeviceFlowProvider.ts) — the new poll() catch stderr line had two issues that the original implementation glossed over: - It treated `AbortError` (the normal cancel/dispose lifecycle event) as a "poll failed" operator audit line, polluting stderr with every user cancellation and shutdown. - It echoed raw `err.message` into stderr. `pollDeviceToken` POSTs `device_code` + PKCE verifier per RFC 8628 §3.4; a WAF / reverse proxy that echoes the request body in its error response would leak bearer-equivalent secret material into daemon logs, violating the BrandedSecret-style "secrets never appear in logs" contract. Restructure: skip on aborted signal / `AbortError`; log STRUCTURED diagnostics only — `QwenOAuthPollError.oauthError` on the OAuth path, `err.name + message length` on non-OAuth. C4 (Bug, deviceFlow.ts) — the first-writer-wins guard from the original follow-up PR used `entry.cancellerClientId === undefined` as the gate, which silently broke when the first canceller was anonymous: their `cancel(id, undefined)` left the field undefined, and a later identified `cancel(id, 'sdk-B')` saw the gate as still open and overwrote attribution. Decouple "have we recorded a canceller" from "do we have a clientId" via a new `cancellerRecorded` boolean flag. Anonymous first cancellers now correctly block any later writer. C3 (Doc, server.ts) — the GET clientId gate from the original follow-up was correctly flagged by Copilot as syntactic-only, NOT a real authentication boundary (anyone holding the bearer token can spoof `X-Qwen-Client-Id`). Behavior unchanged — bearer remains the auth boundary, this gate prevents accidental cross-client reads in well-behaved multi-SDK setups (mirrors POST take-over round-12 #6). Add a "Threat model" paragraph to the JSDoc making this explicit so future readers don't mistake it for a security boundary. Tests: - `cancellerClientId is first-writer-wins even when the first canceller is anonymous` — covers the C4 regression with anonymous-first + identified-second cancel. - `poll() that hangs past POLL_TIMEOUT_MS` — additionally pins `pollCount === 1` to assert the registry doesn't reschedule after a timeout-driven `upstream_error` (Qwen Code review summary, low priority). cli serve 669/669; sdk 389/389; typecheck clean across all 4 workspaces; eslint --max-warnings 0 clean on touched files. Refs: #4175, #4255, #4291 🤖 Generated with [Qwen Code](https://github.com/QwenLM/qwen-code) --- .../cli/src/serve/auth/deviceFlow.test.ts | 66 +++++++++++++++++++ packages/cli/src/serve/auth/deviceFlow.ts | 29 +++++++- .../src/serve/auth/qwenDeviceFlowProvider.ts | 55 ++++++++++++---- packages/cli/src/serve/server.ts | 12 ++++ 4 files changed, 148 insertions(+), 14 deletions(-) diff --git a/packages/cli/src/serve/auth/deviceFlow.test.ts b/packages/cli/src/serve/auth/deviceFlow.test.ts index 9bfafd4ee32..d47e3e881f6 100644 --- a/packages/cli/src/serve/auth/deviceFlow.test.ts +++ b/packages/cli/src/serve/auth/deviceFlow.test.ts @@ -729,6 +729,12 @@ describe('DeviceFlowRegistry — authoritative timeouts (fold-in 7)', () => { line['status'] === 'failed' && line['errorKind'] === 'upstream_error', ); expect(auditFailure).toBeDefined(); + // PR #4291 follow-up review (Qwen Code review summary 🔵 Low): + // poll-tick must NOT reschedule itself after a timeout-driven + // upstream_error (the entry has already transitioned to error + // state; another poll would be a `entry.status !== 'pending'` + // no-op at best, log noise at worst). Pin the invariant. + expect(provider.pollCount).toBe(1); } finally { registry.dispose(); } @@ -1064,6 +1070,66 @@ describe('DeviceFlowRegistry — persist failure paths (fold-in 10 #1)', () => { } }); + it('cancellerClientId is first-writer-wins even when the first canceller is anonymous (no clientId)', async () => { + // PR #4291 follow-up review (Copilot): the first version of the + // first-writer-wins guard used `entry.cancellerClientId === undefined` + // as the gate, which silently broke when the first canceller was + // anonymous: `cancel(id, undefined)` left the field undefined, and + // a later `cancel(id, 'sdk-B')` saw the gate as still open and + // overwrote attribution. The fix decouples the "have we recorded a + // canceller" question (`cancellerRecorded` flag) from the "do we + // have a clientId" question. An anonymous first canceller still + // flips the flag, blocking any later writer. + const provider = new FakeProvider(); + let rejectPersist!: (err: Error) => void; + const persistPromise = new Promise<{ expiresAt?: number }>( + (_resolve, reject) => { + rejectPersist = reject; + }, + ); + provider.pollScript = [ + { + kind: 'success', + persist: () => persistPromise, + }, + ]; + const built = buildRegistry(provider); + const { registry, env, events } = built; + try { + const { view } = await registry.start({ providerId: 'qwen-oauth' }); + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // First (anonymous) canceller wins. cancellerClientId stays + // undefined; cancellerRecorded is now true. + const first = registry.cancel(view.deviceFlowId); + expect(first).toEqual({ alreadyTerminal: false }); + // Second canceller IS identified — but the first-writer-wins + // gate must reject the overwrite. + const second = registry.cancel(view.deviceFlowId, 'sdk-B'); + expect(second).toEqual({ alreadyTerminal: false }); + rejectPersist(new Error('aborted: cancel during persist')); + await flushAsync(); + const snapshot = registry.get(view.deviceFlowId); + expect(snapshot?.status).toBe('cancelled'); + const cancelledEvent = events.find( + (e) => + e.emission.type === 'cancelled' && + e.emission.data.deviceFlowId === view.deviceFlowId, + ); + expect(cancelledEvent).toBeDefined(); + // The deferred SSE event must NOT carry sdk-B as originator — + // the anonymous first writer wins, so `entry.cancellerClientId` + // stays undefined, and the runPollTick deferred-cancel branch + // falls back to `entry.initiatorClientId` (which is also + // undefined here because `start()` itself was anonymous). The + // critical assertion: sdk-B did NOT silently take credit. + expect(cancelledEvent?.clientId).not.toBe('sdk-B'); + } finally { + registry.dispose(); + } + }); + it('records lost_success_after_timeout when persist resolves AFTER the registry timeout (round-12 #8)', async () => { // PR #4255 round-12 #8 (Cy_ZH): pins the split-brain detector // for non-conforming providers. fold-in 9 #7 added an diff --git a/packages/cli/src/serve/auth/deviceFlow.ts b/packages/cli/src/serve/auth/deviceFlow.ts index 132c609be75..aa050060ca0 100644 --- a/packages/cli/src/serve/auth/deviceFlow.ts +++ b/packages/cli/src/serve/auth/deviceFlow.ts @@ -518,6 +518,18 @@ interface DeviceFlowEntry { * 9 review thread #5. */ cancellerClientId?: string; + /** + * First-writer-wins flag. Set the moment ANY `cancel()` call drives + * this entry into `cancelRequestedDuringPersist` — including the + * anonymous case where `cancellerClientId` stays `undefined`. The + * flag is decoupled from `cancellerClientId` because the latter + * being `undefined` is BOTH "no canceller has driven the transition + * yet" AND "an anonymous canceller drove the transition" — using it + * as the gate would let a later identified canceller silently + * overwrite an earlier anonymous one. PR #4255 follow-up review + * (Copilot on #4291): closes the anonymous-first canceller bug. + */ + cancellerRecorded?: boolean; } export interface DeviceFlowRegistryDeps { @@ -939,8 +951,21 @@ export class DeviceFlowRegistry { // event should be attributed to whoever actually drove the // transition first. Subsequent callers stay in the audit trail // through their own `audit.record(...)` line below. - if (cancellerClientId && entry.cancellerClientId === undefined) { - entry.cancellerClientId = cancellerClientId; + // + // PR #4291 follow-up review (Copilot): the gate is `cancellerRecorded` + // (a separate flag), NOT `cancellerClientId === undefined`. The earlier + // shape silently broke when the first canceller was anonymous: their + // `cancel(id, undefined)` left `cancellerClientId` undefined, so the + // next identified `cancel(id, 'sdk-B')` saw the gate as still open + // and overwrote the attribution. Decoupling the "have we recorded a + // canceller" question from the "do we have a clientId" question fixes + // it: an anonymous first canceller still flips the flag, blocking + // any later writer. + if (!entry.cancellerRecorded) { + entry.cancellerRecorded = true; + if (cancellerClientId) { + entry.cancellerClientId = cancellerClientId; + } } try { entry.cancelController.abort(new Error('cancel during persist')); diff --git a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts index d5fc3b406f4..90c4c5fae21 100644 --- a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts +++ b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts @@ -200,18 +200,49 @@ export class QwenOAuthDeviceFlowProvider implements DeviceFlowProvider { ? mapRfc8628OAuthCode(err.oauthError) : 'upstream_error'; // PR #4255 follow-up review thread (deepseek-v4-pro): mirror the - // `start()` path's stderr audit — `poll()` failures (non-RFC-8628, - // non-`authorization_pending` / `slow_down` throws like JSON - // parse errors, WAF HTML, proxy 503) previously had no operator - // breadcrumb; SSE/HTTP only carried the static `upstream_error` - // hint. Without raw detail in stderr the on-call has no way to - // distinguish WAF block from network reset from malformed JSON - // at 3 AM. The truncator caps the kept prefix below container - // log-aggregator per-line limits. - const detail = err instanceof Error ? err.message : String(err); - writeStderrLine( - `[serve] qwen device-flow poll failed (raw, errorKind=${errorKind}): ${truncateForStderr(detail)}`, - ); + // `start()` path's stderr audit so on-call can distinguish WAF + // block from network reset from malformed JSON at 3 AM. + // + // Two follow-up tightenings (Copilot review on #4291): + // + // 1. **Skip abort-driven errors.** When `cancel()` / `dispose()` + // aborts the in-flight `fetch`, the underlying client throws + // a DOMException-like `AbortError` (or fetch wraps it as + // `TypeError: aborted`). That's a normal lifecycle event, + // not a failure — emitting a stderr "poll failed" line for + // every cancel would pollute the operator audit. + // + // 2. **Don't echo raw `err.message`.** `pollDeviceToken` POSTs + // `device_code` + `code_verifier` (PKCE) per RFC 8628 §3.4. + // A WAF / reverse proxy that echoes the request body in its + // error response would put those bearer-equivalent values + // into daemon stderr — violating the BrandedSecret-style + // "secrets never appear in logs" contract the registry + // depends on. Log STRUCTURED diagnostics only: + // `QwenOAuthPollError.oauthError` (RFC 8628 §3.5 enum), or + // for non-OAuth errors, just the constructor name + a + // bounded message length so the on-call still gets a + // breadcrumb without the request-body echo path. + const aborted = + opts.signal.aborted || + (err instanceof Error && err.name === 'AbortError'); + if (!aborted) { + let safeDetail: string; + if (err instanceof QwenOAuthPollError) { + // Structured upstream OAuth error envelope — no raw body. + safeDetail = `oauthError=${err.oauthError ?? '(missing)'}`; + } else if (err instanceof Error) { + // Non-OAuth (network / parse / unexpected upstream shape). + // The constructor name + length is enough for triage; the + // raw message MAY contain WAF-echoed request body fields. + safeDetail = `${err.name} (message ${err.message.length} bytes; raw suppressed to avoid echoing device_code/PKCE)`; + } else { + safeDetail = ``; + } + writeStderrLine( + `[serve] qwen device-flow poll failed (errorKind=${errorKind}): ${truncateForStderr(safeDetail)}`, + ); + } return { kind: 'error', errorKind, diff --git a/packages/cli/src/serve/server.ts b/packages/cli/src/serve/server.ts index c2932506fbf..9d79510e32a 100644 --- a/packages/cli/src/serve/server.ts +++ b/packages/cli/src/serve/server.ts @@ -1788,6 +1788,18 @@ function toDeviceFlowStateBody( // `mutate({ strict: true })`), so the blast radius was small, but // multi-client setups sharing a single daemon token could otherwise // enumerate other clients' verification codes. + // + // **Threat model (PR #4291 follow-up review by Copilot):** this gate + // is BEST-EFFORT ATTRIBUTION, not authentication. `X-Qwen-Client-Id` + // is a syntactic header, not bound to a server-validated identity — + // anyone holding the bearer token can spoof it. The bearer token IS + // the auth boundary; this gate exists to prevent ACCIDENTAL + // cross-client reads in well-behaved multi-SDK setups (and to keep + // GET symmetric with the POST take-over shape closed out in + // round-12 #6 of #4255). A determined attacker who has compromised + // the daemon bearer token already wins; locking down GET further + // would require binding identity into bearer-token issuance, which + // is a separate architectural change. const callerIsInitiator = view.initiatorClientId !== undefined && callerClientId !== undefined && From 1c71a9627f1f9585742a4b96909bc42ffcc97685 Mon Sep 17 00:00:00 2001 From: doudouOUC Date: Tue, 19 May 2026 00:48:51 +0800 Subject: [PATCH 3/5] fix(serve): address qwen-latest review on #4291 (5 threads) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Five new findings from the qwen-latest review on the follow-up PR (#4291), all real: #1 Critical (qwenDeviceFlowProvider.test.ts NEW) — the four poll() catch branches added in the previous round (AbortError skip, QwenOAuthPollError structured detail, generic Error name+length redaction, non-Error throw placeholder) had ZERO unit-test coverage. The security-critical secret-suppression path (preventing device_code + PKCE leakage via WAF-echoed request bodies) was unverified. Added a dedicated test file with 7 tests pinning each branch — including hard negative assertions that the raw `err.message` never appears in stderr when the message contains seeded device-flow secrets. #2 Critical (deviceFlow.ts) — runPollTick's race-timer rejection was routed through the same `provider.poll() threw (raw): ...` audit template as a real provider throw. At 3 AM, on-call grepping the provider source for that throw would waste time on the wrong layer when the actual issue is a hung IdP. Introduced a sentinel `DeviceFlowPollTimeoutError` class; the catch branches on it to use a dedicated hint (`provider.poll() timed out after Nms; check IdP connectivity`) and skip the misleading raw audit template. #3 (server.ts) — the GET clientId gate from the previous round used `initiatorClientId !== undefined && callerClientId !== undefined` as the equality precondition, which silently locked anonymous- started flows out of their own data: a flow started without X-Qwen-Client-Id has `initiatorClientId === undefined`, so even the same anonymous caller could no longer retrieve `userCode` / `verificationUri` via GET (HTTP 200, redacted body, no error). Fix: also accept the both-undefined case so the gate's purpose ("prevent cross-client reads") is preserved without locking anonymous flows out of themselves. #4 (server.ts JSDoc) — the GET handler now calls parseClientIdHeader to drive the gate, which means a malformed X-Qwen-Client-Id (>128 chars or invalid characters) returns 400 instead of the previous 200. Behavior unchanged — strict matches POST/DELETE — but the JSDoc is updated to document the contract change explicitly so future readers / SDK upgrades aren't surprised. Anonymous callers (header absent) are unaffected. #5 (deviceFlow.ts) — when our race-timer fires first, the original `provider.poll()` promise keeps running in the background. If it later resolves (flaky-but-responsive IdP), the second `.then(...)` on the already-settled outer promise was a silent no-op. Added a passive observer on the original promise that records a `lost_late_poll_after_timeout` audit line — symmetric with the `lost_success_after_timeout` pattern on the persist path. Operators can now distinguish "IdP fully unresponsive" from "IdP responsive but slow past the 30s ceiling" — the alerting / triage signal that was missing. Tests: - NEW packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts (7 tests pinning the four stderr branches; uses brandSecret-shaped fixtures so a future regression that re-introduces device_code in stderr fails CI) - deviceFlow.test.ts: poll-timeout test now asserts the timeout hint (timed out after / check IdP connectivity), the absence of the misleading "see daemon audit log for details" line, and that the audit hint never carries the "provider.poll() threw (raw)" template - deviceFlow.test.ts: new test covering the lost_late_poll_after_timeout observer (provider.poll() resolves AFTER the registry race fires) - server.test.ts: new test for the anonymous-started-flow case in #3 cli serve 678/678 (+9 from previous push); sdk 389/389; typecheck clean across all 4 workspaces; eslint --max-warnings 0 clean on touched files. Refs: #4175, #4255, #4291 🤖 Generated with [Qwen Code](https://github.com/QwenLM/qwen-code) --- .../cli/src/serve/auth/deviceFlow.test.ts | 85 +++++- packages/cli/src/serve/auth/deviceFlow.ts | 129 +++++++-- .../serve/auth/qwenDeviceFlowProvider.test.ts | 265 ++++++++++++++++++ packages/cli/src/serve/server.test.ts | 43 +++ packages/cli/src/serve/server.ts | 31 +- 5 files changed, 529 insertions(+), 24 deletions(-) create mode 100644 packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts diff --git a/packages/cli/src/serve/auth/deviceFlow.test.ts b/packages/cli/src/serve/auth/deviceFlow.test.ts index d47e3e881f6..f4223f939aa 100644 --- a/packages/cli/src/serve/auth/deviceFlow.test.ts +++ b/packages/cli/src/serve/auth/deviceFlow.test.ts @@ -719,17 +719,34 @@ describe('DeviceFlowRegistry — authoritative timeouts (fold-in 7)', () => { expect(failed).toBeDefined(); if (failed && failed.emission.type === 'failed') { expect(failed.emission.data.errorKind).toBe('upstream_error'); - expect(failed.emission.data.hint).toContain( + // PR #4291 follow-up review (qwen-latest, #2): the SSE/HTTP + // hint must distinguish a registry-side timeout from a + // provider throw. At 3 AM, on-call reading "provider.poll() + // threw" would grep the provider source for a non-existent + // throw site — when the actual issue is a hung IdP. + expect(failed.emission.data.hint).toContain('timed out after'); + expect(failed.emission.data.hint).toContain('check IdP connectivity'); + // Negative assertion: the misleading provider-throw hint + // MUST NOT appear on the timeout path. + expect(failed.emission.data.hint).not.toContain( 'see daemon audit log for details', ); } - // Audit captures the raw timeout error for the operator. + // Audit captures the timeout for the operator. Critically, the + // audit hint MUST NOT route through the `provider.poll() threw + // (raw)` template — that's reserved for actual provider throws + // and would mis-direct triage. On the timeout path the hint + // field is omitted entirely (rawProviderError stays undefined). const auditFailure = auditLines.find( (line) => line['status'] === 'failed' && line['errorKind'] === 'upstream_error', ); expect(auditFailure).toBeDefined(); - // PR #4291 follow-up review (Qwen Code review summary 🔵 Low): + const auditHint = auditFailure?.['hint'] as string | undefined; + if (auditHint !== undefined) { + expect(auditHint).not.toContain('provider.poll() threw (raw)'); + } + // PR #4291 follow-up review (Qwen Code review summary): // poll-tick must NOT reschedule itself after a timeout-driven // upstream_error (the entry has already transitioned to error // state; another poll would be a `entry.status !== 'pending'` @@ -740,6 +757,68 @@ describe('DeviceFlowRegistry — authoritative timeouts (fold-in 7)', () => { } }); + it('records lost_late_poll_after_timeout when provider.poll() resolves AFTER the registry race timeout (follow-up review #5)', async () => { + // PR #4291 follow-up review (qwen-latest, #5): symmetric with + // `lost_success_after_timeout` on the persist path. A flaky IdP + // that responds 1s past the 30s ceiling should leave an audit + // breadcrumb saying "IdP IS responsive, just slow" — without + // this, the daemon and the operator get the same observability + // as a fully unresponsive IdP. The fix attaches a passive + // observer to the original `provider.poll()` promise. + const provider = new FakeProvider(); + let resolveLate!: (r: DeviceFlowPollResult) => void; + const latePollPromise = new Promise((resolve) => { + resolveLate = resolve; + }); + // Custom hook: poll returns the controllable promise, ignoring signal. + provider.poll = async () => { + provider.pollCount += 1; + return latePollPromise; + }; + const built = buildRegistry(provider); + const { registry, env, auditLines } = built; + try { + const { view } = await registry.start({ providerId: 'qwen-oauth' }); + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + expect(provider.pollCount).toBe(1); + // Fire the registry race timer. + env.clock.tick(DEVICE_FLOW_POLL_TIMEOUT_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // Outer wrapper rejected; entry transitioned to error/upstream_error. + const snapshot = registry.get(view.deviceFlowId); + expect(snapshot?.status).toBe('error'); + // No `lost_late_poll_after_timeout` line YET — the original + // promise hasn't resolved. + expect( + auditLines.some((line) => + (line['hint'] as string | undefined)?.includes( + 'lost_late_poll_after_timeout', + ), + ), + ).toBe(false); + // Now the IdP belatedly responds. + resolveLate({ kind: 'pending' }); + await flushAsync(); + // The passive observer must have recorded an audit line. + const lateAudit = auditLines.find((line) => + (line['hint'] as string | undefined)?.includes( + 'lost_late_poll_after_timeout', + ), + ); + expect(lateAudit).toBeDefined(); + expect(lateAudit?.['errorKind']).toBe('upstream_error'); + expect(lateAudit?.['hint']).toContain('kind=pending'); + expect(lateAudit?.['hint']).toContain( + `${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling`, + ); + } finally { + registry.dispose(); + } + }); + it('persist() that hangs past PERSIST_TIMEOUT_MS maps to persist_failed (#2)', async () => { const provider = new FakeProvider(); // Single poll tick returns success whose persist() never resolves. diff --git a/packages/cli/src/serve/auth/deviceFlow.ts b/packages/cli/src/serve/auth/deviceFlow.ts index aa050060ca0..256a762ec1d 100644 --- a/packages/cli/src/serve/auth/deviceFlow.ts +++ b/packages/cli/src/serve/auth/deviceFlow.ts @@ -610,6 +610,26 @@ export class UpstreamDeviceFlowError extends Error { } } +/** + * Sentinel error raised by `runPollTick`'s own `Promise.race` timer when + * `provider.poll()` exceeds `DEVICE_FLOW_POLL_TIMEOUT_MS`. PR #4291 + * follow-up review (qwen-latest): the catch block previously routed + * this through the same `provider.poll() threw (raw): ...` audit path + * as a real provider throw, mis-leading on-call into investigating + * provider code when the actual issue is a hung IdP / network + * partition. The sentinel lets the catch differentiate the two and + * emit a timeout-specific audit + hint. + */ +export class DeviceFlowPollTimeoutError extends Error { + readonly code = 'poll_timeout'; + readonly timeoutMs: number; + constructor(timeoutMs: number) { + super(`device-flow poll timeout after ${timeoutMs}ms`); + this.name = 'DeviceFlowPollTimeoutError'; + this.timeoutMs = timeoutMs; + } +} + /** * Typed accessors for parking the `DeviceFlowRegistry` on * `express.Application['locals']`. The string key is shared between @@ -1059,6 +1079,7 @@ export class DeviceFlowRegistry { entry.lastPolledAt = now; let result: DeviceFlowPollResult; let rawProviderError: string | undefined; + let pollTimedOut = false; // PR #4255 follow-up review thread (deepseek-v4-pro): bound // `provider.poll()` with the same `Promise.race` shape used by // `doStart` / persist. The cooperative `entry.cancelController.signal` @@ -1068,26 +1089,39 @@ export class DeviceFlowRegistry { // promise indefinitely (occupying the per-provider singleton until // sweeper / daemon restart). The rejecting timer aborts the signal // first so cooperative providers can still tear down cleanly. + // + // PR #4291 follow-up review (qwen-latest, #5): keep a reference to + // the original `provider.poll()` promise so we can detect a LATE + // success/error after our race timer already settled the wrapper. + // Without this, a flaky IdP that responds 1s past the 30s timeout + // would silently no-op (the second `.then(resolve, ...)` lands on + // an already-settled outer promise) — operator has no signal that + // the IdP is in fact responsive (just slow). Symmetric with the + // `lost_success_after_timeout` audit on the persist path (fold-in + // 9 #7 of #4255). let pollTimer: ReturnType | undefined; + let providerPollPromise: Promise | undefined; try { result = await new Promise((resolve, reject) => { pollTimer = this.schedule(DEVICE_FLOW_POLL_TIMEOUT_MS, () => { + pollTimedOut = true; try { - entry.cancelController.abort(new Error('device-flow poll timeout')); + entry.cancelController.abort( + new DeviceFlowPollTimeoutError(DEVICE_FLOW_POLL_TIMEOUT_MS), + ); } catch { // best-effort } - reject(new Error('device-flow poll timeout')); + reject(new DeviceFlowPollTimeoutError(DEVICE_FLOW_POLL_TIMEOUT_MS)); }); - provider - .poll( - { - deviceCode: entry.deviceCode!, - pkceVerifier: entry.pkceVerifier, - }, - { signal: entry.cancelController.signal }, - ) - .then(resolve, reject); + providerPollPromise = provider.poll( + { + deviceCode: entry.deviceCode!, + pkceVerifier: entry.pkceVerifier, + }, + { signal: entry.cancelController.signal }, + ); + providerPollPromise.then(resolve, reject); }); } catch (err: unknown) { // PR #4255 fold-in 9 review thread #1 (refines fold-in 8 #1): @@ -1101,15 +1135,76 @@ export class DeviceFlowRegistry { // outermost defense layer; the full raw `err.message` flows // through the audit channel (whose backing impl writes to // stderr) for operator visibility. - rawProviderError = err instanceof Error ? err.message : String(err); - result = { - kind: 'error', - errorKind: 'upstream_error', - hint: 'provider.poll() failed; see daemon audit log for details', - }; + // + // PR #4291 follow-up review (qwen-latest, #2): the previous + // shape routed our own race-timer rejection through the same + // `provider.poll() threw (raw): ...` audit path as a real + // provider throw — at 3 AM, on-call would mis-triage as + // "provider bug" and waste time investigating provider code. + // Branch on `DeviceFlowPollTimeoutError` to use a dedicated + // hint + suppress the misleading "raw" audit path. + if (err instanceof DeviceFlowPollTimeoutError) { + result = { + kind: 'error', + errorKind: 'upstream_error', + hint: `provider.poll() timed out after ${err.timeoutMs}ms; check IdP connectivity`, + }; + // rawProviderError stays undefined — the audit branch reads + // that to decide whether to emit the misleading "threw (raw)" + // line. Timeout is not a provider throw. + } else { + rawProviderError = err instanceof Error ? err.message : String(err); + result = { + kind: 'error', + errorKind: 'upstream_error', + hint: 'provider.poll() failed; see daemon audit log for details', + }; + } } finally { if (pollTimer !== undefined) this.clearScheduled(pollTimer); } + // PR #4291 follow-up review (qwen-latest, #5): if our race timer + // settled the wrapper as a timeout, attach a passive observer on + // the original `provider.poll()` promise so a late resolution + // (IdP eventually responded after the 30s ceiling) leaves an + // operator audit breadcrumb. Without this, a flaky-but-responsive + // IdP looks identical to a fully unresponsive one. Mirrors the + // `lost_success_after_timeout` pattern on the persist path. + if (pollTimedOut && providerPollPromise !== undefined) { + const tracked = providerPollPromise; + // Detached on purpose; the catch on the ORIGINAL promise has + // already happened (via the wrapper) — the observer below + // sees the eventual settlement of the same promise. Both + // success and error branches go through audit only. + void tracked.then( + (latePollResult) => { + this.deps.audit?.record({ + deviceFlowId: entry.deviceFlowId, + providerId: entry.providerId, + clientId: entry.initiatorClientId, + status: 'failed', + errorKind: 'upstream_error', + hint: `lost_late_poll_after_timeout: provider.poll() resolved kind=${latePollResult.kind} after ${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling — IdP is responsive but slow; consider raising the operator-side IdP latency alert threshold`, + }); + }, + (lateErr: unknown) => { + // Late rejection from the same provider promise. Don't + // double-audit if the wrapper already saw this same error + // (we'd be double-counting the same I/O failure). + if (lateErr instanceof DeviceFlowPollTimeoutError) return; + const detail = + lateErr instanceof Error ? lateErr.message : String(lateErr); + this.deps.audit?.record({ + deviceFlowId: entry.deviceFlowId, + providerId: entry.providerId, + clientId: entry.initiatorClientId, + status: 'failed', + errorKind: 'upstream_error', + hint: `lost_late_poll_after_timeout: provider.poll() rejected after ${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling: ${detail.length > 256 ? `${detail.slice(0, 256)}…[+${detail.length - 256} bytes]` : detail}`, + }); + }, + ); + } // PR #4255 round-12 #1 (gpt-5.5 review CzSpN): also re-check // `this.disposed` after the await. `dispose()` clears // `this.byId` / `this.byProvider` and aborts the entry's diff --git a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts new file mode 100644 index 00000000000..dbd161eb68d --- /dev/null +++ b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts @@ -0,0 +1,265 @@ +/** + * @license + * Copyright 2025 Qwen Team + * SPDX-License-Identifier: Apache-2.0 + */ + +/** + * Unit tests for `QwenOAuthDeviceFlowProvider`'s stderr audit path. + * + * PR #4291 follow-up review (qwen-latest, #1): the catch block in + * `poll()` adds 4 distinct branches (AbortError skip, structured + * `QwenOAuthPollError`, generic `Error` with name+length redaction, + * non-Error throw) that drive what — if anything — lands in the + * operator audit. The security-critical pieces are: + * + * - `device_code` + PKCE verifier are POSTed to the IdP per RFC 8628 + * §3.4. A WAF / reverse proxy that echoes the request body in its + * error response would put both into stderr if we naively logged + * `err.message` — violating the BrandedSecret-style "secrets never + * appear in logs" contract the registry depends on. + * - The cancel/dispose lifecycle MUST stay quiet — emitting a "poll + * failed" line on every normal cancellation pollutes the audit. + * + * These tests pin all four branches against a stub `IQwenOAuth2Client` + * so a future refactor that drops the redaction shows up in CI. + */ + +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; +import { + QwenOAuthPollError, + type IQwenOAuth2Client, +} from '@qwen-code/qwen-code-core'; +import { QwenOAuthDeviceFlowProvider } from './qwenDeviceFlowProvider.js'; +import { brandSecret } from './deviceFlow.js'; + +function fakeClient( + overrides: Partial = {}, +): IQwenOAuth2Client { + return { + setCredentials: () => {}, + getCredentials: () => + ({}) as ReturnType, + getAccessToken: async () => ({}), + requestDeviceAuthorization: async () => + ({}) as Awaited< + ReturnType + >, + pollDeviceToken: async () => + ({}) as Awaited>, + refreshAccessToken: async () => + ({}) as Awaited>, + ...overrides, + }; +} + +describe('QwenOAuthDeviceFlowProvider.poll() — stderr audit branches', () => { + let stderrLines: string[]; + let stderrSpy: ReturnType; + let originalWrite: typeof process.stderr.write; + + beforeEach(() => { + stderrLines = []; + originalWrite = process.stderr.write.bind(process.stderr); + stderrSpy = vi.fn((chunk: string | Uint8Array) => { + stderrLines.push(typeof chunk === 'string' ? chunk : chunk.toString()); + return true; + }); + // process.stderr.write has overloaded signatures; cast to align with + // the chunk-only call shape used by writeStderrLine. + (process.stderr as { write: unknown }).write = stderrSpy; + }); + + afterEach(() => { + (process.stderr as { write: typeof originalWrite }).write = originalWrite; + }); + + function makeState() { + return { + deviceCode: brandSecret('device-code-secret-AAAA1111'), + pkceVerifier: brandSecret('pkce-verifier-secret-BBBB2222'), + }; + } + + it('skips stderr audit when caller aborted before poll started (signal.aborted check)', async () => { + // The early `opts.signal.aborted` short-circuit returns `pending` + // without invoking `pollDeviceToken` at all — no fetch, no catch, + // no audit. Pin the negative case so a future refactor that + // accidentally writes a stderr line on this path fails CI. + const provider = new QwenOAuthDeviceFlowProvider(fakeClient()); + const controller = new AbortController(); + controller.abort(); + const result = await provider.poll(makeState(), { + signal: controller.signal, + }); + expect(result.kind).toBe('pending'); + expect(stderrLines).toHaveLength(0); + }); + + it('skips stderr audit when pollDeviceToken throws AbortError (cancel/dispose lifecycle)', async () => { + // `cancel()` / `dispose()` aborts the AbortController; the + // underlying fetch throws an `AbortError`-like exception. This + // is normal lifecycle, NOT a failure — emitting a stderr line + // would pollute the operator audit with every cancel. + const abortErr = new Error('The operation was aborted.'); + abortErr.name = 'AbortError'; + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + throw abortErr; + }, + }), + ); + const result = await provider.poll(makeState(), { + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + if (result.kind === 'error') { + expect(result.errorKind).toBe('upstream_error'); + } + expect(stderrLines).toHaveLength(0); + }); + + it('skips stderr audit when signal.aborted is set after the throw, even for non-AbortError errors', async () => { + // The other half of the abort guard: a cooperative provider + // notices the signal is aborted post-fetch and throws something + // generic. We still treat the post-await `signal.aborted` as + // proof this was a cancel, not a real failure. + const controller = new AbortController(); + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + controller.abort(); + throw new Error('socket hangup'); + }, + }), + ); + const result = await provider.poll(makeState(), { + signal: controller.signal, + }); + expect(result.kind).toBe('error'); + expect(stderrLines).toHaveLength(0); + }); + + it('logs only the structured oauthError field on QwenOAuthPollError (no raw body, no device_code/PKCE leak)', async () => { + // Critical security path: even when the upstream RESPONSE includes + // the request body verbatim (WAF echo, hostile reverse proxy), the + // QwenOAuthPollError carries only the structured `oauthError` / + // `description` fields. Logging those is safe; logging + // `err.message` would re-introduce the leak vector. + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + throw new QwenOAuthPollError({ + oauthError: 'slow_down', + description: 'Polling too fast', + status: 400, + }); + }, + }), + ); + const result = await provider.poll(makeState(), { + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + expect(stderrLines).toHaveLength(1); + const line = stderrLines[0]; + expect(line).toContain('qwen device-flow poll failed'); + expect(line).toContain('oauthError=slow_down'); + // The raw default message ("Device token poll failed: slow_down - + // Polling too fast") MUST NOT appear — only the structured field. + expect(line).not.toContain('Device token poll failed:'); + expect(line).not.toContain('device-code-secret'); + expect(line).not.toContain('pkce-verifier-secret'); + }); + + it('logs only err.name + message length on generic Error (raw message is suppressed)', async () => { + // The catch block treats any non-OAuth Error as potentially + // tainted (a fetch wrapper that templated the request body into + // its message). Log just the constructor name + length so + // on-call gets a triage-able breadcrumb without the request body. + const longMessage = + 'HTTP 502 from qwen IdP: Forbidden — request body: device_code=device-code-secret-AAAA1111&code_verifier=pkce-verifier-secret-BBBB2222'; + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + throw new Error(longMessage); + }, + }), + ); + const result = await provider.poll(makeState(), { + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + if (result.kind === 'error') { + expect(result.errorKind).toBe('upstream_error'); + } + expect(stderrLines).toHaveLength(1); + const line = stderrLines[0]; + expect(line).toContain('Error'); + expect(line).toContain(`message ${longMessage.length} bytes`); + expect(line).toContain('raw suppressed'); + // Hard assertions: NEITHER the raw message NOR the templated + // device-flow secrets may appear in stderr. + expect(line).not.toContain('HTTP 502 from qwen'); + expect(line).not.toContain('device-code-secret'); + expect(line).not.toContain('pkce-verifier-secret'); + }); + + it('logs placeholder when a non-Error value is thrown', async () => { + // `throw 'string'` is bad practice but fetch wrappers sometimes + // do it (or `throw { code: 'X' }`). The catch block writes a + // typeof-bound placeholder and gives up on extracting more — + // the typed return shape (`upstream_error`) carries enough for + // the SSE consumer. + // The catch in poll() must handle non-Error throws. We wrap the + // raw throw inside a sync function called from the async path so + // the lint rule against literal throws can stay enabled — the + // reject value is what we're testing, not the throw idiom. + const nonErrorThrower = (): never => { + const value: unknown = 'this is not an Error instance'; + throw value as Error; + }; + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => nonErrorThrower(), + }), + ); + const result = await provider.poll(makeState(), { + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + expect(stderrLines).toHaveLength(1); + const line = stderrLines[0]; + expect(line).toContain(''); + // The raw thrown string is NOT echoed. + expect(line).not.toContain('this is not an Error instance'); + }); + + it('reports the resolved errorKind on every emitted stderr line so triage can branch on it', async () => { + // Mapping check: the `errorKind` field in the typed return AND + // the stderr breadcrumb must agree. A mis-mapping here would + // route the SSE consumer one way and the operator another. + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + throw new QwenOAuthPollError({ + oauthError: 'access_denied', + description: 'user declined', + status: 400, + }); + }, + }), + ); + const result = await provider.poll(makeState(), { + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + if (result.kind === 'error') { + expect(result.errorKind).toBe('access_denied'); + } + expect(stderrLines).toHaveLength(1); + expect(stderrLines[0]).toContain('errorKind=access_denied'); + expect(stderrLines[0]).toContain('oauthError=access_denied'); + }); +}); diff --git a/packages/cli/src/serve/server.test.ts b/packages/cli/src/serve/server.test.ts index cfeb7f3ab1f..9d453d65428 100644 --- a/packages/cli/src/serve/server.test.ts +++ b/packages/cli/src/serve/server.test.ts @@ -4487,4 +4487,47 @@ describe('auth device-flow routes', () => { expect(differentCaller.body).not.toHaveProperty('verificationUriComplete'); expect(differentCaller.body).not.toHaveProperty('initiatorClientId'); }); + + it('GET /workspace/auth/device-flow/:id returns userCode for an anonymously-started flow when the GET caller is also anonymous', async () => { + // PR #4291 follow-up review (qwen-latest, #3): the original + // gate required both `initiatorClientId` AND `callerClientId` + // to be defined and equal — which silently locked anonymous- + // started flows out of their own data (the SDK that didn't + // pass `X-Qwen-Client-Id` on POST also doesn't pass it on + // GET, but the response body switched from "useful" to + // "redacted public envelope" with HTTP 200 and no error). Fix: + // also accept `both undefined` as the same caller. The gate's + // purpose is to prevent CROSS-client reads, not to lock + // anonymous flows out of themselves. + const { app } = buildApp({ token: 'tkn' }); + // Start anonymously (no X-Qwen-Client-Id header). + const post = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .send({ providerId: 'qwen-oauth' }); + const id = post.body.deviceFlowId as string; + expect(typeof id).toBe('string'); + // Anonymous GET — must still see the verification fields. + const anonGet = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`); + expect(anonGet.status).toBe(200); + expect(anonGet.body.deviceFlowId).toBe(id); + expect(anonGet.body.userCode).toBe('USER-1'); + expect(anonGet.body.verificationUri).toBe('https://idp.example/verify'); + // No initiatorClientId — there wasn't one (anonymous start). + expect(anonGet.body).not.toHaveProperty('initiatorClientId'); + // An IDENTIFIED caller, however, is NOT the same caller — + // they don't get the verification fields. + const identified = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-X'); + expect(identified.status).toBe(200); + expect(identified.body).not.toHaveProperty('userCode'); + expect(identified.body).not.toHaveProperty('verificationUri'); + }); }); diff --git a/packages/cli/src/serve/server.ts b/packages/cli/src/serve/server.ts index 9d79510e32a..6e4e69c745b 100644 --- a/packages/cli/src/serve/server.ts +++ b/packages/cli/src/serve/server.ts @@ -716,6 +716,16 @@ export function createServeApp( // information-disclosure asymmetry (the sibling // `GET /workspace/auth/status` stays bearer-only because its // pendingDeviceFlows entries intentionally omit `userCode`). + // + // PR #4291 follow-up review (qwen-latest, #4): GET now also runs + // `parseClientIdHeader` to drive the `callerIsInitiator` gate in + // `toDeviceFlowStateBody`. INTENTIONAL contract change: a malformed + // `X-Qwen-Client-Id` (>128 chars or invalid characters) returns + // `400 invalid_client_id` instead of the previous 200, matching the + // POST/DELETE behavior. SDK clients that send the header on POST + // should send a valid value on GET too. Anonymous callers (header + // absent) are unaffected and continue to work as pre-PR-4291 — the + // both-undefined branch in `callerIsInitiator` covers them. app.get( '/workspace/auth/device-flow/:id', mutate({ strict: true }), @@ -1800,17 +1810,30 @@ function toDeviceFlowStateBody( // the daemon bearer token already wins; locking down GET further // would require binding identity into bearer-token issuance, which // is a separate architectural change. + // PR #4291 follow-up review (qwen-latest, #3): the gate must accept + // the both-undefined case too, otherwise an anonymously-started flow + // (POST without `X-Qwen-Client-Id` → `initiatorClientId === undefined`) + // becomes silently unreadable: even the same anonymous caller GETting + // the same id can no longer retrieve `userCode`/`verificationUri` — + // the body switches from "what they got from POST" to a redacted + // public envelope, with HTTP 200, no error. Pre-PR-4291 GET returned + // these fields to anyone with the bearer; this gate's purpose is to + // prevent CROSS-client reads, not to lock anonymous flows out of + // their own data. const callerIsInitiator = - view.initiatorClientId !== undefined && - callerClientId !== undefined && - callerClientId === view.initiatorClientId; + (view.initiatorClientId === undefined && callerClientId === undefined) || + (view.initiatorClientId !== undefined && + callerClientId !== undefined && + callerClientId === view.initiatorClientId); if (callerIsInitiator) { if (view.userCode) body['userCode'] = view.userCode; if (view.verificationUri) body['verificationUri'] = view.verificationUri; if (view.verificationUriComplete) { body['verificationUriComplete'] = view.verificationUriComplete; } - body['initiatorClientId'] = view.initiatorClientId; + if (view.initiatorClientId) { + body['initiatorClientId'] = view.initiatorClientId; + } } return body; } From da7c6e686d196374fe100c412f57611ba0ac19ae Mon Sep 17 00:00:00 2001 From: doudouOUC Date: Tue, 19 May 2026 01:13:00 +0800 Subject: [PATCH 4/5] fix(serve): address gpt-5.5 review on #4291 (3 threads) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three findings from the gpt-5.5 review on the follow-up PR (#4291), all real: #1 (qwenDeviceFlowProvider.ts) — the previous abort-skip gate was `opts.signal.aborted || err.name === 'AbortError'`, which silently dropped stderr breadcrumbs for `AbortError`s coming from sources we did NOT initiate: upstream IdP TCP RST, proxy timeout, undici/ node-fetch wrapping unrelated transport failures as AbortError. Those are real failures the operator needs visibility into. The gate is now `opts.signal.aborted` only — unexpected `AbortError`s fall through to the sanitized non-OAuth path with a `name + length` breadcrumb. New test pins the regression: signal NOT aborted + provider throws AbortError → stderr DOES record a line. #2 (qwenDeviceFlowProvider.ts) — `QwenOAuthPollError.oauthError` comes directly from the upstream JSON `error` field; it's attacker-controlled if the IdP / WAF / proxy is hostile or compromised. A value like `slow_down\n[serve] FORGED LOG ENTRY ...` would otherwise forge additional log lines; a value containing `\x1b[31m` could inject ANSI control sequences into operator terminals. New `sanitizeForStderr(value)` helper replaces C0/C1 controls and DEL with `?` (length-preserving) before interpolation. New test uses a malicious `oauthError` containing both `\n` and `\x1b` and asserts the forged second log line never materializes and the ANSI escapes are gone. #3 (server.ts) — `toDeviceFlowStartResponseBody` previously echoed `userCode` / `verificationUri` / `verificationUriComplete` unconditionally on EVERY POST response, including the take-over case (`attached: true`). That made the carefully-closed GET redaction a paper tiger: any bearer-token holder POSTing the same `providerId` got the verification material another client started. Apply the SAME `callerIsInitiator` gate (with both-undefined branch for anonymous-start → anonymous-reattach) to the take-over response. Fresh starts naturally pass the gate (caller IS the initiator on the same request); take-over callers with a different clientId — or anonymous take-overs against an identified start — see only the public envelope. Tests: - `qwenDeviceFlowProvider.test.ts`: reworked `signal.aborted + AbortError → no stderr` test (the legitimate cancel path); NEW test for `signal NOT aborted + AbortError → stderr DOES record` (the regression #1 closes); NEW test for control-char sanitization (#2). Total 9 tests (was 7). - `server.test.ts`: NEW test for cross-client take-over (sdk-A starts, sdk-B / anonymous take-over → no userCode); NEW test preserving the anonymous-start → anonymous-reattach use case via the both-undefined branch. cli serve 682/682; sdk 389/389; typecheck clean across all 4 workspaces; eslint --max-warnings 0 clean on touched files. Refs: #4175, #4255, #4291 🤖 Generated with [Qwen Code](https://github.com/QwenLM/qwen-code) --- .../serve/auth/qwenDeviceFlowProvider.test.ts | 90 ++++++++++++++++- .../src/serve/auth/qwenDeviceFlowProvider.ts | 87 ++++++++++++----- packages/cli/src/serve/server.test.ts | 96 +++++++++++++++++++ packages/cli/src/serve/server.ts | 28 +++++- 4 files changed, 266 insertions(+), 35 deletions(-) diff --git a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts index dbd161eb68d..499b906ce62 100644 --- a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts +++ b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.test.ts @@ -96,22 +96,25 @@ describe('QwenOAuthDeviceFlowProvider.poll() — stderr audit branches', () => { expect(stderrLines).toHaveLength(0); }); - it('skips stderr audit when pollDeviceToken throws AbortError (cancel/dispose lifecycle)', async () => { - // `cancel()` / `dispose()` aborts the AbortController; the + it('skips stderr audit when AbortError is thrown AND the registry-owned signal is aborted (cancel/dispose lifecycle)', async () => { + // `cancel()` / `dispose()` aborts the AbortController and the // underlying fetch throws an `AbortError`-like exception. This - // is normal lifecycle, NOT a failure — emitting a stderr line - // would pollute the operator audit with every cancel. + // is normal lifecycle. The post-await `opts.signal.aborted` + // check is what proves WE caused the abort — that's the gate, + // not the error name itself. const abortErr = new Error('The operation was aborted.'); abortErr.name = 'AbortError'; + const controller = new AbortController(); const provider = new QwenOAuthDeviceFlowProvider( fakeClient({ pollDeviceToken: async () => { + controller.abort(); throw abortErr; }, }), ); const result = await provider.poll(makeState(), { - signal: new AbortController().signal, + signal: controller.signal, }); expect(result.kind).toBe('error'); if (result.kind === 'error') { @@ -120,6 +123,40 @@ describe('QwenOAuthDeviceFlowProvider.poll() — stderr audit branches', () => { expect(stderrLines).toHaveLength(0); }); + it('LOGS unexpected AbortError when the registry-owned signal is NOT aborted (transport / proxy / undici)', async () => { + // PR #4291 follow-up review (gpt-5.5, #1): an `AbortError` can + // come from sources we did NOT initiate — upstream IdP TCP RST, + // proxy timeout, undici/node-fetch wrapping unrelated transport + // failures as AbortError. Earlier shape silently dropped these + // because of the `err.name === 'AbortError'` skip; now we only + // skip when WE caused the abort. Unexpected AbortError must + // still produce a stderr breadcrumb. + const abortErr = new Error('The operation was aborted.'); + abortErr.name = 'AbortError'; + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + throw abortErr; + }, + }), + ); + const result = await provider.poll(makeState(), { + // Signal NOT aborted — the abort came from an upstream source. + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + if (result.kind === 'error') { + expect(result.errorKind).toBe('upstream_error'); + } + expect(stderrLines).toHaveLength(1); + const line = stderrLines[0]; + // Routes through the non-OAuth Error path (name + length). + expect(line).toContain('AbortError'); + expect(line).toContain('raw suppressed'); + // Negative: the raw message is NOT echoed. + expect(line).not.toContain('The operation was aborted.'); + }); + it('skips stderr audit when signal.aborted is set after the throw, even for non-AbortError errors', async () => { // The other half of the abort guard: a cooperative provider // notices the signal is aborted post-fetch and throws something @@ -262,4 +299,47 @@ describe('QwenOAuthDeviceFlowProvider.poll() — stderr audit branches', () => { expect(stderrLines[0]).toContain('errorKind=access_denied'); expect(stderrLines[0]).toContain('oauthError=access_denied'); }); + + it('sanitizes control characters and ANSI escapes in attacker-controlled oauthError before stderr interpolation', async () => { + // PR #4291 follow-up review (gpt-5.5, #2): the OAuth `error` field + // comes directly from the upstream JSON. A compromised IdP / WAF + // / proxy can return a value containing newlines, terminal control + // characters, or ANSI escape sequences — interpolating that + // verbatim into a stderr line would forge additional log entries + // or inject color/cursor-movement sequences into operator + // terminals. `sanitizeForStderr` strips C0/C1 controls + DEL. + const malicious = + 'slow_down\n[serve] FORGED LOG ENTRY 2026-01-01\x1b[31mRED\x1b[0m'; + const provider = new QwenOAuthDeviceFlowProvider( + fakeClient({ + pollDeviceToken: async () => { + throw new QwenOAuthPollError({ + oauthError: malicious, + description: 'attacker-supplied', + status: 400, + }); + }, + }), + ); + const result = await provider.poll(makeState(), { + signal: new AbortController().signal, + }); + expect(result.kind).toBe('error'); + expect(stderrLines).toHaveLength(1); + const line = stderrLines[0]; + // The forged log line text MUST NOT appear as a real second line. + // Implementation replaces \n with `?`, so the body is on a single + // line and the second `[serve]` no longer leads a line. + expect(line.split('\n').length).toBe(2); // single content line + trailing newline + // ANSI escape \x1b is gone. + expect(line).not.toContain('\x1b[31m'); + expect(line).not.toContain('\x1b[0m'); + // Newline inside the value is gone. + expect(line).not.toMatch(/\n\[serve\] FORGED/); + // The literal text after the controls is preserved (operator can + // still see what the IdP claimed) — only the harmful bytes are + // replaced. + expect(line).toContain('FORGED LOG ENTRY'); + expect(line).toContain('RED'); + }); }); diff --git a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts index 90c4c5fae21..4b35417dd85 100644 --- a/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts +++ b/packages/cli/src/serve/auth/qwenDeviceFlowProvider.ts @@ -52,6 +52,25 @@ function truncateForStderr(detail: string): string { return `${detail.slice(0, STDERR_DETAIL_MAX)}…[+${dropped} bytes truncated]`; } +/** + * Strip / replace bytes that could forge log lines or inject terminal + * control sequences when interpolated into a stderr breadcrumb. PR #4291 + * follow-up review (gpt-5.5, #2): `QwenOAuthPollError.oauthError` comes + * directly from the upstream JSON `error` field — attacker-controlled + * if the IdP, a reverse proxy, or a WAF is hostile / compromised. A + * value like `slow_down\n[serve] FAKE LOG LINE 2026-...` would otherwise + * forge an extra log line; a value containing `\x1b[…m` could inject + * ANSI color or cursor-movement sequences into operator terminals. + * + * Strips C0 controls (0x00–0x1f), DEL (0x7f), and C1 controls (0x80–0x9f). + * Replaces each with `?` so the operator can still see SOMETHING was + * present at that index (length-preserving) instead of silently dropping. + */ +function sanitizeForStderr(value: string): string { + // eslint-disable-next-line no-control-regex + return value.replace(/[\x00-\x1f\x7f-\x9f]/g, '?'); +} + /** * Qwen-OAuth implementation of `DeviceFlowProvider` for `qwen serve`. * @@ -203,38 +222,54 @@ export class QwenOAuthDeviceFlowProvider implements DeviceFlowProvider { // `start()` path's stderr audit so on-call can distinguish WAF // block from network reset from malformed JSON at 3 AM. // - // Two follow-up tightenings (Copilot review on #4291): + // Three follow-up tightenings: + // + // 1. **Skip ONLY when the registry-owned signal aborted (#4291, + // follow-up gpt-5.5 review).** Earlier shape also skipped + // when `err.name === 'AbortError'`, but `AbortError` can + // come from sources WE didn't initiate — upstream IdP TCP + // RST, proxy timeout, undici/node-fetch wrapping unrelated + // transport failures as AbortError. Those are real failures + // that the operator needs visibility into; silently dropping + // them was a signal-loss bug. Now we skip iff `opts.signal` + // was driven aborted by `cancel()` / `dispose()` — anything + // else, including unexpected `AbortError`, falls through to + // the sanitized breadcrumb path with `signalAborted=false`. // - // 1. **Skip abort-driven errors.** When `cancel()` / `dispose()` - // aborts the in-flight `fetch`, the underlying client throws - // a DOMException-like `AbortError` (or fetch wraps it as - // `TypeError: aborted`). That's a normal lifecycle event, - // not a failure — emitting a stderr "poll failed" line for - // every cancel would pollute the operator audit. + // 2. **Don't echo raw `err.message`** (Copilot review on + // #4291). `pollDeviceToken` POSTs `device_code` + + // `code_verifier` (PKCE) per RFC 8628 §3.4. A WAF / reverse + // proxy that echoes the request body in its error response + // would put those bearer-equivalent values into daemon + // stderr — violating the BrandedSecret-style "secrets never + // appear in logs" contract the registry depends on. Log + // STRUCTURED diagnostics only: `QwenOAuthPollError.oauthError` + // (RFC 8628 §3.5 enum), or for non-OAuth errors, just the + // constructor name + a bounded message length so the + // on-call still gets a breadcrumb without the request-body + // echo path. // - // 2. **Don't echo raw `err.message`.** `pollDeviceToken` POSTs - // `device_code` + `code_verifier` (PKCE) per RFC 8628 §3.4. - // A WAF / reverse proxy that echoes the request body in its - // error response would put those bearer-equivalent values - // into daemon stderr — violating the BrandedSecret-style - // "secrets never appear in logs" contract the registry - // depends on. Log STRUCTURED diagnostics only: - // `QwenOAuthPollError.oauthError` (RFC 8628 §3.5 enum), or - // for non-OAuth errors, just the constructor name + a - // bounded message length so the on-call still gets a - // breadcrumb without the request-body echo path. - const aborted = - opts.signal.aborted || - (err instanceof Error && err.name === 'AbortError'); + // 3. **Sanitize `oauthError` before interpolation (#4291, + // follow-up gpt-5.5 review).** The OAuth error code field + // is attacker-controlled JSON from the IdP / proxy / WAF. + // A value like `slow_down\n[serve] FAKE LOG ENTRY ...` would + // forge additional log lines; a value with `\x1b[31m` could + // inject ANSI control sequences into operator terminals. + // Strip C0/C1 controls before interpolation. + const aborted = opts.signal.aborted; if (!aborted) { let safeDetail: string; if (err instanceof QwenOAuthPollError) { - // Structured upstream OAuth error envelope — no raw body. - safeDetail = `oauthError=${err.oauthError ?? '(missing)'}`; + // Structured upstream OAuth error envelope — no raw body, + // but the `oauthError` field IS attacker-controlled, so + // sanitize C0/C1 controls before interpolating. + const rawOauthError = err.oauthError ?? '(missing)'; + safeDetail = `oauthError=${sanitizeForStderr(rawOauthError)}`; } else if (err instanceof Error) { - // Non-OAuth (network / parse / unexpected upstream shape). - // The constructor name + length is enough for triage; the - // raw message MAY contain WAF-echoed request body fields. + // Non-OAuth (network / parse / unexpected upstream shape / + // unexpected AbortError). The constructor name + length is + // enough for triage; the raw message MAY contain WAF-echoed + // request body fields. safeDetail = `${err.name} (message ${err.message.length} bytes; raw suppressed to avoid echoing device_code/PKCE)`; } else { safeDetail = ``; diff --git a/packages/cli/src/serve/server.test.ts b/packages/cli/src/serve/server.test.ts index 9d453d65428..722fb3a18ba 100644 --- a/packages/cli/src/serve/server.test.ts +++ b/packages/cli/src/serve/server.test.ts @@ -4156,6 +4156,102 @@ describe('auth device-flow routes', () => { expect(fakeProvider.startCount()).toBe(1); }); + it('POST take-over only echoes userCode/verificationUri/initiatorClientId to caller matching the initiator (#4291 follow-up review)', async () => { + // PR #4291 follow-up review (gpt-5.5, #3): policy consistency. + // The closed-out GET redaction (don't echo userCode to non- + // initiator callers) was bypassable via POST take-over — + // any bearer-token holder POSTing the same `providerId` got + // `attached: true` AND the original starter's verification + // material. Now the same caller-clientId gate applies. Fresh + // starts naturally pass (caller IS initiator); take-overs by + // a different clientId see only the public envelope. + const { app } = buildApp({ token: 'tkn' }); + // Starter identifies as sdk-A. + const first = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-A') + .send({ providerId: 'qwen-oauth' }); + expect(first.status).toBe(201); + // Fresh starter MUST see the verification material — they ARE + // the initiator. + expect(first.body.userCode).toBe('USER-1'); + expect(first.body.verificationUri).toBe('https://idp.example/verify'); + expect(first.body.initiatorClientId).toBe('sdk-A'); + + // Different SDK take-over — must NOT see verification fields. + const takeoverDifferent = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-B') + .send({ providerId: 'qwen-oauth' }); + expect(takeoverDifferent.status).toBe(200); + expect(takeoverDifferent.body.attached).toBe(true); + expect(takeoverDifferent.body.deviceFlowId).toBe(first.body.deviceFlowId); + expect(takeoverDifferent.body).not.toHaveProperty('userCode'); + expect(takeoverDifferent.body).not.toHaveProperty('verificationUri'); + expect(takeoverDifferent.body).not.toHaveProperty( + 'verificationUriComplete', + ); + expect(takeoverDifferent.body).not.toHaveProperty('initiatorClientId'); + + // Anonymous take-over against an identified-start — must NOT see + // verification fields either (mismatched: identified vs anonymous). + const takeoverAnon = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .send({ providerId: 'qwen-oauth' }); + expect(takeoverAnon.status).toBe(200); + expect(takeoverAnon.body.attached).toBe(true); + expect(takeoverAnon.body).not.toHaveProperty('userCode'); + + // Same-id take-over (sdk-A again) — DOES see the material. + const takeoverSame = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'sdk-A') + .send({ providerId: 'qwen-oauth' }); + expect(takeoverSame.status).toBe(200); + expect(takeoverSame.body.attached).toBe(true); + expect(takeoverSame.body.userCode).toBe('USER-1'); + expect(takeoverSame.body.initiatorClientId).toBe('sdk-A'); + }); + + it('POST take-over preserves the anonymous-start → anonymous-reattach use case', async () => { + // PR #4291 follow-up review (gpt-5.5, #3): the both-undefined + // branch of `callerIsInitiator` keeps the legitimate "anonymous + // start, anonymous re-attach (e.g., process restart, no + // persisted clientId)" use case working. Without this, every + // anonymous re-attach would silently lose the userCode. + const { app } = buildApp({ token: 'tkn' }); + const first = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .send({ providerId: 'qwen-oauth' }); + expect(first.status).toBe(201); + expect(first.body.userCode).toBe('USER-1'); + + const reattach = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .send({ providerId: 'qwen-oauth' }); + expect(reattach.status).toBe(200); + expect(reattach.body.attached).toBe(true); + expect(reattach.body.deviceFlowId).toBe(first.body.deviceFlowId); + // Both-undefined: anonymous initiator, anonymous re-attach → same + // caller. Verification fields ARE returned. + expect(reattach.body.userCode).toBe('USER-1'); + expect(reattach.body.verificationUri).toBe('https://idp.example/verify'); + // No initiatorClientId echoed (none was set originally). + expect(reattach.body).not.toHaveProperty('initiatorClientId'); + }); + it('GET /workspace/auth/device-flow/:id returns 200 for known + 404 for unknown', async () => { const { app } = buildApp({ token: 'tkn' }); const post = await request(app) diff --git a/packages/cli/src/serve/server.ts b/packages/cli/src/serve/server.ts index 6e4e69c745b..f2e14345d99 100644 --- a/packages/cli/src/serve/server.ts +++ b/packages/cli/src/serve/server.ts @@ -1744,14 +1744,34 @@ function toDeviceFlowStartResponseBody( deviceFlowId: view.deviceFlowId, providerId: view.providerId, status: view.status, - userCode: view.userCode ?? '', - verificationUri: view.verificationUri ?? '', expiresAt: view.expiresAt ?? 0, intervalMs: view.intervalMs ?? 0, attached, }; - if (view.verificationUriComplete) { - body['verificationUriComplete'] = view.verificationUriComplete; + // PR #4291 follow-up review (gpt-5.5, #3): policy consistency with + // `toDeviceFlowStateBody` — only the original starter sees the + // verification material. Earlier shape unconditionally returned + // `userCode` / `verificationUri` / `verificationUriComplete` on + // every POST, including the `attached: true` take-over case, so any + // bearer-token holder that POSTed `providerId: ` got the + // verification code another client started. That bypassed the + // closed-out GET redaction completely. Apply the same gate here. + // Fresh starts naturally pass the gate because `view.initiatorClientId` + // was set from the same `callerClientId` on this very request. + // Take-over callers that don't match the initiator now see the + // public envelope only. The both-undefined branch preserves the + // anonymous-start → anonymous-reattach use case. + const callerIsInitiator = + (view.initiatorClientId === undefined && callerClientId === undefined) || + (view.initiatorClientId !== undefined && + callerClientId !== undefined && + callerClientId === view.initiatorClientId); + if (callerIsInitiator) { + body['userCode'] = view.userCode ?? ''; + body['verificationUri'] = view.verificationUri ?? ''; + if (view.verificationUriComplete) { + body['verificationUriComplete'] = view.verificationUriComplete; + } } // PR #4255 round-12 #6 (gpt-5.5 review CzHOK): minor info-leak // close-out — only echo `initiatorClientId` back to a take-over From bcc1a00fade81e87af77dc4521a6b0632b106632 Mon Sep 17 00:00:00 2001 From: doudouOUC Date: Tue, 19 May 2026 01:27:09 +0800 Subject: [PATCH 5/5] fix(serve): address qwen-latest review on #4291 (4 threads) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four findings from the qwen-latest review on the follow-up PR (#4291), all real: N1 (deviceFlow.ts) — `lost_late_poll_after_timeout` success handler unconditionally wrote "IdP is responsive but slow", but for a cooperative provider whose abort path RESOLVES to `{kind: 'error', errorKind: 'upstream_error'}` (the Qwen impl does this in response to AbortError), the late observer's success handler fires with `latePollResult.kind === 'error'`. The "response" is just the abort-cooperation path — IdP could be totally down. At 3 AM, on-call would conclude the IdP is reachable, the exact opposite of correct triage. Branch the hint on `latePollResult.kind === 'error'` to use "abort-driven cooperation; IdP responsiveness unknown" instead. N2 (deviceFlow.test.ts) — the `onRejected` branch of the late-poll observer was zero-tested, leaving three sub-paths uncovered: the `DeviceFlowPollTimeoutError` self-filter guard, the >256-byte truncation tail, and the audit record itself. Added two tests: late-rejection with a connection-reset-shaped error (covers the truncation + audit shape), and a guard test rejecting with the registry's own DeviceFlowPollTimeoutError sentinel that asserts NO late audit line is emitted (no double-counting). N3 (server.test.ts) — the GET strict-clientId behavior change introduced in #4291 (now 400s on malformed `X-Qwen-Client-Id`) was documented in JSDoc but not pinned in CI. A future refactor that removed or reordered `parseClientIdHeader` would silently revert the contract. Added a test pinning both the over-length (>128 chars) and invalid-charset paths. N4 (server.ts) — when the `callerIsInitiator` gate redacts the GET response, operators triaging "SDK got HTTP 200 but no userCode" had zero signal in daemon stderr / audit. Added a `QWEN_SERVE_DEBUG`- gated stderr breadcrumb in the GET handler — cheap, doesn't pollute production logs (multi-SDK setups would otherwise flood the audit with legitimate cross-client traffic), and operators who hit the symptom can flip the env var and get the breadcrumb on the next reproduction. Tests: - N1 paired tests: existing `kind=pending` resolve path now also asserts the "responsive but slow" hint AND negative assertion on "abort-driven"; new test exercises kind=error resolve and asserts the "abort-driven cooperation" hint with negative assertion on "responsive but slow" - N2: late-rejection observer test (with truncation tail assertion) + DeviceFlowPollTimeoutError self-filter guard test - N3: GET 400 invalid_client_id pinned for over-length and invalid-charset paths cli serve 686/686 (was 682, +4); sdk 389/389; typecheck clean; eslint --max-warnings 0 clean on touched files. Refs: #4175, #4255, #4291 🤖 Generated with [Qwen Code](https://github.com/QwenLM/qwen-code) --- .../cli/src/serve/auth/deviceFlow.test.ts | 162 ++++++++++++++++++ packages/cli/src/serve/auth/deviceFlow.ts | 16 +- packages/cli/src/serve/server.test.ts | 37 ++++ packages/cli/src/serve/server.ts | 28 +++ 4 files changed, 242 insertions(+), 1 deletion(-) diff --git a/packages/cli/src/serve/auth/deviceFlow.test.ts b/packages/cli/src/serve/auth/deviceFlow.test.ts index f4223f939aa..6c298170cae 100644 --- a/packages/cli/src/serve/auth/deviceFlow.test.ts +++ b/packages/cli/src/serve/auth/deviceFlow.test.ts @@ -19,6 +19,7 @@ import { DEVICE_FLOW_POLL_TIMEOUT_MS, DEVICE_FLOW_SLOW_DOWN_BUMP_MS, DEVICE_FLOW_START_TIMEOUT_MS, + DeviceFlowPollTimeoutError, DEVICE_FLOW_TERMINAL_GRACE_MS, DeviceFlowRegistry, TooManyActiveDeviceFlowsError, @@ -814,6 +815,167 @@ describe('DeviceFlowRegistry — authoritative timeouts (fold-in 7)', () => { expect(lateAudit?.['hint']).toContain( `${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling`, ); + // PR #4291 follow-up review (qwen-latest, N1): kind=pending is a + // real late response (the IdP eventually responded), so the + // "responsive but slow" hint is appropriate here. The negative + // is the kind === 'error' branch (separately tested below). + expect(lateAudit?.['hint']).toContain('IdP is responsive but slow'); + expect(lateAudit?.['hint']).not.toContain('abort-driven'); + } finally { + registry.dispose(); + } + }); + + it('records lost_late_poll_after_timeout with abort-driven hint when late resolution is kind=error (qwen-latest review N1)', async () => { + // PR #4291 follow-up review (qwen-latest, N1): when the registry + // race timer aborts `entry.cancelController.signal`, a cooperative + // provider's `pollDeviceToken({signal})` typically throws + // AbortError; the provider's catch then resolves to + // `{kind: 'error', errorKind: 'upstream_error'}`. This success + // handler fires with `latePollResult.kind === 'error'`. Earlier + // shape would have audited "IdP is responsive but slow" — but the + // IdP could be totally down; the "response" is just the provider's + // abort cooperation. Pin the corrected attribution. + const provider = new FakeProvider(); + let resolveLate!: (r: DeviceFlowPollResult) => void; + const latePollPromise = new Promise((resolve) => { + resolveLate = resolve; + }); + provider.poll = async () => { + provider.pollCount += 1; + return latePollPromise; + }; + const built = buildRegistry(provider); + const { registry, env, auditLines } = built; + try { + const { view } = await registry.start({ providerId: 'qwen-oauth' }); + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + env.clock.tick(DEVICE_FLOW_POLL_TIMEOUT_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // Cooperative abort path: provider resolves to error AFTER the + // race timer fired. + resolveLate({ + kind: 'error', + errorKind: 'upstream_error', + hint: 'aborted by signal', + }); + await flushAsync(); + const lateAudit = auditLines.find((line) => + (line['hint'] as string | undefined)?.includes( + 'lost_late_poll_after_timeout', + ), + ); + expect(lateAudit).toBeDefined(); + expect(lateAudit?.['hint']).toContain('kind=error'); + // The corrected hint MUST NOT claim the IdP is responsive. + expect(lateAudit?.['hint']).not.toContain('IdP is responsive but slow'); + expect(lateAudit?.['hint']).toContain('abort-driven cooperation'); + expect(lateAudit?.['hint']).toContain('IdP responsiveness unknown'); + // dispose the entry to keep the test isolated. + void view; + } finally { + registry.dispose(); + } + }); + + it('records lost_late_poll_after_timeout when provider.poll() REJECTS after the race timeout (qwen-latest review N2)', async () => { + // PR #4291 follow-up review (qwen-latest, N2): the late observer + // also has an `onRejected` branch covering three sub-paths that + // were previously zero-tested: + // 1. `if (lateErr instanceof DeviceFlowPollTimeoutError) return;` + // (don't double-audit our own race-timer rejection) + // 2. The `detail.length > 256` truncation tail + // 3. The audit record for the rejection itself + // Late rejection is realistic: TCP RST or proxy 502 arriving 1s + // past the 30s ceiling. + const provider = new FakeProvider(); + let rejectLate!: (e: Error) => void; + const latePollPromise = new Promise( + (_resolve, reject) => { + rejectLate = reject; + }, + ); + provider.poll = async () => { + provider.pollCount += 1; + return latePollPromise; + }; + const built = buildRegistry(provider); + const { registry, env, auditLines } = built; + try { + await registry.start({ providerId: 'qwen-oauth' }); + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + env.clock.tick(DEVICE_FLOW_POLL_TIMEOUT_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // Late upstream failure (NOT our own DeviceFlowPollTimeoutError). + // Use a long-enough message to exercise the truncation tail. + const longDetail = `connection reset by peer ${'x'.repeat(400)}`; + rejectLate(new Error(longDetail)); + await flushAsync(); + const lateAudit = auditLines.find((line) => + (line['hint'] as string | undefined)?.includes( + 'lost_late_poll_after_timeout', + ), + ); + expect(lateAudit).toBeDefined(); + expect(lateAudit?.['errorKind']).toBe('upstream_error'); + expect(lateAudit?.['hint']).toContain('rejected after'); + expect(lateAudit?.['hint']).toContain( + `${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling`, + ); + expect(lateAudit?.['hint']).toContain('connection reset by peer'); + // Truncation tail must appear (long detail > 256 bytes). + expect(lateAudit?.['hint']).toContain('bytes]'); + } finally { + registry.dispose(); + } + }); + + it("does NOT double-audit when late rejection is the registry's own DeviceFlowPollTimeoutError (qwen-latest review N2 guard)", async () => { + // PR #4291 follow-up review (qwen-latest, N2): the late-rejection + // observer must filter out our own timer rejection — otherwise a + // single timeout would produce two audit lines (one from the + // wrapper catch, one from the late-rejection observer). The + // guard is `if (lateErr instanceof DeviceFlowPollTimeoutError) + // return;`. Pin it. + const provider = new FakeProvider(); + let rejectLate!: (e: Error) => void; + const latePollPromise = new Promise( + (_resolve, reject) => { + rejectLate = reject; + }, + ); + provider.poll = async () => { + provider.pollCount += 1; + return latePollPromise; + }; + const built = buildRegistry(provider); + const { registry, env, auditLines } = built; + try { + await registry.start({ providerId: 'qwen-oauth' }); + env.clock.tick(DEVICE_FLOW_DEFAULT_INTERVAL_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + env.clock.tick(DEVICE_FLOW_POLL_TIMEOUT_MS + 1); + env.scheduler.flushDue(env.clock.now); + await flushAsync(); + // Reject with the SAME sentinel the registry uses internally. + // The original wrapper catch already recorded a failed audit + // (the "real" failure for this entry). The late observer must + // NOT add a `lost_late_poll_after_timeout` line. + rejectLate(new DeviceFlowPollTimeoutError(DEVICE_FLOW_POLL_TIMEOUT_MS)); + await flushAsync(); + const lateAudits = auditLines.filter((line) => + (line['hint'] as string | undefined)?.includes( + 'lost_late_poll_after_timeout', + ), + ); + expect(lateAudits).toHaveLength(0); } finally { registry.dispose(); } diff --git a/packages/cli/src/serve/auth/deviceFlow.ts b/packages/cli/src/serve/auth/deviceFlow.ts index 256a762ec1d..7e06ecda553 100644 --- a/packages/cli/src/serve/auth/deviceFlow.ts +++ b/packages/cli/src/serve/auth/deviceFlow.ts @@ -1184,7 +1184,21 @@ export class DeviceFlowRegistry { clientId: entry.initiatorClientId, status: 'failed', errorKind: 'upstream_error', - hint: `lost_late_poll_after_timeout: provider.poll() resolved kind=${latePollResult.kind} after ${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling — IdP is responsive but slow; consider raising the operator-side IdP latency alert threshold`, + // PR #4291 follow-up review (qwen-latest, N1): the late- + // poll resolve branch fires when `provider.poll()` returns + // a result AFTER our race timer settled the wrapper. For a + // cooperative provider whose abort path resolves to + // `{kind: 'error', errorKind: 'upstream_error'}` (the Qwen + // implementation does this in response to AbortError), the + // "response" is just the abort-cooperation path — the IdP + // could be completely down. Don't assert "responsive but + // slow" on the error kind: route operators correctly by + // distinguishing "real late response" (pending / slow_down / + // success) from "provider's abort cooperation" (error). + hint: + latePollResult.kind === 'error' + ? `lost_late_poll_after_timeout: provider.poll() resolved kind=error after ${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling — likely abort-driven cooperation; IdP responsiveness unknown` + : `lost_late_poll_after_timeout: provider.poll() resolved kind=${latePollResult.kind} after ${DEVICE_FLOW_POLL_TIMEOUT_MS}ms ceiling — IdP is responsive but slow; consider raising the operator-side IdP latency alert threshold`, }); }, (lateErr: unknown) => { diff --git a/packages/cli/src/serve/server.test.ts b/packages/cli/src/serve/server.test.ts index 722fb3a18ba..79c9dba0a5d 100644 --- a/packages/cli/src/serve/server.test.ts +++ b/packages/cli/src/serve/server.test.ts @@ -4584,6 +4584,43 @@ describe('auth device-flow routes', () => { expect(differentCaller.body).not.toHaveProperty('initiatorClientId'); }); + it('GET /workspace/auth/device-flow/:id returns 400 invalid_client_id when X-Qwen-Client-Id is malformed (qwen-latest review N3)', async () => { + // PR #4291 follow-up review (qwen-latest, N3): the GET handler's + // strict-clientId behavior — added in this PR to drive the + // `callerIsInitiator` gate — was documented in JSDoc but not + // pinned in CI. A future refactor that removes or reorders the + // `parseClientIdHeader` call would silently revert the contract + // change. Pin: a malformed header (>128 chars or invalid chars) + // returns 400 `invalid_client_id` from THIS specific GET route. + const { app } = buildApp({ token: 'tkn' }); + const post = await request(app) + .post('/workspace/auth/device-flow') + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .send({ providerId: 'qwen-oauth' }); + const id = post.body.deviceFlowId as string; + + // Over-length: 129 chars. + const tooLong = 'a'.repeat(129); + const tooLongRes = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', tooLong); + expect(tooLongRes.status).toBe(400); + expect(tooLongRes.body.code).toBe('invalid_client_id'); + + // Invalid characters (spaces / quotes — anything outside the + // allowed token charset). + const badChars = await request(app) + .get(`/workspace/auth/device-flow/${id}`) + .set('Authorization', 'Bearer tkn') + .set('Host', `127.0.0.1:${baseOpts.port}`) + .set('X-Qwen-Client-Id', 'has spaces and "quotes"'); + expect(badChars.status).toBe(400); + expect(badChars.body.code).toBe('invalid_client_id'); + }); + it('GET /workspace/auth/device-flow/:id returns userCode for an anonymously-started flow when the GET caller is also anonymous', async () => { // PR #4291 follow-up review (qwen-latest, #3): the original // gate required both `initiatorClientId` AND `callerClientId` diff --git a/packages/cli/src/serve/server.ts b/packages/cli/src/serve/server.ts index f2e14345d99..8147c629df0 100644 --- a/packages/cli/src/serve/server.ts +++ b/packages/cli/src/serve/server.ts @@ -748,6 +748,34 @@ export function createServeApp( } const clientId = parseClientIdHeader(req, res); if (clientId === null) return; + // PR #4291 follow-up review (qwen-latest, N4): when the + // `callerIsInitiator` gate redacts the verification fields, + // operators triaging "SDK got HTTP 200 but no userCode" have + // zero signal in daemon stderr / audit. The redaction happens + // INSIDE the body shaper which doesn't have an audit sink, so + // the route handler is the right layer to record it. Use + // QWEN_SERVE_DEBUG-gated stderr (rather than unconditional + // audit) — multi-SDK setups sharing a bearer token will cause + // legitimate "different caller GETs same flow" traffic that + // would otherwise flood production logs. Operators who hit + // the symptom can flip QWEN_SERVE_DEBUG=1 and get the + // breadcrumb on the next reproduction. + const callerIsInitiator = + (view.initiatorClientId === undefined && clientId === undefined) || + (view.initiatorClientId !== undefined && + clientId !== undefined && + clientId === view.initiatorClientId); + if ( + !callerIsInitiator && + process.env['QWEN_SERVE_DEBUG'] && + !['0', 'false', 'off', 'no'].includes( + (process.env['QWEN_SERVE_DEBUG'] ?? '').trim().toLowerCase(), + ) + ) { + writeStderrLine( + `qwen serve debug: GET /workspace/auth/device-flow/${id} redacted verification fields — caller-clientId mismatch (initiator=${view.initiatorClientId ?? 'anonymous'}, caller=${clientId ?? 'anonymous'})`, + ); + } res.status(200).json(toDeviceFlowStateBody(view, clientId)); }, );