log

A log is an event with three reserved columns: ts, level and message. Underneath it stages, batches, claims and flushes exactly as an event does, and on top it adds a severity level, a filter that drops the noisy half before it costs anything, an Error overload that puts the stack somewhere queryable, and a child logger that carries context.

import { log, str } from 'metrichouse/core'

export const appLog = log('app_log', {
  fields: { service: str(), requestId: str().optional() },
  minLevel: 'info',
  flush: '30s',
  write: async (rows) => clickhouse.insert({ table: 'app_log', values: rows }),
})

appLog.info('server started', { service: 'checkout' })
appLog.warn('payment processor slow', { service: 'checkout' })
appLog.error(new Error('card declined'), { service: 'checkout' })

Import	import { log } from 'metrichouse/core'
Answers	What did the application say, and how serious was it
Storage	Staged whole, never merged
Row	{ id, ts, level, message, error_stack?, ...fields, _ingested_at }
Write with	the level methods, at(), child()
Read with	pending(), peek(), snapshot()
Use it for	Application messages, request lines, audit trails

Logs matter most in the minute a process is dying, which is why they share the event pipeline rather than arriving with a second transport, a second cadence and second crash behaviour to reason about.

log()

log<F, L>(name: string, config: LogConfig<F, L>): Log<F, L>

Declares a log. It is inert until a house binds it, and writing to an unbound log throws.

Parameter	Type	Required	Meaning
name	string	yes	The metric name
config.fields	shape	no	Extra columns beyond the reserved ones
config.levels	array of strings	no	The closed set of levels
config.minLevel	one of levels	no	The lowest level kept
config.stage	'driver' or 'local'	no	Where lines wait
config.batch	object	no	Local staging size and age limits
config.flush	duration	no	The fastest this may ship
config.claimLimit	number	no	Lines one claim, and one call to write, may carry
config.write	function	yes	Where the rows go

name

log('app_log', { ... })

A non empty string, unique inside a house.

fields

fields?: Record<string, FieldType>      // default: none

Extra columns, alongside the reserved three. Every field type is legal, including json().

fields: {
  service: str(),
  env: str().default('production'),
  requestId: str().optional(),
}

A field may not be named id, ts, level, message, error_stack, _ingested_at or _sample_rate, and the check runs at declaration. fields covers the argument in full.

levels

levels?: readonly string[]      // default: ['debug', 'info', 'warn', 'error']

The closed set of levels, in ascending severity. The order is what minLevel compares on, so it is a declaration rather than a formality.

Each level becomes a method, and the type narrows to exactly what you list.

export const auditLog = log('audit_log', {
  fields: { actorId: str(), action: str() },
  levels: ['routine', 'sensitive', 'critical'],    // ascending severity
  minLevel: 'routine',
  flush: '10s',
  write: toS3('audit'),
})

auditLog.sensitive('permissions changed', { actorId: 'u_1', action: 'grant_admin' })

auditLog.info('...')
//       ^^^^ Type error: this log has no 'info' method

import { DEFAULT_LOG_LEVELS } from 'metrichouse/core'
// ['debug', 'info', 'warn', 'error']

Three things throw at declaration: an empty set, a level declared twice, and a level that would shadow a method on the logger. levels: ['debug', 'drain'] is the third one, and catching it here is better than having logger.drain() quietly write a log line. A level named then is refused for the same reason: a then method makes the logger look like a promise, and await on anything that resolves to it would write a line and never finish.

minLevel

minLevel?: L[number]      // default: the lowest declared level

Drops anything below this level before it reaches the driver.

export const appLog = log('app_log', {
  fields: { service: str() },
  minLevel: process.env.NODE_ENV === 'production' ? 'info' : 'debug',
  flush: '30s',
  write: toClickHouse('app_log'),
})

// In production this costs one array index and returns.
appLog.debug('request headers', { service: 'api' })

Dropped means dropped. No record is created, no field is validated and nothing is queued, so a filtered call costs one comparison.

A minLevel that is not one of the declared levels throws at declaration.

stage

stage?: 'driver' | 'local'      // default: 'driver'

Where lines wait between the call and your write function. Identical to the event's.

Prefer 'driver' on a durable driver. A crash is the moment the last thirty seconds of logs are worth the most, and local staging is the one setting that would lose them.

batch

batch?: { maxSize?: number; maxAge?: DurationInput; maxStaged?: number }
// defaults: { maxSize: 500, maxAge: '10s', maxStaged: 100_000 }

Local staging only, and ignored when stage: 'driver'. Identical to the event's, including the cap on how many lines this process holds.

flush

flush?: DurationInput      // default: the house default, then '30s'

The fastest this log may ship. A log has no resolution for a cadence to divide, so any duration is legal.

claimLimit

claimLimit?: number      // default: unlimited

How many lines one claim, and so one call to write, may carry. Identical to the event's: a flush claims again while a claim comes back full. Worth setting on a log that uploads a file per call.

write

write: (rows: LogRow<F, L>[], context: WriteContext) => Promise<void> | void

Where the rows go. Required.

Parameter	Type	Meaning
rows	LogRow<F, L>[]	The reserved columns, your declared fields, and level typed to the levels you declared
context	WriteContext	Which metric, the span of line timestamps, how many, and which attempt

MetricHouse prints nothing of its own. A write function that also calls console.log is how you get both, and Also writing to the console shows one.

Level methods

info(message: string | Error, fields?: InferShape<F>): void

One method per declared level. With the default levels that is debug(), info(), warn() and error().

Parameter	Type	Required	Meaning
message	string or Error	yes	The line. An Error also fills error_stack
fields	the declared shape	when any field is required	The values for this line

appLog.debug('cache miss', { service: 'api' })
appLog.info('order placed', { service: 'api' })
appLog.warn('retrying upstream', { service: 'api' })
appLog.error('upstream unavailable', { service: 'api' })

The fields argument may be left out once nothing in the shape is still required, which is what makes log.info('started') legal on a log whose fields are all optional or bound by a child().

Returns nothing. A line below minLevel returns immediately and stages nothing.

Throws, for a line at or above minLevel, on an unbound log, or on a field that is unknown, missing or ill typed. A line below minLevel is dropped before any of those checks, so it never throws, bound or not. A field named after a column the log writes itself, such as error_stack, throws too, whether the call passes it or a child() bound it. The message itself never throws, which is the next section.

unknown field "userId". The declared fields are [service, requestId]
app_log: "error_stack" is a column the log writes itself, so a line cannot pass it as a field

An Error as the message

Any level accepts an Error in place of a string. The message goes in message and the stack goes in the reserved error_stack column.

try {
  await chargeCard(order)
} catch (error) {
  appLog.error(error as Error, { service: 'checkout', requestId })
}

{
  level: 'error',
  message: 'card declined',
  error_stack: 'Error: card declined\n    at chargeCard (...)',
}

An error made in another realm, inside vm, a worker or an iframe, counts as an Error too, and keeps its stack. An error that arrives without a stack, which happens with some rethrown errors, still gets a header line, because that is worth more than an empty column. So does one whose stack is not a string. A message that is not a string is turned into one.

A logger never takes down a request

Every other call in MetricHouse throws on a bad value. A log message does not. Something that is neither a string nor an Error is turned into a string. A value String() cannot convert, such as an object made with Object.create(null), is written as [object Object], and one that cannot be described at all, such as a revoked proxy, as [a value that cannot be printed]. This call is made from inside catch blocks, where the value caught can be anything at all, and a logger that throws there replaces the error you were handling.

log.at()

at(level: L[number], message: string | Error, fields?: InferShape<F>): void

Writes at a level chosen while the program runs: one parsed from an upstream payload, or carried in a variable.

appLog.at(level, 'message from upstream', { service: 'gateway' })

Throws when level is not one of the declared levels. A log line with a level nothing queries is worse than a loud failure at the one call site that could have a typo.

log.child()

child(fields: Partial<InferShape<F>>): ChildLog

Returns a logger that merges fields into every call it makes. It is how a request id reaches every line without being threaded through every function.

const requestLog = appLog.child({ service: 'checkout', requestId: 'req_9f21' })

requestLog.info('checkout opened')
requestLog.warn('processor slow')
requestLog.error(new Error('declined'))
// every line carries service and requestId

Children nest, and each one adds to what its parent bound.

const serviceLog = appLog.child({ service: 'checkout' })
const requestLog = serviceLog.child({ requestId: 'req_9f21' })

requestLog.info('checkout opened')   // carries service and requestId
requestLog.bound                     // { service: 'checkout', requestId: 'req_9f21' }

A bound field becomes omittable rather than absent in the child's type, so child({ service }) satisfies a required field and a call site may still override it. Only a key the argument is sure to hold counts: from an object typed Partial<...>, where any key may be missing, every required field stays required at the call site. Passing a field as undefined at the call site does not count as an override: the bound value stays. child() drops a field passed to it as undefined in the same way, so it binds nothing and a parent's value stays.

child() copies the fields it is given. Changing that object afterwards changes nothing the child writes.

requestLog.info('retrying', { requestId: 'req_9f22' })   // the call site wins

A child carries the same level methods, at() and child(), plus bound, which is a frozen copy of every field it merges in, including the ones its parents bound.

Member	Type	Meaning
name	string	The log this child writes into
bound	Readonly<Record<string, unknown>>	The fields merged into every call

A child is not a metric. It stages into the log that made it and shares its batch settings, its cadence and its write function.

log.pending()

pending(): Promise<number>

How many lines are staged and not yet shipped.

await appLog.pending()     // 128

log.peek()

peek(n?: number): Promise<Row[]>

The first n staged lines as rows, without consuming them. Identical to the event's.

await appLog.peek(20)

log.snapshot()

snapshot(options?: SnapshotOptions): Promise<LogLiveRow<F, L>[]>

Unshipped lines as typed rows, with level narrowed to the levels you declared.

await appLog.snapshot({ limit: 100 })
await appLog.snapshot({ from: Date.now() - 60_000, orderBy: 'ts', direction: 'asc' })

Never partial, for the reason an event gives. Options are in Snapshot options.

log.flush()

flush(options?: FlushOptions): Promise<MetricFlushReport>

Claims the staged lines and ships them, in claims of at most claimLimit lines. Flush options covers the argument and the report.

log.drain()

drain(): Promise<void>

Resolves once every line written before the call has reached the driver. On a locally staged log it also ships what is buffered, and waits for that send. Under immediate delivery it also waits for the send to write that follows each one.

log.rowShape()

rowShape(): RowShape

appLog.rowShape().columns.map((c) => c.name)
// ['id', 'ts', 'level', 'message', 'error_stack', 'service', 'requestId',
//  '_ingested_at']

Properties

Property	Type	Value
name	string	The name it was declared with
kind	'log'
storage	'staged'	It keeps each line whole
fields	Shape	The fields you declared. The reserved three are not among them
levels	readonly string[]	The declared levels, lowest severity first
minLevel	string	The lowest level kept
stage	'driver' or 'local'	Where lines wait
flushMs	number	flush, parsed, including one taken from the house
isBound	boolean	true once a house has registered it
write	WriteFn	The function it was declared with

The row

{
  id: '019278b4-3c21-7a4e-9f10-8c2d5b6e1a03',
  ts: Date,
  level: 'error',
  message: 'card declined',
  error_stack: 'Error: card declined\n    at ...',   // only when an Error was passed
  service: 'checkout',                               // your declared fields
  requestId: 'req_9f21',
  _ingested_at: Date,
}

Column	Type	Meaning
id	string	A UUID version 7, minted when the line was written
ts	Date	When the line was written
level	one of levels	The severity
message	string	The line
error_stack	string	Present only on a line written with an Error
one per field	as declared	Your values
_ingested_at	Date	When the call ran

Column order is id, ts, level, message, error_stack, then your fields, then _ingested_at. A log never samples, so there is no _sample_rate.

Inside write, each row is a LogRow<F, L>, with level typed to the levels you declared. See Rows are typed.

Table schema

ClickHouse

CREATE TABLE app_log (
  id            String,
  ts            DateTime64(3),
  level         LowCardinality(String),
  message       String,
  error_stack   Nullable(String),
  service       LowCardinality(String),
  requestId     Nullable(String),
  _ingested_at  DateTime64(3)
)
ENGINE = MergeTree
ORDER BY (ts, level)
TTL toDateTime(ts) + INTERVAL 30 DAY;

Postgres

CREATE TABLE app_log (
  id            TEXT PRIMARY KEY,
  ts            TIMESTAMPTZ NOT NULL,
  level         TEXT NOT NULL,
  message       TEXT NOT NULL,
  error_stack   TEXT,
  service       TEXT NOT NULL,
  "requestId"   TEXT,
  _ingested_at  TIMESTAMPTZ NOT NULL
);
CREATE INDEX ON app_log (ts DESC);
CREATE INDEX ON app_log (level, ts DESC);

Reserved names

import { RESERVED_LOG_COLUMNS } from 'metrichouse/core'
// ['id', 'ts', 'level', 'message', 'error_stack', '_ingested_at', '_sample_rate']

A declared field may not take one of those names. A level may not shadow a method on the logger. Both are checked at declaration. A line that passes one of those names as a field throws when it is written, so error_stack only ever holds the stack of an Error message.

Queries

-- Error rate by service, per hour.
SELECT
  toStartOfHour(ts) AS hour,
  service,
  countIf(level IN ('error', 'fatal')) AS errors,
  count()                              AS lines
FROM app_log
WHERE ts >= now() - INTERVAL 1 DAY
GROUP BY hour, service
ORDER BY errors DESC;

-- Every line for one request.
SELECT ts, level, message, error_stack
FROM app_log
WHERE requestId = 'req_9f21'
ORDER BY ts;

Patterns

A request scoped logger

// metrics/schema.ts
import { log, str } from 'metrichouse/core'

const LEVELS = ['debug', 'info', 'warn', 'error', 'fatal'] as const
type Level = (typeof LEVELS)[number]

// Validate the environment variable here, so a typo is a startup failure with
// a clear message rather than a log that silently drops everything.
function configuredLevel(): Level {
  const value = process.env.LOG_LEVEL ?? 'info'
  if (!LEVELS.includes(value as Level)) {
    throw new Error(`LOG_LEVEL must be one of ${LEVELS.join(', ')}, got ${value}`)
  }
  return value as Level
}

export const appLog = log('app_log', {
  fields: {
    service: str(),
    env: str().default(process.env.NODE_ENV ?? 'development'),
    requestId: str().optional(),
    userId: str().optional(),
    route: str().optional(),
  },

  levels: LEVELS,
  minLevel: configuredLevel(),

  // Durable staging, so a crash does not take the last thirty seconds of logs
  // with it. This is the one signal that matters most while a process is dying.
  stage: 'driver',
  flush: '10s',

  // Bound, so an outage produces several uploads rather than one enormous one.
  claimLimit: 5_000,

  write: async (rows) => {
    const ndjson = rows.map((row) => JSON.stringify(row)).join('\n')
    const day = new Date().toISOString().slice(0, 10)

    await s3.send(
      new PutObjectCommand({
        Bucket: process.env.LOG_BUCKET!,
        Key: `app_log/${day}/${crypto.randomUUID()}.ndjson`,
        Body: ndjson,
        ContentType: 'application/x-ndjson',
      }),
    )
  },
})

// middleware/logger.ts
import { randomUUID } from 'node:crypto'
import { appLog } from '../metrics/schema.js'

declare module 'express-serve-static-core' {
  interface Request {
    log: ReturnType<typeof appLog.child>
  }
}

export function requestLogger(req, res, next) {
  const requestId = req.header('x-request-id') ?? randomUUID()

  // One child per request. Every line it writes carries this context. The
  // route is not in it, because routing has not run yet and req.route is empty.
  req.log = appLog.child({ service: 'api', requestId })

  res.setHeader('x-request-id', requestId)

  res.on('finish', () => {
    // The route is known now, and the mount path is added so a router mounted
    // at /orders does not collapse into '/:id'.
    const route = req.route ? (req.baseUrl ?? '') + req.route.path : 'unmatched'
    const userId = req.auth?.userId

    if (res.statusCode >= 500) {
      req.log.error('request failed', { route, userId })
    } else if (res.statusCode >= 400) {
      req.log.warn('request rejected', { route, userId })
    } else {
      req.log.info('request completed', { route, userId })
    }
  })

  next()
}

// Anywhere downstream.
app.post('/orders', async (req, res) => {
  req.log.info('creating order')

  try {
    const order = await createOrder(req.body)
    req.log.info('order created', { userId: order.userId })
    res.json(order)
  } catch (error) {
    req.log.error(error as Error)     // message and stack both land as columns
    res.status(500).json({ error: 'could not create order' })
  }
})

Also writing to the console

MetricHouse prints nothing. In development you usually want both.

function withConsole(name: string) {
  return async (rows: Record<string, unknown>[]) => {
    if (process.env.NODE_ENV !== 'production') {
      for (const row of rows) {
        console.log(`[${row.level}] ${row.message}`, row)
      }
    }
    await toS3(name)(rows)
  }
}

Printing at the call site is the other option, and it gives immediate feedback while MetricHouse handles storage.

Playground

The filter

minLevel is the setting with the largest effect on what a log costs. Drag it and watch both the volume and the bill.

Try it: what minLevel actually costs you

minLevelinfoanything below this never reaches the driverbytes per line320 Ba rough serialised sizedebug lines per minute2kinfo lines per minute400warn lines per minute30error lines per minute4

debugcache lookup for user u_4821dropped

inforequest completedstored

debugconnection returned to pooldropped

warnpayment processor slowstored

infoorder createdstored

errorcard declined by issuerstored

625klines stored per day

200.0 MBstorage per dayuncompressed

6.0 GBstorage per monthset a TTL on the table

2.9Mdropped per daynever leaves your process

The declaration these settings produce

log('app_log', {
  fields: { service: str() },
  levels: ['debug', 'info', 'warn', 'error'],
  minLevel: 'info',
  flush: '10s',
  write: async (rows) => s3.put(rows),
})

Moving minLevel from debug to info in a busy service usually removes most of the volume, and each dropped line costs one array index.

Staging and batching

Underneath, a log stages and batches exactly like an event, so the same controls apply.

Try it: where records wait, and what moves them

stage

in the driver, or in this process

records per second100what your application producesflush30sthe fastest a flush may ship itbatch.maxSize500local staging onlybatch.maxAge10slocal staging only

Records go to the driver and wait. Whatever calls flush() carries them, no more often than every 30s.

8.6Mrows stored per dayafter sampling

2.9kwrites per daycalls to your database

3krecords per writeone insert this size

The declaration these settings produce

log('app_log', {
  fields: { /* ... */ },
  stage: 'driver',
  flush: '30s',
  write: async (rows) => db.insert(rows),
})