BlogBlog · observability

Logging và observability cho Node.js: structured log, correlation ID, metrics và tracing với OpenTelemetry

Dựng observability cho API Node.js từ đầu: log JSON bằng pino có redact, request ID qua AsyncLocalStorage, metrics RED với prom-client, tracing bằng OpenTelemetry, sampling để kiểm soát chi phí và alert theo SLO.

Part of Deep Dive series
July 19, 2025
27 min read
By Leo Pham
observabilityloggingnodejsopentelemetrymonitoring
Share this post:

14:03, một khách báo không thanh toán được đơn hàng. orders-api chạy 6 pod trên Kubernetes, gọi sang payment-service và Postgres. Bạn mở log và thấy hàng nghìn dòng console.log('error', err) trộn lẫn từ 6 pod, không có request ID, không biết dòng nào thuộc về request của khách đó. Bạn cũng không trả lời được câu sếp hỏi đầu tiên: "lỗi này ảnh hưởng bao nhiêu người?"

Observability là khả năng trả lời những câu hỏi đó mà không phải deploy thêm code để debug. Với một API Node.js, nó gồm ba tín hiệu: log có cấu trúc để biết chuyện gì xảy ra với một request cụ thể, metrics để biết hệ thống đang khoẻ hay yếu, và trace để biết thời gian của một request bị tiêu ở đâu qua nhiều service.

Bài này dựng cả ba cho một API Express 5 + Postgres, theo thứ tự mình làm ở các dự án thật: pino và redact, request ID qua AsyncLocalStorage, log lỗi kèm cause chain, metrics RED với prom-client, tracing bằng OpenTelemetry (kèm Next.js), sampling để kiểm soát chi phí, và cuối cùng là alert theo SLO. Mục tiêu cuối: từ một alert, trong vài phút bạn đi tới đúng trace và đúng các dòng log của request gây lỗi.

TL;DR:

  • Log JSON một dòng mỗi sự kiện, có requestId, service, version; redact secret và dữ liệu cá nhân ngay ở logger.
  • Metrics theo RED (Rate, Errors, Duration) bằng histogram; label chỉ nhận giá trị hữu hạn, không bao giờ là userId hay URL thô.
  • Trace bằng OpenTelemetry auto-instrumentation, export OTLP về Collector; log mang trace_id để nhảy qua lại.
  • Kiểm soát chi phí bằng sampling (head ở SDK, tail ở Collector) và log level.
  • Alert theo triệu chứng người dùng thấy (error rate, latency vượt SLO) với burn rate, không alert theo CPU.

Logs, metrics, traces: mỗi loại trả lời câu hỏi gì

Ba tín hiệu không thay thế cho nhau. Chọn sai tín hiệu cho một câu hỏi là nguồn gốc của dashboard rối và hoá đơn observability cao.

Tín hiệu Câu hỏi trả lời tốt Điểm mạnh Điểm yếu / chi phí Ví dụ
Logs Chuyện gì đã xảy ra với request X, user Y? Chi tiết tuỳ ý, có ngữ cảnh nghiệp vụ Tốn dung lượng theo traffic; khó tổng hợp payment declined, orderId=ord_8f3a
Metrics Hệ thống có đang khoẻ không? Bao nhiêu % request lỗi? Rẻ, chi phí cố định theo số series; alert tốt Không có chi tiết từng request; dễ nổ cardinality http_server_request_duration_seconds p99
Traces Request chậm/lỗi ở chỗ nào qua nhiều service? Thấy được quan hệ cha-con, thời gian từng bước Tốn nhất nếu giữ 100%; cần propagate context span POST /checkout → pg.query → payment.charge

Quy tắc mình dùng khi bắt đầu: log có cấu trúc và metrics RED là bắt buộc ngay từ ngày đầu, kể cả với một service. Tracing trở nên đáng tiền khi bạn có từ hai service trở lên gọi nhau, hoặc khi một request đi qua nhiều tầng I/O (DB, cache, queue, API ngoài) mà bạn hay phải đoán chỗ chậm.

Bước 1: structured log với pino

Log có cấu trúc nghĩa là mỗi sự kiện là một object JSON trên một dòng, với các field cố định. Hệ thống log (Loki, Elasticsearch, CloudWatch, Datadog...) lọc được theo level="error" AND service="orders-api" AND orderId="ord_8f3a" thay vì grep chuỗi.

// src/logger.ts
import pino, { type DestinationStream, type Logger } from 'pino'

export function createLogger(destination?: DestinationStream): Logger {
  return pino(
    {
      level: process.env.LOG_LEVEL ?? 'info',
      base: {
        service: process.env.OTEL_SERVICE_NAME ?? 'orders-api',
        env: process.env.APP_ENV ?? 'local',
        version: process.env.APP_VERSION ?? 'dev', // git SHA hoặc tag lúc build
      },
      timestamp: pino.stdTimeFunctions.isoTime,
      formatters: {
        level: (label) => ({ level: label }), // "level":"error" thay vì 50, dễ query hơn
      },
      serializers: { err: pino.stdSerializers.errWithCause },
      redact: {
        paths: [
          'password',
          '*.password',
          '*.token',
          '*.refreshToken',
          '*.cccd', // số căn cước
          'card.number',
          'req.headers.authorization',
          'req.headers.cookie',
          'res.headers["set-cookie"]',
        ],
        censor: '[REDACTED]',
      },
      transport:
        process.env.NODE_ENV === 'development' && !destination
          ? { target: 'pino-pretty', options: { colorize: true } }
          : undefined,
    },
    destination,
  )
}

export const logger = createLogger()

Giải thích từng quyết định:

  • base gắn service, env, version vào mọi dòng. version giúp trả lời ngay câu "lỗi này bắt đầu từ bản deploy nào?".
  • formatters.level đổi level số (30, 50) sang chữ. Pino mặc định dùng số vì nhanh hơn, nhưng query level="error" dễ đọc hơn level>=50.
  • redact chạy trong logger nên không ai quên được. Path có wildcard một cấp (*.password khớp user.password nhưng không khớp a.b.password). Nếu muốn xoá hẳn key thay vì thay bằng [REDACTED], dùng remove: true.
  • pino-pretty chỉ bật ở local. Ở production, log ra stdout dạng JSON và để agent của hạ tầng (Fluent Bit, Vector, OpenTelemetry Collector với filelog receiver) gom và đẩy đi. App tự gửi log qua HTTP thì dễ mất log khi crash và tạo backpressure lên chính app.

Level nào cho việc gì

  • fatal: process sắp chết (crash handler).
  • error: request/job thất bại do lỗi phía mình, cần người xem. Mỗi dòng error nên là thứ bạn sẵn sàng bị đánh thức vì nó, nếu nó tăng đột biến.
  • warn: bất thường nhưng đã tự xử lý (retry thành công ở lần 2, fallback sang cache cũ).
  • info: sự kiện nghiệp vụ và access log (order created, request completed).
  • debug/trace: chi tiết để debug, tắt ở production và bật tạm qua LOG_LEVEL khi cần.

Lỗi 4xx do client (validation, 404) không phải error. Log chúng ở info hoặc warn, nếu không dashboard lỗi sẽ đầy 404 của bot quét.

Child logger

import { logger } from './logger.js'

const paymentLog = logger.child({ module: 'payments' })

export async function refund(orderId: string, amountVnd: number) {
  const log = paymentLog.child({ orderId })
  log.info({ amountVnd }, 'refund requested')
  // ... gọi payment-service
  log.info('refund completed')
}

Child logger gắn binding một lần và mọi dòng sau đó đều có. Bindings được serialize sẵn khi tạo child nên rẻ hơn truyền lại object mỗi lần log.

Những thứ không bao giờ được log

  • Mật khẩu, OTP, access/refresh token, API key, cookie, header Authorization.
  • Số thẻ đầy đủ, CVV (vi phạm PCI DSS ngay lập tức), số tài khoản ngân hàng đầy đủ.
  • Số CCCD/CMND, ảnh giấy tờ, địa chỉ chi tiết, số điện thoại nếu không thật sự cần. Luật Bảo vệ dữ liệu cá nhân (số 91/2025/QH15, hiệu lực từ 01/01/2026) áp dụng cho mọi hoạt động xử lý dữ liệu cá nhân, kể cả việc ghi và lưu trữ; log giữ 30 ngày trên cloud có số điện thoại khách hàng cũng là dữ liệu bạn phải bảo vệ theo luật.
  • Toàn bộ request/response body. Log ID và vài field cần thiết thay vì { body: req.body }.

Edge case quan trọng: redact chỉ hoạt động trên object, không trên chuỗi message. log.info(\login failed for ${email} with ${password}`)` sẽ lọt nguyên văn. Quy ước trong team: message là chuỗi cố định, dữ liệu luôn đi trong object đầu tiên. Quy ước này còn giúp group log theo message dễ hơn.

Bước 2: request ID, AsyncLocalStorage và pino-http

Request ID là sợi chỉ nối mọi dòng log của một request. Correlation ID là cùng ý tưởng nhưng đi xuyên nhiều service: service A nhận x-request-id, gửi tiếp header đó sang service B, nên log của cả hai đều có cùng một ID.

Vấn đề là code sâu bên trong (repository, client gọi API ngoài) không có req trong tay. Truyền logger qua mọi tham số thì xấu và dễ quên. AsyncLocalStorage giải quyết việc này: nó giữ một store đi theo chuỗi async của request.

// src/request-context.ts
import { AsyncLocalStorage } from 'node:async_hooks'
import type { Logger } from 'pino'
import { logger as rootLogger } from './logger.js'

type RequestContext = { requestId: string; log: Logger }

export const requestContext = new AsyncLocalStorage<RequestContext>()

/** Logger của request hiện tại; ngoài request (cron, startup) thì trả root logger */
export function getLogger(): Logger {
  return requestContext.getStore()?.log ?? rootLogger
}

/** Gắn thêm binding (userId sau khi auth...) cho phần còn lại của request */
export function bindToRequest(bindings: Record<string, unknown>): void {
  const ctx = requestContext.getStore()
  if (ctx) ctx.log = ctx.log.child(bindings)
}
// src/app.ts
import { randomUUID } from 'node:crypto'
import express from 'express'
import pino from 'pino'
import pinoHttp from 'pino-http'
import { logger } from './logger.js'
import { requestContext } from './request-context.js'

const INCOMING_ID = /^[\w-]{8,64}$/ // chỉ tin ID có format hợp lệ từ upstream

export const app = express()

app.use(
  pinoHttp({
    logger,
    quietReqLogger: true, // req.log chỉ bind requestId, không bind cả object req
    customAttributeKeys: { reqId: 'requestId' },
    genReqId(req, res) {
      const incoming = req.headers['x-request-id']
      const id = typeof incoming === 'string' && INCOMING_ID.test(incoming) ? incoming : randomUUID()
      res.setHeader('x-request-id', id) // client/support gửi lại ID này khi báo lỗi
      return id
    },
    customLogLevel(_req, res, err) {
      if (err || res.statusCode >= 500) return 'error'
      if (res.statusCode >= 400) return 'warn'
      return 'info'
    },
    autoLogging: { ignore: (req) => req.url === '/healthz' },
    // Giữ cause chain dạng object lồng nhau (xem Bước 3)
    wrapSerializers: false,
    serializers: {
      req: pino.stdSerializers.req,
      res: pino.stdSerializers.res,
      err: pino.stdSerializers.errWithCause,
    },
  }),
)

app.use(express.json({ limit: '100kb' }))

// Đặt SAU body parser: callback của một số middleware đọc stream có thể làm mất context
app.use((req, _res, next) => {
  requestContext.run({ requestId: String(req.id), log: req.log }, next)
})

Code ở tầng sâu chỉ cần gọi getLogger():

// src/orders/orders.repository.ts
import { getLogger } from '../request-context.js'
import { pool } from '../db.js'

export async function markOrderPaid(orderId: string, paymentId: string): Promise<void> {
  const started = performance.now()
  const result = await pool.query(
    "UPDATE orders SET status = 'PAID', payment_id = $2 WHERE id = $1 AND status = 'PENDING'",
    [orderId, paymentId],
  )
  getLogger().info(
    { orderId, paymentId, rowCount: result.rowCount, durationMs: Math.round(performance.now() - started) },
    'order marked paid',
  )
}

Mỗi request sinh ra một dòng access log của pino-http, cộng các dòng nghiệp vụ, tất cả có chung requestId (output minh hoạ):

{"level":"info","time":"2026-11-03T07:03:12.418Z","service":"orders-api","env":"production","version":"1.42.0","requestId":"5f0c2a9e-0d7b-4f61-9a0e-2b1f3c8d9e10","orderId":"ord_8f3a","paymentId":"pay_77k1","rowCount":1,"durationMs":4,"msg":"order marked paid"}
{"level":"info","time":"2026-11-03T07:03:12.421Z","service":"orders-api","env":"production","version":"1.42.0","requestId":"5f0c2a9e-0d7b-4f61-9a0e-2b1f3c8d9e10","req":{"method":"POST","url":"/orders/ord_8f3a/pay"},"res":{"statusCode":200},"responseTime":187,"msg":"request completed"}

Những điểm hay vấp:

  • Chỉ tin x-request-id từ upstream khi nó đúng format. Header là input của client; không validate thì ai đó gửi chuỗi 10 KB hoặc chèn ký tự xuống dòng vào log của bạn.
  • Propagate sang service khác. Khi gọi payment-service, thêm 'x-request-id': requestContext.getStore()?.requestId vào header. Nếu dùng OpenTelemetry (Bước 5), header traceparent được gắn tự động và trace_id đóng vai trò correlation ID xuyên service. Mình vẫn giữ requestId vì nó ngắn, có trong response header, và support có thể xin khách gửi lại.
  • Mất context. AsyncLocalStorage đi theo promise và hầu hết API callback của Node. Nó có thể mất ở thư viện tự quản lý queue callback hoặc ở listener của EventEmitter được tạo trước request. Cách debug theo tài liệu Node: log requestContext.getStore() sau từng lời gọi nghi ngờ, chỗ đầu tiên ra undefined là thủ phạm. Với callback, bọc bằng AsyncResource.bind() từ node:async_hooks.

Bước 3: log lỗi kèm stack và cause chain

Bài error handling trong TypeScript và Node.js đã nói vì sao mọi chỗ wrap lỗi phải truyền cause. Phía logging chỉ cần đảm bảo hai điều: cause chain không bị mất khi serialize, và mỗi lỗi chỉ được log một lần.

Có một bẫy với pino-http mà mình mất khá lâu mới nhận ra. Mặc định pino-http bọc serializer err của riêng nó: serializer chuẩn chạy trước, gộp message và stack của cause vào lỗi ngoài và bỏ các field khác của cause (như code: 'ECONNRESET'). Đặt errWithCause ở logger gốc là chưa đủ, vì child logger của pino-http dùng serializer của nó. Đó là lý do config ở Bước 2 có wrapSerializers: false kèm bộ serializer tường minh.

Để log lỗi đúng một lần, mình gắn lỗi vào access log thay vì log riêng. pino-http đọc res.err khi response kết thúc:

// src/error-middleware.ts
import type { ErrorRequestHandler } from 'express'

export const errorMiddleware: ErrorRequestHandler = (error, req, res, next) => {
  if (res.headersSent) return next(error)
  const status = typeof error?.httpStatus === 'number' ? error.httpStatus : 500

  // pino-http sẽ ghi lỗi này vào dòng "request completed/errored" của chính request
  res.err = error instanceof Error ? error : new Error(String(error))

  res.status(status).type('application/problem+json').json({
    type: 'about:blank',
    title: status >= 500 ? 'Internal Server Error' : 'Request failed',
    status,
    instance: req.originalUrl,
    requestId: req.id, // user báo lỗi kèm ID này, support tìm được ngay
  })
}

Kết quả là một dòng duy nhất chứa method, URL, status, thời gian xử lý, requestId, và lỗi với cause lồng nhau tới tận ECONNRESET. Không có cảnh 4 tầng code mỗi tầng log một lần cùng một lỗi.

Bước 4: metrics với prom-client theo RED

Log trả lời câu hỏi về một request. Metrics trả lời câu hỏi về tất cả request. Phương pháp RED cho service hướng request gồm ba con số: Rate (bao nhiêu request/giây), Errors (bao nhiêu % lỗi), Duration (phân phối thời gian xử lý). Cả ba lấy được từ một histogram duy nhất.

// src/metrics.ts
import express, { type RequestHandler } from 'express'
import client from 'prom-client'

export const registry = new client.Registry()
registry.setDefaultLabels({ service: process.env.OTEL_SERVICE_NAME ?? 'orders-api' })
client.collectDefaultMetrics({ register: registry }) // heap, GC, event loop lag, CPU...

const httpDuration = new client.Histogram({
  name: 'http_server_request_duration_seconds',
  help: 'Thời gian xử lý HTTP request',
  labelNames: ['method', 'route', 'status_code'] as const,
  // bucket bám theo SLO: có 0.5 vì SLO latency là 500ms
  buckets: [0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10],
  registers: [registry],
})

export const ordersCreated = new client.Counter({
  name: 'orders_created_total',
  help: 'Số đơn hàng tạo thành công',
  labelNames: ['payment_method'] as const, // card | momo | cod: tập giá trị hữu hạn
  registers: [registry],
})

export const httpMetrics: RequestHandler = (req, res, next) => {
  const end = httpDuration.startTimer()
  res.on('finish', () => {
    // Route template (/orders/:id), KHÔNG dùng req.originalUrl (/orders/ord_8f3a?x=1)
    const route = req.route?.path ? `${req.baseUrl}${String(req.route.path)}` : 'unmatched'
    end({ method: req.method, route, status_code: String(res.statusCode) })
  })
  next()
}

// Expose trên port riêng, không đi qua ingress public
export function startMetricsServer(port = 9464): void {
  const metricsApp = express()
  metricsApp.get('/metrics', async (_req, res) => {
    res.set('content-type', registry.contentType)
    res.send(await registry.metrics())
  })
  metricsApp.listen(port)
}

Truy vấn PromQL cho ba chỉ số RED:

# Rate: request/giây theo route
sum by (route) (rate(http_server_request_duration_seconds_count{service="orders-api"}[5m]))

# Errors: tỉ lệ 5xx
sum(rate(http_server_request_duration_seconds_count{service="orders-api",status_code=~"5.."}[5m]))
/
sum(rate(http_server_request_duration_seconds_count{service="orders-api"}[5m]))

# Duration: p99 theo route
histogram_quantile(0.99,
  sum by (le, route) (rate(http_server_request_duration_seconds_bucket{service="orders-api"}[5m])))

Vì sao histogram chứ không phải summary: histogram cộng dồn được giữa các pod (sum by (le)), còn quantile của summary tính sẵn trên từng pod và không thể cộng lại thành p99 toàn cục. Cái giá là histogram_quantile nội suy trong bucket, nên độ chính xác phụ thuộc vào cách chọn bucket. Đặt một bucket đúng ngưỡng SLO (ở đây 0.5s) để phép đo "bao nhiêu % request dưới 500ms" là chính xác.

Cardinality: cách metrics làm cháy hoá đơn

Mỗi tổ hợp giá trị label là một time series riêng. Với histogram, mỗi tổ hợp còn nhân với số bucket cộng 3 (+Inf, _sum, _count). Ước lượng trần cho metric trên: 4 method × 30 route × 8 status code × 13 = 12.480 series mỗi pod, nhân 10 pod là khoảng 125.000. Con số đó vẫn ổn với Prometheus. Giờ thêm label userId với 50.000 user: bạn vừa nhân mọi thứ lên 50.000 lần, Prometheus sẽ hết RAM, còn dịch vụ managed sẽ gửi hoá đơn rất đáng nhớ.

Quy tắc: label chỉ nhận giá trị từ một tập hữu hạn và nhỏ mà bạn liệt kê được (method, route template, status code, payment_method, tên upstream). Những thứ như userId, orderId, email, URL thô, message lỗi thì đưa vào log hoặc span attribute, nơi cardinality cao không thành vấn đề. Route không khớp (404 của bot quét /wp-admin.php) gom về một nhãn unmatched, đúng như code ở trên.

Bước 5: tracing với OpenTelemetry

Trace là cây các span: span gốc POST /orders/:id/pay, con của nó là pg.query UPDATE orders, POST payment-service/charges, và bên payment-service lại có span con của riêng nó. Nhìn vào trace là thấy ngay 1,8 giây của request nằm ở đâu.

OpenTelemetry là chuẩn mở, vendor-neutral. Bạn instrument một lần, export bằng giao thức OTLP, rồi đổi backend (Jaeger, Grafana Tempo, Honeycomb, Datadog...) mà không sửa code.

// src/instrumentation.ts  (phải chạy TRƯỚC mọi import khác của app)
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node'
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-http'
import { NodeSDK } from '@opentelemetry/sdk-node'

export const otelSdk = new NodeSDK({
  serviceName: process.env.OTEL_SERVICE_NAME ?? 'orders-api',
  traceExporter: new OTLPTraceExporter(), // đọc OTEL_EXPORTER_OTLP_ENDPOINT, mặc định http://localhost:4318
  instrumentations: [
    getNodeAutoInstrumentations({
      // tắt tường minh các instrumentation rất ồn mà ít giá trị
      '@opentelemetry/instrumentation-fs': { enabled: false },
      '@opentelemetry/instrumentation-dns': { enabled: false },
    }),
  ],
})

otelSdk.start()
// Trong graceful shutdown của app: await otelSdk.shutdown() để flush span còn trong buffer

Auto-instrumentation patch các thư viện phổ biến (http, express, pg, ioredis, undici/fetch, pino...) để tự tạo span và tự gắn header traceparent (W3C Trace Context) vào request đi ra. Vì nó patch module lúc được load, file instrumentation phải chạy trước app:

# Biến môi trường chuẩn của OpenTelemetry
export OTEL_SERVICE_NAME=orders-api
export OTEL_EXPORTER_OTLP_ENDPOINT=http://otel-collector:4318
export OTEL_RESOURCE_ATTRIBUTES=deployment.environment.name=production,service.version=1.42.0

# App build ra CommonJS
node --require ./dist/instrumentation.js dist/server.js

# App ESM: cần thêm loader hook của OpenTelemetry để patch được module ESM
node --experimental-loader=@opentelemetry/instrumentation/hook.mjs \
     --import ./dist/instrumentation.js dist/server.js

Hỗ trợ ESM là chỗ hay gãy nhất. Không có loader hook, app ESM vẫn chạy và vẫn có span HTTP, nhưng các span pg, ioredis sẽ im lặng biến mất. Node 26 đã chuyển module.register() sang runtime deprecation, nên cơ chế hook có thể in cảnh báo; hãy theo dõi tài liệu ESM support của opentelemetry-js khi nâng Node.

Span nghiệp vụ tự tạo

Auto-instrumentation cho bạn span kỹ thuật. Span cho bước nghiệp vụ thì bạn tự thêm:

// src/orders/checkout.ts
import { SpanStatusCode, trace } from '@opentelemetry/api'
import { chargeOrder } from '../payments.js'
import { reserveStock } from '../inventory.js'

const tracer = trace.getTracer('orders-api')

export async function checkout(orderId: string, paymentMethod: 'card' | 'momo' | 'cod') {
  return tracer.startActiveSpan('checkout', async (span) => {
    // orderId ở đây ổn: span attribute không bị giới hạn cardinality như metric label
    span.setAttributes({ 'order.id': orderId, 'payment.method': paymentMethod })
    try {
      const reservation = await reserveStock(orderId)
      span.addEvent('stock.reserved', { 'reservation.id': reservation.id })
      return await chargeOrder(orderId)
    } catch (error) {
      span.recordException(error instanceof Error ? error : new Error(String(error)))
      span.setStatus({ code: SpanStatusCode.ERROR })
      throw error
    } finally {
      span.end() // quên end() = span không bao giờ được export
    }
  })
}

Nối log với trace

@opentelemetry/instrumentation-pino (có sẵn trong gói auto-instrumentations) chèn trace_id và span_id vào mọi dòng log được ghi khi đang có span active. Trên Grafana, bạn cấu hình "derived field" từ trace_id trong Loki sang Tempo; từ một dòng log lỗi, một click là tới trace. Chiều ngược lại cũng được: từ span chậm, lọc log theo trace_id.

Collector ở giữa

Đừng export thẳng từ app sang backend. Đặt OpenTelemetry Collector ở giữa để app chỉ cần biết một endpoint; batching, retry, lọc dữ liệu nhạy cảm và sampling đều làm ở Collector:

# otel-collector.yaml (bản otelcol-contrib, vì tail_sampling nằm ở contrib)
receivers:
  otlp:
    protocols:
      grpc:
        endpoint: 0.0.0.0:4317
      http:
        endpoint: 0.0.0.0:4318

processors:
  memory_limiter:
    check_interval: 1s
    limit_percentage: 80
    spike_limit_percentage: 20
  tail_sampling:
    decision_wait: 10s
    policies:
      - name: keep-errors
        type: status_code
        status_code: { status_codes: [ERROR] }
      - name: keep-slow
        type: latency
        latency: { threshold_ms: 1000 }
      - name: sample-rest
        type: probabilistic
        probabilistic: { sampling_percentage: 10 }
  batch: {}

exporters:
  otlphttp/tempo:
    endpoint: http://tempo:4318

service:
  pipelines:
    traces:
      receivers: [otlp]
      processors: [memory_limiter, tail_sampling, batch]
      exporters: [otlphttp/tempo]

Next.js: instrumentation.ts

Next.js có file convention instrumentation.ts (stable từ Next.js 15) đặt ở root hoặc trong src/. register() chạy một lần khi server khởi động; onRequestError nhận mọi lỗi phía server kèm ngữ cảnh route:

// instrumentation.ts
import { registerOTel } from '@vercel/otel'
import type { Instrumentation } from 'next'

export function register() {
  registerOTel({ serviceName: 'shop-web' })
}

export const onRequestError: Instrumentation.onRequestError = async (error, request, context) => {
  if (process.env.NEXT_RUNTIME !== 'nodejs') return // pino không chạy ở Edge runtime
  const { logger } = await import('./lib/logger')
  const digest =
    typeof error === 'object' && error !== null && 'digest' in error ? String(error.digest) : undefined
  logger.error(
    {
      err: error,
      digest, // khớp với digest user thấy trên error.tsx
      method: request.method,
      path: request.path,
      routePath: context.routePath,
      routeType: context.routeType, // render | route | action | proxy
    },
    'next.js request error',
  )
}

@vercel/otel không bắt buộc phải deploy trên Vercel. Nó là wrapper gọn quanh OpenTelemetry SDK, chạy được cả ở Node và Edge runtime, và vẫn đọc các biến OTEL_* chuẩn.

Bước 6: sampling và kiểm soát chi phí

Chi phí observability tăng theo traffic, và log thường là khoản lớn nhất. Các đòn bẩy, theo thứ tự hiệu quả:

Đòn bẩy Làm thế nào Đánh đổi
Log level info ở production, debug bật tạm qua LOG_LEVEL Mất chi tiết khi sự cố xảy ra lúc đang tắt debug
Bỏ log vô giá trị autoLogging.ignore cho /healthz, readiness probe Gần như không có
Retention theo loại Access log 7 ngày, audit log lâu hơn theo yêu cầu Phải tách stream/index
Head sampling trace parentbased_traceidratio ở SDK Có thể bỏ lỡ đúng trace lỗi hiếm
Tail sampling trace Collector giữ 100% lỗi, request chậm, 10% còn lại Collector cần RAM, phải route cùng trace về một instance
Cardinality metrics Label hữu hạn, bỏ label không ai query Ít chiều để cắt lát hơn

Head sampling quyết định ngay khi trace bắt đầu, ở SDK, nên rẻ nhất:

export OTEL_TRACES_SAMPLER=parentbased_traceidratio
export OTEL_TRACES_SAMPLER_ARG=0.1   # giữ 10% trace mới; request đã có parent thì theo quyết định của parent

Tiền tố parentbased_ quan trọng: nếu orders-api giữ một trace mà payment-service lại tự tung xúc xắc riêng, bạn sẽ có những trace bị đứt nửa chừng. Với parent-based, service phía sau tôn trọng quyết định của service đầu tiên.

Tail sampling (config Collector ở Bước 5) quyết định sau khi trace kết thúc, nên giữ được 100% trace lỗi và trace chậm, đúng những trace bạn cần khi điều tra. Cái giá: SDK phải gửi 100% span lên Collector (để head sampler always_on), Collector giữ span trong RAM suốt decision_wait, và mọi span của cùng một trace phải đến cùng một instance Collector. Khi chạy nhiều Collector, đặt một tầng loadbalancing exporter phía trước để route theo trace_id.

Quy tắc chọn: traffic thấp (dưới vài chục request/giây) thì giữ 100% và khỏi nghĩ. Traffic vừa thì head sampling 10-20%. Khi bắt đầu bỏ lỡ trace của lỗi hiếm mà mình cần, chuyển sang tail sampling.

Bước 7: alert theo triệu chứng với SLO và error budget

Alert "CPU > 80%" đánh thức bạn lúc 2 giờ sáng trong khi người dùng không hề bị ảnh hưởng, và im lặng khi service trả 500 vì upstream chết với CPU 5%. Hãy alert theo triệu chứng người dùng cảm nhận được; metrics nguyên nhân (CPU, heap, pool) để trên dashboard phục vụ điều tra.

Ba khái niệm:

  • SLI (indicator): tỉ lệ request "tốt", ví dụ request không trả 5xx và xong dưới 500ms.
  • SLO (objective): mục tiêu cho SLI trong một cửa sổ thời gian, ví dụ 99,9% trong 30 ngày.
  • Error budget: phần còn lại, 0,1%. 30 ngày có 43.200 phút, nên 0,1% tương đương khoảng 43 phút "chết hoàn toàn", hoặc 10.000 request lỗi trên 10 triệu request.

Alert theo burn rate: tốc độ tiêu budget so với mức "vừa đủ hết trong 30 ngày". Burn rate 14,4 duy trì trong 1 giờ tiêu 2% budget của cả tháng (14,4 × 1 / 720 = 0,02). Cách làm multi-window theo SRE Workbook của Google: điều kiện cửa sổ dài để chắc chắn sự cố có thật, điều kiện cửa sổ ngắn để alert tự tắt nhanh khi đã hết.

# prometheus-rules.yaml
groups:
  - name: orders-api-slo
    rules:
      - record: slo:orders_api_errors:ratio_rate5m
        expr: |
          sum(rate(http_server_request_duration_seconds_count{service="orders-api",status_code=~"5.."}[5m]))
          / sum(rate(http_server_request_duration_seconds_count{service="orders-api"}[5m]))
      - record: slo:orders_api_errors:ratio_rate30m
        expr: |
          sum(rate(http_server_request_duration_seconds_count{service="orders-api",status_code=~"5.."}[30m]))
          / sum(rate(http_server_request_duration_seconds_count{service="orders-api"}[30m]))
      - record: slo:orders_api_errors:ratio_rate1h
        expr: |
          sum(rate(http_server_request_duration_seconds_count{service="orders-api",status_code=~"5.."}[1h]))
          / sum(rate(http_server_request_duration_seconds_count{service="orders-api"}[1h]))
      - record: slo:orders_api_errors:ratio_rate6h
        expr: |
          sum(rate(http_server_request_duration_seconds_count{service="orders-api",status_code=~"5.."}[6h]))
          / sum(rate(http_server_request_duration_seconds_count{service="orders-api"}[6h]))

      - alert: OrdersApiErrorBudgetFastBurn
        expr: |
          slo:orders_api_errors:ratio_rate1h > (14.4 * 0.001)
          and slo:orders_api_errors:ratio_rate5m > (14.4 * 0.001)
        labels:
          severity: page
        annotations:
          summary: "orders-api đang đốt error budget 14.4x (2% budget tháng trong 1 giờ)"
          runbook: "link tới runbook nội bộ: kiểm tra payment-service, pool Postgres, bản deploy gần nhất"

      - alert: OrdersApiErrorBudgetSlowBurn
        expr: |
          slo:orders_api_errors:ratio_rate6h > (6 * 0.001)
          and slo:orders_api_errors:ratio_rate30m > (6 * 0.001)
        labels:
          severity: page
        annotations:
          summary: "orders-api đốt error budget 6x trong 6 giờ"

SLO latency làm tương tự với bucket le="0.5": tỉ lệ request tốt là rate(..._bucket{le="0.5"}[5m]) / rate(..._count[5m]). Đây chính là lý do histogram ở Bước 4 cần có bucket 0.5.

Hai lưu ý thực tế. Service traffic thấp (vài request/phút) cho tỉ lệ lỗi giật rất mạnh: 1 lỗi trên 3 request là 33%. Với service như vậy, thêm điều kiện số request tối thiểu hoặc dùng synthetic check. Và mỗi alert page phải có runbook: người trực lúc 2 giờ sáng cần biết bước đầu tiên là gì, không phải tự suy luận.

Bảng tổng hợp: tín hiệu, công cụ và alert mẫu

Tín hiệu Công cụ trong bài Lưu ở đâu (ví dụ) Alert / cách dùng mẫu
Access log + log nghiệp vụ pino, pino-http, AsyncLocalStorage Loki, Elasticsearch, CloudWatch Logs Không alert trực tiếp; tra theo requestId, trace_id
Log lỗi có cause chain errWithCause, res.err như trên Đếm level="error" theo err.type trên dashboard
Rate / Errors / Duration prom-client histogram Prometheus, Mimir Burn rate 14,4x (1h & 5m) và 6x (6h & 30m)
Event loop lag, heap, GC collectDefaultMetrics() Prometheus Dashboard; warn nếu nodejs_eventloop_lag_p99_seconds > 0,2 trong 10 phút
Business metric Counter orders_created_total Prometheus Alert khi số đơn/5 phút giảm mạnh so với cùng giờ tuần trước
Trace phân tán OpenTelemetry SDK + Collector Tempo, Jaeger Không alert; mở từ alert/log để tìm span chậm/lỗi
Lỗi server Next.js onRequestError + @vercel/otel log + trace backend Đếm theo routePath, nối với digest user báo

Production: overhead, bảo mật và test

Overhead. pino ghi JSON rất nhanh, nhưng mỗi dòng log vẫn tốn CPU để serialize. Một request sinh 30 dòng info là quá nhiều; 2-5 dòng (access log + vài sự kiện nghiệp vụ) là hợp lý. Auto-instrumentation của OpenTelemetry thêm chi phí ở mỗi lời gọi được patch. Tắt các instrumentation không dùng, và đo p99 trước và sau khi bật bằng cùng một bài load test (xem tối ưu Node.js trong production).

Bảo mật. /metrics lộ tên route, số request, đôi khi cả version thư viện: expose trên port riêng, chỉ Prometheus trong cluster gọi được. Collector nhận OTLP không xác thực thì đừng mở ra Internet. Log thường được nhiều người đọc hơn database production, nên áp dụng quyền truy cập và retention cho log nghiêm túc như cho dữ liệu.

Test redact. Quy tắc redact là code, nên có test. Thêm một field nhạy cảm mà quên cập nhật paths thì test này bắt được:

// test/logger.test.ts
import { Writable } from 'node:stream'
import { describe, expect, it } from 'vitest'
import { createLogger } from '../src/logger.js'

function captureLogs() {
  const lines: Record<string, unknown>[] = []
  const sink = new Writable({
    write(chunk, _encoding, callback) {
      lines.push(JSON.parse(chunk.toString()))
      callback()
    },
  })
  return { logger: createLogger(sink), lines }
}

describe('logger redaction', () => {
  it('ẩn password, token và header Authorization', () => {
    const { logger, lines } = captureLogs()
    logger.info(
      {
        user: { email: 'an@shop.vn', password: 'hunter2' },
        session: { token: 'eyJhbGciOi...' },
        req: { headers: { authorization: 'Bearer abc' } },
      },
      'login attempt',
    )
    expect(lines[0]).toMatchObject({
      user: { password: '[REDACTED]' },
      session: { token: '[REDACTED]' },
      req: { headers: { authorization: '[REDACTED]' } },
    })
  })
})

Graceful shutdown. Khi pod nhận SIGTERM: ngừng nhận request, chờ request đang chạy, gọi otelSdk.shutdown() để flush span, logger.flush() nếu dùng destination async, rồi mới thoát. Thiếu bước flush thì đúng những span và dòng log của lúc deploy (thời điểm hay có lỗi nhất) bị mất.

Những lỗi thường gặp

Log chuỗi thay vì object:

// Sai: không query được theo orderId, redact không áp dụng được cho chuỗi
logger.info(`Order ${orderId} paid by ${email} amount ${amount}`)
// Đúng: message cố định, dữ liệu trong object
logger.info({ orderId, amountVnd: amount }, 'order paid')

URL thô làm label metric:

// Sai: mỗi orderId là một series mới -> nổ cardinality
end({ route: req.originalUrl })
// Đúng: route template
end({ route: req.route?.path ? `${req.baseUrl}${String(req.route.path)}` : 'unmatched' })

Log và throw ở mọi tầng:

// Sai: 1 lỗi = 4 dòng log ở 4 tầng, dòng nào cũng thiếu ngữ cảnh
catch (error) {
  logger.error({ err: error }, 'repository failed')
  throw error
}
// Đúng: wrap với cause rồi throw; chỉ boundary (error middleware, job runner) log
catch (error) {
  throw new Error('markOrderPaid failed', { cause: error })
}

Import app trước khi khởi động OpenTelemetry: import './app.js' chạy trước sdk.start() thì pg, express đã load mà chưa bị patch, nên không có span nào. Luôn nạp instrumentation bằng --require/--import thay vì import trong server.ts.

Tin x-request-id từ client mà không validate: log injection và log phình. Kiểm tra format, giới hạn độ dài, không hợp lệ thì tự sinh ID mới.

Alert theo nguyên nhân thay vì triệu chứng: "heap > 80%" hay "CPU > 70%" làm team nhờn alert. Để chúng trên dashboard; page người trực chỉ khi SLO bị đe doạ.

Bật pino-pretty ở production: chậm và phá format JSON mà hệ thống log cần parse.

Checklist

  • Logger pino dùng chung, có service, env, version trong base, level dạng chữ.
  • redact cho password, token, cookie, Authorization, CCCD, số thẻ, và có test kiểm tra.
  • Mọi request có requestId (validate header vào, trả về trong response header) và code tầng sâu lấy logger qua AsyncLocalStorage.
  • Lỗi được log một lần qua res.err của pino-http, serializer errWithCause với wrapSerializers: false.
  • Histogram http_server_request_duration_seconds với route template, có bucket đúng ngưỡng SLO; /metrics ở port nội bộ.
  • OpenTelemetry nạp bằng --require/--import trước app; đã kiểm tra trace có span pg/redis, không chỉ span HTTP.
  • Log có trace_id và backend log/trace được nối với nhau (derived field hoặc tương đương).
  • Sampling được chọn có chủ đích (parentbased_traceidratio hoặc tail sampling ở Collector).
  • Alert page theo burn rate SLO với runbook; CPU, heap, pool chỉ nằm trên dashboard.
  • Graceful shutdown flush span và log trước khi thoát.

Đọc thêm

Last updated: July 19, 2025

Comments