feat(mcp): add request log writer (PoC for #1351)

gitnexus/src/mcp/request-log.ts

@@ -0,0 +1,136 @@
+/**
+ * MCP request log (PoC for issue #1351).
+ *
+ * Writes one JSONL line per MCP `tools/call` to a configurable path so
+ * downstream utilization analysers (e.g. mcp-value-tracker) have a
+ * server-side ground truth for "is this MCP server being used and how
+ * long do calls take." A simpler counterpart to the full OpenTelemetry
+ * proposal in #1351 — see the issue for the design discussion.
+ *
+ * Configuration via env (opt-in default — no log written unless the
+ * user asks for one, so this PoC is safe to merge without privacy
+ * concerns about incidental capture in shared environments):
+ *
+ *   unset / empty                       — disabled (default)
+ *   GITNEXUS_MCP_REQUEST_LOG=on         — enable; write to ~/.gitnexus/mcp-requests.log
+ *   GITNEXUS_MCP_REQUEST_LOG=/path/log  — enable; write to this absolute path
+ *   GITNEXUS_MCP_REQUEST_LOG=off        — explicitly disabled (same as unset)
+ *
+ * Whether the default should flip to opt-out (so server-side ground
+ * truth exists without setup) is part of the design discussion on
+ * #1351 — the OpenTelemetry / Prometheus direction proposed there
+ * may make the JSONL path moot.
+ *
+ * Privacy note: tool *inputs* (`params`/`rawArgs`) are never logged.
+ * The `error` field, however, captures error messages verbatim. Tool
+ * error messages can echo user input — e.g. cypher parse errors
+ * routinely include the offending clause. Treat the log as
+ * input-adjacent for retention and access purposes.
+ *
+ * Failures to write are swallowed — the MCP server's availability
+ * matters more than logging fidelity.
+ */
+
+import { appendFile, mkdir } from 'node:fs/promises';
+import { homedir } from 'node:os';
+import { dirname, join } from 'node:path';
+
+export interface RequestLogEntry {
+  /** ISO 8601 timestamp at request start. */
+  ts: string;
+  /** MCP tool name (e.g. "impact", "context"). */
+  tool: string;
+  /** Total duration in milliseconds from invocation to result. */
+  durationMs: number;
+  /** Size of the result payload in bytes (0 on error). */
+  resultBytes: number;
+  /** Error message if the call threw, else null. */
+  error: string | null;
+}
+
+/**
+ * Resolve the configured log path. Returns `null` if logging is disabled
+ * (env var explicitly set to "off") so callers can short-circuit.
+ */
+export function resolveLogPath(env: NodeJS.ProcessEnv = process.env): string | null {
+  const raw = env['GITNEXUS_MCP_REQUEST_LOG'];
+  if (typeof raw !== 'string') return null;
+  const trimmed = raw.trim();
+  if (trimmed.length === 0) return null;
+  const lower = trimmed.toLowerCase();
+  if (lower === 'off' || lower === 'false' || lower === '0') return null;
+  if (lower === 'on' || lower === 'true' || lower === '1') {
+    return join(homedir(), '.gitnexus', 'mcp-requests.log');
+  }
+  return trimmed;
+}
+
+/**
+ * Append one JSONL entry to the configured log file. Creates the parent
+ * directory if needed. Swallows all errors — availability over fidelity.
+ */
+export async function appendRequestLog(
+  entry: RequestLogEntry,
+  path: string | null = resolveLogPath(),
+): Promise<void> {
+  if (path === null) return;
+  try {
+    await mkdir(dirname(path), { recursive: true });
+    await appendFile(path, JSON.stringify(entry) + '\n');
+  } catch {
+    // Intentionally silent — see module docstring.
+  }
+}
+
+/**
+ * Wrap an async tool-call handler so each invocation produces a log
+ * entry. Returns the original result unchanged.
+ *
+ * MCP tool errors arrive two ways:
+ * 1. Thrown — caught here; `error` is the thrown message.
+ * 2. Returned as `{ isError: true, content: [...] }` envelopes — the
+ *    handler converts thrown errors into this shape before returning.
+ *    We inspect the envelope so the log doesn't undercount failures.
+ *    The `errorOf` hook lets the wrap site teach us how to read the
+ *    envelope (returns the error message string, or null on success).
+ *
+ * NOTE on error content: MCP tool error messages can echo user input
+ * (e.g. cypher parse errors include the offending clause verbatim). The
+ * log is therefore NOT free of input data; see request-log.ts module
+ * header.
+ */
+export async function instrumented<T>(
+  toolName: string,
+  fn: () => Promise<T>,
+  resultBytesOf: (result: T) => number = (r) => {
+    if (typeof r === 'string') return Buffer.byteLength(r, 'utf8');
+    if (r === null || r === undefined) return 0;
+    try { return Buffer.byteLength(JSON.stringify(r), 'utf8'); } catch { return 0; }
+  },
+  errorOf: (result: T) => string | null = () => null,
+): Promise<T> {
+  const ts = new Date().toISOString();
+  const startedAt = Date.now();
+  try {
+    const result = await fn();
+    let errorMsg: string | null = null;
+    try { errorMsg = errorOf(result); } catch { errorMsg = null; }
+    void appendRequestLog({
+      ts,
+      tool: toolName,
+      durationMs: Date.now() - startedAt,
+      resultBytes: resultBytesOf(result),
+      error: errorMsg,
+    });
+    return result;
+  } catch (err) {
+    void appendRequestLog({
+      ts,
+      tool: toolName,
+      durationMs: Date.now() - startedAt,
+      resultBytes: 0,
+      error: err instanceof Error ? err.message : String(err),
+    });
+    throw err;
+  }
+}

gitnexus/src/mcp/server.ts

@@ -27,6 +27,7 @@ import { GITNEXUS_TOOLS } from './tools.js';
 import { installGlobalStdoutSentinel } from './stdio-context.js';
 import type { LocalBackend } from './local/local-backend.js';
 import { getResourceDefinitions, getResourceTemplates, readResource } from './resources.js';
+import { instrumented } from './request-log.js';
 
 /**
  * Next-step hints appended to tool responses.
@@ -162,35 +163,66 @@ export function createMCPServer(backend: LocalBackend): Server {
     })),
   }));
 
-  // Handle tool calls — append next-step hints to guide agent workflow
+  // Handle tool calls — append next-step hints to guide agent workflow.
+  // Wrapped in `instrumented(...)` so every call writes one JSONL line to
+  // the MCP request log (see ./request-log.ts) for utilization analysis.
+  // The wrap is no-op if GITNEXUS_MCP_REQUEST_LOG=off.
   server.setRequestHandler(CallToolRequestSchema, async (request) => {
     const { name, arguments: args } = request.params;
 
-    try {
-      const result = await backend.callTool(name, args);
-      const resultText = typeof result === 'string' ? result : JSON.stringify(result, null, 2);
-      const hint = getNextStepHint(name, args as Record<string, any> | undefined);
-
-      return {
-        content: [
-          {
-            type: 'text',
-            text: resultText + hint,
-          },
-        ],
-      };
-    } catch (error) {
-      const message = error instanceof Error ? error.message : 'Unknown error';
-      return {
-        content: [
-          {
-            type: 'text',
-            text: `Error: ${message}`,
-          },
-        ],
-        isError: true,
-      };
-    }
+    return instrumented(
+      name,
+      async () => {
+        try {
+          const result = await backend.callTool(name, args);
+          const resultText = typeof result === 'string' ? result : JSON.stringify(result, null, 2);
+          const hint = getNextStepHint(name, args as Record<string, any> | undefined);
+
+          return {
+            content: [
+              {
+                type: 'text',
+                text: resultText + hint,
+              },
+            ],
+          };
+        } catch (error) {
+          const message = error instanceof Error ? error.message : 'Unknown error';
+          return {
+            content: [
+              {
+                type: 'text',
+                text: `Error: ${message}`,
+              },
+            ],
+            isError: true,
+          };
+        }
+      },
+      (result) => {
+        // Size the text payload, not the whole envelope, so the log
+        // metric stays aligned with what the agent actually receives.
+        try {
+          const block = (result as { content?: Array<{ text?: string }> }).content?.[0];
+          return block?.text ? Buffer.byteLength(block.text, 'utf8') : 0;
+        } catch {
+          return 0;
+        }
+      },
+      (result) => {
+        // The handler converts thrown tool errors into a returned
+        // envelope `{ isError: true, content: [{ type: 'text', text: 'Error: ...' }] }`,
+        // so `instrumented`'s catch branch never fires for tool errors.
+        // Inspect the envelope here so the log doesn't undercount failures.
+        try {
+          const envelope = result as { isError?: boolean; content?: Array<{ text?: string }> };
+          if (envelope?.isError !== true) return null;
+          return envelope.content?.[0]?.text ?? 'tool error';
+        } catch {
+          return null;
+        }
+      },
+    );
   });
 
   // Handle list prompts request