Skip to content

Logging

Pino is the recommended logger for autotel. Pino, Bunyan and Winston all get trace context the same way: OpenTelemetry auto-instrumentation, enabled with autoInstrumentations.

The same rules apply to all three:

  • Run init() before the logger loads. The instrumentation patches the logger package as it loads. Put init() in its own module, import it first, and create the logger in another module.
  • Don’t pass the logger to init(). The logger option carries autotel’s own diagnostics only, and passing it forces you to create the logger too early. Canonical log lines go to canonicalLogLines.logger or the OTel Logs API (see below). A pino instance works as logger if you want autotel’s diagnostics in your log stream.
  • ESM apps need the loader hook: node --import autotel/register app.js.
  • Add logs: true to export log records via OTLP. Without it they only get trace_id / span_id in their output.

autotel prints a warning at startup if the logger loaded before init(), an ESM app is missing the hook, or @opentelemetry/auto-instrumentations-node is not installed. See Startup warnings.

// instrumentation.ts - imported first
import { init } from 'autotel';
init({
service: 'my-app',
autoInstrumentations: ['http', 'pino'], // only these load
logs: true,
endpoint: process.env.OTLP_ENDPOINT,
});
logger.ts
import pino from 'pino';
export const logger = pino({ name: 'my-app', level: 'info' });
index.ts
import './instrumentation'; // first
import { withTracing } from 'autotel';
import { logger } from './logger';
const createUser = withTracing({})((ctx) => async (name: string) => {
logger.info({ name }, 'Creating user'); // trace_id, span_id injected
const user = await db.users.create({ name });
logger.info({ userId: user.id }, 'User created');
return user;
});
{
"level": 30,
"time": 1700000000000,
"msg": "Creating user",
"name": "Alice",
"trace_id": "a1b2c3d4e5f6",
"span_id": "1234567890ab"
}

Use auto-instrumentation for trace context injection:

instrumentation.ts
import { init } from 'autotel';
init({
service: 'my-app',
autoInstrumentations: ['bunyan'],
logs: true,
});
import bunyan from 'bunyan';
const logger = bunyan.createLogger({ name: 'my-app' });
// trace_id, span_id automatically added to every log record
logger.info({ userId: '123' }, 'Processing request');
Terminal window
npm install winston @opentelemetry/auto-instrumentations-node @opentelemetry/winston-transport

@opentelemetry/winston-transport is what sends Winston records to OTLP. Without it, logs: true still adds trace_id / span_id but exports nothing.

instrumentation.ts
import { init } from 'autotel';
init({
service: 'my-app',
autoInstrumentations: ['winston'],
logs: true,
});
import winston from 'winston';
const logger = winston.createLogger({
transports: [new winston.transports.Console()],
});
// trace_id, span_id automatically added
logger.info('Processing request');

They serve different purposes:

Feature getRequestLogger() Pino/Bunyan/Winston
Purpose One wide event per request Continuous structured logging
Output Attributes on the span Log stream (stdout/files)
When .emitNow() at end of request Throughout request
Use case Canonical log lines / wide events Debugging, audit trails

Use both together: Pino for continuous logging + getRequestLogger() for the one snapshot at the end of each request.

The request snapshot carries an autotel.log.level attribute. Calling .warn() sets it to warn and .error() sets it to error, so most requests never need you to touch it.

Two cases need you to say it out loud. A request that degraded without logging anything, and a request that logged a warning you do not want colouring the whole snapshot:

const log = getRequestLogger(ctx);
const inventory = await checkStock(sku);
if (inventory.stale) {
log.setLevel('warn'); // served from a stale cache, nothing to log
}

setLevel() takes 'debug' | 'info' | 'warn' | 'error', adds no log event, and records no exception. An explicit level wins: a later .warn() or .error() leaves your choice alone rather than overwriting it. Calls after .emitNow() are ignored, because the snapshot has already left.

Use it to make severity searchable when the interesting thing is the outcome rather than a message.

Canonical log lines: logger and OTLP at once

Section titled “Canonical log lines: logger and OTLP at once”

canonicalLogLines emits one wide line per span. Where it goes is the part worth getting right.

With no logger, lines go through the OpenTelemetry Logs API and out to whichever OTLP logs backend you configured — Loki and the like. Set canonicalLogLines.logger and they go there instead. The top-level logger on init() is only for autotel’s own diagnostics and is never used for lines.

The logger must take pino’s (fields, message) signature, as pino and bunyan do. Winston takes (message, meta), so wrap it: { info: (fields, msg) => winstonLogger.info(msg ?? '', fields), ... } for each of debug, info, warn and error.

On a platform whose log view reads stdout you usually want both:

init({
service: 'my-app',
endpoint: process.env.OTEL_EXPORTER_OTLP_ENDPOINT,
canonicalLogLines: { enabled: true, logger: pino(), otel: true },
});

otel defaults to true only when no logger is given. Setting otel: true explicitly also wires the endpoint’s log exporter for you, unless logs: false (or AUTOTEL_LOGS=off) says otherwise — otherwise the lines would be written to a no-op provider and never arrive.

logger also takes an array, to fan the same line out to several destinations.

  • example-pino: Pino with autoInstrumentations: ['pino'], the logger created after init(), and trace context in every record
  • example-bunyan: Bunyan with auto-instrumentation.
  • example-winston: Winston with auto-instrumentation.