Sample High-Volume Info Logs Without Losing Errors

1. Install pino in the service.

pnpm add pino

Expected output: pino is added to package.json and the lockfile is updated.

2. Create a logging module that hashes the request ID into a stable bucket and exposes an info helper that obeys the configured rate.

import { createHash } from 'node:crypto';
import pino from 'pino';

export const logger = pino({
  level: process.env.LOG_LEVEL ?? 'info',
  base: { service: process.env.SERVICE_NAME ?? 'api' },
});

const RATE = Number(process.env.INFO_SAMPLE_RATE ?? 0.1);

export function sampled(requestId: string): boolean {
  if (!Number.isFinite(RATE) || RATE >= 1) return true;
  if (RATE <= 0) return false;
  const bucket =
    createHash('sha256').update(requestId).digest().readUInt32BE(0) / 0xffffffff;
  return bucket < RATE;
}

export function info(
  requestId: string,
  fields: Record<string, unknown>,
  message: string,
): void {
  if (!sampled(requestId)) return;
  logger.info({ ...fields, requestId, sampled: true }, message);
}

Expected output: With INFO_SAMPLE_RATE=0.1, roughly one in ten request IDs passes sampled(); the same ID always gets the same decision.

3. Log every completed request through one policy: errors always, warnings and slow requests always, successful fast requests through the sampler.

import { randomUUID } from 'node:crypto';
import { performance } from 'node:perf_hooks';
import express from 'express';
import { info, logger } from './logging.js';

const app = express();

function logRequest(requestId: string, status: number, durationMs: number): void {
  const fields = { requestId, status, durationMs };
  if (status >= 500) {
    logger.error(fields, 'request failed');
    return;
  }
  if (status >= 400 || durationMs >= 1_000) {
    logger.warn(fields, 'request rejected or slow');
    return;
  }
  info(requestId, fields, 'request completed');
}

app.use((req, res, next) => {
  const incoming = req.get('x-request-id');
  const requestId =
    incoming && /^[A-Za-z0-9-]{8,64}$/.test(incoming) ? incoming : randomUUID();

  res.setHeader('x-request-id', requestId);
  const started = performance.now();

  res.on('finish', () => {
    logRequest(requestId, res.statusCode, Math.round(performance.now() - started));
  });

  next();
});

Expected output: A 200 response in 40 ms emits one sampled info line; a 200 response in 1.2 s emits a warning; a 500 response always emits an error.

4. Check the sampler distribution over 10,000 synthetic request IDs before deploying.

node --input-type=module -e '
import { createHash } from "node:crypto";
let hits = 0;
for (let i = 0; i < 10000; i += 1) {
  const bucket =
    createHash("sha256").update(`req-${i}`).digest().readUInt32BE(0) / 0xffffffff;
  if (bucket < 0.1) hits += 1;
}
console.log(JSON.stringify({ total: 10000, sampled: hits, ratio: hits / 10000 }));
'

Expected output: The output reports total 10000 and a ratio between 0.09 and 0.11, confirming the hash is evenly distributed.

5. After deploying, confirm that errors survived and that info lines carry the sampled marker and a bounded rate.

kubectl logs deploy/api --since=30m | jq -r 'select(.level == 50) | .msg' | sort | uniq -c
kubectl logs deploy/api --since=30m | jq -r 'select(.sampled == true) | .requestId' | sort -u | wc -l

Expected output: Error messages are present even during sampling, and the count of sampled request IDs is roughly 10 percent of the request count reported by metrics.

Problem

The sample ratio is 0 or 1 regardless of INFO_SAMPLE_RATE

Solution

Parse the rate once at startup and validate that it is a number between 0 and 1. A NaN value fails the finite check and samples everything, so the cost control silently stops working.

Problem

An error disappears after enabling sampling

Solution

The sampler was placed on the wrong logger or too low in the call path. Keep warn and error calls outside the sampled helper and verify with a forced 500 response.

Problem

One request produces a mix of sampled and unsampled lines

Solution

A different or missing request ID is used in some log calls. Generate the ID in the first middleware and pass it explicitly, or use AsyncLocalStorage.