Node.js Structured Logging API - RFC

# Node.js Structured Logging API - RFC

**Author:** @mertcanaltin
**Status:** REVIEW
**Date:** 2025-01-22
**Issue:** [#49296](https://github.com/nodejs/node/issues/49296)

---

## Summary

Add a structured logging API to Node.js core (`node:log`) inspired by Go's `slog`, providing a standard, performant logging interface with handler-based output formatting.

---

## Motivation

**Current Problem:**
- No standard logging in Node.js stdlib
- Ecosystem fragmentation: console.log, heavy deps (Winston 200+ packages), custom solutions
- Libraries either don't log or bring heavy dependencies

**Solution:**
- Building-block API with handler pattern (Go slog style)
- Structured logging with mandatory messages
- High performance via async buffering (SonicBoom)
- Flexible output: JSON (servers), Text (CLI), custom (OTEL)

---

## API Design

### Basic Usage

```javascript
const { createLogger, JSONHandler, TextHandler } = require('node:log');

// Server logging (JSON output)
const logger = createLogger({
  handler: new JSONHandler({ level: 'info' })
});

logger.info({ msg: 'user login', userId: 123, ip: '192.168.1.1' });
// Output: {"level":"info","msg":"user login","userId":123,"ip":"192.168.1.1","time":1737504000000}

// CLI logging (human-readable)
const cliLogger = createLogger({
  handler: new TextHandler({ colorize: true })
});

cliLogger.warn({ msg: 'disk space low', available: '2GB' });
// Output: [WARN] disk space low available=2GB
```

### Child Loggers

```javascript
const logger = createLogger({ level: 'info' });

// Add context to all child logs
const reqLogger = logger.child({ requestId: 'abc-123' });
reqLogger.info({ msg: 'processing' });
// Output: {...,"msg":"processing","requestId":"abc-123"}

// Nested children inherit parent context
const dbLogger = reqLogger.child({ component: 'db' });
dbLogger.debug({ msg: 'query', duration: 45 });
// Output: {...,"requestId":"abc-123","component":"db","duration":45}
```

**Child logger behavior:**
- Shallow merge (child fields override parent)
- Immutable (returns new instance)
- Inherits handler from parent

---

## Core API

### `createLogger(options)`

Creates a logger instance.

**Options:**
- `handler` (Handler) - Output handler (default: JSONHandler)
- `level` (string) - Minimum log level (default: 'info')

**Returns:** Logger

### Logger Methods

All methods accept a single object with required `msg` field:

```javascript
logger.trace({ msg: string, ...fields })
logger.debug({ msg: string, ...fields })
logger.info({ msg: string, ...fields })
logger.warn({ msg: string, ...fields })
logger.error({ msg: string, ...fields })
logger.fatal({ msg: string, ...fields })  // Does NOT exit process
```

**Design Decision:** Single object API (per @mcollina feedback):
- Unambiguous JSON serialization
- Enforces mandatory messages
- Avoids Pino's argument order confusion
- Easy OTEL transformation

**Throws:** `ERR_INVALID_ARG_TYPE` if `msg` missing or not string

### `logger.child(bindings[, options])`

Creates child logger with inherited context.

**Parameters:**
- `bindings` (Object) - Context fields for all logs
- `options` (Object) - Optional overrides
  - `level` (string) - Override parent level

**Returns:** Logger (new instance)

### `logger.enabled(level)`

Check if level would be logged (avoid expensive operations).

```javascript
if (logger.enabled('debug')) {
  logger.debug({ msg: 'data', expensive: JSON.stringify(largeObj) });
}
```

**Returns:** boolean

---

## Handlers

Handlers define output format and destination.

### Handler Interface

```javascript
class CustomHandler {
  handle(record) {
    // record.level, record.msg, record.time, record.bindings, record.fields
  }

  enabled(level) {
    return LEVELS[level] >= LEVELS[this.level];
  }
}
```

### Built-in Handlers

#### JSONHandler (Server Logs)

```javascript
new JSONHandler({
  level: 'info',           // Default: 'info'
  stream: process.stdout,  // Default: stdout
  fields: {                // Additional fields
    hostname: os.hostname(),
    pid: process.pid
  }
})
```

**Output:** `{"level":"info","msg":"...","time":123,...}`

#### TextHandler (CLI Logs)

```javascript
new TextHandler({
  level: 'debug',
  stream: process.stderr,
  colorize: true,      // Auto-detect TTY
  timestamp: true      // Default: true
})
```

**Output:** `2025-01-22 10:30:45 [INFO] message key=value`

#### Custom Handlers (e.g., OTEL)

```javascript
class OTELHandler {
  constructor({ exporter, level }) {
    this.exporter = exporter;
    this.level = level || 'info';
  }

  handle(record) {
    this.exporter.export({
      timestamp: record.time,
      severityText: record.level.toUpperCase(),
      body: record.msg,
      attributes: { ...record.bindings, ...record.fields }
    });
  }

  enabled(level) {
    return LEVELS[level] >= LEVELS[this.level];
  }
}

const logger = createLogger({
  handler: new OTELHandler({ exporter: new OTLPLogExporter() })
});
```

---

## Log Levels

Following **log4j interface** with **RFC5424 numerical ordering**:

| Level  | Value | Description                      |
|--------|-------|----------------------------------|
| trace  | 10    | Very verbose debugging           |
| debug  | 20    | Debugging information            |
| info   | 30    | Informational (default)          |
| warn   | 40    | Warning conditions               |
| error  | 50    | Error conditions                 |
| fatal  | 60    | Critical errors (**no exit**)    |

**Note:** `fatal()` logs only - does NOT call `process.exit()` (per @jsumners feedback)

---

## Performance

### Async Buffering

Based on SonicBoom (PR [#58897](https://github.com/nodejs/node/pull/58897)):
- 4KB buffer, 10ms flush interval
- Batched writes minimize syscalls
- Non-blocking I/O

### Object Allocation

```javascript
// Skip allocation for disabled levels
if (!this.enabled(level)) return;

// Merge only when needed
const record = { level, msg: obj.msg, time: Date.now(), ...this.bindings, ...obj };
```

### Lazy Evaluation

Use `enabled()` to skip expensive operations:

```javascript
if (logger.enabled('debug')) {
  logger.debug({ msg: 'details', data: computeExpensiveData() });
}
```

---

## Implementation Phases

### Phase 1: Core API (v24.x)
- Logger class with level methods
- JSONHandler, TextHandler
- Child loggers with context inheritance
- Level filtering, `enabled()` checks
- Async buffering (depends on SonicBoom #58897)
- Message validation
- Tests & docs

**Dependency:** SonicBoom port (#58897) - in progress by @jasnell

### Phase 2: Advanced Features (v25.x)
- Transport system (off-thread processing)
- ThreadStream integration (volunteer needed)
- Log redaction for sensitive data
- Performance benchmarks vs Pino

### Phase 3: Ecosystem (v26.x)
- diagnostics_channel integration
- OTEL handler examples
- Cloud provider transports

---

## Open Questions

1. **Module name:** `node:log` vs `node:logger` vs `node:logging`?
   *Current preference: `node:log` (brevity)*

2. **ThreadStream port:** Volunteer needed (mentioned by @jasnell)

3. **OTEL handler:** Built-in or userland example?
   *Current direction: Userland example (Phase 3)*

---

## Consensus Points

Based on discussion in #49296:

**API signature:** Single object with required `msg` (@mcollina approved)
**Handler pattern:** JSONHandler, TextHandler, custom (@jsumners, @wesleytodd)
**Child loggers:** Context inheritance (@mcollina requested)
**Levels:** RFC5424 ordering, log4j interface (@mcollina, @jsumners)
**fatal() behavior:** Log only, no exit (@jsumners)
**OTEL:** Via handler, not built-in (@mcollina)
**Building block:** Minimal core, flexible handlers (@wesleytodd)

---

## References

- **Issue:** [#49296](https://github.com/nodejs/node/issues/49296)
- **SonicBoom port:** [#58897](https://github.com/nodejs/node/pull/58897)
- **Go slog:** https://go.dev/blog/slog
- **RFC5424:** https://datatracker.ietf.org/doc/html/rfc5424
- **log4j Levels:** https://logging.apache.org/log4j/2.x/manual/
- **Pino:** https://github.com/pinojs/pino

---

## License

MIT