feat(sync): write a backend's own log lines to the worker log

README.md

@@ -143,7 +143,9 @@ in the worker, the abstraction has leaked.
   root would mean a tree walk on every commit.) Add a directory to `excludePaths`
   when a new tool appears; no release needed.
 - **The log is the diagnostic.** Append-only, rotated not truncated, and writing
-  to it never throws.
+  to it never throws. It also carries whatever the backend logs during an index
+  run (MCP `notifications/message`), as `[<provider>:<level>]` lines, since a
+  backend's own account of a failure is usually more specific than its reply.
 - **`verify` is the one deliberate exception.** Every other command drives a
   backend through the MCP tools it declares. Integrity has no such tool to call
   — "which files does this index claim, and which have content?" is answerable

docs/extending.md

@@ -183,6 +183,23 @@ advice, built from your `detectFiles`.
 invisible to the indexer. If your backend needs configuration, it goes here or in
 a file the hook path reads directly — never in a shell profile.
 
+**Your backend's log lands in the worker log.** A server that declares the MCP
+`logging` capability sends its log lines as `notifications/message`, and every
+one it sends during an index run is written to the log, and to the output of
+`sync`, `drain` and `once`, as `[<name>:<level>] <message>`. MCP's eight levels
+become four: `debug`; `info` (and `notice`); `warn`; `error` (and `critical`,
+`alert`, `emergency`). A level it does not recognise is logged as `info`. Data
+that is not a string is written as JSON, line breaks become ` | `, and a line is
+capped at 2,000 characters, with a note of how much was cut. The backend's
+`logger` name is added in front of the message when it differs from the
+provider's `name`.
+
+Nothing is filtered here: codeindex-sync has no verbosity setting of its own, so
+the backend's configured log level decides what arrives, and no
+`logging/setLevel` is sent to override it. Lines can arrive at any point in a
+session, including before the backend answers `initialize`. Only index runs are
+logged, so `list`, `doctor` and `cleanup` drop them as before.
+
 ### One thing config cannot describe: integrity
 
 `codeindex-sync verify` is the single command that does not go through the
@@ -233,6 +250,12 @@ Three rules, each learned from a production failure:
   everything else is broken. Return `ok: false` with a `remedy` instead.
 - **Distinguish `busy` from `failed`.** See above.
 
+If your backend keeps a log of its own, pass it on through `req.log`, one line
+at a time: `req.log?.({ level: "warn", message: "…" })`, where `level` is
+`debug`, `info`, `warn` or `error`. The worker writes it as
+`[<name>:<level>] <message>`. Keep each message to one line; the log is read
+line by line.
+
 ---
 
 ## 2. Add a git-hook handler

docs/socraticode.md

@@ -426,6 +426,22 @@ reindex clears it: `codeindex-sync sync --full`.
 or at once for a run whose SocratiCode process had to be killed. `codeindex-sync status` shows them and the last error;
 `codeindex-sync retry` requeues them, a full reindex still full.
 
+**Why did it fail? Read the `[socraticode:…]` lines.** From 1.15.0, SocratiCode
+sends its own log over MCP, and codeindex-sync writes each line to its log and to
+the output of `sync`, `drain` and `once`, labelled with the provider's `name` and
+the level:
+
+```
+2026-09-24T13:59:48Z [socraticode:warn] EXTENSION_LANGUAGE_MAP: ignored invalid entries. … {"ignored":[".foo:nolanguage"]}
+```
+
+The detail behind a one-line `failed —`, such as a storage error's reason or a
+warning about one file, is often only there. What arrives is SocratiCode's
+choice, set by `SOCRATICODE_LOG_LEVEL` in the provider's `env` block (default
+`info`). `warn` keeps only warnings and errors, for when a large reindex's info
+lines crowd a log that rotates at 2 MB (`logMaxBytes`), keeping one previous
+file as `sync.log.1`.
+
 **`sync` pauses for up to a minute after a failure.** Before it retries,
 codeindex-sync waits for the previous SocratiCode process to exit, and SocratiCode
 lets its in-flight batch finish first — for up to 60 seconds. A retry started

src/index.ts

@@ -5,6 +5,8 @@ export { shouldCoalesce } from "./coalesce.js";
 export type { CoalesceDecision } from "./coalesce.js";
 export { ProviderRegistry } from "./provider.js";
 export type {
+  BackendLogLevel,
+  BackendLogLine,
   IndexOutcome,
   IndexProvider,
   IndexReason,

src/mcp.ts

@@ -22,6 +22,7 @@
  */
 import { spawn, type ChildProcessWithoutNullStreams } from "node:child_process";
 
+import type { BackendLogLevel } from "./provider.js";
 import { VERSION } from "./version.js";
 
 export interface McpToolResult {
@@ -154,6 +155,88 @@ export interface McpClientOptions {
   timeoutMs?: number;
   /** See {@link DEFAULT_KILL_AFTER_MS}. */
   killAfterMs?: number;
+  /**
+   * Receives the backend's log lines, which are otherwise dropped.
+   *
+   * A server that declares the `logging` capability sends its log as
+   * `notifications/message` on stdout — the one channel a stdio client reads —
+   * and it may do so at any point: before its `initialize` reply, between
+   * calls, while it shuts down. No `logging/setLevel` is ever sent, so what
+   * arrives is whatever the backend's own configured level lets through.
+   *
+   * Must not throw. If it does, that line is lost and the session carries on.
+   */
+  onLog?: (message: McpLogMessage) => void;
+}
+
+/** A log line a backend sent as an MCP `notifications/message`. */
+export interface McpLogMessage {
+  level: BackendLogLevel;
+  /** The backend's name for the logger that wrote it, when it gave one. */
+  logger?: string;
+  /** The message as one bounded line; see {@link parseLogMessage}. */
+  text: string;
+}
+
+/**
+ * MCP's levels are syslog's eight (RFC 5424), finer than anyone reading a sync
+ * log acts on: `notice` is information, and `critical`, `alert` and
+ * `emergency` are errors.
+ */
+const MCP_LOG_LEVELS: ReadonlyMap<string, BackendLogLevel> = new Map([
+  ["debug", "debug"],
+  ["info", "info"],
+  ["notice", "info"],
+  ["warning", "warn"],
+  ["error", "error"],
+  ["critical", "error"],
+  ["alert", "error"],
+  ["emergency", "error"],
+]);
+
+/**
+ * Longest backend log line kept, in characters. Room for a message followed by
+ * the JSON context of a storage error; not room for a backend that dumps a
+ * whole payload into one line to flood a log that is rotated by size.
+ */
+export const MAX_LOG_LINE = 2_000;
+
+/** Longest logger name kept. A name, not a message. */
+const MAX_LOGGER_NAME = 100;
+
+/**
+ * One line, at most `max` characters. The log is read line by line, and a
+ * continuation line would carry no timestamp and no label. A cut says how much
+ * it cut rather than cutting silently.
+ */
+function oneLine(text: string, max: number): string {
+  const flat = text.trim().replace(/\s*[\r\n]+\s*/g, " | ");
+  if (flat.length <= max) return flat;
+  // Never end on the first half of a surrogate pair.
+  const cut = /[\uD800-\uDBFF]/.test(flat.charAt(max - 1)) ? max - 1 : max;
+  return `${flat.slice(0, cut)}… [${flat.length - cut} more chars]`;
+}
+
+/**
+ * Read a `notifications/message`'s params, or null when there is nothing to log.
+ *
+ * `data` may be any JSON value. A string is kept as written and anything else
+ * is written as JSON. A level outside MCP's eight is logged as info rather than
+ * dropped: the line is still worth seeing, and guessing it more severe would
+ * cry wolf. Never throws, whatever the backend sent.
+ */
+export function parseLogMessage(params: unknown): McpLogMessage | null {
+  if (typeof params !== "object" || params === null || Array.isArray(params)) return null;
+  const { level, logger, data } = params as Record<string, unknown>;
+  if (data === undefined) return null;
+  const text = oneLine(typeof data === "string" ? data : JSON.stringify(data), MAX_LOG_LINE);
+  if (!text) return null;
+  const name = typeof logger === "string" ? oneLine(logger, MAX_LOGGER_NAME) : "";
+  return {
+    level: (typeof level === "string" && MCP_LOG_LEVELS.get(level.toLowerCase())) || "info",
+    ...(name ? { logger: name } : {}),
+    text,
+  };
 }
 
 interface JsonRpcMessage {
@@ -309,13 +392,34 @@ export class McpSession {
       } catch {
         continue; // Servers may log non-JSON to stdout; ignore rather than die.
       }
-      if (typeof msg.id === "number") {
-        const resolve = this.pending.get(msg.id);
-        if (resolve) {
-          this.pending.delete(msg.id);
-          resolve(msg);
+      // `null` or `42` is JSON but no message, and reading a field of null throws.
+      if (typeof msg !== "object" || msg === null) continue;
+      if (msg.method === undefined) {
+        if (typeof msg.id === "number") {
+          const resolve = this.pending.get(msg.id);
+          if (resolve) {
+            this.pending.delete(msg.id);
+            resolve(msg);
+          }
         }
+      } else if (msg.method === "notifications/message") {
+        this.onLogMessage(msg.params);
       }
+      // Anything else with a method — another notification, or a request from
+      // the server — is ignored. It is never a response, whatever id it carries:
+      // taking one for the reply to a pending call would answer that call with
+      // nothing.
+    }
+  }
+
+  private onLogMessage(params: unknown): void {
+    const onLog = this.opts.onLog;
+    if (!onLog) return;
+    try {
+      const message = parseLogMessage(params);
+      if (message) onLog(message);
+    } catch {
+      // A log line is never worth a response: this loop is what delivers them.
     }
   }
 

src/provider.ts

@@ -14,6 +14,20 @@
 /** Why an index ran, which providers may use to pick a cheaper path. */
 export type IndexReason = "hook" | "manual" | "retry";
 
+/**
+ * How much one of a backend's own log lines matters. Backends grade more
+ * finely — MCP has eight levels — and a provider coarsens to these four, the
+ * distinctions a reader of the log actually acts on.
+ */
+export type BackendLogLevel = "debug" | "info" | "warn" | "error";
+
+/** One line from a backend's own log. */
+export interface BackendLogLine {
+  level: BackendLogLevel;
+  /** A single line, already bounded in length: the log is read line by line. */
+  message: string;
+}
+
 export interface IndexRequest {
   repoPath: string;
   /** Force complete re-discovery rather than an incremental update. */
@@ -24,6 +38,14 @@ export interface IndexRequest {
    * the provider's own session timeout to stop a hung backend.
    */
   signal?: AbortSignal;
+  /**
+   * Takes whatever the backend logs while this index runs. The worker writes
+   * each line to its own log, labelled with the provider's name and the level,
+   * because a backend's account of a failure — a storage error's reason, a
+   * warning about one file — is usually more specific than its tool's reply.
+   * A provider whose backend reports nothing ignores it.
+   */
+  log?: (line: BackendLogLine) => void;
 }
 
 export interface IndexOutcome {

src/providers/mcp-provider.ts

@@ -39,10 +39,12 @@ import {
   DEFAULT_TIMEOUT_MS,
   withMcp,
   type McpClientOptions,
+  type McpLogMessage,
   type McpSession,
   type McpToolResult,
 } from "../mcp.js";
 import type {
+  BackendLogLine,
   IndexOutcome,
   IndexProvider,
   IndexRequest,
@@ -390,18 +392,35 @@ export class McpIndexProvider implements IndexProvider {
    *
    * Set after process.env so an ambient value cannot re-enable it, and before
    * cfg.env so an operator still can.
+   *
+   * `log`, when given, takes the backend's own log lines for the session.
    */
-  private sessionOpts(repoPath: string | undefined, timeoutMs: number | undefined): McpClientOptions {
+  private sessionOpts(
+    repoPath: string | undefined,
+    timeoutMs: number | undefined,
+    log?: IndexRequest["log"],
+  ): McpClientOptions {
     return {
       command: this.cfg.command,
       args: this.cfg.args,
       cwd: safeCwd(repoPath),
       env: { ...process.env, SOCRATICODE_AUTO_RESUME: "off", ...this.cfg.env },
       ...(timeoutMs === undefined ? {} : { timeoutMs }),
       ...(this.cfg.killAfterMs === undefined ? {} : { killAfterMs: this.cfg.killAfterMs }),
+      ...(log ? { onLog: (m: McpLogMessage) => log(this.logLine(m)) } : {}),
     };
   }
 
+  /**
+   * A backend log message as a line for the worker log, which labels it with
+   * this provider's name. The backend's own logger name is kept only when it
+   * says something that label does not.
+   */
+  private logLine(m: McpLogMessage): BackendLogLine {
+    const from = m.logger && m.logger.toLowerCase() !== this.name.toLowerCase() ? `${m.logger}: ` : "";
+    return { level: m.level, message: `${from}${m.text}` };
+  }
+
   private async call(
     repoPath: string,
     tool: string,
@@ -420,7 +439,7 @@ export class McpIndexProvider implements IndexProvider {
       // finished. Not two: a backend's progress state is per-process, so a
       // second child sees a backend that has never indexed anything.
       res = await withMcp(
-        this.sessionOpts(req.repoPath, this.cfg.timeoutMs),
+        this.sessionOpts(req.repoPath, this.cfg.timeoutMs, req.log),
         async (session) => {
           used = session;
           const started = await session.callTool(tool, this.repoArgs(req.repoPath));

src/worker.ts

@@ -277,6 +277,7 @@ export class Worker {
     );
 
     const marker = markerFile(this.opts.paths.processing, job.repoPath);
+    const backend = provider.name;
     let result: IndexOutcome;
     try {
       try {
@@ -288,6 +289,10 @@ export class Worker {
         repoPath: job.repoPath,
         full: job.full,
         reason: job.attempts > 0 ? "retry" : job.hook === "manual" ? "manual" : "hook",
+        // Everything the backend logs, as it sent it: the backend filters by its
+        // own configured level, and this log has no level of its own to add a
+        // second, disagreeing filter. `[name:level]` keeps it greppable both ways.
+        log: (line) => logger.tag(`${backend}:${line.level}`, line.message),
       });
     } finally {
       rmSync(marker, { force: true });

test/cli.test.ts

@@ -590,6 +590,46 @@ describe("sync", () => {
     expect(second.code).toBe(0);
   });
 
+  it("prints what the backend logs and keeps it in the log", () => {
+    // A backend declaring MCP logging sends its log lines as notifications,
+    // some before it has answered initialize. `sync` is run by hand and from
+    // scripts whose output is captured, and `drain` from a scheduler, so the
+    // lines belong on stdout and in the log alike.
+    const file = path.join(home, "logging-server.mjs");
+    writeFileSync(
+      file,
+      `const send=(o)=>process.stdout.write(JSON.stringify(o)+"\\n");
+       const log=(level,data)=>send({jsonrpc:"2.0",method:"notifications/message",params:{level,logger:"stub",data}});
+       log("warning","EXTRA_MAP: ignored invalid entries");
+       let buf="";process.stdin.on("data",c=>{buf+=c;let n;while((n=buf.indexOf("\\n"))!==-1){const l=buf.slice(0,n).trim();buf=buf.slice(n+1);if(!l)continue;const m=JSON.parse(l);
+       if(m.method==="initialize")send({jsonrpc:"2.0",id:m.id,result:{}});
+       if(m.method==="tools/call"){log("info",{indexed:1});send({jsonrpc:"2.0",id:m.id,result:{content:[{type:"text",text:"Updated project index"}]}});}}});`,
+      "utf8",
+    );
+    writeConfig({
+      root: home,
+      providers: [
+        { name: "stub", command: process.execPath, args: [file], tools: { update: "u" }, detectFiles: [".stub.json"] },
+      ],
+    });
+    const dir = path.join(home, "chatty");
+    mkdirSync(dir, { recursive: true });
+    git(dir, "init", "-q", "-b", "main");
+    git(dir, "config", "user.email", "t@example.com");
+    git(dir, "config", "user.name", "Test");
+    writeFileSync(path.join(dir, ".stub.json"), '{"projectId":"chatty"}\n', "utf8");
+    git(dir, "add", "-A");
+    git(dir, "commit", "-q", "-m", "init");
+
+    const r = cli(["sync", dir]);
+    expect(r.code).toBe(0);
+    const log = readFileSync(path.join(state, "sync.log"), "utf8");
+    for (const text of [r.out, log]) {
+      expect(text).toMatch(/ \[stub:warn\] EXTRA_MAP: ignored invalid entries\n/);
+      expect(text).toMatch(/ \[stub:info\] \{"indexed":1\}\n/);
+    }
+  });
+
   /**
    * A backend whose first `failures` tool calls report an error, recording each
    * call and each exit with its pid and time. State lives in a file because every