Back to blog
Mar 2026·3 min readAI-generated

Structured Logging: Why printf Debugging Doesn't Scale

#backend#observability#javascript

console.log('user logged in', userId) works fine until you have ten servers, a thousand log lines a second, and an incident where you need to find every request from one customer across three services in the last twenty minutes. At that point, plain-text logs stop being a debugging tool and start being a haystack. Structured logging is the fix, and it costs almost nothing to adopt.

The problem with string logs

A traditional log line is a human-readable sentence:

2026-03-17T09:14:02Z User 4821 logged in from 203.0.113.4 after 2 failed attempts

Easy to read in isolation. Nearly impossible to query at scale. To find every login from a specific IP across a week of logs, you're writing regex against free text, hoping nobody ever changes the wording of that log line (which breaks every saved query built against it), and hoping the fields you need — user ID, IP, attempt count — were even included in a parseable position.

Structured logging: log data, not sentences

A structured log line is a machine-parseable record, almost always JSON, where each piece of context is its own field:

logger.info('user_login', {
  userId: 4821,
  ip: '203.0.113.4',
  failedAttempts: 2,
});
{"level":"info","event":"user_login","userId":4821,"ip":"203.0.113.4","failedAttempts":2,"timestamp":"2026-03-17T09:14:02.118Z"}

Now "every login from this IP" is a query against the ip field, not a regex against prose. "Every event for user 4821 in the last hour" is a filter, not a grep. The event name (user_login) stays stable even if you later decide to reword what a human-readable version would say — because there is no human-readable version generated at write time; formatting is a display concern, handled later by whatever's reading the logs.

A minimal structured logger

You don't need a heavyweight framework to get the core benefit. Here's a logger that attaches consistent base fields and always emits JSON:

function createLogger(baseFields = {}) {
  const emit = (level, event, fields = {}) => {
    const record = {
      level,
      event,
      timestamp: new Date().toISOString(),
      ...baseFields,
      ...fields,
    };
    process.stdout.write(JSON.stringify(record) + '\n');
  };

  return {
    info: (event, fields) => emit('info', event, fields),
    warn: (event, fields) => emit('warn', event, fields),
    error: (event, fields) => emit('error', event, fields),
    child: (extraFields) => createLogger({ ...baseFields, ...extraFields }),
  };
}

const logger = createLogger({ service: 'auth-api' });
logger.info('user_login', { userId: 4821, ip: '203.0.113.4' });

child() matters more than it looks: it lets you attach context once and have it flow through every subsequent call, instead of repeating fields everywhere.

Request-scoped context: the actual payoff

The real win shows up when every log line for a single request automatically carries a shared request ID, without every call site having to pass it explicitly.

import { AsyncLocalStorage } from 'node:async_hooks';

const requestContext = new AsyncLocalStorage();

function withRequestContext(requestId, fn) {
  return requestContext.run({ requestId }, fn);
}

function requestLogger(event, fields = {}) {
  const context = requestContext.getStore() ?? {};
  logger.info(event, { ...context, ...fields });
}

// In middleware, per incoming request:
app.use((req, res, next) => {
  withRequestContext(crypto.randomUUID(), next);
});

// Anywhere deeper in the call stack, no requestId parameter needed:
requestLogger('db_query_start', { table: 'orders' });
requestLogger('db_query_end', { table: 'orders', durationMs: 12 });

Every log line emitted anywhere during that request's lifetime — three services deep, in a callback, in an error handler — carries the same requestId. That's what turns "find everything that happened during this one failing request" from an archaeology project into a single filter.

What actually belongs in a log field

  • IDs, not descriptions. userId: 4821, not "for user number 4821". Let the reader join against your user table if they need the name.
  • Durations as numbers, in one consistent unit. durationMs: 340, always milliseconds, never mixing "340ms" and 2.1 (seconds) across different call sites.
  • Stable event names. user_login, not a sentence that changes wording between commits. Treat the event name like an API — renaming it breaks every dashboard and alert built against it.
  • Errors as structured objects, not just their .message:
logger.error('payment_failed', {
  orderId: order.id,
  error: {
    message: err.message,
    name: err.name,
    stack: err.stack,
  },
});

What this doesn't replace

Structured logging isn't a substitute for metrics or traces — it's the third leg of observability, and it's the one best suited for "what exactly happened, in order, for this one request." Metrics answer "how many" over time cheaply; traces answer "where did the time go" across services. Logs answer "what were the actual values involved." Use whichever answers the question you're actually asking — for a specific customer's specific failed request, that's almost always logs.

Takeaway

The change from string logs to structured logs is small at write time — pass an object instead of building a sentence — and enormous at read time, because every field becomes queryable instead of buried in prose. Add request-scoped context on top and you get the thing printf debugging never could: the ability to pull every line related to one request, out of a firehose of everyone else's, in one query.

NewerEvent Sourcing vs Traditional CRUDOlderUnderstanding CORS Once and For All