diff --git a/gitnexus/src/cli/mcp.ts b/gitnexus/src/cli/mcp.ts index 3bc708087..eccbb4318 100644 --- a/gitnexus/src/cli/mcp.ts +++ b/gitnexus/src/cli/mcp.ts @@ -31,12 +31,15 @@ export const mcpCommand = async () => { const repos = await backend.listRepos(); if (repos.length === 0) { - logger.error( + // Operator-actionable but the server still starts and serves; warn-level, + // not error. Tools will discover newly-analyzed repos via lazy refresh. + logger.warn( 'GitNexus: No indexed repos yet. Run `gitnexus analyze` in a git repo — the server will pick it up automatically.', ); } else { - logger.error( - `GitNexus: MCP server starting with ${repos.length} repo(s): ${repos.map((r) => r.name).join(', ')}`, + logger.info( + { repoCount: repos.length, repos: repos.map((r) => r.name) }, + 'GitNexus: MCP server starting', ); } diff --git a/gitnexus/src/core/ingestion/workers/worker-pool.ts b/gitnexus/src/core/ingestion/workers/worker-pool.ts index bcc9aa544..b6f16de66 100644 --- a/gitnexus/src/core/ingestion/workers/worker-pool.ts +++ b/gitnexus/src/core/ingestion/workers/worker-pool.ts @@ -260,10 +260,17 @@ export const createWorkerPool = ( timeoutMs: nextTimeout, }; logger.warn( - `Worker ${workerIndex} parse job idle timeout after ${job.timeoutMs / 1000}s ` + - `(${job.items.length} items, ${job.estimatedBytes} bytes, last progress: ${lastProgress}). ` + - `Splitting into ${first.items.length}/${second.items.length} item jobs with ` + - `${nextTimeout / 1000}s timeout.`, + { + workerIndex, + timeoutSec: job.timeoutMs / 1000, + items: job.items.length, + estimatedBytes: job.estimatedBytes, + lastProgress, + firstSplitItems: first.items.length, + secondSplitItems: second.items.length, + nextTimeoutSec: nextTimeout / 1000, + }, + `Worker ${workerIndex} parse job idle timeout. Splitting into ${first.items.length}/${second.items.length} item jobs.`, ); // Preserve intuitive retry order; final result order is still enforced by startIndex sort. jobs.unshift(first, second); @@ -273,9 +280,14 @@ export const createWorkerPool = ( const nextAttempt = job.attempt + 1; if (nextAttempt <= poolOptions.maxTimeoutRetries) { logger.warn( - `Worker ${workerIndex} parse job idle timeout after ${job.timeoutMs / 1000}s ` + - `(single item, attempt ${nextAttempt}/${poolOptions.maxTimeoutRetries + 1}). ` + - `Retrying with ${nextTimeout / 1000}s timeout.`, + { + workerIndex, + timeoutSec: job.timeoutMs / 1000, + attempt: nextAttempt, + maxAttempts: poolOptions.maxTimeoutRetries + 1, + nextTimeoutSec: nextTimeout / 1000, + }, + `Worker ${workerIndex} parse job idle timeout (single item). Retrying with ${nextTimeout / 1000}s timeout.`, ); jobs.unshift({ ...job, diff --git a/gitnexus/src/core/logger.ts b/gitnexus/src/core/logger.ts index d97146a61..3230b91a5 100644 --- a/gitnexus/src/core/logger.ts +++ b/gitnexus/src/core/logger.ts @@ -69,6 +69,10 @@ function tryBuildPrettyTransport(): LoggerOptions['transport'] | undefined { return { target: 'pino-pretty', options: { + // Route to stderr (fd 2) so pretty output doesn't contaminate + // CLI tool data on stdout (fd 1). pino-pretty's default is fd 1, + // which would interleave with `gitnexus query | jq` output. + destination: 2, colorize: true, translateTime: 'SYS:HH:MM:ss.l', ignore: 'pid,hostname', diff --git a/gitnexus/src/mcp/local/local-backend.ts b/gitnexus/src/mcp/local/local-backend.ts index fade093ea..47dbf31dd 100644 --- a/gitnexus/src/mcp/local/local-backend.ts +++ b/gitnexus/src/mcp/local/local-backend.ts @@ -165,29 +165,27 @@ const confidenceForRelType = (relType: string | undefined): number => /** Structured error logging for query failures — replaces empty catch blocks */ function logQueryError(context: string, err: unknown): void { const msg = err instanceof Error ? err.message : String(err); - logger.error(`GitNexus [${context}]: ${msg}`); + logger.error({ context, err: msg }, 'GitNexus query failed'); } /** - * Structured per-query latency log for production aggregation (#553). + * Per-query latency telemetry for production aggregation (#553). * - * Emitted on stderr — NOT stdout — because the MCP stdio transport uses - * stdout exclusively for JSON-RPC responses (#324), and the CLI e2e test - * `tool output goes to stdout via fd 1` asserts that stdout parses cleanly - * as JSON. Any `console.log` from inside a tool handler would corrupt the - * protocol. Matches the existing `logQueryError` convention above, which - * uses stderr for the same reason. + * Logged at `debug` level — timing is observability/telemetry, not an + * error. Operators wanting per-query timing set `GITNEXUS_LOG_LEVEL=debug` + * (or equivalent). Emitting at `error` level (the original migration + * artifact) caused alerting rules to fire on every successful query and + * inflated stderr noise for every MCP/CLI invocation. * - * The `GitNexus [query:timing] …` prefix keeps lines greppable; the - * `phases` payload is JSON so log-scraping pipelines can parse it - * without custom format knowledge. + * Emitted via the project logger which routes to stderr — never stdout — + * because the MCP stdio transport uses stdout exclusively for JSON-RPC + * responses (#324) and the CLI e2e test `tool output goes to stdout via + * fd 1` asserts stdout parses cleanly as JSON. */ function logQueryTiming(query: string, phases: Record): void { const totalMs = phases.wall ?? Object.values(phases).reduce((a, b) => a + b, 0); const truncated = query.length > 80 ? `${query.slice(0, 80)}…` : query; - logger.error( - `GitNexus [query:timing] query=${JSON.stringify(truncated)} totalMs=${totalMs} phases=${JSON.stringify(phases)}`, - ); + logger.debug({ query: truncated, totalMs, phases }, 'GitNexus query timing'); } export interface CodebaseContext {