Wide Event Logger

Most services log once per step, which means debugging one request means reassembling it from several unrelated lines. Building a single event object across the request's lifetime and logging it once, a "wide event" or canonical log line, means every field anyone set along the way lands on the same row.

@itsnas checkout.ts

codecheckout.ts

async function checkout(req: Request) {
  // @src/code/wide-event
  const event = createEvent('checkout', { requestId: req.id })
 
  try {
    const cart = await getCart(req.body.cartId)
    event.set({ userId: req.userId, cartId: cart.id, cartTotal: cart.total })
 
    const order = await placeOrder(cart)
    event.set({ orderId: order.id, outcome: 'success' })
 
    return json(200, { orderId: order.id })
  } catch (error) {
    event.set({
      outcome: 'error',
      errorType: error instanceof Error ? error.constructor.name : 'unknown',
    })
    throw error
  } finally {
    event.emit()
  }
}

main

Nas (@itsnas)

type Fields = Record<string, unknown>
 
interface WideEvent {
  set: (fields: Fields) => void
  emit: () => void
}
 
export function createEvent(name: string, seed: Fields = {}): WideEvent {
  const startedAt = Date.now()
  const fields: Fields = { event: name, ...seed }
  let emitted = false
 
  return {
    set(next) {
      Object.assign(fields, next)
    },
    emit() {
      // A request can hit multiple error handlers on the way out
      // (a caught error, then a top-level handler); only the first
      // emit is the real one.
      if (emitted) return
      emitted = true
      fields.durationMs = Date.now() - startedAt
      logger.info(fields)
    },
  }
}

main

Nas (@itsnas)