diff --git a/CHANGELOG.md b/CHANGELOG.md index 86ba64a..f737c9d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added +- `mcpc @ logs` command to show or follow the bridge log file. Supports `-n/--tail ` (default 50), `--follow` to stream new lines, and `--since ` (e.g. `1h`, `30m`, `2026-04-28T12:00:00Z`). Transparently spans rotated files (`.log.1` … `.log.5`) when more lines are needed. With `--json`, returns parsed `{ ts, level, context, message }` records (or `{ ts: null, raw }` for unparseable lines); combined with `--follow`, output is NDJSON. `mcpc @ --json` now also exposes `_mcpc.logPath` and `_mcpc.logSize`. Error messages that previously pointed users to a raw log file path now suggest `mcpc @ logs` instead (#205). - New `npm run test:conformance` script (and on-demand `Conformance` GitHub Actions workflow) that runs the `@modelcontextprotocol/conformance` framework against mcpc to verify adherence to the MCP specification. The conformance adapter now covers the `initialize`, `tools_call`, and `sse-retry` client scenarios and exercises a broader set of mcpc sub-commands (`tools-list`, `tools-get`, `tools-call` with and without `--task`, `ping`, `logging-set-level`, `resources-list`, `resources-templates-list`, `prompts-list`) against the conformance test server. - `mcpc connect` (with no arguments) now auto-discovers standard MCP config files (`.mcp.json`, `mcp.json`, `mcp_config.json`, `.cursor/mcp.json`, `.vscode/mcp.json`, `.kiro/settings/mcp.json`, `~/.claude.json`, `~/.codeium/windsurf/mcp_config.json`, VS Code app config, Claude Desktop config, etc.) in the current directory and home directory, and connects every server defined across them. Entries with duplicate session names across files are deduplicated (project-scoped files win over global ones). Config files using VS Code's `"servers"` key (instead of `"mcpServers"`) are also supported. - `mcpc connect` auto-connects to `mcp.apify.com` as `@apify` when the `APIFY_API_TOKEN` environment variable is set, using it as a Bearer token. Existing live sessions are reused without restart. diff --git a/README.md b/README.md index 3010f15..af82647 100644 --- a/README.md +++ b/README.md @@ -153,6 +153,57 @@ MCP session commands (after connecting): <@session> tasks-cancel <@session> logging-set-level <@session> ping + <@session> logs [-n N] [--follow] [--since 1h] + +Run "mcpc" without arguments to show active sessions and OAuth profiles. +Run "mcpc --json" to get the same data as `{ sessions: [...], profiles: [...] }`. +``` +Usage: mcpc [<@session>] [] [options] + +Universal command-line client for the Model Context Protocol (MCP). + +Commands: + connect [@session] Connect to an MCP server and start a named @session + close <@session> Close a session + restart <@session> Restart a session (losing all state) + shell <@session> Open interactive shell for a session + login Interactively login to a server using OAuth and save profile + logout Delete an OAuth profile for a server + clean [resources...] Clean up mcpc data (sessions, profiles, logs, all) + grep Search tools and instructions across all active sessions + x402 [subcommand] [args...] Configure an x402 payment wallet (EXPERIMENTAL) + help [command] [subcommand] Show help for a specific command + +Options: + --json Output in JSON format for scripting + --verbose Enable debug logging + --profile OAuth profile for the server ("default" if not provided) + --timeout Request timeout in seconds (default: 300) + --max-chars Truncate output to n characters (ignored in --json mode) + --insecure Skip TLS certificate verification (for self-signed certs) + -v, --version Output the version number + -h, --help Display help + +MCP session commands (after connecting): + <@session> Show MCP server info, capabilities, and tools overview + <@session> grep Search tools and instructions + <@session> tools-list List all server tools + <@session> tools-get Get tool details and schema + <@session> tools-call [arg:=val ... | | prompts-list + <@session> prompts-get [arg:=val ... | | resources-list + <@session> resources-read + <@session> resources-subscribe + <@session> resources-unsubscribe + <@session> resources-templates-list + <@session> tasks-list + <@session> tasks-get + <@session> tasks-result + <@session> tasks-cancel + <@session> logging-set-level + <@session> ping + <@session> logs [-n N] [--follow] [--since 1h] Run "mcpc" without arguments to show active sessions and OAuth profiles. Run "mcpc --json" to get the same data as `{ sessions: [...], profiles: [...] }`. diff --git a/src/cli/commands/logs.ts b/src/cli/commands/logs.ts new file mode 100644 index 0000000..edb3729 --- /dev/null +++ b/src/cli/commands/logs.ts @@ -0,0 +1,203 @@ +/** + * `mcpc @ logs` — show or follow bridge log files. + */ + +import { stat } from 'fs/promises'; +import chalk from 'chalk'; +import { ClientError } from '../../lib/errors.js'; +import { getSession } from '../../lib/sessions.js'; +import { + followLog, + getBridgeLogPath, + listLogFiles, + parseLogLine, + readRecentLogLines, + resolveSince, + type LogRecord, +} from '../../lib/log-reader.js'; +import { formatJson } from '../output.js'; +import type { CommandOptions } from '../../lib/types.js'; + +const DEFAULT_TAIL = 50; + +export interface LogsCommandOptions extends CommandOptions { + tail?: number; + follow?: boolean; + since?: string; +} + +/** + * Implementation of `mcpc @ logs`. + * + * `target` is the session name including the leading "@" (e.g. "@apify"). + */ +export async function showLogs(target: string, options: LogsCommandOptions): Promise { + if (!target.startsWith('@')) { + throw new ClientError( + `logs requires a session target (e.g. mcpc @ logs). Got: ${target}` + ); + } + + const session = await getSession(target); + if (!session) { + throw new ClientError( + `Session not found: ${target}\n\n` + + `List sessions with: mcpc\nCreate one with: mcpc connect ${target}` + ); + } + + const logPath = getBridgeLogPath(target); + const files = await listLogFiles(target); + + let since: Date | undefined; + if (options.since) { + const resolved = resolveSince(options.since); + if (!resolved) { + throw new ClientError( + `Invalid --since value: "${options.since}". ` + + `Use a duration (e.g. 30s, 5m, 2h, 1d, 1w) or an ISO 8601 timestamp.` + ); + } + since = resolved; + } + + // Default tail: 50 in non-follow mode, also used as the backlog size when --follow is set. + const tail = options.tail ?? DEFAULT_TAIL; + + const emitOpts: EmitOpts = { + tail, + ...(since && { since }), + ...(options.follow && { follow: true }), + }; + + if (options.outputMode === 'json') { + await emitJson(target, logPath, files, emitOpts); + return; + } + + await emitHuman(target, logPath, files, emitOpts); +} + +interface EmitOpts { + tail: number; + since?: Date; + follow?: boolean; +} + +async function emitHuman( + sessionName: string, + logPath: string, + files: string[], + opts: EmitOpts +): Promise { + const header = await buildHeader(sessionName, logPath, files, opts); + for (const line of header) { + console.error(line); + } + + const backlog = await readRecentLogLines(sessionName, { + tail: opts.tail, + ...(opts.since && { since: opts.since }), + }); + for (const line of backlog) { + console.log(line); + } + + if (!opts.follow) { + return; + } + + await new Promise((resolve) => { + const sub = followLog(sessionName, (line) => { + console.log(line); + }); + const onSignal = (): void => { + void sub.stop().finally(resolve); + }; + process.once('SIGINT', onSignal); + process.once('SIGTERM', onSignal); + }); +} + +async function emitJson( + sessionName: string, + logPath: string, + files: string[], + opts: EmitOpts +): Promise { + const backlog = await readRecentLogLines(sessionName, { + tail: opts.tail, + ...(opts.since && { since: opts.since }), + }); + const records = backlog.map(parseLogLine); + + if (!opts.follow) { + console.log(formatJson(records)); + return; + } + + // Streaming mode: emit NDJSON (one record per line). A JSON array can't be streamed. + for (const rec of records) { + process.stdout.write(JSON.stringify(rec) + '\n'); + } + + await new Promise((resolve) => { + const sub = followLog(sessionName, (line) => { + const rec: LogRecord = parseLogLine(line); + process.stdout.write(JSON.stringify(rec) + '\n'); + }); + const onSignal = (): void => { + void sub.stop().finally(resolve); + }; + process.once('SIGINT', onSignal); + process.once('SIGTERM', onSignal); + }); + + // Suppress unused-parameter warnings for parameters kept for symmetry with emitHuman. + void logPath; + void files; +} + +async function buildHeader( + sessionName: string, + logPath: string, + files: string[], + opts: EmitOpts +): Promise { + const lines: string[] = []; + let size = 0; + let exists = false; + try { + const st = await stat(logPath); + size = st.size; + exists = true; + } catch { + // file doesn't exist yet + } + + const fileCount = files.length; + const sizeStr = formatBytes(size); + const tailLabel = opts.follow + ? `following (backlog ${opts.tail} lines)` + : opts.since + ? `since ${opts.since.toISOString()}, last ${opts.tail} lines` + : `last ${opts.tail} lines`; + + lines.push(chalk.dim(`Session ${sessionName} · ${logPath} · ${tailLabel}`)); + if (fileCount > 1) { + lines.push(chalk.dim(` ${fileCount} files (current + ${fileCount - 1} rotated), ${sizeStr}`)); + } else if (exists) { + lines.push(chalk.dim(` ${sizeStr}`)); + } else { + lines.push(chalk.dim(` no logs yet for ${sessionName}`)); + } + lines.push(''); + return lines; +} + +function formatBytes(n: number): string { + if (n < 1024) return `${n} B`; + if (n < 1024 * 1024) return `${(n / 1024).toFixed(1)} KB`; + if (n < 1024 * 1024 * 1024) return `${(n / 1024 / 1024).toFixed(1)} MB`; + return `${(n / 1024 / 1024 / 1024).toFixed(2)} GB`; +} diff --git a/src/cli/commands/sessions.ts b/src/cli/commands/sessions.ts index 10c8438..65b18da 100644 --- a/src/cli/commands/sessions.ts +++ b/src/cli/commands/sessions.ts @@ -3,6 +3,7 @@ */ import { createServer } from 'net'; +import { stat } from 'fs/promises'; import { OutputMode, isValidSessionName, @@ -759,6 +760,21 @@ export async function showServerDetails( }), }; + // Bridge log path/size are useful debug context for callers — only meaningful + // for session targets (those starting with "@"); ad-hoc URL/config targets + // have no persistent bridge log. + let logPath: string | undefined; + let logSize: number | undefined; + if (target.startsWith('@')) { + logPath = `${getLogsDir()}/bridge-${target}.log`; + try { + const st = await stat(logPath); + logSize = st.size; + } catch { + // log file doesn't exist yet — leave logSize undefined + } + } + console.log( formatOutput( { @@ -766,6 +782,8 @@ export async function showServerDetails( sessionName: context.sessionName, profileName: context.profileName, server, + ...(logPath && { logPath }), + ...(logSize !== undefined && { logSize }), }, protocolVersion, capabilities, diff --git a/src/cli/index.ts b/src/cli/index.ts index 8a51bb2..cd8576f 100644 --- a/src/cli/index.ts +++ b/src/cli/index.ts @@ -22,6 +22,7 @@ import * as prompts from './commands/prompts.js'; import * as sessions from './commands/sessions.js'; import * as logging from './commands/logging.js'; import * as utilities from './commands/utilities.js'; +import * as logs from './commands/logs.js'; import * as auth from './commands/auth.js'; import * as tasks from './commands/tasks.js'; import * as grepCmd from './commands/grep.js'; @@ -425,6 +426,7 @@ ${chalk.bold('MCP session commands (after connecting):')} <@session> ${chalk.cyan('tasks-cancel')} <@session> ${chalk.cyan('logging-set-level')} <@session> ${chalk.cyan('ping')} + <@session> ${chalk.cyan('logs')} [-n N] [--follow] [--since 1h] Run "mcpc" without arguments to show active sessions and OAuth profiles. Run "mcpc --json" to get the same data as \`{ sessions: [...], profiles: [...] }\`. @@ -1243,6 +1245,50 @@ ${jsonHelp('`GetPromptResult` object', '`{ description?, messages: [{ role, cont .action(async (_options, command) => { await utilities.ping(session, getOptionsFromCommand(command)); }); + + // Logs command + program + .command('logs') + .description('Show or follow the bridge log file for this session.') + .option('-n, --tail ', 'Number of recent lines to show (default: 50)') + .option('--follow', 'Stream new log lines as they are written') + .option( + '--since ', + 'Only show entries newer than a duration (30s, 5m, 2h, 1d) or ISO timestamp' + ) + .addHelpText( + 'after', + ` +${chalk.bold('Examples:')} + mcpc ${session} logs Last 50 lines + mcpc ${session} logs -n 200 Last 200 lines + mcpc ${session} logs --follow Stream new lines (Ctrl+C to stop) + mcpc ${session} logs --since 1h Lines from the last hour + mcpc ${session} logs --since 30m -n 50 + +${chalk.bold('Notes:')} + Reads ~/.mcpc/logs/bridge-${session}.log and transparently spans + rotated files (.log.1 … .log.5) when -n or --since needs older lines. + With --follow, output is NDJSON (one record per line) instead of a JSON array. +${jsonHelp( + 'Array of `LogRecord` objects', + '`[{ ts: string|null, level: string|null, context: string|null, message?: string, raw?: string }, ...]`' +)}` + ) + .action(async (opts, command) => { + const tail = opts.tail !== undefined ? parseInt(opts.tail as string, 10) : undefined; + if (tail !== undefined && (isNaN(tail) || tail < 0)) { + throw new ClientError( + `Invalid --tail value: "${opts.tail as string}". Must be a non-negative integer.` + ); + } + await logs.showLogs(session, { + ...getOptionsFromCommand(command), + ...(tail !== undefined && { tail }), + ...(opts.follow && { follow: true as boolean }), + ...(opts.since && { since: opts.since as string }), + }); + }); } /** diff --git a/src/cli/output.ts b/src/cli/output.ts index 087b92e..2d7437a 100644 --- a/src/cli/output.ts +++ b/src/cli/output.ts @@ -1463,15 +1463,19 @@ export function formatServerDetails( commands.push(`${bullet} ${bt}mcpc ${target} logging-set-level ${bt}`); } + if (target.startsWith('@')) { + commands.push(`${bullet} ${bt}mcpc ${target} logs${bt}`); + } commands.push(`${bullet} ${bt}mcpc ${target} shell${bt}`); lines.push(commands.join('\n')); lines.push(''); - // Debugging hint: bridge log file path (only shown for sessions, i.e. @name targets) + // Debugging hint: how to view logs (only shown for sessions, i.e. @name targets) if (target.startsWith('@')) { const logPath = join(getLogsDir(), `bridge-${target}.log`); - lines.push(chalk.dim(`Session log for debugging: ${logPath}`)); + lines.push(chalk.dim(`For session logs, run: mcpc ${target} logs`)); + lines.push(chalk.dim(`Log file: ${logPath}`)); lines.push(''); } diff --git a/src/cli/parser.ts b/src/cli/parser.ts index 09c334e..15eea6d 100644 --- a/src/cli/parser.ts +++ b/src/cli/parser.ts @@ -108,6 +108,7 @@ export const KNOWN_SESSION_COMMANDS = [ 'prompts-get', 'logging-set-level', 'ping', + 'logs', 'tasks-list', 'tasks-get', 'tasks-result', diff --git a/src/cli/shell.ts b/src/cli/shell.ts index 56ccb8b..6d2667e 100644 --- a/src/cli/shell.ts +++ b/src/cli/shell.ts @@ -16,6 +16,7 @@ import * as prompts from './commands/prompts.js'; import * as tasks from './commands/tasks.js'; import * as logging from './commands/logging.js'; import { ping } from './commands/utilities.js'; +import { showLogs } from './commands/logs.js'; import { createSessionClient } from '../lib/session-client.js'; import type { SessionClient } from '../lib/session-client.js'; import { parseShellCommand } from './shell-parser.js'; @@ -157,6 +158,7 @@ function showShellHelp(): void { console.log(' prompts-get [key:=value ...]'); console.log(' logging-set-level '); console.log(' ping'); + console.log(' logs [-n N] [--follow] [--since 1h]'); console.log(''); console.log(chalk.cyan(' Shell commands:')); console.log(' help Show this help message'); @@ -204,6 +206,47 @@ async function executeCommand(ctx: ShellContext, line: string): Promise { await ping(ctx.target, options); break; + case 'logs': { + let tail: number | undefined; + let follow = false; + let since: string | undefined; + for (let i = 0; i < args.length; i++) { + const a = args[i]; + if (a === '--follow') { + follow = true; + } else if (a === '-n' || a === '--tail') { + const next = args[++i]; + if (!next) { + console.log(chalk.red(`Error: ${a} requires a value`)); + return; + } + const parsed = parseInt(next, 10); + if (isNaN(parsed) || parsed < 0) { + console.log(chalk.red(`Error: invalid ${a} value: "${next}"`)); + return; + } + tail = parsed; + } else if (a === '--since') { + const next = args[++i]; + if (!next) { + console.log(chalk.red('Error: --since requires a value')); + return; + } + since = next; + } else if (a) { + console.log(chalk.red(`Error: unknown logs option: ${a}`)); + return; + } + } + await showLogs(ctx.target, { + ...options, + ...(tail !== undefined && { tail }), + ...(follow && { follow }), + ...(since && { since }), + }); + break; + } + case 'tools': case 'tools-list': await tools.listTools(ctx.target, options); diff --git a/src/lib/bridge-manager.ts b/src/lib/bridge-manager.ts index f54c245..5936da1 100644 --- a/src/lib/bridge-manager.ts +++ b/src/lib/bridge-manager.ts @@ -60,11 +60,10 @@ async function classifyAndThrowSessionError( await updateSession(sessionName, { status: 'expired' }).catch((e) => logger.warn(`Failed to mark session ${sessionName} as expired:`, e) ); - const logPath = `${getLogsDir()}/bridge-${sessionName}.log`; throw new ClientError( `Session ${sessionName} expired (server rejected session ID). ` + `Use "mcpc ${sessionName} restart" to start a new session. ` + - `For details, check logs at ${logPath}` + `For details, run: mcpc ${sessionName} logs` ); } if (isAuthenticationError(errorMessage)) { @@ -668,11 +667,10 @@ export async function ensureBridgeReady(sessionName: string): Promise { const errorMsg = result.error?.message || 'unknown error'; await classifyAndThrowSessionError(sessionName, session, errorMsg, result.error); - // Other errors - provide enriched error with log path + // Other errors - provide enriched error with hint to view logs const serverUrl = session.server.url; - const logPath = `${getLogsDir()}/bridge-${sessionName}.log`; throw new ClientError( - `${enrichErrorMessage(errorMsg, serverUrl)}\n` + `For details, check logs at ${logPath}` + `${enrichErrorMessage(errorMsg, serverUrl)}\n` + `For details, run: mcpc ${sessionName} logs` ); } diff --git a/src/lib/errors.ts b/src/lib/errors.ts index 38144ea..03d9ecb 100644 --- a/src/lib/errors.ts +++ b/src/lib/errors.ts @@ -117,7 +117,11 @@ export function createServerAuthError( } if (options?.logPath) { - hint += `\n\nFor details, check logs at ${options.logPath}`; + if (options.sessionName) { + hint += `\n\nFor details, run: mcpc ${options.sessionName} logs`; + } else { + hint += `\n\nFor details, check logs at ${options.logPath}`; + } } return new AuthError( diff --git a/src/lib/log-reader.ts b/src/lib/log-reader.ts new file mode 100644 index 0000000..3910383 --- /dev/null +++ b/src/lib/log-reader.ts @@ -0,0 +1,353 @@ +/** + * Reader for bridge log files (~/.mcpc/logs/bridge-.log[.N]). + * + * Produces raw text lines for human output and structured records for JSON output. + * Transparently spans rotated files (.log.5 → .log.1 → .log). + */ + +import { readdir, readFile, stat } from 'fs/promises'; +import { createReadStream, watch as fsWatch, type FSWatcher, type Stats } from 'fs'; +import { join } from 'path'; +import { getLogsDir } from './utils.js'; + +export interface LogRecord { + /** ISO timestamp parsed from the line, or null if the line had no recognizable prefix. */ + ts: string | null; + /** Log level lowercased (debug|info|warn|error|...) or null. */ + level: string | null; + /** Optional context tag (e.g. "bridge-manager"), or null. */ + context: string | null; + /** Message body without the timestamp/level/context prefix. */ + message?: string; + /** Raw line, set only when the line did not match the expected prefix format. */ + raw?: string; +} + +export interface ReadLogsOptions { + /** Maximum number of lines to return (most recent kept). */ + tail?: number; + /** Drop lines with a parseable timestamp older than this Date. Unparseable lines are kept. */ + since?: Date; +} + +const LINE_RE = + /^\[(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?Z)\] \[([A-Z]+)\](?: \[([^\]]+)\])?\s?(.*)$/; + +/** + * Path of the active (current) bridge log file for a session. + * `sessionName` should include the leading "@". + */ +export function getBridgeLogPath(sessionName: string): string { + return join(getLogsDir(), `bridge-${sessionName}.log`); +} + +/** + * Parse a single raw log line into a structured record. + * Lines that don't match the expected `[ISO] [LEVEL] [context?] msg` shape return `{ ts: null, raw }`. + */ +export function parseLogLine(line: string): LogRecord { + const m = LINE_RE.exec(line); + if (!m) { + return { ts: null, level: null, context: null, raw: line }; + } + return { + ts: m[1] ?? null, + level: (m[2] ?? '').toLowerCase() || null, + context: m[3] ?? null, + message: m[4] ?? '', + }; +} + +/** + * List all log files for a session in age order (oldest first, current last). + * Returns absolute paths. Returns [] if the logs directory or files don't exist. + */ +export async function listLogFiles(sessionName: string): Promise { + const dir = getLogsDir(); + const baseName = `bridge-${sessionName}.log`; + const basePath = join(dir, baseName); + + let files: string[]; + try { + files = await readdir(dir); + } catch { + return []; + } + + const rotated: { path: string; num: number }[] = []; + for (const file of files) { + if (file.startsWith(baseName + '.')) { + const numStr = file.substring(baseName.length + 1); + const num = parseInt(numStr, 10); + if (!isNaN(num)) { + rotated.push({ path: join(dir, file), num }); + } + } + } + // Higher rotation numbers are older (.5 oldest, .1 newest among rotated). + rotated.sort((a, b) => b.num - a.num); + const result = rotated.map((r) => r.path); + + try { + await stat(basePath); + result.push(basePath); + } catch { + // current file doesn't exist yet + } + return result; +} + +function parseLineTimestamp(line: string): number | null { + const m = LINE_RE.exec(line); + if (!m || !m[1]) return null; + const t = Date.parse(m[1]); + return isNaN(t) ? null : t; +} + +/** + * Read recent log lines for a session, transparently spanning rotated files. + * Returns lines in chronological order (oldest first). + */ +export async function readRecentLogLines( + sessionName: string, + options: ReadLogsOptions = {} +): Promise { + const files = await listLogFiles(sessionName); + if (files.length === 0) return []; + + const cutoff = options.since ? options.since.getTime() : null; + const collected: string[] = []; + + // Read newest file first; stop early once we have enough lines or hit a fully out-of-range file. + for (let i = files.length - 1; i >= 0; i--) { + const path = files[i]; + if (!path) continue; + let content: string; + try { + content = await readFile(path, 'utf8'); + } catch { + continue; + } + + const rawLines = content.split('\n'); + if (rawLines.length > 0 && rawLines[rawLines.length - 1] === '') { + rawLines.pop(); + } + + let kept = rawLines; + if (cutoff !== null) { + kept = rawLines.filter((line) => { + const ts = parseLineTimestamp(line); + // Lines without parseable timestamps (banners, stack frames) are kept. + return ts === null || ts >= cutoff; + }); + } + + collected.unshift(...kept); + + // Stop reading older files when we either have enough lines (no --since) + // or every line in the just-read file pre-dates the cutoff (--since path). + if (cutoff === null && options.tail !== undefined && collected.length >= options.tail) { + break; + } + if (cutoff !== null && rawLines.length > 0) { + const allBeforeCutoff = rawLines.every((line) => { + const ts = parseLineTimestamp(line); + return ts !== null && ts < cutoff; + }); + if (allBeforeCutoff) break; + } + } + + if (options.tail !== undefined && collected.length > options.tail) { + return collected.slice(collected.length - options.tail); + } + return collected; +} + +/** + * Parse a duration shorthand like "30s", "5m", "2h", "1d", "1w" into milliseconds. + * Returns null for unparseable input. + */ +export function parseDuration(input: string): number | null { + const m = /^(\d+)\s*(s|sec|secs|m|min|mins|h|hr|hrs|d|day|days|w|wk|wks)$/i.exec(input.trim()); + if (!m || !m[1] || !m[2]) return null; + const n = parseInt(m[1], 10); + const unit = m[2].toLowerCase(); + const SEC = 1000; + const MIN = 60 * SEC; + const HOUR = 60 * MIN; + const DAY = 24 * HOUR; + const WEEK = 7 * DAY; + if (unit.startsWith('s')) return n * SEC; + if (unit.startsWith('mi') || unit === 'm') return n * MIN; + if (unit.startsWith('h')) return n * HOUR; + if (unit.startsWith('d')) return n * DAY; + if (unit.startsWith('w')) return n * WEEK; + return null; +} + +/** + * Resolve `--since ` to an absolute Date. + * Accepts duration shorthand (treated as relative to now) or an ISO 8601 timestamp. + * Returns null if the input cannot be parsed. + */ +export function resolveSince(input: string): Date | null { + const ms = parseDuration(input); + if (ms !== null) { + return new Date(Date.now() - ms); + } + const t = Date.parse(input); + if (!isNaN(t)) { + return new Date(t); + } + return null; +} + +export interface FollowOptions { + /** + * Poll interval in ms. Backstop for filesystems where fs.watch is unreliable + * (NFS, some network mounts). Defaults to 1000ms; tests can lower it. + */ + pollIntervalMs?: number; + /** + * Start streaming from the beginning of the file instead of the end. + * Default false — backlog is normally the caller's responsibility. + */ + startAtBeginning?: boolean; +} + +/** + * Live-follow the current log file for a session (tail -f style). + * + * - Streams appended bytes to `onLine`, line by line. + * - On rotation (size shrinks or inode changes), re-opens the file from the start. + * - Returns a `stop()` function that cleans up watchers and pending reads. + */ +export function followLog( + sessionName: string, + onLine: (line: string) => void, + options: FollowOptions = {} +): { stop: () => Promise } { + const path = getBridgeLogPath(sessionName); + const pollIntervalMs = options.pollIntervalMs ?? 1000; + let position = 0; + let inode: number | null = null; + let watcher: FSWatcher | null = null; + let reading = false; + let queued = false; + let stopped = false; + let buffer = ''; + + const flush = (chunk: string): void => { + buffer += chunk; + let idx = buffer.indexOf('\n'); + while (idx !== -1) { + const line = buffer.slice(0, idx); + buffer = buffer.slice(idx + 1); + onLine(line); + idx = buffer.indexOf('\n'); + } + }; + + const drainPending = async (): Promise => { + if (stopped) return; + if (reading) { + queued = true; + return; + } + reading = true; + try { + let st: Stats; + try { + st = await stat(path); + } catch { + // File doesn't exist yet — wait for it via the directory watcher (set up below). + return; + } + // Detect rotation: inode changed or size shrunk → reset to start of new file. + if (inode !== null && (st.ino !== inode || st.size < position)) { + position = 0; + if (buffer) { + // Emit any partial line we had buffered before rotation. + onLine(buffer); + buffer = ''; + } + } + inode = st.ino; + if (st.size <= position) { + return; + } + await new Promise((resolve, reject) => { + const stream = createReadStream(path, { + start: position, + end: st.size - 1, + encoding: 'utf8', + }); + stream.on('data', (chunk) => flush(chunk as string)); + stream.on('error', reject); + stream.on('end', () => { + position = st.size; + resolve(); + }); + }); + } finally { + reading = false; + if (queued && !stopped) { + queued = false; + void drainPending(); + } + } + }; + + // Start at end of file so backlog is the caller's responsibility, unless the + // caller explicitly opts into replaying from the beginning (used by tests). + void (async () => { + try { + const st = await stat(path); + position = options.startAtBeginning ? 0 : st.size; + inode = st.ino; + if (options.startAtBeginning) { + await drainPending(); + } + } catch { + position = 0; + } + if (stopped) return; + try { + watcher = fsWatch(path, () => void drainPending()); + watcher.on('error', () => { + // Swallow: the periodic poll below keeps us going if fs.watch hiccups. + }); + } catch { + // fs.watch may fail on some filesystems; the poller below covers us. + } + })(); + + // Belt-and-suspenders polling so rotations and edge cases on certain filesystems + // (NFS, network mounts) still get picked up. + const poll = setInterval(() => { + void drainPending(); + }, pollIntervalMs); + + return { + stop: async (): Promise => { + stopped = true; + clearInterval(poll); + if (watcher) { + try { + watcher.close(); + } catch { + // ignore + } + watcher = null; + } + // Final drain to flush any pending tail before exit. + await drainPending(); + if (buffer) { + onLine(buffer); + buffer = ''; + } + }, + }; +} diff --git a/src/lib/session-client.ts b/src/lib/session-client.ts index f06bd3d..a150b9b 100644 --- a/src/lib/session-client.ts +++ b/src/lib/session-client.ts @@ -35,7 +35,7 @@ import { BridgeClient } from './bridge-client.js'; import { ensureBridgeReady, restartBridge } from './bridge-manager.js'; import { updateSession } from './sessions.js'; import { NetworkError } from './errors.js'; -import { getSocketPath, getLogsDir, generateRequestId } from './utils.js'; +import { getSocketPath, generateRequestId } from './utils.js'; import { createLogger } from './logger.js'; const logger = createLogger('session-client'); @@ -92,8 +92,7 @@ export class SessionClient extends EventEmitter implements IMcpClient { if (!(error instanceof NetworkError)) { // Add log hint for MCP/server errors const err = error as Error; - const logPath = `${getLogsDir()}/bridge-${this.sessionName}.log`; - err.message = `${err.message}. For details, check logs at ${logPath}`; + err.message = `${err.message}. For details, run: mcpc ${this.sessionName} logs`; throw error; } @@ -333,8 +332,7 @@ export class SessionClient extends EventEmitter implements IMcpClient { } catch (error) { if (!(error instanceof NetworkError)) { const err = error as Error; - const logPath = `${getLogsDir()}/bridge-${this.sessionName}.log`; - err.message = `${err.message}. For details, check logs at ${logPath}`; + err.message = `${err.message}. For details, run: mcpc ${this.sessionName} logs`; throw error; } diff --git a/test/e2e/suites/sessions/logs.test.sh b/test/e2e/suites/sessions/logs.test.sh new file mode 100755 index 0000000..185d67d --- /dev/null +++ b/test/e2e/suites/sessions/logs.test.sh @@ -0,0 +1,311 @@ +#!/bin/bash +# Test: `mcpc @ logs` command +# +# Covers: +# - error when session does not exist +# - default output (last 50 lines, header on stderr, lines on stdout) +# - --json produces parsed records, banners become {raw} +# - -n / --tail caps output +# - --since filters by timestamp; invalid value rejected +# - --tail and --since combine +# - rotation files (.log.1, .log.2) are spanned when more lines are needed +# - _mcpc.logPath / _mcpc.logSize appear in `mcpc @ --json` +# - error messages from a real failing session point users at `mcpc logs` + +source "$(dirname "$0")/../../lib/framework.sh" +test_init "sessions/logs" --isolated + +start_test_server + +SESSION=$(session_name "logs") +_SESSIONS_CREATED+=("$SESSION") + +# Real connect so the session exists in sessions.json and the bridge log +# file gets created with at least the startup banner. +run_mcpc connect "$TEST_SERVER_URL" "$SESSION" --header "X-Test: true" +assert_success "connect should succeed" + +LOG_DIR="$MCPC_HOME_DIR/logs" +LOG_FILE="$LOG_DIR/bridge-${SESSION}.log" + +# ============================================================================= +# Error: session does not exist +# ============================================================================= + +test_case "logs on unknown session fails with helpful error" +NONEXISTENT="@nope-$(date +%s)" +run_mcpc "$NONEXISTENT" logs +assert_failure +assert_contains "$STDERR" "Session not found" +assert_contains "$STDERR" "$NONEXISTENT" +test_pass + +# ============================================================================= +# Error: invalid --since value +# ============================================================================= + +test_case "invalid --since value is rejected" +run_mcpc "$SESSION" logs --since not-a-duration +assert_failure +assert_contains "$STDERR" "Invalid --since value" +test_pass + +# ============================================================================= +# Default human output +# ============================================================================= + +test_case "default logs prints header on stderr and lines on stdout" +run_mcpc "$SESSION" logs +assert_success +# Header (path + tail label) goes to stderr +assert_contains "$STDERR" "$LOG_FILE" +assert_contains "$STDERR" "last 50 lines" +# At least one log line on stdout (bridge writes a startup banner + version line) +if [[ -z "$STDOUT" ]]; then + test_fail "expected at least one log line on stdout, got empty" + exit 1 +fi +test_pass + +# ============================================================================= +# --json shape +# ============================================================================= + +test_case "--json returns array of structured records" +run_mcpc --json "$SESSION" logs +assert_success +assert_json_valid "$STDOUT" +# Should be a non-empty array +arr_len=$(echo "$STDOUT" | jq 'length') +if [[ "$arr_len" -lt 1 ]]; then + test_fail "expected at least one log record, got $arr_len" + exit 1 +fi +# Records that match the [ts] [LEVEL] [ctx?] msg shape have ts populated; +# banner separators don't and surface as { ts: null, raw: "..." } instead. +parsed_count=$(echo "$STDOUT" | jq '[.[] | select(.ts != null)] | length') +raw_count=$(echo "$STDOUT" | jq '[.[] | select(.raw != null)] | length') +if [[ "$parsed_count" -lt 1 ]]; then + test_fail "expected at least one parsed record with non-null ts, got $parsed_count" + exit 1 +fi +# Either format is acceptable, but the union should equal total length. +total=$(( parsed_count + raw_count )) +if [[ "$total" -ne "$arr_len" ]]; then + test_fail "every record should have either ts or raw, got parsed=$parsed_count raw=$raw_count total=$arr_len" + exit 1 +fi +# Parsed records should expose the documented fields. +first_parsed=$(echo "$STDOUT" | jq '[.[] | select(.ts != null)][0]') +assert_contains "$first_parsed" '"level"' +assert_contains "$first_parsed" '"context"' +assert_contains "$first_parsed" '"message"' +test_pass + +# ============================================================================= +# -n / --tail caps output +# ============================================================================= + +test_case "-n 1 returns exactly 1 record in JSON" +run_mcpc --json "$SESSION" logs -n 1 +assert_success +arr_len=$(echo "$STDOUT" | jq 'length') +if [[ "$arr_len" -ne 1 ]]; then + test_fail "expected 1 record with -n 1, got $arr_len" + exit 1 +fi +test_pass + +test_case "--tail 2 returns exactly 2 records in JSON" +run_mcpc --json "$SESSION" logs --tail 2 +assert_success +arr_len=$(echo "$STDOUT" | jq 'length') +if [[ "$arr_len" -ne 2 ]]; then + test_fail "expected 2 records with --tail 2, got $arr_len" + exit 1 +fi +test_pass + +test_case "invalid -n value is rejected" +run_mcpc "$SESSION" logs -n not-a-number +assert_failure +assert_contains "$STDERR" "Invalid" +test_pass + +# ============================================================================= +# --since filters by timestamp +# ============================================================================= + +# An ISO timestamp far in the future should yield zero records (well, zero +# parseable records — banners with no timestamp survive the filter). +test_case "--since in the future yields no parseable records" +run_mcpc --json "$SESSION" logs --since 2099-01-01T00:00:00Z +assert_success +parsed_count=$(echo "$STDOUT" | jq '[.[] | select(.ts != null)] | length') +if [[ "$parsed_count" -ne 0 ]]; then + test_fail "expected 0 parsed records after filtering with future --since, got $parsed_count" + exit 1 +fi +test_pass + +# A duration that covers everything written so far should keep all records. +test_case "--since 1d keeps all recent records" +run_mcpc --json "$SESSION" logs --since 1d +assert_success +arr_len=$(echo "$STDOUT" | jq 'length') +if [[ "$arr_len" -lt 1 ]]; then + test_fail "expected --since 1d to retain recent records, got $arr_len" + exit 1 +fi +test_pass + +# ============================================================================= +# Rotation: tail spans .log.1, .log.2 transparently +# +# We use a fresh, never-connected session so the bridge isn't actively writing +# to the log file while we inject fixture content. The session entry has to +# exist in sessions.json (otherwise `logs` would error) but never needs a +# running bridge — the command just reads the on-disk files. +# ============================================================================= + +ROTATION_SESSION="@rot-$(date +%s)" +_SESSIONS_CREATED+=("$ROTATION_SESSION") + +# Add a synthetic session entry so `mcpc logs` accepts the target. +sessions_file="$MCPC_HOME_DIR/sessions.json" +if [[ ! -f "$sessions_file" ]]; then + echo '{"sessions":{}}' > "$sessions_file" +fi +jq --arg name "$ROTATION_SESSION" --arg url "$TEST_SERVER_URL" \ + '.sessions[$name] = { + name: $name, + server: { url: $url }, + transport: "http", + status: "live", + createdAt: "2026-04-28T00:00:00.000Z" + }' "$sessions_file" > "$sessions_file.tmp" +mv "$sessions_file.tmp" "$sessions_file" + +ROT_LOG_DIR="$MCPC_HOME_DIR/logs" +ROT_LOG_FILE="$ROT_LOG_DIR/bridge-${ROTATION_SESSION}.log" +mkdir -p "$ROT_LOG_DIR" + +cat > "$ROT_LOG_DIR/bridge-${ROTATION_SESSION}.log.2" <<'OLDER' +[2026-04-28T08:00:00.000Z] [INFO] [test] r2-line-a +[2026-04-28T08:00:01.000Z] [INFO] [test] r2-line-b +OLDER +cat > "$ROT_LOG_DIR/bridge-${ROTATION_SESSION}.log.1" <<'OLD' +[2026-04-28T09:00:00.000Z] [INFO] [test] r1-line-a +[2026-04-28T09:00:01.000Z] [INFO] [test] r1-line-b +[2026-04-28T09:00:02.000Z] [INFO] [test] r1-line-c +OLD +cat > "$ROT_LOG_FILE" <<'CUR' +[2026-04-28T10:00:00.000Z] [INFO] [test] cur-line-a +[2026-04-28T10:00:01.000Z] [INFO] [test] cur-line-b +CUR + +test_case "tail spans rotated log files" +# tail 4 should return the LAST 4 lines (chronological order): +# r1-line-b, r1-line-c, cur-line-a, cur-line-b +run_mcpc --json "$ROTATION_SESSION" logs -n 4 +assert_success +arr_len=$(echo "$STDOUT" | jq 'length') +assert_eq "$arr_len" "4" "expected exactly 4 records with -n 4" +got=$(echo "$STDOUT" | jq -r '[.[] | .message] | join(",")') +assert_contains "$got" "r1-line-b" +assert_contains "$got" "r1-line-c" +assert_contains "$got" "cur-line-a" +assert_contains "$got" "cur-line-b" +# r2-line-* should NOT appear (older than the tail window) +if echo "$got" | grep -q "r2-line"; then + test_fail "r2-line-* should not appear in tail 4 result, got: $got" + exit 1 +fi +test_pass + +test_case "tail larger than total reads everything across rotations" +run_mcpc --json "$ROTATION_SESSION" logs -n 1000 +assert_success +got=$(echo "$STDOUT" | jq -r '[.[] | .message // .raw] | join("|")') +# All injected lines should appear, in order. +assert_contains "$got" "r2-line-a" +assert_contains "$got" "r2-line-b" +assert_contains "$got" "r1-line-a" +assert_contains "$got" "cur-line-b" +# Order: oldest-first across files +expected_order=("r2-line-a" "r2-line-b" "r1-line-a" "r1-line-b" "r1-line-c" "cur-line-a" "cur-line-b") +prev_idx=-1 +for marker in "${expected_order[@]}"; do + idx=$(echo "$got" | grep -bo "$marker" | head -1 | cut -d: -f1) + if [[ -z "$idx" ]]; then + test_fail "missing marker '$marker' in output: $got" + exit 1 + fi + if [[ "$idx" -le "$prev_idx" ]]; then + test_fail "marker '$marker' appears out of order in: $got" + exit 1 + fi + prev_idx=$idx +done +test_pass + +test_case "--since spans rotated files" +run_mcpc --json "$ROTATION_SESSION" logs --since 2026-04-28T08:30:00.000Z +assert_success +got=$(echo "$STDOUT" | jq -r '[.[] | .message] | join(",")') +# r2-line-a is before the cutoff and should be filtered out +if echo "$got" | grep -q "r2-line-a"; then + test_fail "r2-line-a should be filtered out by --since, got: $got" + exit 1 +fi +# r1-line-* and cur-line-* are after the cutoff +assert_contains "$got" "r1-line-a" +assert_contains "$got" "cur-line-b" +test_pass + +# ============================================================================= +# `mcpc @ --json` exposes _mcpc.logPath / _mcpc.logSize +# ============================================================================= + +test_case "session JSON exposes _mcpc.logPath and _mcpc.logSize" +run_mcpc --json "$SESSION" +assert_success +log_path=$(echo "$STDOUT" | jq -r '._mcpc.logPath // empty') +log_size=$(echo "$STDOUT" | jq -r '._mcpc.logSize // empty') +if [[ -z "$log_path" ]]; then + test_fail "expected _mcpc.logPath in session JSON output" + exit 1 +fi +assert_contains "$log_path" "bridge-${SESSION}.log" +if [[ -z "$log_size" || "$log_size" -lt 1 ]]; then + test_fail "expected _mcpc.logSize > 0, got: $log_size" + exit 1 +fi +test_pass + +# ============================================================================= +# Error messages now point users at the new logs command +# ============================================================================= + +test_case "error from broken session points to 'mcpc logs'" +# Use an explicitly-named session (not derived from session_name() which +# already has an @) since session names can only contain one @ at the start. +BROKEN="@broken-$(date +%s)-$$" +# Add a manually-crafted session entry pointing at a server that 401s. +jq --arg name "$BROKEN" --arg url "$TEST_SERVER_URL" \ + '.sessions[$name] = { + name: $name, + server: { url: $url, headers: { "Authorization": "InvalidScheme bogus" } }, + transport: "http", + status: "unauthorized", + createdAt: "2026-04-28T00:00:00.000Z" + }' "$sessions_file" > "$sessions_file.tmp" +mv "$sessions_file.tmp" "$sessions_file" +_SESSIONS_CREATED+=("$BROKEN") + +run_mcpc "$BROKEN" tools-list +assert_failure +assert_contains "$STDERR" "mcpc ${BROKEN} logs" +test_pass + +test_done diff --git a/test/e2e/suites/sessions/unauthorized-persist.test.sh b/test/e2e/suites/sessions/unauthorized-persist.test.sh index c9eaa8a..0ddba27 100755 --- a/test/e2e/suites/sessions/unauthorized-persist.test.sh +++ b/test/e2e/suites/sessions/unauthorized-persist.test.sh @@ -18,16 +18,15 @@ _SESSIONS_CREATED+=("$SESSION") # Test: bearer-only session fails with auth error containing log path # ============================================================================= -test_case "connect with bad bearer token fails with auth error + log path" +test_case "connect with bad bearer token fails with auth error + logs hint" run_mcpc connect "$TEST_SERVER_URL" "$SESSION" \ --header "X-Test: true" \ --header "Authorization: InvalidScheme not-a-bearer-token" assert_failure assert_exit_code 4 "should fail with auth exit code (4)" assert_contains "$STDERR" "Authentication required by server" -# The error should point at the bridge log file so the user can investigate -assert_contains "$STDERR" "check logs at" -assert_contains "$STDERR" "bridge-${SESSION}.log" +# The error should point at the new logs command so the user can investigate +assert_contains "$STDERR" "mcpc ${SESSION} logs" test_pass # ============================================================================= @@ -86,13 +85,12 @@ test_pass # Test: using an unauthorized session surfaces the auth error + log path # ============================================================================= -test_case "using unauthorized session surfaces auth error with log path" +test_case "using unauthorized session surfaces auth error with logs hint" run_mcpc "$SESSION" tools-list assert_failure assert_exit_code 4 "should fail with auth exit code (4)" assert_contains "$STDERR" "Authentication required by server" -assert_contains "$STDERR" "check logs at" -assert_contains "$STDERR" "bridge-${SESSION}.log" +assert_contains "$STDERR" "mcpc ${SESSION} logs" test_pass test_done diff --git a/test/unit/cli/logs.test.ts b/test/unit/cli/logs.test.ts new file mode 100644 index 0000000..78d3526 --- /dev/null +++ b/test/unit/cli/logs.test.ts @@ -0,0 +1,202 @@ +/** + * Unit tests for the `showLogs` command handler. + * + * Drives the real handler against a tmp MCPC_HOME_DIR. Captures stdout/stderr. + */ + +// Mock chalk to plain strings (Jest can't handle chalk's ESM imports). +const id = (s: string): string => s; +jest.mock('chalk', () => { + const m = { + cyan: id, + yellow: id, + red: id, + dim: id, + gray: id, + bold: id, + green: id, + greenBright: id, + blue: id, + magenta: id, + white: id, + }; + return { default: m, ...m }; +}); + +import { mkdtemp, mkdir, writeFile, rm } from 'fs/promises'; +import { tmpdir } from 'os'; +import { join } from 'path'; +import { saveSession } from '../../../src/lib/sessions'; +import { showLogs } from '../../../src/cli/commands/logs'; +import type { OutputMode } from '../../../src/lib/types'; + +interface Captured { + stdout: string; + stderr: string; +} + +async function capture(fn: () => Promise): Promise { + const stdout: string[] = []; + const stderr: string[] = []; + // eslint-disable-next-line @typescript-eslint/unbound-method + const origLog = console.log; + // eslint-disable-next-line @typescript-eslint/unbound-method + const origErr = console.error; + console.log = (...args: unknown[]): void => { + stdout.push(args.map((a) => (typeof a === 'string' ? a : JSON.stringify(a))).join(' ')); + }; + console.error = (...args: unknown[]): void => { + stderr.push(args.map((a) => (typeof a === 'string' ? a : JSON.stringify(a))).join(' ')); + }; + try { + await fn(); + } finally { + console.log = origLog; + console.error = origErr; + } + return { stdout: stdout.join('\n'), stderr: stderr.join('\n') }; +} + +async function seedSession(name: string): Promise { + await saveSession(name, { + server: { url: 'https://example.com' }, + transport: 'http', + status: 'live', + } as never); +} + +describe('showLogs (CLI command)', () => { + let homeDir: string; + let originalHome: string | undefined; + + beforeEach(async () => { + homeDir = await mkdtemp(join(tmpdir(), 'mcpc-cmdlogs-test-')); + originalHome = process.env.MCPC_HOME_DIR; + process.env.MCPC_HOME_DIR = homeDir; + await mkdir(join(homeDir, 'logs'), { recursive: true }); + }); + + afterEach(async () => { + if (originalHome === undefined) delete process.env.MCPC_HOME_DIR; + else process.env.MCPC_HOME_DIR = originalHome; + await rm(homeDir, { recursive: true, force: true }); + }); + + it('rejects targets without a leading @', async () => { + await expect( + showLogs('https://example.com', { outputMode: 'human' as OutputMode }) + ).rejects.toThrow(/requires a session target/); + }); + + it('errors when session does not exist', async () => { + await expect( + showLogs('@does-not-exist', { outputMode: 'human' as OutputMode }) + ).rejects.toThrow(/Session not found: @does-not-exist/); + }); + + it('errors with a friendly message on invalid --since', async () => { + await seedSession('@x'); + await expect( + showLogs('@x', { outputMode: 'human' as OutputMode, since: 'not-a-date' }) + ).rejects.toThrow(/Invalid --since value/); + }); + + it('writes header to stderr and lines to stdout in human mode', async () => { + await seedSession('@x'); + const logFile = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile( + logFile, + '[2026-04-28T10:00:00.000Z] [INFO] [test] hello\n' + + '[2026-04-28T10:00:01.000Z] [INFO] [test] world\n' + ); + const out = await capture(() => + showLogs('@x', { outputMode: 'human' as OutputMode, tail: 100 }) + ); + expect(out.stderr).toContain('@x'); + expect(out.stderr).toContain(logFile); + expect(out.stderr).toContain('last 100 lines'); + expect(out.stdout).toContain('hello'); + expect(out.stdout).toContain('world'); + }); + + it('shows "no logs yet" header when log file is missing', async () => { + await seedSession('@x'); + const out = await capture(() => showLogs('@x', { outputMode: 'human' as OutputMode })); + expect(out.stderr).toContain('no logs yet for @x'); + expect(out.stdout).toBe(''); + }); + + it('JSON mode emits structured records', async () => { + await seedSession('@x'); + const logFile = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile( + logFile, + '[2026-04-28T10:00:00.000Z] [INFO] [test] one\n' + + '======== banner ========\n' + + '[2026-04-28T10:00:01.000Z] [WARN] [test] two\n' + ); + const out = await capture(() => showLogs('@x', { outputMode: 'json' as OutputMode })); + expect(out.stderr).toBe(''); + const parsed = JSON.parse(out.stdout) as Array>; + expect(parsed).toHaveLength(3); + expect(parsed[0]).toMatchObject({ + ts: '2026-04-28T10:00:00.000Z', + level: 'info', + context: 'test', + message: 'one', + }); + expect(parsed[1]).toMatchObject({ ts: null, raw: '======== banner ========' }); + expect(parsed[2]).toMatchObject({ + ts: '2026-04-28T10:00:01.000Z', + level: 'warn', + message: 'two', + }); + }); + + it('JSON mode honours --tail', async () => { + await seedSession('@x'); + const logFile = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(logFile, 'a\nb\nc\nd\ne\n'); + const out = await capture(() => showLogs('@x', { outputMode: 'json' as OutputMode, tail: 2 })); + const parsed = JSON.parse(out.stdout) as Array>; + expect(parsed).toHaveLength(2); + expect(parsed[0]).toMatchObject({ raw: 'd' }); + expect(parsed[1]).toMatchObject({ raw: 'e' }); + }); + + it('JSON mode honours --since', async () => { + await seedSession('@x'); + const logFile = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile( + logFile, + '[2026-04-28T08:00:00.000Z] [INFO] old\n' + '[2026-04-28T13:00:00.000Z] [INFO] new\n' + ); + const out = await capture(() => + showLogs('@x', { + outputMode: 'json' as OutputMode, + since: '2026-04-28T12:00:00Z', + }) + ); + const parsed = JSON.parse(out.stdout) as Array>; + expect(parsed).toHaveLength(1); + expect(parsed[0]).toMatchObject({ message: 'new' }); + }); + + it('header shows file count when rotated files are present', async () => { + await seedSession('@x'); + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'curr\n'); + await writeFile(join(dir, 'bridge-@x.log.1'), 'one\n'); + await writeFile(join(dir, 'bridge-@x.log.2'), 'two\n'); + const out = await capture(() => showLogs('@x', { outputMode: 'human' as OutputMode })); + expect(out.stderr).toContain('3 files'); + expect(out.stderr).toContain('rotated'); + }); + + it('default tail is 50 (advertised in header)', async () => { + await seedSession('@x'); + await writeFile(join(homeDir, 'logs', 'bridge-@x.log'), 'one\n'); + const out = await capture(() => showLogs('@x', { outputMode: 'human' as OutputMode })); + expect(out.stderr).toContain('last 50 lines'); + }); +}); diff --git a/test/unit/lib/log-reader.test.ts b/test/unit/lib/log-reader.test.ts new file mode 100644 index 0000000..6f685a1 --- /dev/null +++ b/test/unit/lib/log-reader.test.ts @@ -0,0 +1,479 @@ +/** + * Unit tests for the log-reader module. + */ + +import { mkdtemp, mkdir, writeFile, appendFile, rename, rm } from 'fs/promises'; +import { tmpdir } from 'os'; +import { join } from 'path'; +import { + followLog, + getBridgeLogPath, + listLogFiles, + parseDuration, + parseLogLine, + readRecentLogLines, + resolveSince, +} from '../../../src/lib/log-reader'; + +describe('parseLogLine', () => { + it('parses a well-formed line with context', () => { + const rec = parseLogLine( + '[2026-04-28T12:01:14.231Z] [INFO] [bridge-manager] Started bridge for @apify' + ); + expect(rec.ts).toBe('2026-04-28T12:01:14.231Z'); + expect(rec.level).toBe('info'); + expect(rec.context).toBe('bridge-manager'); + expect(rec.message).toBe('Started bridge for @apify'); + expect(rec.raw).toBeUndefined(); + }); + + it('parses a line without context', () => { + const rec = parseLogLine('[2026-04-28T12:01:14.231Z] [WARN] something happened'); + expect(rec.level).toBe('warn'); + expect(rec.context).toBeNull(); + expect(rec.message).toBe('something happened'); + }); + + it('parses every standard log level', () => { + for (const level of ['DEBUG', 'INFO', 'WARN', 'ERROR']) { + const rec = parseLogLine(`[2026-04-28T12:00:00.000Z] [${level}] msg`); + expect(rec.level).toBe(level.toLowerCase()); + } + }); + + it('handles a missing message body', () => { + const rec = parseLogLine('[2026-04-28T12:00:00.000Z] [INFO]'); + expect(rec.ts).toBe('2026-04-28T12:00:00.000Z'); + expect(rec.level).toBe('info'); + expect(rec.message).toBe(''); + }); + + it('falls back to raw for non-matching lines', () => { + const rec = parseLogLine('========================================'); + expect(rec.ts).toBeNull(); + expect(rec.level).toBeNull(); + expect(rec.context).toBeNull(); + expect(rec.raw).toBe('========================================'); + }); + + it('falls back to raw for stack-trace continuation lines', () => { + const rec = parseLogLine(' at Foo.bar (/path/to/file.ts:42:13)'); + expect(rec.ts).toBeNull(); + expect(rec.raw).toBe(' at Foo.bar (/path/to/file.ts:42:13)'); + }); + + it('falls back to raw for empty input', () => { + const rec = parseLogLine(''); + expect(rec.ts).toBeNull(); + expect(rec.raw).toBe(''); + }); +}); + +describe('parseDuration', () => { + it('parses common shortforms', () => { + expect(parseDuration('30s')).toBe(30 * 1000); + expect(parseDuration('5m')).toBe(5 * 60 * 1000); + expect(parseDuration('2h')).toBe(2 * 60 * 60 * 1000); + expect(parseDuration('1d')).toBe(24 * 60 * 60 * 1000); + expect(parseDuration('1w')).toBe(7 * 24 * 60 * 60 * 1000); + }); + + it('parses long unit names', () => { + expect(parseDuration('30sec')).toBe(30 * 1000); + expect(parseDuration('5mins')).toBe(5 * 60 * 1000); + expect(parseDuration('2hrs')).toBe(2 * 60 * 60 * 1000); + expect(parseDuration('3days')).toBe(3 * 24 * 60 * 60 * 1000); + expect(parseDuration('2wks')).toBe(2 * 7 * 24 * 60 * 60 * 1000); + }); + + it('is case-insensitive and tolerant of whitespace', () => { + expect(parseDuration('30S')).toBe(30 * 1000); + expect(parseDuration(' 5m ')).toBe(5 * 60 * 1000); + }); + + it('returns null for garbage', () => { + expect(parseDuration('1y')).toBeNull(); // years not supported + expect(parseDuration('abc')).toBeNull(); + expect(parseDuration('')).toBeNull(); + expect(parseDuration('m5')).toBeNull(); // wrong order + expect(parseDuration('5')).toBeNull(); // missing unit + expect(parseDuration('-5m')).toBeNull(); // negative not supported + }); +}); + +describe('resolveSince', () => { + it('treats durations as relative to now', () => { + const now = Date.now(); + const d = resolveSince('1h'); + expect(d).not.toBeNull(); + const diff = now - d!.getTime(); + expect(diff).toBeGreaterThanOrEqual(60 * 60 * 1000 - 1000); + expect(diff).toBeLessThanOrEqual(60 * 60 * 1000 + 1000); + }); + + it('parses ISO 8601 timestamps', () => { + const d = resolveSince('2026-04-28T12:00:00Z'); + expect(d?.toISOString()).toBe('2026-04-28T12:00:00.000Z'); + }); + + it('parses ISO 8601 with milliseconds', () => { + const d = resolveSince('2026-04-28T12:00:00.500Z'); + expect(d?.toISOString()).toBe('2026-04-28T12:00:00.500Z'); + }); + + it('returns null for invalid input', () => { + expect(resolveSince('not a date')).toBeNull(); + expect(resolveSince('')).toBeNull(); + }); +}); + +describe('getBridgeLogPath', () => { + it('returns expected path under MCPC_HOME_DIR/logs', () => { + const original = process.env.MCPC_HOME_DIR; + process.env.MCPC_HOME_DIR = '/tmp/mcpc-fake'; + try { + const p = getBridgeLogPath('@x'); + expect(p).toBe('/tmp/mcpc-fake/logs/bridge-@x.log'); + } finally { + if (original === undefined) delete process.env.MCPC_HOME_DIR; + else process.env.MCPC_HOME_DIR = original; + } + }); +}); + +describe('listLogFiles + readRecentLogLines', () => { + let homeDir: string; + let originalHome: string | undefined; + + beforeEach(async () => { + homeDir = await mkdtemp(join(tmpdir(), 'mcpc-logs-test-')); + originalHome = process.env.MCPC_HOME_DIR; + process.env.MCPC_HOME_DIR = homeDir; + await mkdir(join(homeDir, 'logs'), { recursive: true }); + }); + + afterEach(async () => { + if (originalHome === undefined) delete process.env.MCPC_HOME_DIR; + else process.env.MCPC_HOME_DIR = originalHome; + await rm(homeDir, { recursive: true, force: true }); + }); + + it('returns [] when no log files exist', async () => { + const files = await listLogFiles('@nope'); + expect(files).toEqual([]); + const lines = await readRecentLogLines('@nope'); + expect(lines).toEqual([]); + }); + + it('returns [] when only logs directory is missing', async () => { + await rm(join(homeDir, 'logs'), { recursive: true, force: true }); + expect(await listLogFiles('@nope')).toEqual([]); + expect(await readRecentLogLines('@nope')).toEqual([]); + }); + + it('orders rotated files oldest-first, then current last', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'current\n'); + await writeFile(join(dir, 'bridge-@x.log.1'), 'one\n'); + await writeFile(join(dir, 'bridge-@x.log.2'), 'two\n'); + await writeFile(join(dir, 'bridge-@x.log.5'), 'five\n'); + const files = await listLogFiles('@x'); + expect(files.map((f) => f.split('/').pop())).toEqual([ + 'bridge-@x.log.5', + 'bridge-@x.log.2', + 'bridge-@x.log.1', + 'bridge-@x.log', + ]); + }); + + it('ignores files with non-numeric rotation suffixes', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'current\n'); + await writeFile(join(dir, 'bridge-@x.log.bak'), 'oops\n'); + await writeFile(join(dir, 'bridge-@x.log.tmp'), 'oops\n'); + const files = await listLogFiles('@x'); + expect(files.map((f) => f.split('/').pop())).toEqual(['bridge-@x.log']); + }); + + it('does not match other sessions whose names share a prefix', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'mine\n'); + await writeFile(join(dir, 'bridge-@xyz.log'), 'other\n'); + await writeFile(join(dir, 'bridge-@xyz.log.1'), 'other-rotated\n'); + const files = await listLogFiles('@x'); + expect(files.map((f) => f.split('/').pop())).toEqual(['bridge-@x.log']); + }); + + it('handles a missing trailing newline on the last line', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'a\nb\nno-newline'); + const lines = await readRecentLogLines('@x'); + expect(lines).toEqual(['a', 'b', 'no-newline']); + }); + + it('preserves blank/empty lines between log entries', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'a\n\nb\n'); + const lines = await readRecentLogLines('@x'); + expect(lines).toEqual(['a', '', 'b']); + }); + + it('tail returns the last N lines, spanning rotations when needed', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log.1'), 'line1\nline2\nline3\nline4\nline5\n'); + await writeFile(join(dir, 'bridge-@x.log'), 'line6\nline7\nline8\n'); + const lines = await readRecentLogLines('@x', { tail: 6 }); + expect(lines).toEqual(['line3', 'line4', 'line5', 'line6', 'line7', 'line8']); + }); + + it('tail spans multiple rotation files when needed', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log.3'), 'r3a\nr3b\n'); + await writeFile(join(dir, 'bridge-@x.log.2'), 'r2a\nr2b\n'); + await writeFile(join(dir, 'bridge-@x.log.1'), 'r1a\nr1b\n'); + await writeFile(join(dir, 'bridge-@x.log'), 'cur\n'); + const lines = await readRecentLogLines('@x', { tail: 6 }); + // 7 lines total; tail 6 drops the oldest "r3a" + expect(lines).toEqual(['r3b', 'r2a', 'r2b', 'r1a', 'r1b', 'cur']); + }); + + it('tail does not read older files when current alone has enough lines', async () => { + const dir = join(homeDir, 'logs'); + // If readRecentLogLines opened the rotated file unnecessarily, the test + // would still pass — so we validate the bounded slice instead. + await writeFile(join(dir, 'bridge-@x.log.1'), 'old1\nold2\n'); + await writeFile(join(dir, 'bridge-@x.log'), 'a\nb\nc\nd\ne\n'); + const lines = await readRecentLogLines('@x', { tail: 3 }); + expect(lines).toEqual(['c', 'd', 'e']); + }); + + it('tail larger than total returns everything in chronological order', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log.1'), 'old1\nold2\n'); + await writeFile(join(dir, 'bridge-@x.log'), 'new1\n'); + const lines = await readRecentLogLines('@x', { tail: 1000 }); + expect(lines).toEqual(['old1', 'old2', 'new1']); + }); + + it('tail = 0 returns no lines', async () => { + const dir = join(homeDir, 'logs'); + await writeFile(join(dir, 'bridge-@x.log'), 'a\nb\nc\n'); + const lines = await readRecentLogLines('@x', { tail: 0 }); + expect(lines).toEqual([]); + }); + + it('--since filters by timestamp and keeps unparseable lines', async () => { + const dir = join(homeDir, 'logs'); + const old = '[2026-04-28T10:00:00.000Z] [INFO] old line'; + const banner = '========================================'; + const newer = '[2026-04-28T13:00:00.000Z] [INFO] new line'; + await writeFile(join(dir, 'bridge-@x.log'), `${old}\n${banner}\n${newer}\n`); + const lines = await readRecentLogLines('@x', { + since: new Date('2026-04-28T12:00:00.000Z'), + }); + expect(lines).toEqual([banner, newer]); + }); + + it('--since drops everything when all lines pre-date cutoff', async () => { + const dir = join(homeDir, 'logs'); + await writeFile( + join(dir, 'bridge-@x.log'), + '[2026-04-28T08:00:00.000Z] [INFO] a\n[2026-04-28T08:30:00.000Z] [INFO] b\n' + ); + const lines = await readRecentLogLines('@x', { + since: new Date('2026-04-28T12:00:00.000Z'), + }); + expect(lines).toEqual([]); + }); + + it('--since spans rotated files', async () => { + const dir = join(homeDir, 'logs'); + await writeFile( + join(dir, 'bridge-@x.log.1'), + '[2026-04-28T08:00:00.000Z] [INFO] old\n' + + '[2026-04-28T11:00:00.000Z] [INFO] within window\n' + ); + await writeFile(join(dir, 'bridge-@x.log'), '[2026-04-28T13:00:00.000Z] [INFO] newer\n'); + const lines = await readRecentLogLines('@x', { + since: new Date('2026-04-28T10:00:00.000Z'), + }); + expect(lines).toEqual([ + '[2026-04-28T11:00:00.000Z] [INFO] within window', + '[2026-04-28T13:00:00.000Z] [INFO] newer', + ]); + }); + + it('combines tail and --since (since is a floor, tail caps the result)', async () => { + const dir = join(homeDir, 'logs'); + await writeFile( + join(dir, 'bridge-@x.log'), + '[2026-04-28T08:00:00.000Z] [INFO] way old\n' + + '[2026-04-28T11:00:00.000Z] [INFO] in-window-1\n' + + '[2026-04-28T11:30:00.000Z] [INFO] in-window-2\n' + + '[2026-04-28T12:00:00.000Z] [INFO] in-window-3\n' + ); + const lines = await readRecentLogLines('@x', { + since: new Date('2026-04-28T10:00:00.000Z'), + tail: 2, + }); + expect(lines).toEqual([ + '[2026-04-28T11:30:00.000Z] [INFO] in-window-2', + '[2026-04-28T12:00:00.000Z] [INFO] in-window-3', + ]); + }); +}); + +describe('followLog', () => { + // Polling-based file follow is timing-sensitive. We use a 50ms poll interval + // and a small wait helper to keep these tests reasonably fast and reliable. + + let homeDir: string; + let originalHome: string | undefined; + + beforeEach(async () => { + homeDir = await mkdtemp(join(tmpdir(), 'mcpc-follow-test-')); + originalHome = process.env.MCPC_HOME_DIR; + process.env.MCPC_HOME_DIR = homeDir; + await mkdir(join(homeDir, 'logs'), { recursive: true }); + }); + + afterEach(async () => { + if (originalHome === undefined) delete process.env.MCPC_HOME_DIR; + else process.env.MCPC_HOME_DIR = originalHome; + await rm(homeDir, { recursive: true, force: true }); + }); + + const sleep = (ms: number): Promise => new Promise((r) => setTimeout(r, ms)); + + async function waitFor(predicate: () => boolean, timeoutMs = 2000, stepMs = 25): Promise { + const start = Date.now(); + while (!predicate()) { + if (Date.now() - start > timeoutMs) { + throw new Error(`waitFor timed out after ${timeoutMs}ms`); + } + await sleep(stepMs); + } + } + + it('emits lines appended after follow starts', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, 'pre-existing\n'); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { pollIntervalMs: 50 }); + try { + // Give the watcher a tick to start at end-of-file. + await sleep(100); + await appendFile(path, 'one\n'); + await appendFile(path, 'two\n'); + await waitFor(() => seen.length >= 2); + expect(seen).toEqual(['one', 'two']); + } finally { + await sub.stop(); + } + }); + + it('does not replay backlog by default', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, 'old1\nold2\nold3\n'); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { pollIntervalMs: 50 }); + try { + await sleep(150); + expect(seen).toEqual([]); + } finally { + await sub.stop(); + } + }); + + it('handles partial writes that complete a line later', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, ''); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { pollIntervalMs: 50 }); + try { + await sleep(100); + await appendFile(path, 'hello '); + await sleep(100); + // Line shouldn't be emitted yet: still buffered without a newline. + expect(seen).toEqual([]); + await appendFile(path, 'world\n'); + await waitFor(() => seen.length >= 1); + expect(seen).toEqual(['hello world']); + } finally { + await sub.stop(); + } + }); + + it('detects rotation (file replaced with smaller content)', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, 'pre\n'); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { pollIntervalMs: 50 }); + try { + await sleep(100); + // Append, then "rotate" by renaming current to .1 and writing a fresh, + // smaller file at the same path — this is what FileLogger does. + await appendFile(path, 'before-rotation\n'); + await waitFor(() => seen.includes('before-rotation')); + await rename(path, path + '.1'); + await writeFile(path, 'fresh-line\n'); + await waitFor(() => seen.includes('fresh-line'), 3000); + expect(seen).toContain('before-rotation'); + expect(seen).toContain('fresh-line'); + } finally { + await sub.stop(); + } + }); + + it('startAtBeginning replays existing content', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, 'a\nb\nc\n'); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { + pollIntervalMs: 50, + startAtBeginning: true, + }); + try { + await waitFor(() => seen.length >= 3); + expect(seen).toEqual(['a', 'b', 'c']); + } finally { + await sub.stop(); + } + }); + + it('survives following a file that does not exist yet', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { pollIntervalMs: 50 }); + try { + await sleep(100); + // Now the file appears + await writeFile(path, 'first-line\n'); + await waitFor(() => seen.includes('first-line'), 3000); + expect(seen).toContain('first-line'); + } finally { + await sub.stop(); + } + }); + + it('stop() flushes a partial trailing line', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, ''); + const seen: string[] = []; + const sub = followLog('@x', (l) => seen.push(l), { pollIntervalMs: 50 }); + await sleep(100); + await appendFile(path, 'no-trailing-newline'); + // Wait for the read to drain the bytes into the internal buffer. + await sleep(150); + await sub.stop(); + expect(seen).toContain('no-trailing-newline'); + }); + + it('stop() is idempotent', async () => { + const path = join(homeDir, 'logs', 'bridge-@x.log'); + await writeFile(path, ''); + const sub = followLog('@x', () => {}, { pollIntervalMs: 50 }); + await sub.stop(); + await expect(sub.stop()).resolves.toBeUndefined(); + }); +});