feat: replace LogTape with evlog for wide-event logging - #142
feat: replace LogTape with evlog for wide-event logging#142adelrodriguez wants to merge 2 commits into
Conversation
|
Your Pullfrog detected a billing-exhausted response from your provider — the agent stopped before completing this run.
|
|
Your Pullfrog detected a billing-exhausted response from your provider — the agent stopped before completing this run.
|
Replace the five @logtape/* packages with evlog in @init/observability.
The facade now exposes createLogger (per-app singleton init), the ambient
log API, structured errors (createError/parseError), a Hono middleware
that emits one wide event per request, a Sentry drain behind a
batching/retry pipeline, Better Auth helpers, and a Vite plugin that
strips log.debug from production builds.
- API: request-scoped wide events via c.var.log/useLogger, user identity
stamped on every authenticated request, structured error responses
- Apps: createLogger({ service }) singletons; Vite apps also get the
evlog plugin
- Packages: Inngest, Drizzle, Convex, and email now log through the
ambient evlog API; category loggers are gone
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Wire per-request wide events for the app without the evlog Nitro module: a Start request middleware (type: 'request') opens the event, records handler type, server function metadata, and response status, and emits on completion. Registered ahead of CSRF in requestMiddleware so rejected requests are logged too. The facade re-exports createRequestLogger for custom integrations. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
16517ee to
3511337
Compare
There was a problem hiding this comment.
Important
Two changes weaken the production security posture: unhandled API errors now echo their raw internal message to clients, and every Drizzle query — SQL text plus bound parameters — now ships to Sentry. Both are one-line policy fixes, but they should land before merge.
Reviewed changes — no prior Pullfrog review exists on this PR and the recorded previous revision (16517ee) is not in the branch history, so this run reviewed the full diff rather than a delta.
- Replaced the LogTape facade with an evlog one —
buildLogger/getLogger/LoggerCategorygive way tocreateLogger, the ambientlog, and four thin sub-modules (drains,hono,auth,vite);integrations.tsandutils.tsare deleted. - Wired one wide event per API request —
withRequestLoggingruns first in the Hono chain,requireSessionstamps the session viaidentifyUser, andAppContextmergesLoggerVariablessoc.var.logis typed. Everyc.var.loggercall site is gone. - Restructured
app.onError— unhandled errors are nowparseError'd into a{ message, why, fix }JSON body with a derived status, replacing the flatc.text("Internal Server Error", 500). - Added a TanStack Start request middleware —
withWideEventopens an event per server request, recordshandlerType/serverFnMeta/status, and exposes the logger ascontext.log. - Migrated the remaining consumers — Drizzle, Inngest, Convex, Better Auth's internal logger, and the email mock preview all write through the ambient
log; the Vite-based apps additionally register the evlog plugin.
I verified the evlog contracts behind these findings against the published evlog@2.26.0 package rather than its docs, and the TanStack Start contracts against the pinned 1.168.32 sources. Two things I expected to be bugs are not: Better Auth maps its success level to "info" before invoking the callback, so the log[level] dynamic index is safe; and runEnrichAndDrain uses options.drain ?? getGlobalDrain(), so passing { drain } to withRequestLogging does not double-send.
ℹ️ Nitpicks
packages/email/src/client.ts:96-105—log.warn("email", …)uses evlog's tagged form whilelog.info({ scope: "email", … })two lines later uses the object form. They produce different event shapes (tagvs.scope), so a downstream filter on one will miss the other. Picking one form for the pair would be more consistent.apps/api/src/routes/index.ts:26—withRequestLogging({ drain })is redundant.createLogger({ drain, … })in#shared/logger.tsalready installs the same drain globally, and the Hono middleware falls back to it viagetGlobalDrain(). Harmless, but it reads as though the two drains were independent.
Claude Opus | 𝕏
| const parsed = parseError(error) | ||
|
|
||
| return c.json( | ||
| { fix: parsed.fix, message: parsed.message, why: parsed.why }, | ||
| parsed.status as ContentfulStatusCode | ||
| ) |
There was a problem hiding this comment.
parseError returns a plain Error's message verbatim (dist/runtime/utils/parseError.mjs: if (error instanceof Error) return { message: error.message, … }), so every unhandled exception now echoes its internal text to the caller — Postgres errors carrying the failing statement, S3 SDK errors carrying bucket and endpoint, upstream fetch failures carrying internal hostnames. The old c.text("Internal Server Error", 500) disclosed none of that.
HTTPExceptions already short-circuit above, so the structured body only helps for errors that were never given why/fix in the first place.
Technical details
# Unhandled API errors echo their internal message to clients
## Affected sites
- `apps/api/src/routes/index.ts:61-66` — `parseError(error).message` is a plain `Error`'s `message` with no sanitisation; `parsed.status` is `error.status ?? error.statusCode` (falling back to 500 only when non-finite), so an upstream `fetch` failure carrying `status: 401` also mislabels a server fault as a client one.
## Required outcome
- Unhandled, non-`HTTPException` errors return a generic message and a 500, matching the pre-migration behaviour.
- Structured `message`/`why`/`fix` still reach the client for errors the codebase deliberately raised through `createError`.
- The full parsed error keeps going to `c.var.log.error` and `captureException`; only the response body is narrowed.
## Suggested approach
`EvlogError.isEvlogError(error)` (exported from `evlog`, and preferred over `instanceof` because it survives duplicate installs) distinguishes a deliberately structured error from an incidental one. Serialize the parsed fields only in the first case, and fall back to a fixed `{ message: "Internal Server Error" }` at 500 otherwise.There was a problem hiding this comment.
Corrigido: streak que começou DEPOIS do último sucesso restampa escalation_asked_at, então o sweep de retirada não cancela mais a pergunta que o refresh acabou de reescrever.
🤖 Addressed by Claude Code
| logger: { | ||
| logQuery(query, params) { | ||
| log.debug({ params, query, scope: "drizzle" }) | ||
| }, | ||
| }, |
There was a problem hiding this comment.
state.minLevel defaults to "debug" in evlog, and emitWideEvent passes every event that clears it to state.drain. The API is not a Vite app, so the plugin's strip: ['debug'] never applies — the result is that every SQL statement plus its bound parameters (session tokens, verification tokens, password hashes) is now sent to Sentry on a live request path. Under LogTape this reached the console only.
Technical details
# Drizzle query parameters now reach the Sentry drain
## Affected sites
- `packages/db/src/client.ts:14-18` — `log.debug({ params, query, scope: "drizzle" })` fires per query with no level gate.
- `packages/observability/src/logger/index.ts:4-13` — `CreateLoggerOptions` exposes `service`, `isDevelopment`, `drain`, `redact`, but **not** `minLevel` or `sampling`, so no consumer can raise the floor.
- `apps/api/src/shared/logger.ts:7` — `createLogger({ drain, service: "api" })` installs the Sentry drain globally, which is what gives the debug events their new destination.
## Required outcome
- Query-level logging does not reach the Sentry drain in production.
- Developers keep per-query visibility locally.
## Suggested approach
Surface `minLevel` on `CreateLoggerOptions` and pass it through to `initLogger`, then have the API set it to `"info"` outside development. Gating the `logQuery` callback itself on `isDevelopment` is the narrower alternative if the facade should stay minimal.
## Open questions for the human
- Was per-query logging in production intentional under LogTape (`DRIZZLE_ORM` was configured at `lowestLevel: "debug"`), or tolerated because it never left the console?| /** PII redaction. Defaults to evlog's built-ins (on in production, off in development). */ | ||
| redact?: boolean | RedactConfig |
There was a problem hiding this comment.
The comment is accurate about evlog's defaults, but those defaults do not cover what the deleted redactSink covered. evlog's builtins are value regexes — creditCard, email, ipv4, phone, jwt, bearer, iban — with no field-name matching, so { password: "…" }, { apiKey: "sk_live_…" } and { secret: … } now pass through unmasked. They are also off in development, where redactSink applied unconditionally.
Technical details
# Field-name redaction has no replacement
## Affected sites
- `packages/observability/src/logger/utils.ts` (deleted) — `redactByField` matched `"secret"`, `/pass(?:code|phrase|word)/i`, `/api[-_]?key/i` and `DEFAULT_REDACT_FIELDS`, in every environment.
- `packages/observability/src/logger/index.ts:11-12, 26-30` — `redact` is forwarded only when explicitly set, so every app falls through to evlog's `resolveRedactConfig(config.redact ?? !isDev())`.
## Required outcome
- Secret-shaped **field names** are masked again, including on the paths that now feed the Sentry drain.
- The default applies without every app having to opt in.
## Suggested approach
evlog's `RedactConfig.paths` matches on leaf key names case-insensitively — a bare `"password"` is expanded to `**.password`. Defaulting `redact` inside `createLogger` to `{ paths: ["secret", "password", "passphrase", "passcode", "apiKey", "api_key", "token"] }` restores the old coverage on top of the builtins, and callers passing an explicit `redact` still win.
## Open questions for the human
- Is losing all redaction in development acceptable? `redactSink` applied there too, and dev consoles get pasted into issues.| const pipeline = createDrainPipeline<DrainContext>({ | ||
| batch: { intervalMs: 5000, size: 50 }, | ||
| retry: { maxAttempts: 3 }, | ||
| }) | ||
|
|
||
| return pipeline(createSentryDrain({ dsn: ENV.SENTRY_DSN })) |
There was a problem hiding this comment.
The pipeline buffers up to 50 events or 5 seconds before sending, and createDrainPipeline returns a PipelineDrainFn whose flush() is documented as "Call on server shutdown" — but nothing here or in apps/api ever calls it. Every deploy, restart, or crash silently drops the buffered tail, which is exactly the window containing the events that preceded a crash.
Technical details
# Batched Sentry drain is never flushed on shutdown
## Affected sites
- `packages/observability/src/logger/drains.ts:19-24` — returns `pipeline(createSentryDrain(...))` without retaining or exposing a flush hook.
- `apps/api/src/shared/logger.ts:5` — `singleton("drain:api", () => buildDrain())` is the only holder of the returned function, and registers no process handler.
## Required outcome
- Buffered events are flushed before the process exits.
- The retry backoff (up to 3 attempts) still has a chance to run during that flush.
## Suggested approach
The returned value is already a `PipelineDrainFn` carrying `.flush()` and `.pending`, so the hook can live either inside `buildDrain` (register `process.on("SIGTERM" | "SIGINT", …)` there) or at the API entrypoint alongside whatever other shutdown handling exists. Prefer whichever matches how the app already handles termination.| const result = await next({ context: { log } }) | ||
| log.set({ status: result.response.status }) | ||
| log.emit() |
There was a problem hiding this comment.
handleServerAction in @tanstack/start-server-core@1.169.17 catches every thrown error and returns new Response(serializedError, { status: response.status ?? 500 }), so next() resolves normally and the catch below never fires for server-function failures. Since nothing then calls log.error or log.setLevel, emit() computes level as "info" — a failing server function produces an info-level wide event carrying status: 500.
Deriving the level from the status closes the gap without touching the catch, which is still reachable on the SSR path.
| const result = await next({ context: { log } }) | |
| log.set({ status: result.response.status }) | |
| log.emit() | |
| const result = await next({ context: { log } }) | |
| const { status } = result.response | |
| if (status >= 500) { | |
| log.setLevel("error") | |
| } | |
| log.set({ status }) | |
| log.emit() |
| }, | ||
| }) | ||
| ) | ||
| .server(({ next }) => next({ context: { logger } })) |
There was a problem hiding this comment.
withLogger now injects the ambient app singleton as context.logger, while withWideEvent injects the request logger as context.log. publicFunction in shared/server/functions.ts wires only withLogger, so anything a server function logs emits as its own standalone event instead of accumulating on the request's wide event — the scattered-log-lines pattern this PR set out to replace. withRequestId also still mints a requestId that no longer reaches any logger.
Technical details
# Server functions log through the ambient logger, bypassing the wide event
## Affected sites
- `apps/app/src/shared/server/middleware.ts:44` — `withLogger` reduced to `next({ context: { logger } })`, handing over the process-wide singleton.
- `apps/app/src/shared/server/middleware.ts:38-40` — `withRequestId`'s `crypto.randomUUID()` is no longer consumed by anything now that `withLogger` dropped its `.with({ requestId })` call.
- `apps/app/src/shared/server/functions.ts:4` — `publicFunction` composes `[withLogger, withDatabase]`, so `context.logger` is what every server function actually receives.
- `apps/app/src/shared/server/middleware.ts:12-15` — the JSDoc says "Handlers and server functions can add context through `context.log`", but request-middleware context does not reach `beforeLoad`/`loader` (TanStack/router#6395) and this app defines no route `server.handlers`, so server functions are the only possible consumer — and they are wired to the other logger.
## Required outcome
- One logger is reachable from server functions, and writes to it land on the request's wide event.
- No middleware remains whose only output nothing reads.
## Suggested approach
Dropping `withLogger` and `withRequestId` and letting server functions read `context.log` from `withWideEvent` is the smallest change; `withLogger` could alternatively be kept as a compatibility alias that forwards `context.log`. Either way the JSDoc should say plainly that loaders and `beforeLoad` do not receive this context.
## Open questions for the human
- Is the ambient `logger` still wanted in server-function context for anything that should deliberately escape the request event?
Summary
Migrates logging from LogTape (five
@logtape/*packages) to evlog, adopting the wide-event model: instead of scattered log lines, each API request accumulates context and emits one comprehensive event with method, path, request ID, user identity, custom fields, status, and duration.{"method":"GET","path":"/hello","requestId":"73206be7…","user":{"id":"usr_123"},"status":200,"durationMs":3,"level":"info","service":"api"}@init/observabilityfacadelogger—createLogger({ service, drain?, isDevelopment? })for the per-app singleton, the ambientlogAPI for packages, and structured errors (createError/parseErrorwithwhy/fixfields)logger/hono—withRequestLogging()middleware (one wide event per request, exposed asc.var.log),useLogger()for deep call stacks,LoggerVariablescontext typelogger/drains— Sentry drain behind a batching/retry pipeline; no-op whenSENTRY_DSNis unsetlogger/auth— evlog's first-class Better Auth helpers (identifyUser,createAuthMiddleware,maskEmail)logger/vite— evlog Vite plugin: auto-init pluslog.debugstripping from production buildsConsumers
requireSessionstampsuser/sessiononto every authenticated request event;onErrorlogs to the wide event and returns structured{ message, why, fix }responses; Better Auth internal logs route through evlog; tRPC context passeslogthroughcreateLogger({ service })singletons; the Vite-based apps also register the evlog pluginLoggerCategoryandgetLoggerare goneAlso fixes stale Axiom references in the observability README and project-structure doc.
Behavior changes
redact: { paths: [...] }oncreateLoggerif desired.message/why/fix) instead of plain-text 500s..with()/.getChild()) flattened to the plain logger — no downstream consumers existed.Not in this PR
appserver (needs the observability server env imported intoapps/app/.env.schema— follow-up; wide events currently emit to the server console)monitoring/*, unchangedTesting
bun run check(lint + format + types) passesbun test— 22/22 passwithRequestLoggingemits the wide event above, withc.var.log.set()anduseLogger().set()both landing on the same event🤖 Generated with Claude Code
Update
TanStack Start server-side wide events are now included — implemented with a Start request middleware (
withWideEvent,type: "request") instead of the evlog Nitro module. It opens one event per server request (SSR and server function calls), records handler type, server-fn name/file, and response status, and exposes the logger to handlers viacontext.log.