feat(serve): add daemon file logger (#4548)

docs/users/qwen-serve.md

@@ -480,6 +480,30 @@ const result = await flow.awaitCompletion({ signal: abortCtrl.signal });
 
 **Cross-client take-over.** Two SDK clients on the same daemon that both `POST /workspace/auth/device-flow` for the same provider get the per-provider singleton: the first call starts a fresh IdP request and returns `attached: false`; the second call returns the EXISTING in-flight entry with `attached: true`. The take-over is recorded on the audit trail (under the second client's `X-Qwen-Client-Id`) but does NOT emit a separate event — both clients eventually observe the SAME `auth_device_flow_authorized` once the user finishes the IdP page. If your UI distinguishes "I started this" from "someone else's flow I joined", branch on the `attached` field returned by `start()`.
 
+## Daemon log file
+
+`qwen serve` writes a per-process diagnostic log to:
+
+```
+${QWEN_RUNTIME_DIR or ~/.qwen}/debug/daemon/serve-<pid>-<workspaceHash>.log
+```
+
+A `latest` symlink in the same directory always points at the current process's log, so `tail -f ~/.qwen/debug/daemon/latest` will follow whichever daemon is running.
+
+The log captures lifecycle messages, route errors (with `route=` and `sessionId=` context), ACP child stderr, and — when `QWEN_SERVE_DEBUG=1` is set — extra bridge breadcrumbs. Lines that go to stderr today still go to stderr; the file log is **additive**, not a replacement.
+
+### Disabling
+
+Set `QWEN_DAEMON_LOG_FILE=0` (or `false`/`off`/`no`) to skip file logging entirely. Stderr output is unaffected.
+
+### Relation to session debug logs
+
+Session-scoped debug logs (`~/.qwen/debug/<sessionId>.txt` and the `~/.qwen/debug/latest` symlink) are independent. The daemon log lives in a sibling `daemon/` subdirectory; per-session debug semantics are unchanged by this feature.
+
+### No rotation
+
+The daemon log appends indefinitely. Rotate manually if it grows large. A future enhancement may add automatic rotation; track via [#4548](https://github.com/QwenLM/qwen-code/issues/4548) follow-ups.
+
 ## What's next
 
 - **Setting up a long-running daemon?** [Local launch templates (systemd / launchd / nohup / tmux)](./qwen-serve-deploy-local.md) for v0.16-alpha (local-only).

packages/acp-bridge/src/bridge.test.ts

@@ -7161,3 +7161,162 @@ describe('createHttpAcpBridge — F3 multi-client permission coordination', () =
     ).toThrow(/positive integer/);
   });
 });
+
+// ============================================================
+// BridgeOptions.onDiagnosticLine — verify the tee callback
+// receives writeServeDebugLine output when QWEN_SERVE_DEBUG=1.
+// ============================================================
+describe('onDiagnosticLine', () => {
+  const originalDebug = process.env['QWEN_SERVE_DEBUG'];
+  afterEach(() => {
+    if (originalDebug === undefined) delete process.env['QWEN_SERVE_DEBUG'];
+    else process.env['QWEN_SERVE_DEBUG'] = originalDebug;
+  });
+
+  it('receives writeServeDebugLine output when QWEN_SERVE_DEBUG=1', async () => {
+    process.env['QWEN_SERVE_DEBUG'] = '1';
+    const captured: Array<{ line: string; level?: string }> = [];
+
+    // Thread scope → two distinct sessions sharing one channel.
+    let capturedConn: InstanceType<typeof AgentSideConnection> | undefined;
+    const factory: ChannelFactory = async () => {
+      const { clientStream, agentStream } = createInMemoryChannel();
+      const fakeAgent = new FakeAgent();
+      const conn = new AgentSideConnection(() => fakeAgent, agentStream);
+      capturedConn = conn;
+      return {
+        stream: clientStream,
+        exited: new Promise<
+          | { exitCode: number | null; signalCode: NodeJS.Signals | null }
+          | undefined
+        >(() => {}),
+        kill: async () => {},
+        killSync: () => {},
+      };
+    };
+
+    const bridge = makeBridge({
+      sessionScope: 'thread',
+      channelFactory: factory,
+      onDiagnosticLine: (line, level) => captured.push({ line, level }),
+    });
+
+    const sessionA = await bridge.spawnOrAttach({ workspaceCwd: WS_A });
+    const sessionB = await bridge.spawnOrAttach({ workspaceCwd: WS_A });
+    expect(sessionA.sessionId).not.toBe(sessionB.sessionId);
+
+    // Issue a permission request on session A via the agent side.
+    const subAbort = new AbortController();
+    const iter = bridge.subscribeEvents(sessionA.sessionId, {
+      signal: subAbort.signal,
+    });
+
+    // Fire requestPermission from the agent side (same pattern as
+    // setupForPermission in the permission_request tests above).
+    void (
+      capturedConn as unknown as {
+        requestPermission(p: unknown): Promise<unknown>;
+      }
+    ).requestPermission({
+      sessionId: sessionA.sessionId,
+      toolCall: { toolCallId: 'tc-diag', title: 'test-tool' },
+      options: [
+        { optionId: 'allow', name: 'Allow', kind: 'allow_once' },
+        { optionId: 'deny', name: 'Deny', kind: 'reject_once' },
+      ],
+    });
+
+    // Read the permission_request event to get the requestId.
+    const it2 = iter[Symbol.asyncIterator]();
+    const next = await it2.next();
+    expect(next.done).toBe(false);
+    const payload = next.value!.data as { requestId: string };
+
+    // Vote using session B's sessionId → cross-session rejection path
+    // which triggers teeServeDebugLine (bridge.ts line ~2253).
+    const accepted = bridge.respondToSessionPermission(
+      sessionB.sessionId,
+      payload.requestId,
+      { outcome: { outcome: 'cancelled' } },
+    );
+    expect(accepted).toBe(false);
+
+    // Verify the onDiagnosticLine callback received the debug line.
+    expect(captured.some((e) => e.line.includes('qwen serve debug: '))).toBe(
+      true,
+    );
+    expect(
+      captured.some((e) => e.line.includes('rejected permission vote')),
+    ).toBe(true);
+    expect(
+      captured.every((e) => e.level === undefined || e.level === 'info'),
+    ).toBe(true);
+
+    subAbort.abort();
+    await bridge.shutdown();
+  });
+
+  it('does not invoke callback when QWEN_SERVE_DEBUG is off', async () => {
+    delete process.env['QWEN_SERVE_DEBUG'];
+    const captured: Array<{ line: string; level?: string }> = [];
+
+    let capturedConn: InstanceType<typeof AgentSideConnection> | undefined;
+    const factory: ChannelFactory = async () => {
+      const { clientStream, agentStream } = createInMemoryChannel();
+      const fakeAgent = new FakeAgent();
+      const conn = new AgentSideConnection(() => fakeAgent, agentStream);
+      capturedConn = conn;
+      return {
+        stream: clientStream,
+        exited: new Promise<
+          | { exitCode: number | null; signalCode: NodeJS.Signals | null }
+          | undefined
+        >(() => {}),
+        kill: async () => {},
+        killSync: () => {},
+      };
+    };
+
+    const bridge = makeBridge({
+      sessionScope: 'thread',
+      channelFactory: factory,
+      onDiagnosticLine: (line, level) => captured.push({ line, level }),
+    });
+
+    const sessionA = await bridge.spawnOrAttach({ workspaceCwd: WS_A });
+    const sessionB = await bridge.spawnOrAttach({ workspaceCwd: WS_A });
+
+    const subAbort = new AbortController();
+    const iter = bridge.subscribeEvents(sessionA.sessionId, {
+      signal: subAbort.signal,
+    });
+
+    void (
+      capturedConn as unknown as {
+        requestPermission(p: unknown): Promise<unknown>;
+      }
+    ).requestPermission({
+      sessionId: sessionA.sessionId,
+      toolCall: { toolCallId: 'tc-diag2', title: 'test-tool' },
+      options: [
+        { optionId: 'allow', name: 'Allow', kind: 'allow_once' },
+        { optionId: 'deny', name: 'Deny', kind: 'reject_once' },
+      ],
+    });
+
+    const it2 = iter[Symbol.asyncIterator]();
+    const next = await it2.next();
+    const payload = next.value!.data as { requestId: string };
+
+    // Same cross-session vote — but QWEN_SERVE_DEBUG is off.
+    bridge.respondToSessionPermission(sessionB.sessionId, payload.requestId, {
+      outcome: { outcome: 'cancelled' },
+    });
+
+    // Callback must NOT have been invoked.
+    expect(captured).toHaveLength(0);
+
+    subAbort.abort();
+    await bridge.shutdown();
+  });
+});

packages/acp-bridge/src/bridge.ts

@@ -697,6 +697,17 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
   // (b) `server.close` rejecting new connections, during which a
   // late-arriving `POST /session` slips a fresh child past cleanup.
   let shuttingDown = false;
+
+  // Tee writeServeDebugLine through the optional onDiagnosticLine callback.
+  // The module-level writeServeDebugLine is left intact for other entry points;
+  // inside createHttpAcpBridge we use this wrapper exclusively.
+  const teeServeDebugLine = (message: string): void => {
+    writeServeDebugLine(message);
+    if (opts.onDiagnosticLine && isServeDebugLoggingEnabled()) {
+      opts.onDiagnosticLine(`qwen serve debug: ${message}`, 'info');
+    }
+  };
+
   // Coalesces concurrent `spawnOrAttach` calls under single-scope and
   // tracks in-progress thread-scope spawns for shutdown to await.
   // Single-scope uses the workspaceKey as the dedup key (at most one
@@ -1426,7 +1437,7 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
         const published = entry.events.publish(envelope);
         if (published === undefined) {
           failureCount += 1;
-          writeServeDebugLine(
+          teeServeDebugLine(
             `broadcastWorkspaceEvent: publish on session ${entry.sessionId} no-op (bus closed)`,
           );
         } else {
@@ -1439,7 +1450,7 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
           `${JSON.stringify(entry.sessionId)} (type=${envelope.type}): ` +
           `${err instanceof Error ? err.message : String(err)}`;
         if (shuttingDown) {
-          writeServeDebugLine(detail);
+          teeServeDebugLine(detail);
         } else {
           writeStderrLine(`qwen serve: ${detail}`);
         }
@@ -2263,7 +2274,7 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
       // `context.clientId` against this session's registry.
       const actualSessionId = permissionMediator.peekSessionFor(requestId);
       if (actualSessionId !== undefined && actualSessionId !== sessionId) {
-        writeServeDebugLine(
+        teeServeDebugLine(
           `rejected permission vote ${JSON.stringify(requestId)} ` +
             `for session ${JSON.stringify(sessionId)}; request belongs to ` +
             `session ${JSON.stringify(actualSessionId)}.`,
@@ -2349,7 +2360,7 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
           // Mediator already emitted `permission_already_resolved`.
           return false;
         case 'unknown_request':
-          writeServeDebugLine(
+          teeServeDebugLine(
             `rejected permission vote ${JSON.stringify(requestId)} ` +
               `for session ${JSON.stringify(sessionId)}; mediator has no ` +
               `pending or resolved record.`,
@@ -2645,7 +2656,7 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
           const published = entry.events.publish(event);
           if (published === undefined) {
             failureCount += 1;
-            writeServeDebugLine(
+            teeServeDebugLine(
               `publishWorkspaceEvent: publish on session ${entry.sessionId} no-op (bus closed)`,
             );
           } else {
@@ -2658,7 +2669,7 @@ export function createHttpAcpBridge(opts: BridgeOptions): HttpAcpBridge {
             `${JSON.stringify(entry.sessionId)} (type=${event.type}): ` +
             `${err instanceof Error ? err.message : String(err)}`;
           if (shuttingDown) {
-            writeServeDebugLine(detail);
+            teeServeDebugLine(detail);
           } else {
             writeStderrLine(`qwen serve: ${detail}`);
           }

packages/acp-bridge/src/bridgeOptions.ts

@@ -18,6 +18,18 @@ import type { PermissionAuditPublisher } from './permissionMediator.js';
 import type { ServePreflightCell, ServeWorkspaceEnvStatus } from './status.js';
 import type { BridgeFileSystem } from './bridgeFileSystem.js';
 
+/**
+ * Sink for serve-level diagnostic lines (set by the cli daemon logger).
+ * When provided, the bridge tees `writeServeDebugLine` output through
+ * this callback alongside the existing stderr write — used by
+ * runQwenServe to capture them in the daemon log file. The bridge
+ * does not own a file logger itself; this is a pure pass-through hook.
+ */
+export type DiagnosticLineSink = (
+  line: string,
+  level?: 'info' | 'warn' | 'error',
+) => void;
+
 /**
  * Optional injection seam for daemon-host-specific status cells —
  * `process.env` snapshots and the daemon-side preflight checks
@@ -320,4 +332,9 @@ export interface BridgeOptions {
    * timeouts even when the audit publisher is the no-op fallback.
    */
   permissionAudit?: PermissionAuditPublisher;
+  /**
+   * Optional: tee `writeServeDebugLine` output. See {@link DiagnosticLineSink}.
+   * No-op when omitted. Set by cli `runQwenServe` from the daemon logger.
+   */
+  onDiagnosticLine?: DiagnosticLineSink;
 }

packages/acp-bridge/src/spawnChannel.test.ts

@@ -30,8 +30,97 @@
  * Each branch listed below is now regression-guarded by an assertion.
  */
 
-import { describe, expect, it } from 'vitest';
-import { scrubChildEnv } from './spawnChannel.js';
+import { describe, expect, it, vi } from 'vitest';
+import { createStderrForwarder, scrubChildEnv } from './spawnChannel.js';
+
+describe('createStderrForwarder', () => {
+  it('calls onDiagnosticLine for each complete line', () => {
+    const captured: Array<{ line: string; level?: string }> = [];
+    const stderrSpy = vi.spyOn(process.stderr, 'write').mockReturnValue(true);
+    const forwarder = createStderrForwarder({
+      prefix: '[test] ',
+      onDiagnosticLine: (l, lvl) => captured.push({ line: l, level: lvl }),
+    });
+    forwarder.onData('hello\nworld\n');
+    expect(captured).toEqual([
+      { line: '[test] hello', level: 'warn' },
+      { line: '[test] world', level: 'warn' },
+    ]);
+    // Also writes to process.stderr
+    expect(stderrSpy).toHaveBeenCalledWith('[test] hello\n');
+    expect(stderrSpy).toHaveBeenCalledWith('[test] world\n');
+    stderrSpy.mockRestore();
+  });
+
+  it('buffers partial lines until newline arrives', () => {
+    const captured: Array<{ line: string; level?: string }> = [];
+    const stderrSpy = vi.spyOn(process.stderr, 'write').mockReturnValue(true);
+    const forwarder = createStderrForwarder({
+      prefix: '[p] ',
+      onDiagnosticLine: (l, lvl) => captured.push({ line: l, level: lvl }),
+    });
+    forwarder.onData('partial');
+    expect(captured).toHaveLength(0); // no newline yet
+    forwarder.onData(' more\n');
+    expect(captured).toEqual([{ line: '[p] partial more', level: 'warn' }]);
+    stderrSpy.mockRestore();
+  });
+
+  it('flushes buffered content on end', () => {
+    const captured: Array<{ line: string; level?: string }> = [];
+    const stderrSpy = vi.spyOn(process.stderr, 'write').mockReturnValue(true);
+    const forwarder = createStderrForwarder({
+      prefix: '[p] ',
+      onDiagnosticLine: (l, lvl) => captured.push({ line: l, level: lvl }),
+    });
+    forwarder.onData('partial');
+    expect(captured).toHaveLength(0);
+    forwarder.onEnd();
+    expect(captured).toEqual([{ line: '[p] partial', level: 'warn' }]);
+    stderrSpy.mockRestore();
+  });
+
+  it('does not call onDiagnosticLine for empty lines', () => {
+    const captured: Array<{ line: string; level?: string }> = [];
+    const stderrSpy = vi.spyOn(process.stderr, 'write').mockReturnValue(true);
+    const forwarder = createStderrForwarder({
+      prefix: '[p] ',
+      onDiagnosticLine: (l, lvl) => captured.push({ line: l, level: lvl }),
+    });
+    forwarder.onData('\n\n');
+    expect(captured).toHaveLength(0);
+    stderrSpy.mockRestore();
+  });
+
+  it('force-flushes with [truncated] when buffer exceeds 64 KiB cap', () => {
+    const captured: Array<{ line: string; level?: string }> = [];
+    const stderrSpy = vi.spyOn(process.stderr, 'write').mockReturnValue(true);
+    const forwarder = createStderrForwarder({
+      prefix: '[x] ',
+      onDiagnosticLine: (l, lvl) => captured.push({ line: l, level: lvl }),
+    });
+    // Write 65 KiB without a newline — exceeds the 64 KiB cap
+    const bigChunk = 'A'.repeat(65 * 1024);
+    forwarder.onData(bigChunk);
+    // Should have force-flushed the first 64 KiB with [truncated]
+    expect(captured.length).toBeGreaterThanOrEqual(1);
+    expect(captured[0]!.line).toContain('[truncated]');
+    expect(captured[0]!.level).toBe('warn');
+    // The flushed line should have the prefix
+    expect(captured[0]!.line).toMatch(/^\[x\] /);
+    stderrSpy.mockRestore();
+  });
+
+  it('works without onDiagnosticLine (still writes to stderr)', () => {
+    const stderrSpy = vi.spyOn(process.stderr, 'write').mockReturnValue(true);
+    const forwarder = createStderrForwarder({
+      prefix: '[no-cb] ',
+    });
+    forwarder.onData('line1\n');
+    expect(stderrSpy).toHaveBeenCalledWith('[no-cb] line1\n');
+    stderrSpy.mockRestore();
+  });
+});
 
 // Decoupled canary: we deliberately hand-roll the test set instead of
 // importing `SCRUBBED_CHILD_ENV_KEYS` from `spawnChannel.ts` so the