ehsan.blog
~/blog/validate-structured-log-shape-with-standard-schema — zsh
cat validate-structured-log-shape-with-standard-schema.md

How to stop your structured logs from silently drifting out of shape

·12 min read

Structured logging’s entire pitch is: log an object, not a sentence, so you can query it later. log.info('order placed', { orderId, amountCents }) instead of log.info('order 123 placed for 499 cents'). Once it’s an object, your log platform can filter on orderId, aggregate on amountCents, build a dashboard.

That pitch only holds if the shape of data actually stays the same across every call site. And nothing in a plain logger enforces that.

Here’s how it goes wrong in practice, because I’ve watched it happen. Someone writes log.child('checkout').info('order placed', { orderId: 'o_1', amountCents: 500 }). Three weeks later, someone else — maybe you, six months from now, having forgotten the first call site — writes log.child('checkout').info('order placed', { order_id: 'o_1' }). Both compile. Both log successfully. Your dashboard, built assuming orderId and amountCents are always there, is now silently wrong for a slice of your checkout events, and there’s no error anywhere telling you that happened. The failure is invisible at write time, which is exactly when it would be cheap to catch, and expensive at read time, which is when you find out your metrics have been lying to you.

This is the problem nextjs-logger’s schema validation solves, and I want to walk through the actual design, because a few of the choices in it are more interesting than “just validate with Zod.”

Why it doesn’t just import Zod

The obvious approach: pick a validation library, require it, done. The problem is that “pick a library” is exactly the kind of decision a logging package shouldn’t be making for you. You might already use Zod. You might use Valibot, or ArkType, or nothing at all and just want one field checked with a plain function.

So instead, validation goes through Standard Schema — a small, shared interface that Zod 3.24+, Valibot, ArkType and others already implement natively. The interface is genuinely tiny:

ts
export interface StandardSchemaV1<Input = unknown, Output = Input> {
  readonly '~standard': {
    readonly version: 1
    readonly vendor: string
    readonly validate: (value: unknown) => StandardSchemaResult<Output> | Promise<StandardSchemaResult<Output>>
  }
}

Any object with a ~standard.validate method matching that shape works — including a schema you built with a library this package has never heard of. And the type is declared structurally inside the logger’s own source, copied rather than imported, because @standard-schema/spec is a types-only package, and adding a real dependency just to describe an interface that exists so you don’t need a dependency would defeat the point.

If you don’t want a validation library at all, a plain predicate function works too:

ts
registerSchema('checkout', (data) => {
  const d = data as Record<string, unknown>
  return typeof d.orderId === 'string' || 'orderId must be a string'
})

Return true and it passes. Return a string and that string becomes the reported problem.

Registering a schema

With Zod, it looks like this:

ts
import { z } from 'zod'
import { registerSchema } from '@developerehsan/nextjs-logger'

registerSchema('checkout', z.object({
  orderId: z.string(),
  amountCents: z.number().int(),
}))

Now:

ts
log.child('checkout').info('order placed', { orderId: 'o_1', amountCents: 500 }) // fine
log.child('checkout').info('order placed', { order_id: 'o_1' }) // ⚠ warns

The registration is namespace-scoped and, like level filtering, inherits down to children — a schema registered for checkout also applies to checkout:payment and checkout:refund, so you don’t have to register the same shape three times for one feature area.

The rule that matters most: a violation never drops the log

This is the part I’d flag as the actual design decision worth remembering, more than the Standard Schema plumbing. When data fails validation, the entry is never dropped. It’s logged either way, just annotated:

ts
return {
  ...entry,
  data: { ...(entry.data as Record<string, unknown>), __schemaError: problem },
}

Think about why. A schema violation is a bug in the logging call itself — someone wrote order_id instead of orderId. That’s a real problem worth surfacing. But the thing that log line was recording — an order actually got placed — still happened, and it’s still evidence you might need during an incident. If the validator’s response to “this doesn’t match the shape I expected” were to silently swallow the entry, you’d have traded a shape-drift bug for a much worse bug: missing log lines, with no clue anything was ever dropped. A logging pipeline that quietly loses data on a technicality is worse than one that’s occasionally sloppy about shape. So the entry always goes through; only the annotation tells you something was off.

Two failure modes, and why they get different defaults

What happens with that annotation depends on a “violation mode,” and there are three:

  • warn — attach __schemaError to the entry and print a warning to the process console (not through the logger itself — more on that below). The entry is logged either way. This is the default in development.
  • annotate — attach __schemaError and log the entry, no console noise. Default in production.
  • ignore — do nothing at all: no annotation, no warning, entry logged untouched.

The reasoning for different defaults per environment is straightforward once you say it out loud: a schema violation while you’re actively writing code is worth interrupting you for, right now, so you fix the call site before it ships. The same violation happening a thousand times a day in production from a code path you can’t immediately redeploy is not worth a thousand console warnings — it’s worth a quiet flag in the data your log platform can query on later (__schemaError: "orderId must be a string"), so you can go find every affected entry without drowning your terminal in noise today.

Notice the warning path routes through console.warn directly, not back through the logger:

ts
console.warn(
  `[logger] Log data for namespace "${entry.context.namespace}" does not match its ` +
    `registered schema — ${problem}. The entry was logged anyway.`,
)

If it went through log.warn() on the same namespace instead, and that namespace has a schema registered, you’d re-enter the validation path recursively. Small detail, but the kind of thing that’s easy to get wrong and hard to debug once it’s wrong — an infinite loop or a stack overflow the first time someone forgets this exact edge case.

Async validators are accepted, and silently skipped

One real limitation, stated plainly rather than papered over: validation runs synchronously, inside the same code path that turns a log call into a written line. Some validators — a Zod schema with an async .refine, say — can return a promise. There’s nowhere in this pipeline to await that.

ts
if (result instanceof Promise || typeof (result as PromiseLike<unknown>)?.then === 'function') {
  return undefined
}

An async result is treated as “no opinion” and skipped, rather than blocking the log call or floating an unhandled promise. This is a genuine trade-off, not a bug: making the entire log-writing path asynchronous so a log-time schema could do a database lookup would be solving a problem nobody should have in the first place. If you need database-backed validation, that belongs in your application logic before you ever call log.info() — not inside the schema attached to the log call.

What happens when data isn’t even an object

One more edge case worth knowing about, because it’s the kind of thing that looks like a bug until you understand the reasoning: what if the log call didn’t pass an object at all?

ts
log.child('checkout').info('order placed', 'not an object')

A schema like z.object({ orderId: z.string() }) obviously can’t validate a bare string against an object shape — but the annotation logic still has to produce something sensible rather than throwing:

ts
data:
  entry.data === undefined || typeof entry.data !== 'object' || entry.data === null
    ? { __schemaError: problem, value: entry.data }
    : { ...(entry.data as Record<string, unknown>), __schemaError: problem }

When data isn’t a spreadable object, the whole thing gets wrapped: { __schemaError: '...', value: 'not an object' }, preserving the original value under a value key instead of trying to spread a string’s characters into an object (which is a real, silent footgun if you get the type check slightly wrong — spreading a string in JavaScript gives you an object keyed by numeric indices, one entry per character, which is almost never what anyone wants). Getting this branch right is a small thing, but it’s exactly the kind of small thing that turns into a confusing bug report six months later if it’s missed.

Rolling this out on an existing codebase

If you’re retrofitting this onto logging calls that already exist across a real codebase, don’t register schemas everywhere on day one. Start with warn mode on the one or two namespaces you already suspect have drifted — usually the ones with the most call sites, written by the most different people, over the longest time. Watch the console warnings for a few days in development, fix what surfaces, and only then flip that namespace’s mode to annotate in production, where you’d rather have a queryable flag on the entry than a noisy console. Rolling it out namespace by namespace, rather than registering a strict schema for your whole app in one commit, keeps you from being surprised by a wall of pre-existing drift you didn’t know you had — surprise that would otherwise make the whole feature feel like it’s fighting you instead of helping you.

Three things I only found by testing it

Everything above is what the feature is designed to do. Then I sat down with the published package (@developerehsan/nextjs-logger@1.0.1), wired a capture transport to a logger, and poked at the edges. Three behaviours came out that aren’t obvious from reading the docs, and all three can quietly cost you the exact coverage you thought you’d bought.

1. The newest registration wins — not the most specific one

Your instinct, borrowed from CSS and from routing tables, is that a more specific rule beats a broader one. Here it doesn’t. Registration is a flat list, each new schema is pushed onto the front, and lookup takes the first entry whose namespace matches — so the most recently registered match wins, regardless of how specific it is.

Register the broad one last and it swallows the specific one:

ts
registerSchema('checkout:payment', z.object({ txId: z.string() }))
registerSchema('checkout',         z.object({ orderId: z.string() }))

log.child('checkout:payment').info('m', { txId: 't1' })
// __schemaError: "orderId: Invalid input: expected string, received undefined"

That { txId: 't1' } is perfectly valid for the schema you wrote for that exact namespace. It still gets flagged, because the broader checkout schema was registered afterwards and matched first. Flip the two lines and it passes cleanly.

The fix is a one-line habit: register broad schemas first, specific ones last. If your registrations are spread across modules, that ordering depends on import order, which is exactly the kind of thing that changes underneath you during a refactor. Put them all in one file, top to bottom, broadest to narrowest.

2. Registering the same namespace twice doesn’t replace — it shadows

ts
registerSchema('billing', z.object({ a: z.string() }))
registerSchema('billing', z.object({ b: z.string() }))

log.child('billing').info('m', { a: 'x' })  // ⚠ flagged: "b: expected string"
log.child('billing').info('m', { b: 'x' })  // clean

The second call doesn’t overwrite the first. It hides it. The first schema stays in the list forever and simply never matches anything again. No warning, no error — the old schema just stops having an opinion.

Most of the time that’s harmless, because it means the newest definition is the live one, which is usually what you wanted. It bites in one specific place: if registerSchema runs somewhere that executes more than once — a hot-reloaded module, a function you call per request, a test beforeEach — the list grows on every pass and never shrinks. That’s what clearSchemas() is for. Call it at the top of your registration file, and in test setup:

ts
clearSchemas()
registerSchema('checkout', /* ... */)

Registering the same schema a thousand times still validates correctly — I checked — so this isn’t a correctness bug. It’s a slow leak, and clearSchemas() costs you one line.

3. Level filtering runs before validation

This is the one I’d actually lose sleep over. In the pipeline, the level check happens first, and validation only runs on entries that survived it:

ts
if (!shouldLog(level, namespace, cfg)) return   // ← entry is gone here
// ...
if (hasSchemas()) entry = applySchemaValidation(entry, isDev())

So a schema violation inside a log.debug() call is completely invisible in production, where your minLevel is almost certainly info or warn. The entry never reaches the validator. There’s no annotation, no warning, and nothing in your log platform to query — because there’s no log line at all.

ts
configureLogger({ minLevel: 'info' })
registerSchema('audit', z.object({ must: z.string() }))

log.child('audit').debug('m', { wrong: 1 })
// nothing. no entry, no __schemaError, no warning.

In development, where minLevel is usually debug, the same call warns loudly. That asymmetry is fine — it’s the same reasoning behind the warn-in-dev / annotate-in-prod default, and it’s arguably correct: validating entries you’re about to throw away would be wasted work. Just know the boundary. Schema validation covers the levels you actually ship, and nothing below them. If a debug payload’s shape genuinely matters to you, either it isn’t really a debug log, or its shape needs checking somewhere other than the logger.

The rest held up

For what it’s worth, the parts above that I described from the design all behaved exactly as advertised when I ran them: violations are annotated and never dropped, valid data passes through untouched, child namespaces inherit the parent’s schema, non-object data gets wrapped as { __schemaError, value } instead of being spread, predicate functions return true or a problem string (returning plain false gives you the generic "data failed the registered predicate"), and a schema that throws is caught and reported as "schema threw: boom" rather than taking your log call down with it. That last one matters more than it sounds — a validator crash on the logging path would be a spectacularly annoying way to lose an incident’s worth of logs.

The actual takeaway

The interesting idea here isn’t “validate your logs” — that’s obvious once you say it. It’s that a validation failure and a missing log entry are two very different severities of problem, and conflating them (by dropping invalid entries) trades a fixable annoyance for a much worse, silent one. If you’re building anything that validates data on a path where the data was already going to be recorded regardless — logs, audit trails, event streams — the same rule applies: annotate the problem, never make the record disappear because of it.

ls ./related
cat ./comments

Comments are not configured yet. Enable GitHub Discussions and paste the giscus repo-id / category-id into src/consts.ts.