From 0cd7948ba0dc3be849241e470afc75f2caf01ab8 Mon Sep 17 00:00:00 2001 From: Hugo Richard Date: Sun, 4 Oct 2026 12:24:18 +0100 Subject: [PATCH 1/5] feat(cli): add evlog logs to read the events the fs drain wrote --- .changeset/cli-logs.md | 5 + .changeset/fs-reader-pretty.md | 5 + .gitignore | 2 + apps/docs/content/3.cli/0.overview.md | 2 +- apps/docs/content/3.cli/10.logs.md | 102 +++++++ packages/cli/README.md | 8 +- packages/cli/src/commands/index.ts | 4 + packages/cli/src/commands/logs.ts | 129 +++++++++ packages/cli/src/index.ts | 3 +- packages/cli/src/lib/errors.ts | 49 ++++ packages/cli/src/lib/logs/query.ts | 184 +++++++++++++ packages/cli/src/lib/logs/render.ts | 189 +++++++++++++ packages/cli/test/logs.command.test.ts | 249 ++++++++++++++++++ packages/evlog/src/adapters/fs.ts | 64 ++++- .../evlog/test/adapters/fs-reader.test.ts | 39 +++ skills/analyze-logs/SKILL.md | 11 + 16 files changed, 1028 insertions(+), 17 deletions(-) create mode 100644 .changeset/cli-logs.md create mode 100644 .changeset/fs-reader-pretty.md create mode 100644 apps/docs/content/3.cli/10.logs.md create mode 100644 packages/cli/src/commands/logs.ts create mode 100644 packages/cli/src/lib/logs/query.ts create mode 100644 packages/cli/src/lib/logs/render.ts create mode 100644 packages/cli/test/logs.command.test.ts diff --git a/.changeset/cli-logs.md b/.changeset/cli-logs.md new file mode 100644 index 000000000..e5cb2b62b --- /dev/null +++ b/.changeset/cli-logs.md @@ -0,0 +1,5 @@ +--- +"@evlog/cli": minor +--- + +`evlog logs` reads the wide events the fs drain wrote to `.evlog/logs`: the last 50 (`evlog logs`), the failures (`evlog logs errors`), the slowest (`evlog logs slow --over 1s`), or one request in full by id (`evlog logs `, a UUID prefix is enough). Filters compose with every view: `--since 15m`, `--until`, `--level error,fatal`, `--path`, `--status 5xx`, `--limit`, `--dir`. `-f` follows new events like `tail -f`; `--json` returns the events as JSON. It finds the project's log directory the way `doctor` does, reads both the compact and the pretty layout, and never writes. diff --git a/.changeset/fs-reader-pretty.md b/.changeset/fs-reader-pretty.md new file mode 100644 index 000000000..1136cc666 --- /dev/null +++ b/.changeset/fs-reader-pretty.md @@ -0,0 +1,5 @@ +--- +"evlog": patch +--- + +`readFsLogs()` and `tailFsLogs()` from `evlog/fs` now read files the drain wrote with `pretty: true`, assembling each indented event, where they used to skip every line of them as malformed. diff --git a/.gitignore b/.gitignore index 2c326881a..d4d81086a 100644 --- a/.gitignore +++ b/.gitignore @@ -17,6 +17,8 @@ node_modules logs !examples/eve/app/api/demo/logs/ !examples/eve/app/api/demo/logs/** +!packages/cli/src/lib/logs/ +!packages/cli/src/lib/logs/** *.log # Misc diff --git a/apps/docs/content/3.cli/0.overview.md b/apps/docs/content/3.cli/0.overview.md index 8744c70dc..89326a400 100644 --- a/apps/docs/content/3.cli/0.overview.md +++ b/apps/docs/content/3.cli/0.overview.md @@ -21,7 +21,7 @@ The `evlog` executable ships with the `evlog` package. It runs separately from y Start with [`evlog map`](/cli/map) to check supported entry points for evlog logging patterns and get a static observability score with suggested fixes. It writes `evlog.map.json` unless you pass `--no-write`. The score describes recognized source patterns, not the logs your handlers produce in production. -[`evlog init`](/cli/init) adds evlog configuration to the app. [`evlog agents`](/cli/agents) writes logging conventions for the AI agents working in the repository. +[`evlog init`](/cli/init) adds evlog configuration to the app. [`evlog logs`](/cli/logs) reads the events the fs drain wrote: the latest requests, the failures, the slowest, or one request in full. [`evlog agents`](/cli/agents) writes logging conventions for the AI agents working in the repository. ::warning{icon="i-lucide-flask-conical"} **Early days.** `evlog map` has adapters for Nuxt, Nitro, Next.js App Router, TanStack Start, Hono, Express, and Fastify. Each adapter recognizes specific entry-point shapes. Check the detected framework and entry-point count before interpreting the score. Rules can change between releases, so [pin the version](/cli/ci#pin-the-version) when you gate CI on the number. diff --git a/apps/docs/content/3.cli/10.logs.md b/apps/docs/content/3.cli/10.logs.md new file mode 100644 index 000000000..0599c39bf --- /dev/null +++ b/apps/docs/content/3.cli/10.logs.md @@ -0,0 +1,102 @@ +--- +title: evlog logs +description: Read the wide events your app wrote to .evlog/logs from the terminal — the latest requests, the failures, the slowest, or one request in full. +navigation: + title: logs + icon: i-lucide-scroll-text +links: + - label: File system adapter + icon: i-lucide-folder-open + to: /integrate/adapters/self-hosted/fs + color: neutral + variant: subtle +--- + +`evlog logs` reads the events the [file system drain](/integrate/adapters/self-hosted/fs) wrote and shows them the way you would want to read them: one line per request, the thing that mattered at the end of it, and one request in full when you have its id. It reads files; it never touches the app. + +```bash [Terminal] +evlog logs +``` + +```text [Output] +6 events · .evlog/logs + +08:00:00 GET /api/health 200 2ms +10:00:00 POST /api/checkout 402 412ms ✗ Error: Payment processing failed · Card declined by issuer +10:30:00 GET /api/reports 200 1.2s report.id=r-1 +11:00:00 POST /api/refund 200 80ms audit billing.refund user:usr_42 → invoice:inv_1 success +11:30:00 GET /api/items 500 30ms +11:45:00 GET /api/items warn 700ms user.id=usr_7 + +evlog logs errors — the 2 that failed · evlog logs — one request in full · evlog logs slow — worst first +``` + +The newest event is at the bottom, like `tail`. Nothing is written: the fs drain writes on every request and this reads what it wrote, both the compact and the `pretty: true` layout, across the dated files. + +## Four views + +| Command | Shows | +| --- | --- | +| `evlog logs` | The last 50 events, oldest first | +| `evlog logs errors` | Events that failed: a `5xx` status, an `error` or `fatal` level, or an `error` block | +| `evlog logs slow` | Events over 500ms, worst first (`--over 1s` to move the bar) | +| `evlog logs ` | Every event carrying that id, in full: request, error with `why` and `fix`, audit record, then the business fields. The first block of a UUID is enough | + +## Filters + +Filters compose with any view. + +| Flag | What it does | +| --- | --- | +| `--since ` | Only events after: a duration back from now (`15m`, `2h`, `3d`) or a date (`2026-10-01`, `2026-10-01T09:00`) | +| `--until ` | Only events before, same spellings | +| `--level ` | Only these levels: `trace`, `debug`, `info`, `warn`, `error`, `fatal` | +| `--path ` | Only requests on this exact path | +| `--status ` | Only this status (`404`) or class (`4xx`) | +| `--over ` | For `slow`: what a request has to exceed (default `500ms`) | +| `--limit ` | Most events to show (default 50) | +| `--dir ` | Read another directory (default: the project's `.evlog/logs`, or the directory its fs drain is configured for) | +| `-f`, `--follow` | Keep reading as the app writes, like `tail -f`; `Ctrl-C` stops | +| `--json` | The events as JSON on stdout | +| `--cwd ` | Another project in the workspace | + +A time, level, status or limit that cannot be read stops the command (exit 2) rather than silently widening the query. + +```bash [Terminal] +evlog logs errors --since 1h +evlog logs slow --over 2s --path /api/reports +evlog logs --status 5xx --level error,fatal --limit 20 +evlog logs -f --path /api/checkout +``` + +## For agents + +`--json` returns one envelope: the directory, the view, how many events matched, and the events shown. + +```bash [Terminal] +evlog logs errors --since 30m --json +``` + +```json +{ + "schemaVersion": 2, + "dir": "/app/.evlog/logs", + "view": "errors", + "count": 2, + "matched": 2, + "events": [ { "timestamp": "…", "path": "/api/checkout", "status": 402, "error": { "data": { "why": "…", "fix": "…" } } } ] +} +``` + +With `--follow --json`, each new event is one JSON line on stdout, since a stream has no end. The [`analyze-logs` skill](/reference/agent-skills) calls `evlog logs` first and falls back to reading the files only when the CLI is not available. + +## What it will not do + +- **It reads local files.** A remote drain (Axiom, Datadog, …) has its own query language and UI; this command does not wrap them. +- **One directory per run.** In a monorepo, run it from the app (`--cwd apps/web`) or pass `--dir`. +- **No aggregation yet.** Counts by route or status are a `jq` away from `--json`; a `stats` view may come later. + +## Next + +- [File system drain](/integrate/adapters/self-hosted/fs): what writes the files, rotation, `pretty` +- [`evlog map`](/cli/map): which handlers emit a wide event at all diff --git a/packages/cli/README.md b/packages/cli/README.md index 329696036..a195a0bd8 100644 --- a/packages/cli/README.md +++ b/packages/cli/README.md @@ -64,9 +64,15 @@ pnpm evlog map | `evlog map --baseline [ref]` | Exit 1 on a regression against the committed `evlog.map.json` (path, or `git:`) | | `evlog map --no-write` | Skip writing `evlog.map.json` to the project root | | `evlog map --format github` | GitHub Actions annotations on stdout; or use [`evloghq/action`](https://github.com/evloghq/action), which adds the base comparison, the job summary and a pull request comment | -| `evlog map --format sarif` | SARIF 2.1.0 on stdout, for code scanning | | `evlog map --verbose` | Show per-file parse warnings | | `evlog map --cwd ` | Scan another app in the workspace | +| `evlog logs` | The last 50 wide events the fs drain wrote, oldest first | +| `evlog logs errors` | The ones that failed: a `5xx`, an `error` level, or an `error` block | +| `evlog logs slow [--over 1s]` | Over the bar (default 500ms), worst first | +| `evlog logs ` | One request in full: error with `why`/`fix`, audit record, business fields | +| `evlog logs -f` | Follow new events as the app writes them | +| `evlog logs --since 15m --path /api/x --status 5xx --level error` | Filters, composable with every view | +| `evlog logs --json` | The events as JSON on stdout (one line per event with `-f`) | | `evlog doctor` | Monorepo-aware diagnosis: Node, project/workspace, stack, evlog install, `.evlog/logs` | | `evlog doctor --cwd ` | Run against another directory | | `evlog doctor --debug` | Same, plus a debug wide event (see Debug) | diff --git a/packages/cli/src/commands/index.ts b/packages/cli/src/commands/index.ts index 76bd2ea3c..e36e99b6b 100644 --- a/packages/cli/src/commands/index.ts +++ b/packages/cli/src/commands/index.ts @@ -24,6 +24,10 @@ export const subCommands = { { name: 'doctor', description: 'Diagnose your evlog setup' }, () => import('./doctor'), ), + logs: lazyCommand( + { name: 'logs', description: 'Read the wide events your app wrote to .evlog/logs' }, + () => import('./logs'), + ), map: lazyCommand( { name: 'map', description: 'Static observability map — Lighthouse for wide events' }, () => import('./map'), diff --git a/packages/cli/src/commands/logs.ts b/packages/cli/src/commands/logs.ts new file mode 100644 index 000000000..9590c186d --- /dev/null +++ b/packages/cli/src/commands/logs.ts @@ -0,0 +1,129 @@ +import { existsSync } from 'node:fs' +import { resolve } from 'node:path' +import { telemetry } from '@evlog/telemetry' +import { EvlogError } from 'evlog' +import type { WideEvent } from 'evlog' +import { readFsLogs, tailFsLogs } from 'evlog/fs' +import type { CliContext } from '../core/context' +import { createStyle, EXIT_FAIL, EXIT_USAGE } from '../core/output' +import { defineEvlogCommand } from '../lib/command' +import { cliErrors } from '../lib/errors' +import { buildQuery, select } from '../lib/logs/query' +import type { LogsArgs, LogsQuery } from '../lib/logs/query' +import { formatLine, formatLogsReport } from '../lib/logs/render' +import type { LogsResult } from '../lib/logs/render' +import { findConfiguredFsDrain, findLogsSink, resolveProject } from '../lib/project' + +export type { LogsResult } from '../lib/logs/render' + +/** + * Where the events are. `--dir` wins; otherwise the sink the project already + * writes to, or the directory its fs drain is configured for, which may not + * exist yet when nothing has run. + */ +export async function resolveLogsDir(ctx: CliContext, dir: string | undefined): Promise { + if (dir) return resolve(ctx.cwd, dir) + const project = await resolveProject(ctx.cwd) + const sink = await findLogsSink(project) + if (sink) return sink.dir + const configured = await findConfiguredFsDrain(project, ctx.env) + if (configured) return resolve(project.packageDir, configured.dir) + throw cliErrors.LOGS_NO_SINK({ cwd: ctx.cwd }) +} + +export interface RunLogsOptions { + dir?: string + /** Keep reading as the app writes; resolves when `signal` aborts. */ + follow?: boolean + signal?: AbortSignal + /** Called for each event that arrives while following. */ + onEvent?: (event: WideEvent) => void + now?: Date +} + +/** Read the events the query asks for. Pure with respect to the context: nothing is written. */ +export async function runLogs(ctx: CliContext, args: LogsArgs, options: RunLogsOptions = {}): Promise { + const query = buildQuery(args, options.now) + const dir = await resolveLogsDir(ctx, options.dir) + if (!existsSync(dir) && !options.follow) throw cliErrors.LOGS_NO_SINK({ cwd: ctx.cwd }) + + const matched: WideEvent[] = [] + for await (const event of readFsLogs({ dir, since: query.since, until: query.until, level: query.level, filter: query.filter })) { + matched.push(event) + } + const result: LogsResult = { dir, query, matched: matched.length, events: select(matched, query) } + + if (options.follow) { + await followLogs(dir, query, options) + } + return result +} + +async function followLogs(dir: string, query: LogsQuery, options: RunLogsOptions): Promise { + for await (const event of tailFsLogs({ dir, fromEnd: true, level: query.level, filter: query.filter, pollIntervalMs: 250, signal: options.signal })) { + options.onEvent?.(event) + } +} + +/** + * `evlog logs` — the wide events the app wrote, from the terminal. + * Logic lives in {@link runLogs}; this file owns the citty surface. + */ +export default defineEvlogCommand('logs', { + meta: { name: 'logs' }, + args: { + what: { type: 'positional', required: false, description: '`errors`, `slow`, or a request id to show in full' }, + follow: { type: 'boolean', alias: 'f', description: 'Keep reading as the app writes, like tail -f' }, + since: { type: 'string', description: 'Only events after this: a duration back (15m, 2h, 3d) or a date' }, + until: { type: 'string', description: 'Only events before this: a duration back or a date' }, + level: { type: 'string', description: 'Only these levels, comma-separated (error,fatal)' }, + path: { type: 'string', description: 'Only requests on this exact path' }, + status: { type: 'string', description: 'Only this status (500) or class (5xx)' }, + over: { type: 'string', description: 'For `slow`: the duration a request has to exceed (default 500ms)' }, + limit: { type: 'string', description: 'Most events to show (default 50)' }, + dir: { type: 'string', description: 'Log directory (default: the project\'s .evlog/logs)' }, + }, + async run({ args, cli, ui }) { + const style = createStyle(cli) + const controller = new AbortController() + const stop = (): void => controller.abort() + if (args.follow) process.once('SIGINT', stop) + + let result: LogsResult + try { + result = await runLogs(cli, args, { + dir: args.dir, + follow: args.follow, + signal: controller.signal, + onEvent: (event) => { + if (args.json) ui.stdout(JSON.stringify(event)) + else ui.human(formatLine(style, event)) + }, + }) + } catch (error) { + if (error instanceof EvlogError) { + ui.done({ + jsonMode: args.json, + json: { error: { code: error.code, message: error.message, why: error.why, fix: error.fix } }, + human: error.fix ? `${error.message}\n→ ${error.fix}` : error.message, + }) + ui.exit(error.code === cliErrors.LOGS_NO_SINK.code ? EXIT_FAIL : EXIT_USAGE) + return + } + throw error + } finally { + process.off('SIGINT', stop) + } + + telemetry.set({ logsView: result.query.view, logsFollow: args.follow === true, logsEvents: result.matched } as unknown as Record) + + /* While following, the one-shot part was already streamed line by line + before the tail started, so the report is only for the one-shot run. */ + if (args.follow) return + ui.done({ + jsonMode: args.json, + json: { dir: result.dir, view: result.query.view, count: result.events.length, matched: result.matched, events: result.events }, + human: formatLogsReport(cli, result), + }) + }, +}) diff --git a/packages/cli/src/index.ts b/packages/cli/src/index.ts index 0655be2f9..eae79fcec 100644 --- a/packages/cli/src/index.ts +++ b/packages/cli/src/index.ts @@ -5,6 +5,7 @@ import { COMMON_ARGS } from './lib/command' import { TELEMETRY_ENDPOINT, TOOL_NAME, VERSION } from './lib/constants' import { resolveCliEnvironment } from './lib/environment' import { INIT_TELEMETRY_FIELDS } from './lib/init/telemetry' +import { LOGS_TELEMETRY_FIELDS } from './lib/logs/query' import { MAP_TELEMETRY_FIELDS } from './lib/map/telemetry-fields' /** @@ -34,7 +35,7 @@ export const main = withTelemetry( can be calibrated against reality. Values are ids from this CLI's own catalog — the allowlist is what keeps a free-text answer from ever being sent. */ - collect: { fields: { ...INIT_TELEMETRY_FIELDS, ...MAP_TELEMETRY_FIELDS } }, + collect: { fields: { ...INIT_TELEMETRY_FIELDS, ...LOGS_TELEMETRY_FIELDS, ...MAP_TELEMETRY_FIELDS } }, }, ) diff --git a/packages/cli/src/lib/errors.ts b/packages/cli/src/lib/errors.ts index fa31ff609..dce1df584 100644 --- a/packages/cli/src/lib/errors.ts +++ b/packages/cli/src/lib/errors.ts @@ -246,6 +246,55 @@ export const cliErrors = defineErrorCatalog('cli', { fix: 'Drop --json, or pass --format json', tags: ['map'], }, + LOGS_NO_SINK: { + status: 404, + message: ({ cwd }: { cwd: string }) => + `No local logs under ${cwd}`, + why: 'There is no .evlog/logs directory here and no fs drain is configured, so nothing has been written to read', + fix: 'Run evlog init --drain fs, start the app and make a request, or pass --dir ', + link: 'https://evlog.dev/cli/logs', + tags: ['logs'], + }, + LOGS_INVALID_TIME: { + status: 400, + message: ({ flag, value }: { flag: string, value: string }) => + `Invalid --${flag} "${value}"`, + why: 'A time bound that cannot be read would silently become no bound, and the run would show everything', + fix: 'Pass a duration back from now (15m, 2h, 3d) or a date (2026-10-01, 2026-10-01T09:00)', + tags: ['logs'], + }, + LOGS_INVALID_LEVEL: { + status: 400, + message: ({ value }: { value: string }) => + `Unknown level "${value}"`, + why: 'Levels are the six evlog writes', + fix: 'Pass one or more of: trace, debug, info, warn, error, fatal', + tags: ['logs'], + }, + LOGS_INVALID_STATUS: { + status: 400, + message: ({ value }: { value: string }) => + `Invalid --status "${value}"`, + why: 'A status filter that cannot be read would silently match nothing', + fix: 'Pass a status (404) or a class (4xx)', + tags: ['logs'], + }, + LOGS_INVALID_DURATION: { + status: 400, + message: ({ flag, value }: { flag: string, value: string }) => + `Invalid --${flag} "${value}"`, + why: 'A duration that cannot be read would silently fall back to the default', + fix: 'Pass milliseconds (500) or a unit (500ms, 1.5s)', + tags: ['logs'], + }, + LOGS_INVALID_LIMIT: { + status: 400, + message: ({ value }: { value: string }) => + `Invalid --limit "${value}"`, + why: 'A limit that cannot be read would silently become the default', + fix: 'Pass a whole number of 1 or more, e.g. --limit 20', + tags: ['logs'], + }, }) declare module 'evlog' { diff --git a/packages/cli/src/lib/logs/query.ts b/packages/cli/src/lib/logs/query.ts new file mode 100644 index 000000000..d0321ddcc --- /dev/null +++ b/packages/cli/src/lib/logs/query.ts @@ -0,0 +1,184 @@ +import type { LogLevel, WideEvent } from 'evlog' +import { cliErrors } from '../errors' + +/** What the run shows: the latest events, the failures, the slowest, or one request. */ +const VIEWS = ['recent', 'errors', 'slow', 'trace'] as const +export type LogsView = typeof VIEWS[number] + +/** + * String fields of the `evlog logs` telemetry, with the exact set of values each may take. + * Registered on the root command without loading the reader. + */ +export const LOGS_TELEMETRY_FIELDS = { + logsView: VIEWS, +} as const satisfies Record + +const LEVELS: readonly LogLevel[] = ['trace', 'debug', 'info', 'warn', 'error', 'fatal'] + +const DURATION_UNITS: Record = { ms: 1, s: 1_000, m: 60_000, h: 3_600_000, d: 86_400_000 } + +/** `500ms`, `1.5s`, `15m`, `2h`, `3d`; a bare number is milliseconds. */ +export function parseDuration(value: string): number | undefined { + const match = /^(\d+(?:\.\d+)?)(ms|s|m|h|d)?$/.exec(value.trim()) + if (!match) return undefined + return Number(match[1]) * DURATION_UNITS[match[2] ?? 'ms']! +} + +/** + * `--since` and `--until` take a duration back from now (`15m`) or a date + * (`2026-10-01`, `2026-10-01T09:00`). `now` is a parameter so a test does not + * depend on the clock. + */ +export function parseTime(flag: 'since' | 'until', value: unknown, now: Date): Date | undefined { + if (typeof value !== 'string' || value.length === 0) return undefined + const ago = parseDuration(value) + if (ago !== undefined) return new Date(now.getTime() - ago) + const at = Date.parse(value) + if (Number.isNaN(at)) throw cliErrors.LOGS_INVALID_TIME({ flag, value }) + return new Date(at) +} + +export function parseLevels(value: unknown): LogLevel[] | undefined { + if (typeof value !== 'string' || value.length === 0) return undefined + const levels = value.split(',').map(level => level.trim()) + for (const level of levels) { + if (!(LEVELS as readonly string[]).includes(level)) throw cliErrors.LOGS_INVALID_LEVEL({ value: level }) + } + return levels as LogLevel[] +} + +/** `500` matches that status; `5xx` the whole class. */ +export function parseStatus(value: unknown): ((status: number) => boolean) | undefined { + if (typeof value !== 'string' || value.length === 0) return undefined + const clazz = /^([1-5])xx$/i.exec(value) + if (clazz) { + const hundreds = Number(clazz[1]) + return status => Math.floor(status / 100) === hundreds + } + const exact = Number(value) + if (!Number.isInteger(exact) || exact < 100 || exact > 599) throw cliErrors.LOGS_INVALID_STATUS({ value }) + return status => status === exact +} + +export function parseOver(value: unknown): number | undefined { + if (typeof value !== 'string' || value.length === 0) return undefined + const ms = parseDuration(value) + if (ms === undefined) throw cliErrors.LOGS_INVALID_DURATION({ flag: 'over', value }) + return ms +} + +const DEFAULT_LIMIT = 50 + +export function parseLimit(value: unknown): number { + if (typeof value !== 'string' || value.length === 0) return DEFAULT_LIMIT + const limit = Number(value) + if (!Number.isInteger(limit) || limit < 1) throw cliErrors.LOGS_INVALID_LIMIT({ value }) + return limit +} + +export interface LogsQuery { + view: LogsView + /** The request or trace id a `trace` view looks for. */ + id?: string + since?: Date + until?: Date + level?: LogLevel[] + limit: number + /** Lower bound on `durationMs` for the `slow` view. */ + over: number + /** Every filter the flags asked for, as one predicate for the reader. */ + filter: (event: WideEvent) => boolean +} + +export interface LogsArgs { + what?: string + since?: string + until?: string + level?: string + path?: string + status?: string + over?: string + limit?: string +} + +const DEFAULT_OVER = 500 + +export function field(event: WideEvent, key: string): unknown { + return (event as Record)[key] +} + +function text(event: WideEvent, key: string): string | undefined { + const value = field(event, key) + return typeof value === 'string' ? value : undefined +} + +function number(event: WideEvent, key: string): number | undefined { + const value = field(event, key) + return typeof value === 'number' ? value : undefined +} + +/** A failure by any of the three signals an event can carry: level, status, an error block. */ +export function isError(event: WideEvent): boolean { + if (event.level === 'error' || event.level === 'fatal') return true + const status = number(event, 'status') + if (status !== undefined && status >= 500) return true + const error = field(event, 'error') + return typeof error === 'object' && error !== null +} + +const ID_FIELDS = ['requestId', 'traceId', 'spanId', '_parentRequestId'] as const + +/** + * Whether the event belongs to the request: an exact id, or a prefix of at + * least eight characters, so the first block of a UUID is enough to type. + */ +export function matchesId(event: WideEvent, id: string): boolean { + return ID_FIELDS.some((key) => { + const value = text(event, key) + if (!value) return false + return value === id || (id.length >= 8 && value.startsWith(id)) + }) +} + +/** Turn the flags into a query. Validation happens here, before any file is read. */ +export function buildQuery(args: LogsArgs, now = new Date()): LogsQuery { + const since = parseTime('since', args.since, now) + const until = parseTime('until', args.until, now) + const level = parseLevels(args.level) + const status = parseStatus(args.status) + const over = parseOver(args.over) ?? DEFAULT_OVER + const limit = parseLimit(args.limit) + const path = typeof args.path === 'string' && args.path.length > 0 ? args.path : undefined + + const what = args.what?.trim() + const view: LogsView = what === 'errors' ? 'errors' : what === 'slow' ? 'slow' : what ? 'trace' : 'recent' + const id = view === 'trace' ? what : undefined + + const filter = (event: WideEvent): boolean => { + if (path !== undefined && text(event, 'path') !== path) return false + if (status !== undefined) { + const value = number(event, 'status') + if (value === undefined || !status(value)) return false + } + if (view === 'errors' && !isError(event)) return false + if (view === 'slow' && (number(event, 'durationMs') ?? -1) < over) return false + if (id !== undefined && !matchesId(event, id)) return false + return true + } + + return { view, id, since, until, level, limit, over, filter } +} + +/** + * The events a one-shot run shows, from everything the reader yielded in + * file order: the last `limit` of them, oldest first, so the newest is at the + * bottom like `tail`. The `slow` view is the exception: worst first. + */ +export function select(events: WideEvent[], query: LogsQuery): WideEvent[] { + if (query.view === 'slow') { + return [...events] + .sort((a, b) => (number(b, 'durationMs') ?? 0) - (number(a, 'durationMs') ?? 0)) + .slice(0, query.limit) + } + return events.slice(-query.limit) +} diff --git a/packages/cli/src/lib/logs/render.ts b/packages/cli/src/lib/logs/render.ts new file mode 100644 index 000000000..56b0ae296 --- /dev/null +++ b/packages/cli/src/lib/logs/render.ts @@ -0,0 +1,189 @@ +import type { WideEvent } from 'evlog' +import type { CliContext } from '../../core/context' +import { createStyle } from '../../core/output' +import type { Style, StyleCode } from '../../core/output' +import { field, isError } from './query' +import type { LogsQuery } from './query' + +/** Fields every request event carries, shown in the fixed columns rather than the summary. */ +const STANDARD = new Set([ + 'timestamp', 'level', 'service', 'environment', 'version', 'commitHash', 'region', + 'duration', 'durationMs', 'method', 'path', 'status', 'requestId', 'traceId', 'spanId', + '_parentRequestId', 'operation', 'requestLogs', 'userAgent', 'source', 'error', 'audit', +]) + +function str(value: unknown): string | undefined { + return typeof value === 'string' ? value : undefined +} + +function obj(value: unknown): Record | undefined { + return typeof value === 'object' && value !== null && !Array.isArray(value) ? value as Record : undefined +} + +function clock(timestamp: string): string { + const at = new Date(timestamp) + if (Number.isNaN(at.getTime())) return '--:--:--' + return at.toTimeString().slice(0, 8) +} + +function statusColor(status: number | undefined, level: string): StyleCode { + if (level === 'error' || level === 'fatal' || (status !== undefined && status >= 500)) return 'red' + if (level === 'warn' || (status !== undefined && status >= 400)) return 'yellow' + return 'green' +} + +/** `{ a: 1, b: { c: 2 } }` → `a=1 b{…}`; the business fields, as much as fits in a line. */ +function fields(event: WideEvent, max = 3): string { + const out: string[] = [] + for (const [key, value] of Object.entries(event)) { + if (STANDARD.has(key) || value === undefined || value === null) continue + if (typeof value === 'object') { + const inner = obj(value) + const scalar = inner && Object.entries(inner).find(([, v]) => typeof v !== 'object') + out.push(scalar ? `${key}.${scalar[0]}=${String(scalar[1])}` : `${key}{…}`) + } else { + out.push(`${key}=${String(value)}`) + } + if (out.length === max) break + } + return out.join(' ') +} + +/** The one thing to know about the event: the error, the audit record, or the business fields. */ +function summary(event: WideEvent): { text: string, color?: StyleCode } { + const error = obj(field(event, 'error')) + if (error) { + const data = obj(error.data) + const name = str(error.code) ?? str(data?.code) ?? str(error.name) ?? 'error' + const why = str(data?.why) ?? str(error.why) + return { text: `✗ ${name}: ${str(error.message) ?? ''}${why ? ` · ${why}` : ''}`, color: 'red' } + } + const audit = obj(event.audit) + if (audit) { + const actor = obj(audit.actor) + const target = obj(audit.target) + const who = actor ? `${str(actor.type) ?? ''}:${str(actor.id) ?? ''}` : '' + const what = target ? ` → ${str(target.type) ?? ''}:${str(target.id) ?? ''}` : '' + return { text: `audit ${str(audit.action) ?? ''} ${who}${what} ${str(audit.outcome) ?? ''}`.trim(), color: 'magenta' } + } + return { text: fields(event) } +} + +/** One event on one line: time, request, status, duration, and what mattered. */ +export function formatLine(style: Style, event: WideEvent): string { + const status = typeof field(event, 'status') === 'number' ? field(event, 'status') as number : undefined + const method = str(field(event, 'method')) + const path = str(field(event, 'path')) ?? str(field(event, 'operation')) ?? event.service + const where = method ? `${method.padEnd(6)} ${path}` : ` ${path}` + const { text, color } = summary(event) + const columns = [ + style.paint('dim', clock(event.timestamp)), + where.padEnd(44), + style.paint(statusColor(status, event.level), status !== undefined ? String(status) : event.level.padEnd(3)), + style.paint('dim', (event.duration ?? '').padStart(7)), + color ? style.paint(color, text) : text, + ] + return columns.join(' ').trimEnd() +} + +function section(style: Style, title: string, rows: Array<[string, string | undefined]>): string[] { + const kept = rows.filter((row): row is [string, string] => row[1] !== undefined && row[1] !== '') + if (kept.length === 0) return [] + const width = Math.max(...kept.map(([key]) => key.length)) + return [style.paint('dim', title.toUpperCase()), ...kept.map(([key, value]) => ` ${key.padEnd(width)} ${value}`), ''] +} + +/** The whole event, grouped by what a reader looks for first, then the rest as JSON. */ +export function formatEvent(style: Style, event: WideEvent): string { + const lines: string[] = [formatLine(style, event), ''] + const error = obj(field(event, 'error')) + const data = error ? obj(error.data) : undefined + const audit = obj(event.audit) + const actor = audit ? obj(audit.actor) : undefined + const target = audit ? obj(audit.target) : undefined + + lines.push(...section(style, 'request', [ + ['requestId', str(field(event, 'requestId'))], + ['traceId', str(field(event, 'traceId'))], + ['parent', str(field(event, '_parentRequestId'))], + ['service', `${event.service} · ${event.environment}${event.version ? ` · ${event.version}` : ''}`], + ['at', event.timestamp], + ])) + if (error) { + const stack = str(error.stack)?.split('\n').slice(1, 4).map(line => line.trim()).join('\n' + ' '.repeat(9)) + lines.push(...section(style, 'error', [ + ['name', str(error.name)], + ['message', str(error.message)], + ['status', error.statusCode !== undefined ? String(error.statusCode) : undefined], + ['code', str(error.code) ?? str(data?.code)], + ['why', str(data?.why) ?? str(error.why)], + ['fix', str(data?.fix) ?? str(error.fix)], + ['link', str(data?.link) ?? str(error.link)], + ['stack', stack], + ])) + } + if (audit) { + lines.push(...section(style, 'audit', [ + ['action', str(audit.action)], + ['actor', actor ? `${str(actor.type) ?? ''}:${str(actor.id) ?? ''}` : undefined], + ['target', target ? `${str(target.type) ?? ''}:${str(target.id) ?? ''}` : undefined], + ['outcome', str(audit.outcome)], + ['reason', str(audit.reason)], + ])) + } + const rest = Object.fromEntries(Object.entries(event).filter(([key]) => !STANDARD.has(key))) + if (Object.keys(rest).length > 0) { + lines.push(style.paint('dim', 'FIELDS'), ...JSON.stringify(rest, null, 2).split('\n').map(line => ` ${line}`)) + } + return lines.join('\n').trimEnd() +} + +export interface LogsResult { + dir: string + query: LogsQuery + /** Every event that matched, in the reader's order. */ + matched: number + /** The events shown: `select()` applied to `matched`. */ + events: WideEvent[] +} + +function describe(query: LogsQuery): string { + const parts: string[] = [] + if (query.view === 'errors') parts.push('errors') + if (query.view === 'slow') parts.push(`slower than ${query.over}ms`) + if (query.view === 'trace') parts.push(`request ${query.id}`) + if (query.since) parts.push(`since ${query.since.toISOString()}`) + if (query.until) parts.push(`until ${query.until.toISOString()}`) + if (query.level) parts.push(`level ${query.level.join(',')}`) + return parts.join(' · ') +} + +/** The one-shot report: a header, one line per event (or the full event for a trace), and what to try next. */ +export function formatLogsReport(ctx: CliContext, result: LogsResult): string { + const style = createStyle(ctx) + const { query, events, matched } = result + const lines: string[] = [] + const filters = describe(query) + const shown = events.length === matched ? `${matched} event${matched === 1 ? '' : 's'}` : `${events.length} of ${matched} events` + lines.push(style.paint('dim', `${shown} · ${result.dir}${filters ? ` · ${filters}` : ''}`), '') + + if (events.length === 0) { + lines.push(query.view === 'trace' ? `no event carries the id ${query.id}` : 'no event matches') + lines.push('', style.paint('dim', 'the fs drain writes on every request · evlog logs -f follows new events')) + return lines.join('\n') + } + + if (query.view === 'trace') { + for (const event of events) lines.push(formatEvent(style, event), '') + return lines.join('\n').trimEnd() + } + + for (const event of events) lines.push(formatLine(style, event)) + const failures = events.filter(isError).length + const hints: string[] = [] + if (query.view === 'recent' && failures > 0) hints.push(`evlog logs errors — the ${failures} that failed`) + hints.push('evlog logs — one request in full') + if (query.view !== 'slow') hints.push('evlog logs slow — worst first') + lines.push('', style.paint('dim', hints.join(' · '))) + return lines.join('\n') +} diff --git a/packages/cli/test/logs.command.test.ts b/packages/cli/test/logs.command.test.ts new file mode 100644 index 000000000..7ff790c2c --- /dev/null +++ b/packages/cli/test/logs.command.test.ts @@ -0,0 +1,249 @@ +import { appendFile, mkdir, mkdtemp, rm, writeFile } from 'node:fs/promises' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { runCommand } from 'citty' +import type { WideEvent } from 'evlog' +import { afterEach, describe, expect, it, vi } from 'vitest' +import logs, { runLogs } from '../src/commands/logs' +import { createContext } from '../src/core/context' +import type { CliContext } from '../src/core/context' +import { buildQuery, matchesId, parseDuration, parseTime } from '../src/lib/logs/query' +import { formatEvent, formatLine } from '../src/lib/logs/render' +import { createStyle } from '../src/core/output' + +const NOW = new Date('2026-10-01T12:00:00.000Z') +const tempDirs: string[] = [] + +function event(overrides: Record): WideEvent { + return { + timestamp: '2026-10-01T11:00:00.000Z', + level: 'info', + service: 'shop', + environment: 'development', + method: 'GET', + path: '/api/items', + status: 200, + durationMs: 12, + duration: '12ms', + requestId: 'aaaaaaaa-0000-4000-8000-000000000001', + ...overrides, + } as WideEvent +} + +/** Six requests over two days, one of them pretty-printed, in the fs drain's layout. */ +const EVENTS: WideEvent[] = [ + event({ timestamp: '2026-09-30T08:00:00.000Z', requestId: 'bbbbbbbb-0000-4000-8000-000000000002', path: '/api/health', durationMs: 2, duration: '2ms' }), + event({ timestamp: '2026-10-01T10:00:00.000Z', requestId: 'cccccccc-0000-4000-8000-000000000003', method: 'POST', path: '/api/checkout', status: 402, level: 'error', durationMs: 412, duration: '412ms', + error: { name: 'Error', message: 'Payment processing failed', statusCode: 402, data: { why: 'Card declined by issuer', fix: 'Use another card', link: 'https://docs.example.com/declined' }, stack: 'Error: Payment processing failed\n at handler (checkout.ts:12:3)\n at run (h3.mjs:2017:19)' }, + cart: { items: 3, total: 9999 } }), + event({ timestamp: '2026-10-01T10:30:00.000Z', requestId: 'dddddddd-0000-4000-8000-000000000004', _parentRequestId: 'aaaaaaaa-0000-4000-8000-000000000001', path: '/api/reports', durationMs: 1200, duration: '1.2s', report: { id: 'r-1' } }), + event({ timestamp: '2026-10-01T11:00:00.000Z', requestId: 'eeeeeeee-0000-4000-8000-000000000005', method: 'POST', path: '/api/refund', status: 200, durationMs: 80, duration: '80ms', + audit: { action: 'billing.refund', actor: { type: 'user', id: 'usr_42' }, target: { type: 'invoice', id: 'inv_1' }, outcome: 'success' } }), + event({ timestamp: '2026-10-01T11:30:00.000Z', requestId: 'ffffffff-0000-4000-8000-000000000006', path: '/api/items', status: 500, durationMs: 30, duration: '30ms' }), + event({ timestamp: '2026-10-01T11:45:00.000Z', requestId: 'aaaaaaaa-0000-4000-8000-000000000001', path: '/api/items', level: 'warn', durationMs: 700, duration: '700ms', user: { id: 'usr_7', plan: 'pro' } }), +] + +async function makeSink(): Promise { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-')) + tempDirs.push(cwd) + await writeFile(join(cwd, 'package.json'), JSON.stringify({ name: 'shop' })) + const dir = join(cwd, '.evlog', 'logs') + await mkdir(dir, { recursive: true }) + /* The first day is pretty-printed, the way `pretty: true` writes it. */ + await writeFile(join(dir, '2026-09-30.jsonl'), `${JSON.stringify(EVENTS[0], null, 2)}\n`) + await writeFile(join(dir, '2026-10-01.jsonl'), `${EVENTS.slice(1).map(e => JSON.stringify(e)).join('\n') }\n`) + return cwd +} + +function fakeContext(cwd: string, overrides: Partial = {}): CliContext { + return createContext({ cwd, env: {}, nodeVersion: 'v22.0.0', tty: false, color: false, columns: 120, ...overrides }) +} + +function captureStdout(): string[] { + const out: string[] = [] + vi.spyOn(process.stdout, 'write').mockImplementation(((chunk: string | Uint8Array) => { + out.push(typeof chunk === 'string' ? chunk : Buffer.from(chunk).toString()) + return true + }) as typeof process.stdout.write) + vi.spyOn(process.stderr, 'write').mockImplementation(() => true) + return out +} + +afterEach(async () => { + vi.restoreAllMocks() + process.exitCode = undefined + await Promise.all(tempDirs.splice(0).map(dir => rm(dir, { recursive: true, force: true }))) +}) + +describe('parsing', () => { + it('reads durations with and without a unit', () => { + expect(parseDuration('500')).toBe(500) + expect(parseDuration('1.5s')).toBe(1500) + expect(parseDuration('15m')).toBe(900_000) + expect(parseDuration('2h')).toBe(7_200_000) + expect(parseDuration('3d')).toBe(259_200_000) + expect(parseDuration('soon')).toBeUndefined() + }) + + it('reads --since as a duration back or a date, and refuses the rest', () => { + expect(parseTime('since', '15m', NOW)?.toISOString()).toBe('2026-10-01T11:45:00.000Z') + expect(parseTime('since', '2026-09-30', NOW)?.toISOString()).toBe('2026-09-30T00:00:00.000Z') + expect(parseTime('since', undefined, NOW)).toBeUndefined() + expect(() => parseTime('since', 'yesterday-ish', NOW)).toThrow(/Invalid --since/) + }) + + it('picks the view from the positional', () => { + expect(buildQuery({}).view).toBe('recent') + expect(buildQuery({ what: 'errors' }).view).toBe('errors') + expect(buildQuery({ what: 'slow' }).view).toBe('slow') + expect(buildQuery({ what: 'cccccccc' })).toMatchObject({ view: 'trace', id: 'cccccccc' }) + }) + + it.each([ + [{ level: 'loud' }, /Unknown level/], + [{ status: '42' }, /Invalid --status/], + [{ status: '6xx' }, /Invalid --status/], + [{ over: 'fast' }, /Invalid --over/], + [{ limit: '0' }, /Invalid --limit/], + ])('rejects %o', (args, message) => { + expect(() => buildQuery(args)).toThrow(message) + }) + + it('matches an id exactly, or by a prefix of at least eight characters', () => { + const e = event({ requestId: 'cccccccc-0000-4000-8000-000000000003', traceId: 'trace-1' }) + expect(matchesId(e, 'cccccccc-0000-4000-8000-000000000003')).toBe(true) + expect(matchesId(e, 'cccccccc')).toBe(true) + expect(matchesId(e, 'ccc')).toBe(false) + expect(matchesId(e, 'trace-1')).toBe(true) + }) +}) + +describe('runLogs', () => { + it('shows the last events oldest first, across both file formats', async () => { + const cwd = await makeSink() + const result = await runLogs(fakeContext(cwd), {}, { now: NOW }) + expect(result.dir).toBe(join(cwd, '.evlog', 'logs')) + expect(result.matched).toBe(6) + expect(result.events.map(e => e.path)).toEqual(['/api/health', '/api/checkout', '/api/reports', '/api/refund', '/api/items', '/api/items']) + }) + + it('keeps the newest when --limit cuts the list', async () => { + const cwd = await makeSink() + const result = await runLogs(fakeContext(cwd), { limit: '2' }, { now: NOW }) + expect(result.events.map(e => e.status)).toEqual([500, 200]) + expect(result.matched).toBe(6) + }) + + it('errors: a failing status, an error level, or an error block', async () => { + const cwd = await makeSink() + const result = await runLogs(fakeContext(cwd), { what: 'errors' }, { now: NOW }) + expect(result.events.map(e => [e.path, e.status])).toEqual([['/api/checkout', 402], ['/api/items', 500]]) + }) + + it('slow: worst first, above --over', async () => { + const cwd = await makeSink() + const slow = await runLogs(fakeContext(cwd), { what: 'slow' }, { now: NOW }) + expect(slow.events.map(e => e.durationMs)).toEqual([1200, 700]) + const slower = await runLogs(fakeContext(cwd), { what: 'slow', over: '1s' }, { now: NOW }) + expect(slower.events.map(e => e.durationMs)).toEqual([1200]) + }) + + it('trace: every event carrying the id, by prefix', async () => { + const cwd = await makeSink() + const result = await runLogs(fakeContext(cwd), { what: 'aaaaaaaa' }, { now: NOW }) + /* The forked report event links back through `_parentRequestId`. */ + expect(result.events.map(e => e.path)).toEqual(['/api/reports', '/api/items']) + }) + + it('filters on time, level, path and status class together', async () => { + const cwd = await makeSink() + const ctx = fakeContext(cwd) + /* `since` is inclusive: the checkout at exactly 10:00 is two hours before noon. */ + expect((await runLogs(ctx, { since: '2h' }, { now: NOW })).events.map(e => e.timestamp)).toEqual(['2026-10-01T10:00:00.000Z', '2026-10-01T10:30:00.000Z', '2026-10-01T11:00:00.000Z', '2026-10-01T11:30:00.000Z', '2026-10-01T11:45:00.000Z']) + expect((await runLogs(ctx, { until: '2026-10-01T10:00:00.000Z' }, { now: NOW })).events).toHaveLength(2) + expect((await runLogs(ctx, { level: 'warn,error' }, { now: NOW })).events.map(e => e.level)).toEqual(['error', 'warn']) + expect((await runLogs(ctx, { path: '/api/items', status: '5xx' }, { now: NOW })).events).toHaveLength(1) + expect((await runLogs(ctx, { status: '402' }, { now: NOW })).events.map(e => e.path)).toEqual(['/api/checkout']) + }) + + it('reads --dir as given and refuses a project with no sink', async () => { + const cwd = await makeSink() + const elsewhere = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-other-')) + tempDirs.push(elsewhere) + await writeFile(join(elsewhere, 'package.json'), '{"name":"other"}') + const result = await runLogs(fakeContext(elsewhere), {}, { dir: join(cwd, '.evlog', 'logs'), now: NOW }) + expect(result.matched).toBe(6) + await expect(runLogs(fakeContext(elsewhere), {}, { now: NOW })).rejects.toThrow(/No local logs/) + }) + + it('follows: new lines arrive through onEvent until the signal aborts', async () => { + const cwd = await makeSink() + const controller = new AbortController() + const seen: WideEvent[] = [] + const run = runLogs(fakeContext(cwd), { path: '/api/items' }, { + follow: true, + signal: controller.signal, + now: NOW, + onEvent: (event) => { + seen.push(event) + controller.abort() + }, + }) + await new Promise(resolve => setTimeout(resolve, 300)) + await appendFile(join(cwd, '.evlog', 'logs', '2026-10-01.jsonl'), `${JSON.stringify(event({ timestamp: '2026-10-01T11:50:00.000Z', path: '/api/other' }))}\n${JSON.stringify(event({ timestamp: '2026-10-01T11:51:00.000Z', path: '/api/items', status: 201 }))}\n`) + const result = await run + expect(result.matched).toBe(2) + expect(seen.map(e => e.status)).toEqual([201]) + }) +}) + +describe('rendering', () => { + const style = createStyle({ color: false }) + + it('puts the error, the audit record, or the business fields at the end of the line', () => { + expect(formatLine(style, EVENTS[1]!)).toMatch(/POST {3}\/api\/checkout\s+402\s+412ms\s+✗ Error: Payment processing failed · Card declined by issuer$/) + expect(formatLine(style, EVENTS[3]!)).toMatch(/audit billing\.refund user:usr_42 → invoice:inv_1 success$/) + expect(formatLine(style, EVENTS[5]!)).toMatch(/user\.id=usr_7$/) + }) + + it('shows why, fix and the first frames of the stack for one event', () => { + const text = formatEvent(style, EVENTS[1]!) + expect(text).toContain('why Card declined by issuer') + expect(text).toContain('fix Use another card') + expect(text).toContain('at handler (checkout.ts:12:3)') + expect(text).toContain('"cart"') + expect(text).not.toContain('"error"') + }) +}) + +describe('logs command', () => { + it('--json is an envelope with the events and the counts', async () => { + const cwd = await makeSink() + const out = captureStdout() + await runCommand(logs, { rawArgs: ['--cwd', cwd, '--json', '--no-header', 'errors'] }) + const payload = JSON.parse(out.join('')) as { view: string, count: number, matched: number, events: Array<{ path: string }> } + expect(payload.view).toBe('errors') + expect(payload.count).toBe(2) + expect(payload.matched).toBe(2) + expect(payload.events.map(e => e.path)).toEqual(['/api/checkout', '/api/items']) + expect(process.exitCode).toBeUndefined() + }) + + it('a bad flag is a usage error, before any file is read', async () => { + const cwd = await makeSink() + const out = captureStdout() + await runCommand(logs, { rawArgs: ['--cwd', cwd, '--json', '--no-header', '--since', 'nope'] }) + expect(JSON.parse(out.join('')).error.code).toBe('cli.LOGS_INVALID_TIME') + expect(process.exitCode).toBe(2) + }) + + it('no sink is a failure with the fix', async () => { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-empty-')) + tempDirs.push(cwd) + await writeFile(join(cwd, 'package.json'), '{"name":"empty"}') + const out = captureStdout() + await runCommand(logs, { rawArgs: ['--cwd', cwd, '--json', '--no-header'] }) + expect(JSON.parse(out.join('')).error.code).toBe('cli.LOGS_NO_SINK') + expect(process.exitCode).toBe(1) + }) +}) diff --git a/packages/evlog/src/adapters/fs.ts b/packages/evlog/src/adapters/fs.ts index cab80673c..254f7b4bb 100644 --- a/packages/evlog/src/adapters/fs.ts +++ b/packages/evlog/src/adapters/fs.ts @@ -302,18 +302,48 @@ function fileWithinRange(filename: string, since?: number, until?: number): bool return true } +/** + * Turn lines into events, one object per line or one object across lines. + * + * `pretty: true` writes each event indented, so its closing brace sits alone + * at the start of a line while every nested one is indented: that is how an + * object's end is found without parsing on every line. Anything that does not + * parse once assembled (a partial write, a manual edit) is dropped silently, + * the same as a malformed single line. + */ +function createEventAssembler(): (line: string) => WideEvent | undefined { + let pending: string[] = [] + return (line) => { + if (pending.length === 0) { + const trimmed = line.trim() + if (!trimmed) return undefined + try { + return JSON.parse(trimmed) as WideEvent + } catch { + if (trimmed === '{') pending.push(trimmed) + return undefined + } + } + pending.push(line) + if (line !== '}') return undefined + const text = pending.join('\n') + pending = [] + try { + return JSON.parse(text) as WideEvent + } catch { + return undefined + } + } +} + async function* iterateFile(filePath: string): AsyncGenerator { const stream = createReadStream(filePath, { encoding: 'utf-8' }) const rl = createInterface({ input: stream, crlfDelay: Infinity }) + const assemble = createEventAssembler() try { for await (const line of rl) { - const trimmed = line.trim() - if (!trimmed) continue - try { - yield JSON.parse(trimmed) as WideEvent - } catch { - // Skip malformed lines (partial writes, manual edits) silently. - } + const event = assemble(line) + if (event) yield event } } finally { rl.close() @@ -379,7 +409,7 @@ async function readAppendedLines( } const complete = chunk.slice(0, newlineIdx) const remainder = chunk.slice(newlineIdx + 1) - const lines = complete.split('\n').map(l => l.trim()).filter(Boolean) + const lines = complete.split('\n').filter(l => l.trim()) return { events: lines, offset: size, carry: remainder } } finally { await handle.close() @@ -432,6 +462,15 @@ export async function* tailFsLogs(options: TailFsLogsOptions = {}): AsyncGenerat const offsets = new Map() const carries = new Map() + const assemblers = new Map>() + function assemblerFor(filename: string): ReturnType { + let assemble = assemblers.get(filename) + if (!assemble) { + assemble = createEventAssembler() + assemblers.set(filename, assemble) + } + return assemble + } if (options.fromEnd) { const files = await listLogFiles(dir) @@ -472,14 +511,11 @@ export async function* tailFsLogs(options: TailFsLogsOptions = {}): AsyncGenerat offsets.set(filename, offset) carries.set(filename, newCarry) + const assemble = assemblerFor(filename) for (const line of events) { if (signal?.aborted) return - try { - const event = JSON.parse(line) as WideEvent - if (predicate(event)) yield event - } catch { - // Skip malformed lines. - } + const event = assemble(line) + if (event && predicate(event)) yield event } } } diff --git a/packages/evlog/test/adapters/fs-reader.test.ts b/packages/evlog/test/adapters/fs-reader.test.ts index 85250a932..23173ac87 100644 --- a/packages/evlog/test/adapters/fs-reader.test.ts +++ b/packages/evlog/test/adapters/fs-reader.test.ts @@ -75,6 +75,18 @@ describe('readFsLogs', () => { expect(events).toEqual([1, 2, 3]) }) + it('reads events written with pretty: true, mixed with compact ones', async () => { + const pretty = (event: WideEvent): string => JSON.stringify(event, null, 2) + await writeFile( + join(dir, '2026-03-14.jsonl'), + `${pretty(makeEvent(1, { nested: { deep: { x: 1 } } }))}\n${JSON.stringify(makeEvent(2))}\n${pretty(makeEvent(3))}\n`, + ) + + const ids: number[] = [] + for await (const event of readFsLogs({ dir })) ids.push(event.id as number) + expect(ids).toEqual([1, 2, 3]) + }) + it('skips malformed lines without throwing', async () => { await writeFile( join(dir, '2026-03-14.jsonl'), @@ -307,6 +319,33 @@ describe('tailFsLogs', () => { expect(collected).toEqual([42]) }) + it('assembles a pretty-printed event appended across polls', async () => { + const file = join(dir, '2026-03-14.jsonl') + await writeFile(file, '') + + const ac = new AbortController() + const collected: number[] = [] + + const consumer = (async () => { + for await (const event of tailFsLogs({ dir, pollIntervalMs: 50, signal: ac.signal, fromEnd: true })) { + collected.push(event.id as number) + if (collected.length === 2) { + ac.abort() + break + } + } + })() + + await new Promise(r => setTimeout(r, 100)) + const lines = JSON.stringify(makeEvent(7, { nested: { a: 1 } }), null, 2).split('\n') + await appendFile(file, `${lines.slice(0, 4).join('\n')}\n`) + await new Promise(r => setTimeout(r, 100)) + await appendFile(file, `${lines.slice(4).join('\n')}\n${JSON.stringify(makeEvent(8))}\n`) + + await consumer + expect(collected).toEqual([7, 8]) + }) + it('aborts cleanly via AbortSignal', async () => { const ac = new AbortController() const start = Date.now() diff --git a/skills/analyze-logs/SKILL.md b/skills/analyze-logs/SKILL.md index a00d517e9..c5f6204f6 100644 --- a/skills/analyze-logs/SKILL.md +++ b/skills/analyze-logs/SKILL.md @@ -21,6 +21,17 @@ Read and analyze structured wide-event logs from the local `.evlog/logs/` direct ## Finding the logs +Try the CLI first; it reads both file layouts, every dated file, and knows where the project's drain writes: + +```bash +npx evlog logs --json # the last 50 events +npx evlog logs errors --since 1h --json # what failed +npx evlog logs slow --over 1s --json # what was slow, worst first +npx evlog logs --json # one request, every event with that id +``` + +`--json` is an envelope (`dir`, `view`, `matched`, `events`); filters are `--since`, `--until`, `--level`, `--path`, `--status` (`500` or `5xx`), `--limit`, and `--dir` for a non-default directory. Docs: https://www.evlog.dev/cli/logs. If the CLI is unavailable or the user declines it, read the files directly as below. + Logs are written by evlog's file system drain as `.jsonl` files, organized by date. **Format detection**: The drain supports two modes: From ff74fb783de5e72e718492ba8af0a6e968d3f35b Mon Sep 17 00:00:00 2001 From: Hugo Richard Date: Sun, 4 Oct 2026 12:50:44 +0100 Subject: [PATCH 2/5] feat(cli): logs --where, stats, workspace reading and --url --- .changeset/cli-logs.md | 2 +- apps/docs/content/3.cli/10.logs.md | 45 +++++- packages/cli/README.md | 3 + packages/cli/src/commands/logs.ts | 203 +++++++++++++++++++++---- packages/cli/src/lib/errors.ts | 17 +++ packages/cli/src/lib/logs/query.ts | 149 +++++++++++++++++- packages/cli/src/lib/logs/render.ts | 44 +++++- packages/cli/test/logs.command.test.ts | 126 ++++++++++++++- skills/analyze-logs/SKILL.md | 4 +- 9 files changed, 542 insertions(+), 51 deletions(-) diff --git a/.changeset/cli-logs.md b/.changeset/cli-logs.md index e5cb2b62b..1884d91d9 100644 --- a/.changeset/cli-logs.md +++ b/.changeset/cli-logs.md @@ -2,4 +2,4 @@ "@evlog/cli": minor --- -`evlog logs` reads the wide events the fs drain wrote to `.evlog/logs`: the last 50 (`evlog logs`), the failures (`evlog logs errors`), the slowest (`evlog logs slow --over 1s`), or one request in full by id (`evlog logs `, a UUID prefix is enough). Filters compose with every view: `--since 15m`, `--until`, `--level error,fatal`, `--path`, `--status 5xx`, `--limit`, `--dir`. `-f` follows new events like `tail -f`; `--json` returns the events as JSON. It finds the project's log directory the way `doctor` does, reads both the compact and the pretty layout, and never writes. +`evlog logs` reads the wide events the fs drain wrote to `.evlog/logs`: the last 50 (`evlog logs`), the failures (`evlog logs errors`), the slowest (`evlog logs slow --over 1s`), one request in full by id (`evlog logs `, a UUID prefix is enough), or the shape of the traffic (`evlog logs stats`: per route, status class and level). Filters compose with every view: `--since 15m`, `--until`, `--level error,fatal`, `--path`, `--status 5xx`, `--where payment.amount>5000` on any field of the event (`=`, `!=`, `>`, `>=`, `<`, `<=`, `~regex`, present, `!absent`, repeatable), `--limit`, `--dir`. `-f` follows new events like `tail -f`; `--json` returns the events as JSON. It finds the project's log directory the way `doctor` does, reads every app of a workspace when the root has none, reads the memory drain's dev endpoint with `--url`, handles both the compact and the pretty layout, and never writes. diff --git a/apps/docs/content/3.cli/10.logs.md b/apps/docs/content/3.cli/10.logs.md index 0599c39bf..f20b6d386 100644 --- a/apps/docs/content/3.cli/10.logs.md +++ b/apps/docs/content/3.cli/10.logs.md @@ -33,7 +33,7 @@ evlog logs errors — the 2 that failed · evlog logs — one reques The newest event is at the bottom, like `tail`. Nothing is written: the fs drain writes on every request and this reads what it wrote, both the compact and the `pretty: true` layout, across the dated files. -## Four views +## Five views | Command | Shows | | --- | --- | @@ -41,6 +41,7 @@ The newest event is at the bottom, like `tail`. Nothing is written: the fs drain | `evlog logs errors` | Events that failed: a `5xx` status, an `error` or `fatal` level, or an `error` block | | `evlog logs slow` | Events over 500ms, worst first (`--over 1s` to move the bar) | | `evlog logs ` | Every event carrying that id, in full: request, error with `why` and `fix`, audit record, then the business fields. The first block of a UUID is enough | +| `evlog logs stats` | The shape of the traffic: per route, count, errors, p50 and p95, routes with the most errors first; then counts by status class and by level | ## Filters @@ -53,9 +54,11 @@ Filters compose with any view. | `--level ` | Only these levels: `trace`, `debug`, `info`, `warn`, `error`, `fatal` | | `--path ` | Only requests on this exact path | | `--status ` | Only this status (`404`) or class (`4xx`) | +| `--where ` | Only events where a field matches, see below; repeat the flag for several clauses, all must hold | | `--over ` | For `slow`: what a request has to exceed (default `500ms`) | | `--limit ` | Most events to show (default 50) | -| `--dir ` | Read another directory (default: the project's `.evlog/logs`, or the directory its fs drain is configured for) | +| `--dir ` | Read another directory (default: the project's `.evlog/logs`; in a workspace with no logs at the root, every `apps/*/.evlog/logs` and the like, merged by time with the app in a column) | +| `--url ` | Read the [memory drain](/integrate/adapters/self-hosted/memory)'s dev endpoint instead of files: a JSON array of events, or `{ "events": [...] }` | | `-f`, `--follow` | Keep reading as the app writes, like `tail -f`; `Ctrl-C` stops | | `--json` | The events as JSON on stdout | | `--cwd ` | Another project in the workspace | @@ -69,6 +72,28 @@ evlog logs --status 5xx --level error,fatal --limit 20 evlog logs -f --path /api/checkout ``` +### `--where`: any field on the event + +A clause is a dotted field, an operator, and a value. Numbers compare as numbers, everything else as text, and the field can sit anywhere in the event, which is the point of a wide event: the business fields are there to be queried. + +| Clause | Matches when | +| --- | --- | +| `user.id=usr_42` | the field equals the value (`true`/`false` and numbers are read as such) | +| `audit.outcome!=success` | the field differs | +| `payment.amount>5000` | greater; also `>=`, `<`, `<=` | +| `error.message~declined` | the field matches the regular expression, case-insensitive; an object is matched as JSON | +| `audit` | the field is present | +| `!error` | the field is absent | + +```bash [Terminal] +evlog logs --where payment.amount>5000 --where audit.outcome=failure +evlog logs errors --where error.data.why~"card declined" +evlog logs stats --where user.plan=pro +evlog logs -f --where '!error' --where durationMs>1000 +``` + +Quote a value with spaces (`path="/a b"`), and quote the whole clause when the shell would read `>` or `!` (`'durationMs>1000'`, `'!error'`). + ## For agents `--json` returns one envelope: the directory, the view, how many events matched, and the events shown. @@ -88,13 +113,21 @@ evlog logs errors --since 30m --json } ``` -With `--follow --json`, each new event is one JSON line on stdout, since a stream has no end. The [`analyze-logs` skill](/reference/agent-skills) calls `evlog logs` first and falls back to reading the files only when the CLI is not available. +`stats --json` carries `stats` (`total`, `errors`, `byRoute`, `byStatus`, `byLevel`) in place of `events`. With `--follow --json`, each new event is one JSON line on stdout, since a stream has no end. The [`analyze-logs` skill](/reference/agent-skills) calls `evlog logs` first and falls back to reading the files only when the CLI is not available. + +## A workspace, and a running app + +Run from a monorepo root with no `.evlog/logs` of its own, it reads every app that has one (`apps/*`, `packages/*`, `examples/*`, `services/*`), merges the events by time, and shows the app in a column. `--cwd apps/web` reads one app; `--dir` reads one directory. + +An app on the [memory drain](/integrate/adapters/self-hosted/memory) (Cloudflare Workers, where there is no file system) has no files to read, but it can expose `readMemoryLogs()` on a dev route. Point `--url` at it; every view and filter works the same, and `-f` polls it once a second. + +```bash [Terminal] +evlog logs errors --url http://localhost:8787/_evlog/logs +``` ## What it will not do -- **It reads local files.** A remote drain (Axiom, Datadog, …) has its own query language and UI; this command does not wrap them. -- **One directory per run.** In a monorepo, run it from the app (`--cwd apps/web`) or pass `--dir`. -- **No aggregation yet.** Counts by route or status are a `jq` away from `--json`; a `stats` view may come later. +- **It reads local files and a dev endpoint.** A remote drain (Axiom, Datadog, …) has its own query language and UI; this command does not wrap them. ## Next diff --git a/packages/cli/README.md b/packages/cli/README.md index a195a0bd8..b96e7c3ad 100644 --- a/packages/cli/README.md +++ b/packages/cli/README.md @@ -70,6 +70,9 @@ pnpm evlog map | `evlog logs errors` | The ones that failed: a `5xx`, an `error` level, or an `error` block | | `evlog logs slow [--over 1s]` | Over the bar (default 500ms), worst first | | `evlog logs ` | One request in full: error with `why`/`fix`, audit record, business fields | +| `evlog logs stats` | Per route: count, errors, p50, p95; then by status class and level | +| `evlog logs --where payment.amount>5000 --where audit.outcome=failure` | Any field on the event: `=`, `!=`, `>`, `>=`, `<`, `<=`, `~regex`, present, `!absent` | +| `evlog logs --url http://localhost:8787/_evlog/logs` | Read the memory drain's dev endpoint instead of files | | `evlog logs -f` | Follow new events as the app writes them | | `evlog logs --since 15m --path /api/x --status 5xx --level error` | Filters, composable with every view | | `evlog logs --json` | The events as JSON on stdout (one line per event with `-f`) | diff --git a/packages/cli/src/commands/logs.ts b/packages/cli/src/commands/logs.ts index 9590c186d..051a42ea8 100644 --- a/packages/cli/src/commands/logs.ts +++ b/packages/cli/src/commands/logs.ts @@ -1,5 +1,5 @@ -import { existsSync } from 'node:fs' -import { resolve } from 'node:path' +import { existsSync, readdirSync } from 'node:fs' +import { basename, join, resolve } from 'node:path' import { telemetry } from '@evlog/telemetry' import { EvlogError } from 'evlog' import type { WideEvent } from 'evlog' @@ -8,60 +8,184 @@ import type { CliContext } from '../core/context' import { createStyle, EXIT_FAIL, EXIT_USAGE } from '../core/output' import { defineEvlogCommand } from '../lib/command' import { cliErrors } from '../lib/errors' -import { buildQuery, select } from '../lib/logs/query' +import { buildQuery, computeStats, select } from '../lib/logs/query' import type { LogsArgs, LogsQuery } from '../lib/logs/query' -import { formatLine, formatLogsReport } from '../lib/logs/render' -import type { LogsResult } from '../lib/logs/render' -import { findConfiguredFsDrain, findLogsSink, resolveProject } from '../lib/project' +import { formatLine, formatLogsReport, SOURCE } from '../lib/logs/render' +import type { LogsResult, Sourced } from '../lib/logs/render' +import { findConfiguredFsDrain, findLogsSink, prettyPath, resolveProject } from '../lib/project' +import type { ProjectInfo } from '../lib/project' export type { LogsResult } from '../lib/logs/render' +/** One place events are read from: a directory on disk, labelled when there are several. */ +export interface LogsSource { + dir: string + /** The app the directory belongs to, when a workspace is read as a whole. */ + name?: string +} + +const WORKSPACE_PARENTS = ['apps', 'packages', 'examples', 'services'] + +/** + * The log directories of every app in the workspace: `apps//.evlog/logs` + * and the like, one level down from the root. Only directories that exist count, + * so a workspace with one app that writes reads as that app. + */ +function workspaceSources(root: string): LogsSource[] { + const sources: LogsSource[] = [] + for (const parent of WORKSPACE_PARENTS) { + const base = join(root, parent) + if (!existsSync(base)) continue + for (const entry of readdirSync(base, { withFileTypes: true })) { + if (!entry.isDirectory()) continue + const dir = join(base, entry.name, '.evlog', 'logs') + if (existsSync(dir)) sources.push({ dir, name: entry.name }) + } + } + return sources +} + /** - * Where the events are. `--dir` wins; otherwise the sink the project already - * writes to, or the directory its fs drain is configured for, which may not - * exist yet when nothing has run. + * Where the events are. `--dir` wins; otherwise the directory the project + * already writes to, else every app of the workspace that writes, else the + * directory the fs drain is configured for, which may not exist yet. */ -export async function resolveLogsDir(ctx: CliContext, dir: string | undefined): Promise { - if (dir) return resolve(ctx.cwd, dir) - const project = await resolveProject(ctx.cwd) +export async function resolveLogsSources(ctx: CliContext, dir: string | undefined): Promise { + if (dir) return [{ dir: resolve(ctx.cwd, dir) }] + const project: ProjectInfo = await resolveProject(ctx.cwd) const sink = await findLogsSink(project) - if (sink) return sink.dir + if (sink) return [{ dir: sink.dir }] + const apps = workspaceSources(project.root) + if (apps.length > 0) return apps const configured = await findConfiguredFsDrain(project, ctx.env) - if (configured) return resolve(project.packageDir, configured.dir) + if (configured) return [{ dir: resolve(project.packageDir, configured.dir) }] throw cliErrors.LOGS_NO_SINK({ cwd: ctx.cwd }) } export interface RunLogsOptions { dir?: string + /** Read a JSON array of events from this URL (the memory drain's dev endpoint) instead of files. */ + url?: string /** Keep reading as the app writes; resolves when `signal` aborts. */ follow?: boolean signal?: AbortSignal /** Called for each event that arrives while following. */ - onEvent?: (event: WideEvent) => void + onEvent?: (event: Sourced) => void now?: Date + fetchFn?: typeof fetch +} + +function tag(event: WideEvent, name: string | undefined): Sourced { + if (!name) return event + return Object.defineProperty(event, SOURCE, { value: name, enumerable: false }) as Sourced +} + +async function fetchEvents(url: string, fetchFn: typeof fetch): Promise { + let response: Response + try { + response = await fetchFn(url, { headers: { accept: 'application/json' } }) + } catch (error) { + throw cliErrors.LOGS_URL_UNREACHABLE({ url, reason: error instanceof Error ? error.message : String(error) }) + } + if (!response.ok) throw cliErrors.LOGS_URL_UNREACHABLE({ url, reason: `HTTP ${response.status}` }) + const body = await response.json() as unknown + const events = Array.isArray(body) ? body : typeof body === 'object' && body !== null && Array.isArray((body as { events?: unknown }).events) ? (body as { events: unknown[] }).events : undefined + if (!events) throw cliErrors.LOGS_URL_UNREACHABLE({ url, reason: 'the response is not a JSON array of events' }) + return events as WideEvent[] } +const timeOf = (event: WideEvent): number => Date.parse(event.timestamp) || 0 + /** Read the events the query asks for. Pure with respect to the context: nothing is written. */ export async function runLogs(ctx: CliContext, args: LogsArgs, options: RunLogsOptions = {}): Promise { const query = buildQuery(args, options.now) - const dir = await resolveLogsDir(ctx, options.dir) - if (!existsSync(dir) && !options.follow) throw cliErrors.LOGS_NO_SINK({ cwd: ctx.cwd }) + const fetchFn = options.fetchFn ?? fetch + const inRange = (event: WideEvent): boolean => { + const at = timeOf(event) + if (query.since && at < query.since.getTime()) return false + if (query.until && at > query.until.getTime()) return false + if (query.level && !query.level.includes(event.level)) return false + return query.filter(event) + } - const matched: WideEvent[] = [] - for await (const event of readFsLogs({ dir, since: query.since, until: query.until, level: query.level, filter: query.filter })) { - matched.push(event) + let all: Sourced[] + let sources: string[] + if (options.url) { + all = (await fetchEvents(options.url, fetchFn)).filter(inRange) + sources = [options.url] + } else { + const found = await resolveLogsSources(ctx, options.dir) + if (!options.follow && !found.some(source => existsSync(source.dir))) throw cliErrors.LOGS_NO_SINK({ cwd: ctx.cwd }) + all = [] + for (const source of found) { + for await (const event of readFsLogs({ dir: source.dir, since: query.since, until: query.until, level: query.level, filter: query.filter })) { + all.push(tag(event, found.length > 1 ? source.name : undefined)) + } + } + if (found.length > 1) all.sort((a, b) => timeOf(a) - timeOf(b)) + sources = found.map(source => prettyPath(ctx.cwd, source.dir)) } - const result: LogsResult = { dir, query, matched: matched.length, events: select(matched, query) } + const result: LogsResult = { sources, query, matched: all.length, events: select(all, query), all } if (options.follow) { - await followLogs(dir, query, options) + if (options.url) await followUrl(options.url, all, inRange, options) + else await followDirs(await resolveLogsSources(ctx, options.dir), query, options) } return result } -async function followLogs(dir: string, query: LogsQuery, options: RunLogsOptions): Promise { - for await (const event of tailFsLogs({ dir, fromEnd: true, level: query.level, filter: query.filter, pollIntervalMs: 250, signal: options.signal })) { - options.onEvent?.(event) +async function followDirs(sources: LogsSource[], query: LogsQuery, options: RunLogsOptions): Promise { + const label = sources.length > 1 + await Promise.all(sources.map(async (source) => { + for await (const event of tailFsLogs({ dir: source.dir, fromEnd: true, level: query.level, filter: query.filter, pollIntervalMs: 250, signal: options.signal })) { + options.onEvent?.(tag(event, label ? source.name : undefined)) + } + })) +} + +/** What a poll of the endpoint has already shown: the newest instant, and every event at it. */ +interface Seen { + newest: number + atNewest: Set +} + +function seenOf(events: WideEvent[], newest: number): Seen { + return { newest, atNewest: new Set(events.filter(event => timeOf(event) === newest).map(event => JSON.stringify(event))) } +} + +function isFresh(event: WideEvent, seen: Seen): boolean { + const at = timeOf(event) + return at > seen.newest || (at === seen.newest && !seen.atNewest.has(JSON.stringify(event))) +} + +function pause(ms: number, signal: AbortSignal | undefined): Promise { + return new Promise((done) => { + const timer = setTimeout(done, ms) + signal?.addEventListener('abort', () => { + clearTimeout(timer) + done() + }, { once: true }) + }) +} + +/** + * The endpoint is a snapshot, so following it means polling and keeping what + * was already shown apart from what is new: an event later than the newest + * shown, or one at the same instant that was not in the last snapshot. + */ +async function followUrl(url: string, shown: WideEvent[], inRange: (event: WideEvent) => boolean, options: RunLogsOptions): Promise { + const fetchFn = options.fetchFn ?? fetch + let seen = seenOf(shown, shown.reduce((max, event) => Math.max(max, timeOf(event)), 0)) + while (!options.signal?.aborted) { + await pause(1000, options.signal) + if (options.signal?.aborted) return + const events = (await fetchEvents(url, fetchFn)).filter(inRange) + const fresh: WideEvent[] = [] + for (const event of events) { + if (isFresh(event, seen)) fresh.push(event) + } + for (const event of fresh) options.onEvent?.(event) + if (fresh.length > 0) seen = seenOf(events, fresh.reduce((max, event) => Math.max(max, timeOf(event)), seen.newest)) } } @@ -72,16 +196,18 @@ async function followLogs(dir: string, query: LogsQuery, options: RunLogsOptions export default defineEvlogCommand('logs', { meta: { name: 'logs' }, args: { - what: { type: 'positional', required: false, description: '`errors`, `slow`, or a request id to show in full' }, + what: { type: 'positional', required: false, description: '`errors`, `slow`, `stats`, or a request id to show in full' }, follow: { type: 'boolean', alias: 'f', description: 'Keep reading as the app writes, like tail -f' }, since: { type: 'string', description: 'Only events after this: a duration back (15m, 2h, 3d) or a date' }, until: { type: 'string', description: 'Only events before this: a duration back or a date' }, level: { type: 'string', description: 'Only these levels, comma-separated (error,fatal)' }, path: { type: 'string', description: 'Only requests on this exact path' }, status: { type: 'string', description: 'Only this status (500) or class (5xx)' }, + where: { type: 'string', description: 'Only events where a field matches: user.id=42, payment.amount>5000, error.message~declined, audit, !error (repeatable)' }, over: { type: 'string', description: 'For `slow`: the duration a request has to exceed (default 500ms)' }, limit: { type: 'string', description: 'Most events to show (default 50)' }, - dir: { type: 'string', description: 'Log directory (default: the project\'s .evlog/logs)' }, + dir: { type: 'string', description: 'Log directory (default: the project\'s .evlog/logs, or every app\'s in a workspace)' }, + url: { type: 'string', description: 'Read the memory drain\'s dev endpoint instead of files (a JSON array of events)' }, }, async run({ args, cli, ui }) { const style = createStyle(cli) @@ -91,8 +217,9 @@ export default defineEvlogCommand('logs', { let result: LogsResult try { - result = await runLogs(cli, args, { + result = await runLogs(cli, args as LogsArgs, { dir: args.dir, + url: args.url, follow: args.follow, signal: controller.signal, onEvent: (event) => { @@ -107,7 +234,8 @@ export default defineEvlogCommand('logs', { json: { error: { code: error.code, message: error.message, why: error.why, fix: error.fix } }, human: error.fix ? `${error.message}\n→ ${error.fix}` : error.message, }) - ui.exit(error.code === cliErrors.LOGS_NO_SINK.code ? EXIT_FAIL : EXIT_USAGE) + const failed = error.code === cliErrors.LOGS_NO_SINK.code || error.code === cliErrors.LOGS_URL_UNREACHABLE.code + ui.exit(failed ? EXIT_FAIL : EXIT_USAGE) return } throw error @@ -115,14 +243,27 @@ export default defineEvlogCommand('logs', { process.off('SIGINT', stop) } - telemetry.set({ logsView: result.query.view, logsFollow: args.follow === true, logsEvents: result.matched } as unknown as Record) + telemetry.set({ + logsView: result.query.view, + logsFollow: args.follow === true, + logsEvents: result.matched, + logsWhere: result.query.where.length, + logsSources: result.sources.length, + logsUrl: args.url !== undefined, + } as unknown as Record) /* While following, the one-shot part was already streamed line by line before the tail started, so the report is only for the one-shot run. */ if (args.follow) return ui.done({ jsonMode: args.json, - json: { dir: result.dir, view: result.query.view, count: result.events.length, matched: result.matched, events: result.events }, + json: { + sources: result.sources, + view: result.query.view, + count: result.events.length, + matched: result.matched, + ...(result.query.view === 'stats' ? { stats: computeStats(result.all) } : { events: result.events }), + }, human: formatLogsReport(cli, result), }) }, diff --git a/packages/cli/src/lib/errors.ts b/packages/cli/src/lib/errors.ts index dce1df584..6f9e36ac3 100644 --- a/packages/cli/src/lib/errors.ts +++ b/packages/cli/src/lib/errors.ts @@ -287,6 +287,23 @@ export const cliErrors = defineErrorCatalog('cli', { fix: 'Pass milliseconds (500) or a unit (500ms, 1.5s)', tags: ['logs'], }, + LOGS_INVALID_WHERE: { + status: 400, + message: ({ value }: { value: string }) => + `Invalid --where "${value}"`, + why: 'A clause that cannot be read would silently match everything', + fix: 'Write field=value, field!=value, field>n, field>=n, field + `Could not read events from ${url}: ${reason}`, + why: 'The memory drain only exists while the app runs, and only where the app exposes readMemoryLogs() over HTTP', + fix: 'Start the app, check the endpoint returns a JSON array of events, and pass its URL to --url', + link: 'https://evlog.dev/cli/logs', + tags: ['logs'], + }, LOGS_INVALID_LIMIT: { status: 400, message: ({ value }: { value: string }) => diff --git a/packages/cli/src/lib/logs/query.ts b/packages/cli/src/lib/logs/query.ts index d0321ddcc..f9e8f5150 100644 --- a/packages/cli/src/lib/logs/query.ts +++ b/packages/cli/src/lib/logs/query.ts @@ -2,7 +2,7 @@ import type { LogLevel, WideEvent } from 'evlog' import { cliErrors } from '../errors' /** What the run shows: the latest events, the failures, the slowest, or one request. */ -const VIEWS = ['recent', 'errors', 'slow', 'trace'] as const +const VIEWS = ['recent', 'errors', 'slow', 'trace', 'stats'] as const export type LogsView = typeof VIEWS[number] /** @@ -76,8 +76,92 @@ export function parseLimit(value: unknown): number { return limit } +/** One `--where` clause: a dotted field, an operator, and the value it is held against. */ +export interface Where { + path: string[] + op: '=' | '!=' | '>' | '>=' | '<' | '<=' | '~' | 'exists' | 'absent' + value: string | number | boolean | RegExp | undefined +} + +const WHERE = /^(!?)([\w.$-]+)(?:(>=|<=|!=|=|>|<|~)(.*))?$/s + +function coerce(raw: string): string | number | boolean { + if (raw === 'true') return true + if (raw === 'false') return false + const number = Number(raw) + return raw.trim() !== '' && !Number.isNaN(number) ? number : raw +} + +/** + * `payment.amount>5000`, `audit.outcome=failure`, `error.message~declined`, + * `user.id`, `!error`. A quoted value keeps its quotes off: `path="/a b"`. + */ +export function parseWhere(raw: string): Where { + const match = WHERE.exec(raw.trim()) + if (!match) throw cliErrors.LOGS_INVALID_WHERE({ value: raw }) + const [, negated, key, op, value] = match + const path = key!.split('.') + if (op === undefined) return { path, op: negated ? 'absent' : 'exists', value: undefined } + if (negated) throw cliErrors.LOGS_INVALID_WHERE({ value: raw }) + if (/^[=<>~!]/.test(value!)) throw cliErrors.LOGS_INVALID_WHERE({ value: raw }) + const text = value!.replace(/^(["'])(.*)\1$/s, '$2') + if (op === '~') { + try { + return { path, op, value: new RegExp(text, 'i') } + } catch { + throw cliErrors.LOGS_INVALID_WHERE({ value: raw }) + } + } + return { path, op: op as Where['op'], value: coerce(text) } +} + +export function parseWheres(value: unknown): Where[] { + const raws = Array.isArray(value) ? value : typeof value === 'string' && value.length > 0 ? [value] : [] + return raws.map(raw => parseWhere(String(raw))) +} + +function read(event: WideEvent, path: string[]): unknown { + let current: unknown = event + for (const key of path) { + if (typeof current !== 'object' || current === null) return undefined + current = (current as Record)[key] + } + return current +} + +export function matchesWhere(event: WideEvent, where: Where): boolean { + const actual = read(event, where.path) + if (where.op === 'exists') return actual !== undefined && actual !== null + if (where.op === 'absent') return actual === undefined || actual === null + if (actual === undefined || actual === null) return false + if (where.op === '~') return where.value instanceof RegExp && where.value.test(typeof actual === 'string' ? actual : JSON.stringify(actual)) + const expected = where.value + if (typeof expected === 'number' && typeof actual === 'number') { + switch (where.op) { + case '=': return actual === expected + case '!=': return actual !== expected + case '>': return actual > expected + case '>=': return actual >= expected + case '<': return actual < expected + case '<=': return actual <= expected + } + } + const left = typeof actual === 'object' ? JSON.stringify(actual) : String(actual) + const right = String(expected) + switch (where.op) { + case '=': return left === right + case '!=': return left !== right + case '>': return left > right + case '>=': return left >= right + case '<': return left < right + case '<=': return left <= right + } + return false +} + export interface LogsQuery { view: LogsView + where: Where[] /** The request or trace id a `trace` view looks for. */ id?: string since?: Date @@ -99,6 +183,7 @@ export interface LogsArgs { status?: string over?: string limit?: string + where?: string | string[] } const DEFAULT_OVER = 500 @@ -149,9 +234,10 @@ export function buildQuery(args: LogsArgs, now = new Date()): LogsQuery { const over = parseOver(args.over) ?? DEFAULT_OVER const limit = parseLimit(args.limit) const path = typeof args.path === 'string' && args.path.length > 0 ? args.path : undefined + const where = parseWheres(args.where) const what = args.what?.trim() - const view: LogsView = what === 'errors' ? 'errors' : what === 'slow' ? 'slow' : what ? 'trace' : 'recent' + const view: LogsView = what === 'errors' ? 'errors' : what === 'slow' ? 'slow' : what === 'stats' ? 'stats' : what ? 'trace' : 'recent' const id = view === 'trace' ? what : undefined const filter = (event: WideEvent): boolean => { @@ -163,10 +249,10 @@ export function buildQuery(args: LogsArgs, now = new Date()): LogsQuery { if (view === 'errors' && !isError(event)) return false if (view === 'slow' && (number(event, 'durationMs') ?? -1) < over) return false if (id !== undefined && !matchesId(event, id)) return false - return true + return where.every(clause => matchesWhere(event, clause)) } - return { view, id, since, until, level, limit, over, filter } + return { view, id, where, since, until, level, limit, over, filter } } /** @@ -175,6 +261,7 @@ export function buildQuery(args: LogsArgs, now = new Date()): LogsQuery { * bottom like `tail`. The `slow` view is the exception: worst first. */ export function select(events: WideEvent[], query: LogsQuery): WideEvent[] { + if (query.view === 'stats') return [] if (query.view === 'slow') { return [...events] .sort((a, b) => (number(b, 'durationMs') ?? 0) - (number(a, 'durationMs') ?? 0)) @@ -182,3 +269,57 @@ export function select(events: WideEvent[], query: LogsQuery): WideEvent[] { } return events.slice(-query.limit) } + +export interface RouteStats { + route: string + count: number + errors: number + p50: number | undefined + p95: number | undefined +} + +export interface LogsStats { + total: number + errors: number + byRoute: RouteStats[] + byStatus: Record + byLevel: Record +} + +function percentile(sorted: number[], p: number): number | undefined { + if (sorted.length === 0) return undefined + return sorted[Math.min(sorted.length - 1, Math.ceil(sorted.length * p) - 1)] +} + +/** The shape of the traffic: per route, per status class, per level. Routes with the most errors first, then the busiest. */ +export function computeStats(events: WideEvent[]): LogsStats { + const routes = new Map() + const byStatus: Record = {} + const byLevel: Record = {} + let errors = 0 + for (const event of events) { + const method = text(event, 'method') + const route = `${method ? `${method} ` : ''}${text(event, 'path') ?? text(event, 'operation') ?? event.service}` + const entry = routes.get(route) ?? { count: 0, errors: 0, durations: [] } + entry.count += 1 + const failed = isError(event) + if (failed) { + entry.errors += 1 + errors += 1 + } + const duration = number(event, 'durationMs') + if (duration !== undefined) entry.durations.push(duration) + routes.set(route, entry) + const status = number(event, 'status') + const statusKey = status === undefined ? 'none' : `${Math.floor(status / 100)}xx` + byStatus[statusKey] = (byStatus[statusKey] ?? 0) + 1 + byLevel[event.level] = (byLevel[event.level] ?? 0) + 1 + } + const byRoute = [...routes.entries()] + .map(([route, entry]) => { + const sorted = [...entry.durations].sort((a, b) => a - b) + return { route, count: entry.count, errors: entry.errors, p50: percentile(sorted, 0.5), p95: percentile(sorted, 0.95) } + }) + .sort((a, b) => b.errors - a.errors || b.count - a.count || a.route.localeCompare(b.route)) + return { total: events.length, errors, byRoute, byStatus, byLevel } +} diff --git a/packages/cli/src/lib/logs/render.ts b/packages/cli/src/lib/logs/render.ts index 56b0ae296..68e957a75 100644 --- a/packages/cli/src/lib/logs/render.ts +++ b/packages/cli/src/lib/logs/render.ts @@ -2,8 +2,8 @@ import type { WideEvent } from 'evlog' import type { CliContext } from '../../core/context' import { createStyle } from '../../core/output' import type { Style, StyleCode } from '../../core/output' -import { field, isError } from './query' -import type { LogsQuery } from './query' +import { computeStats, field, isError } from './query' +import type { LogsQuery, LogsStats } from './query' /** Fields every request event carries, shown in the fixed columns rather than the summary. */ const STANDARD = new Set([ @@ -69,15 +69,21 @@ function summary(event: WideEvent): { text: string, color?: StyleCode } { return { text: fields(event) } } +/** The app an event came from when several directories are read, kept off the event itself. */ +export const SOURCE = Symbol('evlog.source') +export type Sourced = WideEvent & { [SOURCE]?: string } + /** One event on one line: time, request, status, duration, and what mattered. */ -export function formatLine(style: Style, event: WideEvent): string { +export function formatLine(style: Style, event: Sourced): string { const status = typeof field(event, 'status') === 'number' ? field(event, 'status') as number : undefined const method = str(field(event, 'method')) const path = str(field(event, 'path')) ?? str(field(event, 'operation')) ?? event.service const where = method ? `${method.padEnd(6)} ${path}` : ` ${path}` const { text, color } = summary(event) + const source = event[SOURCE] const columns = [ style.paint('dim', clock(event.timestamp)), + ...(source ? [style.paint('cyan', source.padEnd(12))] : []), where.padEnd(44), style.paint(statusColor(status, event.level), status !== undefined ? String(status) : event.level.padEnd(3)), style.paint('dim', (event.duration ?? '').padStart(7)), @@ -139,12 +145,15 @@ export function formatEvent(style: Style, event: WideEvent): string { } export interface LogsResult { - dir: string + /** Where the events came from: a directory per line, or the URL. */ + sources: string[] query: LogsQuery /** Every event that matched, in the reader's order. */ matched: number /** The events shown: `select()` applied to `matched`. */ - events: WideEvent[] + events: Sourced[] + /** Every matched event, for `stats`. */ + all: Sourced[] } function describe(query: LogsQuery): string { @@ -152,20 +161,42 @@ function describe(query: LogsQuery): string { if (query.view === 'errors') parts.push('errors') if (query.view === 'slow') parts.push(`slower than ${query.over}ms`) if (query.view === 'trace') parts.push(`request ${query.id}`) + for (const clause of query.where) parts.push(`${clause.path.join('.')}${clause.op === 'exists' ? '' : clause.op === 'absent' ? ' absent' : `${clause.op}${String(clause.value)}`}`) if (query.since) parts.push(`since ${query.since.toISOString()}`) if (query.until) parts.push(`until ${query.until.toISOString()}`) if (query.level) parts.push(`level ${query.level.join(',')}`) return parts.join(' · ') } +function formatStats(style: Style, stats: LogsStats): string[] { + const lines: string[] = [] + const ms = (value: number | undefined): string => (value === undefined ? '–' : `${value}ms`) + const width = Math.max(5, ...stats.byRoute.map(row => row.route.length)) + lines.push(style.paint('dim', `${'ROUTE'.padEnd(width)} ${'COUNT'.padStart(5)} ${'ERRORS'.padStart(6)} ${'P50'.padStart(7)} ${'P95'.padStart(7)}`)) + for (const row of stats.byRoute) { + const errors = row.errors > 0 ? style.paint('red', String(row.errors).padStart(6)) : String(row.errors).padStart(6) + lines.push(`${row.route.padEnd(width)} ${String(row.count).padStart(5)} ${errors} ${ms(row.p50).padStart(7)} ${ms(row.p95).padStart(7)}`) + } + const classes = Object.entries(stats.byStatus).sort().map(([key, count]) => `${key} ${count}`).join(' · ') + const levels = Object.entries(stats.byLevel).sort((a, b) => b[1] - a[1]).map(([key, count]) => `${key} ${count}`).join(' · ') + lines.push('', `${style.paint('dim', 'status')} ${classes}`, `${style.paint('dim', 'level ')} ${levels}`) + return lines +} + /** The one-shot report: a header, one line per event (or the full event for a trace), and what to try next. */ export function formatLogsReport(ctx: CliContext, result: LogsResult): string { const style = createStyle(ctx) const { query, events, matched } = result const lines: string[] = [] const filters = describe(query) + const where = result.sources.length === 1 ? result.sources[0] : `${result.sources.length} apps` + if (query.view === 'stats') { + lines.push(style.paint('dim', `${matched} event${matched === 1 ? '' : 's'} · ${where}${filters ? ` · ${filters}` : ''}`), '') + if (matched === 0) return [...lines, 'no event matches'].join('\n') + return [...lines, ...formatStats(style, computeStats(result.all))].join('\n') + } const shown = events.length === matched ? `${matched} event${matched === 1 ? '' : 's'}` : `${events.length} of ${matched} events` - lines.push(style.paint('dim', `${shown} · ${result.dir}${filters ? ` · ${filters}` : ''}`), '') + lines.push(style.paint('dim', `${shown} · ${where}${filters ? ` · ${filters}` : ''}`), '') if (events.length === 0) { lines.push(query.view === 'trace' ? `no event carries the id ${query.id}` : 'no event matches') @@ -184,6 +215,7 @@ export function formatLogsReport(ctx: CliContext, result: LogsResult): string { if (query.view === 'recent' && failures > 0) hints.push(`evlog logs errors — the ${failures} that failed`) hints.push('evlog logs — one request in full') if (query.view !== 'slow') hints.push('evlog logs slow — worst first') + if (query.view === 'recent') hints.push('evlog logs stats — by route') lines.push('', style.paint('dim', hints.join(' · '))) return lines.join('\n') } diff --git a/packages/cli/test/logs.command.test.ts b/packages/cli/test/logs.command.test.ts index 7ff790c2c..e7de4c468 100644 --- a/packages/cli/test/logs.command.test.ts +++ b/packages/cli/test/logs.command.test.ts @@ -7,7 +7,7 @@ import { afterEach, describe, expect, it, vi } from 'vitest' import logs, { runLogs } from '../src/commands/logs' import { createContext } from '../src/core/context' import type { CliContext } from '../src/core/context' -import { buildQuery, matchesId, parseDuration, parseTime } from '../src/lib/logs/query' +import { buildQuery, computeStats, matchesId, matchesWhere, parseDuration, parseTime, parseWhere } from '../src/lib/logs/query' import { formatEvent, formatLine } from '../src/lib/logs/render' import { createStyle } from '../src/core/output' @@ -109,6 +109,43 @@ describe('parsing', () => { expect(() => buildQuery(args)).toThrow(message) }) + it('reads every --where shape', () => { + expect(parseWhere('user.id=42')).toEqual({ path: ['user', 'id'], op: '=', value: 42 }) + expect(parseWhere('payment.amount>5000')).toMatchObject({ op: '>', value: 5000 }) + expect(parseWhere('status<=299')).toMatchObject({ op: '<=', value: 299 }) + expect(parseWhere('audit.outcome!=success')).toMatchObject({ op: '!=', value: 'success' }) + expect(parseWhere('error.message~declined')).toMatchObject({ op: '~' }) + expect(parseWhere('path="/a b"')).toMatchObject({ op: '=', value: '/a b' }) + expect(parseWhere('audit')).toEqual({ path: ['audit'], op: 'exists', value: undefined }) + expect(parseWhere('!error')).toEqual({ path: ['error'], op: 'absent', value: undefined }) + expect(parseWhere('cart.items=true')).toMatchObject({ value: true }) + }) + + it.each(['', '=1', '!user=1', 'a~[', 'a>>1'])('rejects --where %j', (raw) => { + expect(() => parseWhere(raw)).toThrow(/Invalid --where/) + }) + + it('compares numbers as numbers, strings as strings, and reaches into objects', () => { + const e = event({ user: { id: 'usr_7', plan: 'pro' }, cart: { total: 9999 } }) + expect(matchesWhere(e, parseWhere('cart.total>5000'))).toBe(true) + expect(matchesWhere(e, parseWhere('cart.total>10000'))).toBe(false) + expect(matchesWhere(e, parseWhere('user.plan=pro'))).toBe(true) + expect(matchesWhere(e, parseWhere('user.plan!=pro'))).toBe(false) + expect(matchesWhere(e, parseWhere('user.id~^usr_'))).toBe(true) + expect(matchesWhere(e, parseWhere('user'))).toBe(true) + expect(matchesWhere(e, parseWhere('!error'))).toBe(true) + expect(matchesWhere(e, parseWhere('error'))).toBe(false) + expect(matchesWhere(e, parseWhere('missing.deep=1'))).toBe(false) + }) + + it('takes several --where clauses and requires all of them', () => { + const query = buildQuery({ where: ['status=200', 'durationMs>50'] }) + expect(query.where).toHaveLength(2) + expect(query.filter(event({ status: 200, durationMs: 80 }))).toBe(true) + expect(query.filter(event({ status: 200, durationMs: 10 }))).toBe(false) + expect(buildQuery({ where: 'status=200' }).where).toHaveLength(1) + }) + it('matches an id exactly, or by a prefix of at least eight characters', () => { const e = event({ requestId: 'cccccccc-0000-4000-8000-000000000003', traceId: 'trace-1' }) expect(matchesId(e, 'cccccccc-0000-4000-8000-000000000003')).toBe(true) @@ -122,7 +159,7 @@ describe('runLogs', () => { it('shows the last events oldest first, across both file formats', async () => { const cwd = await makeSink() const result = await runLogs(fakeContext(cwd), {}, { now: NOW }) - expect(result.dir).toBe(join(cwd, '.evlog', 'logs')) + expect(result.sources).toEqual(['.evlog/logs']) expect(result.matched).toBe(6) expect(result.events.map(e => e.path)).toEqual(['/api/health', '/api/checkout', '/api/reports', '/api/refund', '/api/items', '/api/items']) }) @@ -166,6 +203,80 @@ describe('runLogs', () => { expect((await runLogs(ctx, { status: '402' }, { now: NOW })).events.map(e => e.path)).toEqual(['/api/checkout']) }) + it('--where composes with a view', async () => { + const cwd = await makeSink() + const ctx = fakeContext(cwd) + expect((await runLogs(ctx, { where: 'audit.actor.id=usr_42' }, { now: NOW })).events.map(e => e.path)).toEqual(['/api/refund']) + expect((await runLogs(ctx, { what: 'errors', where: 'error.data.why~declined' }, { now: NOW })).events.map(e => e.status)).toEqual([402]) + expect((await runLogs(ctx, { where: ['!error', 'durationMs>=700'] }, { now: NOW })).events.map(e => e.path)).toEqual(['/api/reports', '/api/items']) + }) + + it('stats: per route with errors first, then by status class and level', async () => { + const cwd = await makeSink() + const result = await runLogs(fakeContext(cwd), { what: 'stats' }, { now: NOW }) + expect(result.events).toEqual([]) + expect(result.matched).toBe(6) + const stats = computeStats(result.all) + expect(stats.total).toBe(6) + expect(stats.errors).toBe(2) + expect(stats.byRoute[0]).toEqual({ route: 'GET /api/items', count: 2, errors: 1, p50: 30, p95: 700 }) + expect(stats.byRoute[1]).toMatchObject({ route: 'POST /api/checkout', count: 1, errors: 1, p50: 412 }) + expect(stats.byStatus).toEqual({ '2xx': 4, '4xx': 1, '5xx': 1 }) + expect(stats.byLevel).toEqual({ info: 4, error: 1, warn: 1 }) + }) + + it('reads every app of a workspace when the root has no logs, labelling each event', async () => { + const root = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-mono-')) + tempDirs.push(root) + await writeFile(join(root, 'package.json'), JSON.stringify({ name: 'mono', workspaces: ['apps/*'] })) + for (const [app, path, at] of [['web', '/home', '2026-10-01T10:00:00.000Z'], ['api', '/users', '2026-10-01T09:00:00.000Z']] as const) { + await mkdir(join(root, 'apps', app, '.evlog', 'logs'), { recursive: true }) + await writeFile(join(root, 'apps', app, 'package.json'), JSON.stringify({ name: app })) + await writeFile(join(root, 'apps', app, '.evlog', 'logs', '2026-10-01.jsonl'), `${JSON.stringify(event({ path, timestamp: at }))}\n`) + } + await mkdir(join(root, 'apps', 'docs')) + const result = await runLogs(fakeContext(root), {}, { now: NOW }) + expect(result.sources).toEqual(['apps/api/.evlog/logs', 'apps/web/.evlog/logs']) + expect(result.events.map(e => e.path)).toEqual(['/users', '/home']) + expect(formatLine(createStyle({ color: false }), result.events[0]!)).toMatch(/^\S+ api\s+GET \/users/) + }) + + it('reads a memory drain endpoint with --url, and follows it by polling', async () => { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-url-')) + tempDirs.push(cwd) + const snapshot: WideEvent[] = [EVENTS[1]!, EVENTS[4]!] + const fetchFn = (() => Promise.resolve({ ok: true, status: 200, json: () => Promise.resolve(snapshot) })) as unknown as typeof fetch + const result = await runLogs(fakeContext(cwd), { what: 'errors' }, { url: 'http://localhost:3000/_evlog/logs', fetchFn, now: NOW }) + expect(result.sources).toEqual(['http://localhost:3000/_evlog/logs']) + expect(result.events.map(e => e.status)).toEqual([402, 500]) + + const wrapped = (() => Promise.resolve({ ok: true, status: 200, json: () => Promise.resolve({ events: snapshot }) })) as unknown as typeof fetch + expect((await runLogs(fakeContext(cwd), {}, { url: 'http://x', fetchFn: wrapped, now: NOW })).matched).toBe(2) + + const controller = new AbortController() + const seen: WideEvent[] = [] + const run = runLogs(fakeContext(cwd), {}, { + url: 'http://x', fetchFn, follow: true, signal: controller.signal, now: NOW, + onEvent: (e) => { + seen.push(e) + controller.abort() + }, + }) + await new Promise(resolve => setTimeout(resolve, 50)) + snapshot.push(event({ timestamp: '2026-10-01T11:59:00.000Z', path: '/api/new' })) + await run + expect(seen.map(e => e.path)).toEqual(['/api/new']) + }) + + it('an unreachable --url is a failure with the fix', async () => { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-url-down-')) + tempDirs.push(cwd) + const down = (() => Promise.reject(new Error('ECONNREFUSED'))) as unknown as typeof fetch + await expect(runLogs(fakeContext(cwd), {}, { url: 'http://localhost:1', fetchFn: down })).rejects.toThrow(/Could not read events from http:\/\/localhost:1: ECONNREFUSED/) + const notJson = (() => Promise.resolve({ ok: true, status: 200, json: () => Promise.resolve({ hello: 1 }) })) as unknown as typeof fetch + await expect(runLogs(fakeContext(cwd), {}, { url: 'http://x', fetchFn: notJson })).rejects.toThrow(/not a JSON array/) + }) + it('reads --dir as given and refuses a project with no sink', async () => { const cwd = await makeSink() const elsewhere = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-other-')) @@ -237,6 +348,17 @@ describe('logs command', () => { expect(process.exitCode).toBe(2) }) + it('stats --json carries the table instead of events', async () => { + const cwd = await makeSink() + const out = captureStdout() + await runCommand(logs, { rawArgs: ['--cwd', cwd, '--json', '--no-header', 'stats', '--where', 'status<500'] }) + const payload = JSON.parse(out.join('')) as { view: string, matched: number, events?: unknown, stats: { total: number, byStatus: Record } } + expect(payload.view).toBe('stats') + expect(payload.events).toBeUndefined() + expect(payload.stats.total).toBe(5) + expect(payload.stats.byStatus).toEqual({ '2xx': 4, '4xx': 1 }) + }) + it('no sink is a failure with the fix', async () => { const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-empty-')) tempDirs.push(cwd) diff --git a/skills/analyze-logs/SKILL.md b/skills/analyze-logs/SKILL.md index c5f6204f6..1c6fe62e4 100644 --- a/skills/analyze-logs/SKILL.md +++ b/skills/analyze-logs/SKILL.md @@ -28,9 +28,11 @@ npx evlog logs --json # the last 50 events npx evlog logs errors --since 1h --json # what failed npx evlog logs slow --over 1s --json # what was slow, worst first npx evlog logs --json # one request, every event with that id +npx evlog logs stats --json # per route: count, errors, p50, p95; by status and level +npx evlog logs --where payment.amount>5000 --where audit.outcome=failure --json ``` -`--json` is an envelope (`dir`, `view`, `matched`, `events`); filters are `--since`, `--until`, `--level`, `--path`, `--status` (`500` or `5xx`), `--limit`, and `--dir` for a non-default directory. Docs: https://www.evlog.dev/cli/logs. If the CLI is unavailable or the user declines it, read the files directly as below. +`--json` is an envelope (`sources`, `view`, `matched`, `events`; `stats` carries `stats` instead); filters are `--since`, `--until`, `--level`, `--path`, `--status` (`500` or `5xx`), `--where field=value|field>n|field~regex|field|!field` on any dotted field (repeatable), `--limit`, `--dir` for a non-default directory, and `--url` for an app on the memory drain that exposes `readMemoryLogs()` over HTTP. From a monorepo root it reads every app's `.evlog/logs` and labels each event. Docs: https://www.evlog.dev/cli/logs. If the CLI is unavailable or the user declines it, read the files directly as below. Logs are written by evlog's file system drain as `.jsonl` files, organized by date. From 9ecfa47e6fc4333f92d0c157117df4c0f6ec9aa3 Mon Sep 17 00:00:00 2001 From: Hugo Richard Date: Mon, 5 Oct 2026 21:05:25 +0100 Subject: [PATCH 3/5] fix(cli): stream what logs -f already found, keep following a flaky endpoint, compare numeric text as numbers --- apps/docs/content/3.cli/10.logs.md | 8 ++--- packages/cli/README.md | 4 +-- packages/cli/src/commands/logs.ts | 13 ++++++- packages/cli/src/lib/logs/query.ts | 21 +++++++---- packages/cli/test/logs.command.test.ts | 49 +++++++++++++++++++++++--- skills/analyze-logs/SKILL.md | 16 ++++----- 6 files changed, 84 insertions(+), 27 deletions(-) diff --git a/apps/docs/content/3.cli/10.logs.md b/apps/docs/content/3.cli/10.logs.md index f20b6d386..ec5c27bae 100644 --- a/apps/docs/content/3.cli/10.logs.md +++ b/apps/docs/content/3.cli/10.logs.md @@ -86,13 +86,13 @@ A clause is a dotted field, an operator, and a value. Numbers compare as numbers | `!error` | the field is absent | ```bash [Terminal] -evlog logs --where payment.amount>5000 --where audit.outcome=failure -evlog logs errors --where error.data.why~"card declined" +evlog logs --where 'payment.amount>5000' --where audit.outcome=failure +evlog logs errors --where 'error.data.why~card declined' evlog logs stats --where user.plan=pro -evlog logs -f --where '!error' --where durationMs>1000 +evlog logs -f --where '!error' --where 'durationMs>1000' ``` -Quote a value with spaces (`path="/a b"`), and quote the whole clause when the shell would read `>` or `!` (`'durationMs>1000'`, `'!error'`). +Quote the whole clause whenever it carries `>`, `<` or `!`, which the shell reads as redirection or history before `evlog` ever sees them, and whenever the value has a space: `'payment.amount>5000'`, `'!error'`, `'error.data.why~card declined'`. ## For agents diff --git a/packages/cli/README.md b/packages/cli/README.md index b96e7c3ad..cf4fea074 100644 --- a/packages/cli/README.md +++ b/packages/cli/README.md @@ -67,11 +67,11 @@ pnpm evlog map | `evlog map --verbose` | Show per-file parse warnings | | `evlog map --cwd ` | Scan another app in the workspace | | `evlog logs` | The last 50 wide events the fs drain wrote, oldest first | -| `evlog logs errors` | The ones that failed: a `5xx`, an `error` level, or an `error` block | +| `evlog logs errors` | The ones that failed: a `5xx`, an `error` or `fatal` level, or an `error` block | | `evlog logs slow [--over 1s]` | Over the bar (default 500ms), worst first | | `evlog logs ` | One request in full: error with `why`/`fix`, audit record, business fields | | `evlog logs stats` | Per route: count, errors, p50, p95; then by status class and level | -| `evlog logs --where payment.amount>5000 --where audit.outcome=failure` | Any field on the event: `=`, `!=`, `>`, `>=`, `<`, `<=`, `~regex`, present, `!absent` | +| `evlog logs --where 'payment.amount>5000' --where audit.outcome=failure` | Any field on the event: `=`, `!=`, `>`, `>=`, `<`, `<=`, `~regex`, present, `!absent` | | `evlog logs --url http://localhost:8787/_evlog/logs` | Read the memory drain's dev endpoint instead of files | | `evlog logs -f` | Follow new events as the app writes them | | `evlog logs --since 15m --path /api/x --status 5xx --level error` | Filters, composable with every view | diff --git a/packages/cli/src/commands/logs.ts b/packages/cli/src/commands/logs.ts index 051a42ea8..5e92995f9 100644 --- a/packages/cli/src/commands/logs.ts +++ b/packages/cli/src/commands/logs.ts @@ -128,6 +128,10 @@ export async function runLogs(ctx: CliContext, args: LogsArgs, options: RunLogsO const result: LogsResult = { sources, query, matched: all.length, events: select(all, query), all } if (options.follow) { + /* `tail -f` shows the end of the file before it waits, and the caller only + renders what it is handed, so the events already found go through the + same path as the ones still to come. */ + for (const event of result.events) options.onEvent?.(event) if (options.url) await followUrl(options.url, all, inRange, options) else await followDirs(await resolveLogsSources(ctx, options.dir), query, options) } @@ -179,7 +183,14 @@ async function followUrl(url: string, shown: WideEvent[], inRange: (event: WideE while (!options.signal?.aborted) { await pause(1000, options.signal) if (options.signal?.aborted) return - const events = (await fetchEvents(url, fetchFn)).filter(inRange) + let events: WideEvent[] + try { + events = (await fetchEvents(url, fetchFn)).filter(inRange) + } catch { + /* A follower outlives the app it watches: a dev server restarting is a + gap in the stream, not a reason to stop. */ + continue + } const fresh: WideEvent[] = [] for (const event of events) { if (isFresh(event, seen)) fresh.push(event) diff --git a/packages/cli/src/lib/logs/query.ts b/packages/cli/src/lib/logs/query.ts index f9e8f5150..ec261b2eb 100644 --- a/packages/cli/src/lib/logs/query.ts +++ b/packages/cli/src/lib/logs/query.ts @@ -136,14 +136,21 @@ export function matchesWhere(event: WideEvent, where: Where): boolean { if (actual === undefined || actual === null) return false if (where.op === '~') return where.value instanceof RegExp && where.value.test(typeof actual === 'string' ? actual : JSON.stringify(actual)) const expected = where.value - if (typeof expected === 'number' && typeof actual === 'number') { + /* A numeric field does not always arrive as a number — a header, an env var + or a hand-written payload carries it as text, and `"10000" > "5000"` is + false lexicographically. Against a numeric clause, read it as the number + it is rather than silently answering the wrong question. */ + const number = typeof actual === 'number' + ? actual + : typeof actual === 'string' && actual.trim() !== '' ? Number(actual) : Number.NaN + if (typeof expected === 'number' && !Number.isNaN(number)) { switch (where.op) { - case '=': return actual === expected - case '!=': return actual !== expected - case '>': return actual > expected - case '>=': return actual >= expected - case '<': return actual < expected - case '<=': return actual <= expected + case '=': return number === expected + case '!=': return number !== expected + case '>': return number > expected + case '>=': return number >= expected + case '<': return number < expected + case '<=': return number <= expected } } const left = typeof actual === 'object' ? JSON.stringify(actual) : String(actual) diff --git a/packages/cli/test/logs.command.test.ts b/packages/cli/test/logs.command.test.ts index e7de4c468..2c49ee74c 100644 --- a/packages/cli/test/logs.command.test.ts +++ b/packages/cli/test/logs.command.test.ts @@ -138,6 +138,16 @@ describe('parsing', () => { expect(matchesWhere(e, parseWhere('missing.deep=1'))).toBe(false) }) + it('reads a numeric field that arrived as text as the number it is', () => { + const e = event({ headers: { 'content-length': '10000' }, label: '5kg' }) + expect(matchesWhere(e, parseWhere('headers.content-length>5000'))).toBe(true) + expect(matchesWhere(e, parseWhere('headers.content-length<5000'))).toBe(false) + expect(matchesWhere(e, parseWhere('headers.content-length=10000'))).toBe(true) + /* Text that is not a number is still compared as text, not coerced. */ + expect(matchesWhere(e, parseWhere('label=5kg'))).toBe(true) + expect(matchesWhere(e, parseWhere('label=5'))).toBe(false) + }) + it('takes several --where clauses and requires all of them', () => { const query = buildQuery({ where: ['status=200', 'durationMs>50'] }) expect(query.where).toHaveLength(2) @@ -259,13 +269,41 @@ describe('runLogs', () => { url: 'http://x', fetchFn, follow: true, signal: controller.signal, now: NOW, onEvent: (e) => { seen.push(e) - controller.abort() + if (seen.length === 3) controller.abort() }, }) await new Promise(resolve => setTimeout(resolve, 50)) snapshot.push(event({ timestamp: '2026-10-01T11:59:00.000Z', path: '/api/new' })) await run - expect(seen.map(e => e.path)).toEqual(['/api/new']) + expect(seen.map(e => e.path)).toEqual(['/api/checkout', '/api/items', '/api/new']) + }) + + it('a failed poll is a gap in the follow, not the end of it', async () => { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-url-flaky-')) + tempDirs.push(cwd) + const snapshot: WideEvent[] = [EVENTS[0]!] + let polls = 0 + const flaky = (() => { + polls += 1 + /* The second call is the first poll: the app is restarting. */ + if (polls === 2) return Promise.reject(new Error('ECONNREFUSED')) + return Promise.resolve({ ok: true, status: 200, json: () => Promise.resolve(snapshot) }) + }) as unknown as typeof fetch + + const controller = new AbortController() + const seen: WideEvent[] = [] + const run = runLogs(fakeContext(cwd), {}, { + url: 'http://x', fetchFn: flaky, follow: true, signal: controller.signal, now: NOW, + onEvent: (e) => { + seen.push(e) + if (seen.length === 2) controller.abort() + }, + }) + await new Promise(resolve => setTimeout(resolve, 50)) + snapshot.push(event({ timestamp: '2026-10-01T11:59:00.000Z', path: '/api/back-up' })) + await run + expect(polls).toBeGreaterThanOrEqual(3) + expect(seen.map(e => e.path)).toEqual(['/api/health', '/api/back-up']) }) it('an unreachable --url is a failure with the fix', async () => { @@ -287,7 +325,7 @@ describe('runLogs', () => { await expect(runLogs(fakeContext(elsewhere), {}, { now: NOW })).rejects.toThrow(/No local logs/) }) - it('follows: new lines arrive through onEvent until the signal aborts', async () => { + it('follows: what it already found streams first, then what arrives, until the signal aborts', async () => { const cwd = await makeSink() const controller = new AbortController() const seen: WideEvent[] = [] @@ -297,14 +335,15 @@ describe('runLogs', () => { now: NOW, onEvent: (event) => { seen.push(event) - controller.abort() + if (seen.length === 3) controller.abort() }, }) await new Promise(resolve => setTimeout(resolve, 300)) await appendFile(join(cwd, '.evlog', 'logs', '2026-10-01.jsonl'), `${JSON.stringify(event({ timestamp: '2026-10-01T11:50:00.000Z', path: '/api/other' }))}\n${JSON.stringify(event({ timestamp: '2026-10-01T11:51:00.000Z', path: '/api/items', status: 201 }))}\n`) const result = await run expect(result.matched).toBe(2) - expect(seen.map(e => e.status)).toEqual([201]) + /* The two already on disk, oldest first, then the one appended. */ + expect(seen.map(e => e.status)).toEqual([500, 200, 201]) }) }) diff --git a/skills/analyze-logs/SKILL.md b/skills/analyze-logs/SKILL.md index 1c6fe62e4..dc3fa60f3 100644 --- a/skills/analyze-logs/SKILL.md +++ b/skills/analyze-logs/SKILL.md @@ -21,15 +21,15 @@ Read and analyze structured wide-event logs from the local `.evlog/logs/` direct ## Finding the logs -Try the CLI first; it reads both file layouts, every dated file, and knows where the project's drain writes: +Try the CLI first; it reads both file layouts, every dated file, and knows where the project's drain writes. Prefer the copy the project installed (`pnpm evlog`, `npm exec evlog`, `bunx evlog`): `npx evlog` fetches `@evlog/cli` when the project has none, which runs code the lockfile never pinned. Ask before that happens. ```bash -npx evlog logs --json # the last 50 events -npx evlog logs errors --since 1h --json # what failed -npx evlog logs slow --over 1s --json # what was slow, worst first -npx evlog logs --json # one request, every event with that id -npx evlog logs stats --json # per route: count, errors, p50, p95; by status and level -npx evlog logs --where payment.amount>5000 --where audit.outcome=failure --json +pnpm evlog logs --json # the last 50 events +pnpm evlog logs errors --since 1h --json # what failed +pnpm evlog logs slow --over 1s --json # what was slow, worst first +pnpm evlog logs "$REQUEST_ID" --json # one request, every event with that id +pnpm evlog logs stats --json # per route: count, errors, p50, p95; by status and level +pnpm evlog logs --where 'payment.amount>5000' --where audit.outcome=failure --json ``` `--json` is an envelope (`sources`, `view`, `matched`, `events`; `stats` carries `stats` instead); filters are `--since`, `--until`, `--level`, `--path`, `--status` (`500` or `5xx`), `--where field=value|field>n|field~regex|field|!field` on any dotted field (repeatable), `--limit`, `--dir` for a non-default directory, and `--url` for an app on the memory drain that exposes `readMemoryLogs()` over HTTP. From a monorepo root it reads every app's `.evlog/logs` and labels each event. Docs: https://www.evlog.dev/cli/logs. If the CLI is unavailable or the user declines it, read the files directly as below. @@ -131,7 +131,7 @@ Read the latest `.jsonl` file. Each line is one JSON event. Parse each line inde Filter based on the user's question: -- **Errors**: look for `"level":"error"` or `status >= 400` +- **Errors**: `"level"` of `"error"` or `"fatal"`, `status >= 500`, or an `error` object on the event, which is what `evlog logs errors` matches. A 4xx is the client's own and is not counted; read `status` or pass `--status 4xx` for those - **Specific endpoint**: match on `path` - **Slow requests**: filter on `durationMs` (e.g. `durationMs > 500`) - **Specific user/action**: match on application-specific fields From 69f644b33a90d80da3d562d53557166e0f8db21c Mon Sep 17 00:00:00 2001 From: Hugo Richard Date: Mon, 5 Oct 2026 23:41:30 +0100 Subject: [PATCH 4/5] fix(cli): interrupt a stalled logs --url poll and report a quiet endpoint --- .changeset/cli-logs.md | 2 +- apps/docs/content/3.cli/10.logs.md | 2 +- packages/cli/src/commands/logs.ts | 31 ++++++++++++---- packages/cli/test/logs.command.test.ts | 50 ++++++++++++++++++++++++++ skills/analyze-logs/SKILL.md | 2 +- 5 files changed, 78 insertions(+), 9 deletions(-) diff --git a/.changeset/cli-logs.md b/.changeset/cli-logs.md index 1884d91d9..1afa331be 100644 --- a/.changeset/cli-logs.md +++ b/.changeset/cli-logs.md @@ -2,4 +2,4 @@ "@evlog/cli": minor --- -`evlog logs` reads the wide events the fs drain wrote to `.evlog/logs`: the last 50 (`evlog logs`), the failures (`evlog logs errors`), the slowest (`evlog logs slow --over 1s`), one request in full by id (`evlog logs `, a UUID prefix is enough), or the shape of the traffic (`evlog logs stats`: per route, status class and level). Filters compose with every view: `--since 15m`, `--until`, `--level error,fatal`, `--path`, `--status 5xx`, `--where payment.amount>5000` on any field of the event (`=`, `!=`, `>`, `>=`, `<`, `<=`, `~regex`, present, `!absent`, repeatable), `--limit`, `--dir`. `-f` follows new events like `tail -f`; `--json` returns the events as JSON. It finds the project's log directory the way `doctor` does, reads every app of a workspace when the root has none, reads the memory drain's dev endpoint with `--url`, handles both the compact and the pretty layout, and never writes. +`evlog logs` reads the wide events the fs drain wrote to `.evlog/logs`: the last 50 (`evlog logs`), the failures (`evlog logs errors`), the slowest (`evlog logs slow --over 1s`), one request in full by id (`evlog logs `, a UUID prefix is enough), or the shape of the traffic (`evlog logs stats`: per route, status class and level). Filters compose with every view: `--since 15m`, `--until`, `--level error,fatal`, `--path`, `--status 5xx`, `--where payment.amount>5000` on any field of the event (`=`, `!=`, `>`, `>=`, `<`, `<=`, `~regex`, present, `!absent`, repeatable), `--limit`, `--dir`. `-f` follows new events like `tail -f`; `--json` returns the events as JSON. It finds the project's log directory the way `doctor` does, reads every app of a workspace when the root has none, reads the memory drain's dev endpoint with `--url` (a follow there survives the app restarting, and says so when the endpoint stays quiet), handles both the compact and the pretty layout, and never writes. diff --git a/apps/docs/content/3.cli/10.logs.md b/apps/docs/content/3.cli/10.logs.md index ec5c27bae..6b0bf7bf0 100644 --- a/apps/docs/content/3.cli/10.logs.md +++ b/apps/docs/content/3.cli/10.logs.md @@ -119,7 +119,7 @@ evlog logs errors --since 30m --json Run from a monorepo root with no `.evlog/logs` of its own, it reads every app that has one (`apps/*`, `packages/*`, `examples/*`, `services/*`), merges the events by time, and shows the app in a column. `--cwd apps/web` reads one app; `--dir` reads one directory. -An app on the [memory drain](/integrate/adapters/self-hosted/memory) (Cloudflare Workers, where there is no file system) has no files to read, but it can expose `readMemoryLogs()` on a dev route. Point `--url` at it; every view and filter works the same, and `-f` polls it once a second. +An app on the [memory drain](/integrate/adapters/self-hosted/memory) (Cloudflare Workers, where there is no file system) has no files to read, but it can expose `readMemoryLogs()` on a dev route. Point `--url` at it; every view and filter works the same, and `-f` polls it once a second. A failed poll is a gap rather than the end, since the app restarting under a follower is normal; if the endpoint stays quiet the run says so once and keeps trying. ```bash [Terminal] evlog logs errors --url http://localhost:8787/_evlog/logs diff --git a/packages/cli/src/commands/logs.ts b/packages/cli/src/commands/logs.ts index 5e92995f9..71dc15c45 100644 --- a/packages/cli/src/commands/logs.ts +++ b/packages/cli/src/commands/logs.ts @@ -71,8 +71,12 @@ export interface RunLogsOptions { signal?: AbortSignal /** Called for each event that arrives while following. */ onEvent?: (event: Sourced) => void + /** Called when following has something to say that is not an event: the endpoint went quiet, or came back. */ + onNotice?: (message: string) => void now?: Date fetchFn?: typeof fetch + /** How often a followed `--url` is re-read. The endpoint is a snapshot, so there is nothing to wait on. */ + pollIntervalMs?: number } function tag(event: WideEvent, name: string | undefined): Sourced { @@ -80,10 +84,10 @@ function tag(event: WideEvent, name: string | undefined): Sourced { return Object.defineProperty(event, SOURCE, { value: name, enumerable: false }) as Sourced } -async function fetchEvents(url: string, fetchFn: typeof fetch): Promise { +async function fetchEvents(url: string, fetchFn: typeof fetch, signal?: AbortSignal): Promise { let response: Response try { - response = await fetchFn(url, { headers: { accept: 'application/json' } }) + response = await fetchFn(url, { headers: { accept: 'application/json' }, signal }) } catch (error) { throw cliErrors.LOGS_URL_UNREACHABLE({ url, reason: error instanceof Error ? error.message : String(error) }) } @@ -111,7 +115,7 @@ export async function runLogs(ctx: CliContext, args: LogsArgs, options: RunLogsO let all: Sourced[] let sources: string[] if (options.url) { - all = (await fetchEvents(options.url, fetchFn)).filter(inRange) + all = (await fetchEvents(options.url, fetchFn, options.signal)).filter(inRange) sources = [options.url] } else { const found = await resolveLogsSources(ctx, options.dir) @@ -172,6 +176,13 @@ function pause(ms: number, signal: AbortSignal | undefined): Promise { }) } +/** + * Consecutive failed polls before the silence is reported. A restart takes a + * few seconds, so warning on the first one would cry wolf; never warning + * leaves a follower that looks alive and delivers nothing. + */ +const QUIET_POLLS = 5 + /** * The endpoint is a snapshot, so following it means polling and keeping what * was already shown apart from what is new: an event later than the newest @@ -180,15 +191,22 @@ function pause(ms: number, signal: AbortSignal | undefined): Promise { async function followUrl(url: string, shown: WideEvent[], inRange: (event: WideEvent) => boolean, options: RunLogsOptions): Promise { const fetchFn = options.fetchFn ?? fetch let seen = seenOf(shown, shown.reduce((max, event) => Math.max(max, timeOf(event)), 0)) + let failures = 0 while (!options.signal?.aborted) { - await pause(1000, options.signal) + await pause(options.pollIntervalMs ?? 1000, options.signal) if (options.signal?.aborted) return let events: WideEvent[] try { - events = (await fetchEvents(url, fetchFn)).filter(inRange) - } catch { + events = (await fetchEvents(url, fetchFn, options.signal)).filter(inRange) + if (failures >= QUIET_POLLS) options.onNotice?.(`${url} is answering again`) + failures = 0 + } catch (error) { /* A follower outlives the app it watches: a dev server restarting is a gap in the stream, not a reason to stop. */ + failures += 1 + if (failures === QUIET_POLLS) { + options.onNotice?.(`no answer from ${url} for ${failures} polls (${error instanceof Error ? error.message : String(error)}) — still trying`) + } continue } const fresh: WideEvent[] = [] @@ -237,6 +255,7 @@ export default defineEvlogCommand('logs', { if (args.json) ui.stdout(JSON.stringify(event)) else ui.human(formatLine(style, event)) }, + onNotice: message => ui.human(style.paint('dim', message)), }) } catch (error) { if (error instanceof EvlogError) { diff --git a/packages/cli/test/logs.command.test.ts b/packages/cli/test/logs.command.test.ts index 2c49ee74c..18c0cf728 100644 --- a/packages/cli/test/logs.command.test.ts +++ b/packages/cli/test/logs.command.test.ts @@ -306,6 +306,56 @@ describe('runLogs', () => { expect(seen.map(e => e.path)).toEqual(['/api/health', '/api/back-up']) }) + it('hands the abort signal to the fetch, so a stalled poll can be interrupted', async () => { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-url-signal-')) + tempDirs.push(cwd) + const signals: Array = [] + const controller = new AbortController() + const fetchFn = ((_url: string, init?: { signal?: AbortSignal }) => { + signals.push(init?.signal) + if (signals.length === 2) controller.abort() + return Promise.resolve({ ok: true, status: 200, json: () => Promise.resolve([EVENTS[1]!]) }) + }) as unknown as typeof fetch + + await runLogs(fakeContext(cwd), {}, { url: 'http://x', fetchFn, follow: true, signal: controller.signal, pollIntervalMs: 5, now: NOW }) + + expect(signals).toHaveLength(2) + expect(signals.every(signal => signal === controller.signal)).toBe(true) + }) + + it('says when a followed endpoint goes quiet, and when it answers again', async () => { + const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-url-quiet-')) + tempDirs.push(cwd) + let calls = 0 + const fetchFn = (() => { + calls += 1 + /* The first call is the one-shot read; then six dead polls, then it is back. */ + if (calls > 1 && calls <= 7) return Promise.reject(new Error('ECONNREFUSED')) + return Promise.resolve({ ok: true, status: 200, json: () => Promise.resolve([EVENTS[1]!]) }) + }) as unknown as typeof fetch + + const controller = new AbortController() + const notices: string[] = [] + await runLogs(fakeContext(cwd), {}, { + url: 'http://x', + fetchFn, + follow: true, + signal: controller.signal, + pollIntervalMs: 5, + now: NOW, + onNotice: (message) => { + notices.push(message) + if (notices.length === 2) controller.abort() + }, + }) + + /* One line per outage, not one per poll: the sixth failure is silent. */ + expect(notices).toEqual([ + 'no answer from http://x for 5 polls (Could not read events from http://x: ECONNREFUSED) — still trying', + 'http://x is answering again', + ]) + }) + it('an unreachable --url is a failure with the fix', async () => { const cwd = await mkdtemp(join(tmpdir(), 'evlog-cli-logs-url-down-')) tempDirs.push(cwd) diff --git a/skills/analyze-logs/SKILL.md b/skills/analyze-logs/SKILL.md index dc3fa60f3..1c818a8ca 100644 --- a/skills/analyze-logs/SKILL.md +++ b/skills/analyze-logs/SKILL.md @@ -21,7 +21,7 @@ Read and analyze structured wide-event logs from the local `.evlog/logs/` direct ## Finding the logs -Try the CLI first; it reads both file layouts, every dated file, and knows where the project's drain writes. Prefer the copy the project installed (`pnpm evlog`, `npm exec evlog`, `bunx evlog`): `npx evlog` fetches `@evlog/cli` when the project has none, which runs code the lockfile never pinned. Ask before that happens. +Try the CLI first; it reads both file layouts, every dated file, and knows where the project's drain writes. Prefer the copy the project installed (`pnpm evlog`, or the equivalent for its package manager). The wrappers that fetch on demand (`npx`, `bunx`, `npm exec`) install `@evlog/cli` when the project has none, which runs a release the lockfile never pinned. Ask before that happens. ```bash pnpm evlog logs --json # the last 50 events From 7cf7d32545fb8f6beebdc8e745ee9d0e02fab23b Mon Sep 17 00:00:00 2001 From: Hugo Richard Date: Tue, 6 Oct 2026 08:19:41 +0100 Subject: [PATCH 5/5] docs: a 4xx event still counts as an error when it carries one --- skills/analyze-logs/SKILL.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/skills/analyze-logs/SKILL.md b/skills/analyze-logs/SKILL.md index 1c818a8ca..caf87604d 100644 --- a/skills/analyze-logs/SKILL.md +++ b/skills/analyze-logs/SKILL.md @@ -131,7 +131,7 @@ Read the latest `.jsonl` file. Each line is one JSON event. Parse each line inde Filter based on the user's question: -- **Errors**: `"level"` of `"error"` or `"fatal"`, `status >= 500`, or an `error` object on the event, which is what `evlog logs errors` matches. A 4xx is the client's own and is not counted; read `status` or pass `--status 4xx` for those +- **Errors**: `"level"` of `"error"` or `"fatal"`, `status >= 500`, or an `error` object on the event, which is what `evlog logs errors` matches. A 4xx status on its own is the client's and does not count, though a 4xx event still matches when it carries one of the other two signals; read `status` or pass `--status 4xx` to see them all - **Specific endpoint**: match on `path` - **Slow requests**: filter on `durationMs` (e.g. `durationMs > 500`) - **Specific user/action**: match on application-specific fields