Structured logging: debug production hiệu quả mà không cần SSH — hoatq.dev

cat blog/.md

Structured logging: debug production hiệu quả mà không cần SSH

date: tags: backend, devops, observability, best-practices

Bạn đã bao giờ gặp tình huống này chưa: production có bug, user report lỗi, và việc đầu tiên bạn làm là SSH vào server rồi tail -f log file?

Nếu có, bạn không đơn độc — mình cũng từng làm vậy suốt. Cho đến khi hệ thống scale lên 4-5 instances, log nằm rải rác mỗi nơi một ít, và mình nhận ra cách làm đó không scale được.

Bài này mình chia sẻ cách mình chuyển từ print()console.log() sang structured logging — và vì sao đây là một trong những thay đổi có ROI cao nhất mình từng làm cho hệ thống.

Log thường vs structured log

Hầu hết developer bắt đầu với log kiểu này:

print(f"User {user_id} đặt hàng thất bại: {error}")

Hoặc bên Node.js:

console.log(`Payment failed for order ${orderId}: ${err.message}`);

Output ra terminal nhìn ổn, đọc được. Nhưng khi bạn cần tìm kiếm, filter, aggregate trên hàng triệu dòng log, plain text trở thành ác mộng. Bạn phải regex, grep, rồi đoán format.

Structured log thì khác — mỗi dòng là một JSON object với các field rõ ràng:

{
  "timestamp": "2026-04-12T08:30:15.234Z",
  "level": "error",
  "service": "commerce",
  "message": "Payment failed",
  "user_id": "usr_abc123",
  "order_id": "ord_789",
  "error_code": "INSUFFICIENT_BALANCE",
  "duration_ms": 1523,
  "correlation_id": "req_xyz456"
}

Giờ bạn có thể query: “cho tôi tất cả error của service commerce trong 1 giờ qua mà liên quan đến payment” — trong vài giây, không cần SSH.

Bước 1: Setup structured logging

Python (với structlog)

import structlog

structlog.configure(
    processors=[
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.add_log_level,
        structlog.processors.JSONRenderer(),
    ],
)

logger = structlog.get_logger()

# Sử dụng
logger.info("order_created", user_id=user_id, order_id=order.id, total=order.total)
logger.error("payment_failed", user_id=user_id, order_id=order.id, error=str(e))

Node.js (với pino)

import pino from "pino";

const logger = pino({
  level: process.env.LOG_LEVEL || "info",
  formatters: {
    level: (label) => ({ level: label }),
  },
  timestamp: pino.stdTimeFmt,
});

// Sử dụng
logger.info({ userId, orderId, total }, "order_created");
logger.error({ userId, orderId, err }, "payment_failed");

Cả hai library đều output JSON mặc định. Quan trọng là log message ngắn gọn, dữ liệu đi vào fields riêng — đừng nhét tất cả vào một string.

Bước 2: Correlation ID — xâu chuỗi mọi thứ lại

Đây là thứ thay đổi cuộc chơi debug nhất mà mình từng áp dụng.

Ý tưởng rất đơn giản: mỗi request đến hệ thống được gán một ID duy nhất, và ID này được truyền qua tất cả service, tất cả log liên quan.

# middleware/correlation.py
import uuid
from starlette.middleware.base import BaseHTTPMiddleware

class CorrelationMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        correlation_id = request.headers.get("X-Correlation-ID", str(uuid.uuid4()))
        # Bind vào context để mọi log trong request đều có field này
        structlog.contextvars.clear_contextvars()
        structlog.contextvars.bind_contextvars(correlation_id=correlation_id)

        response = await call_next(request)
        response.headers["X-Correlation-ID"] = correlation_id
        return response

Khi service A gọi service B, truyền header X-Correlation-ID theo:

async def call_payment_service(order_id: str, correlation_id: str):
    async with httpx.AsyncClient() as client:
        response = await client.post(
            f"{PAYMENT_URL}/charge",
            json={"order_id": order_id},
            headers={"X-Correlation-ID": correlation_id},
        )
    return response

Bây giờ khi user báo lỗi, bạn chỉ cần correlation ID là có thể trace toàn bộ hành trình của request đó qua tất cả service: từ gateway → identity → commerce → payment → notification. Không cần đoán, không cần SSH.

Bước 3: Log levels — đừng log mọi thứ ở cùng mức

Một sai lầm phổ biến là log quá nhiều ở production hoặc quá ít khi cần debug. Nguyên tắc mình dùng:

LevelKhi nào dùngVí dụ
errorCần xử lý ngay, ảnh hưởng userPayment thất bại, DB connection lost
warnBất thường nhưng chưa chếtRate limit gần ngưỡng, retry lần 2
infoBusiness events quan trọngOrder tạo, user đăng ký, deploy xong
debugChi tiết kỹ thuật cho troubleshootingQuery params, response body, cache hit/miss

Production chạy ở level info. Khi cần debug issue cụ thể, tạm hạ xuống debug cho service liên quan rồi đẩy lên lại — không cần redeploy, chỉ cần thay đổi environment variable hoặc config flag.

# Có thể thay đổi log level runtime qua endpoint
@router.post("/admin/log-level")
async def set_log_level(level: str, admin: AdminDep):
    structlog.configure(
        wrapper_class=structlog.make_filtering_bound_logger(
            getattr(logging, level.upper())
        ),
    )
    logger.info("log_level_changed", new_level=level, changed_by=admin.id)

Bước 4: Đưa log đi đâu?

Structured log mạnh nhất khi đổ vào một nơi tập trung có thể search được. Một số option:

Self-hosted (tiết kiệm):

  • Loki + Grafana — lightweight, query bằng LogQL, tích hợp tốt với Prometheus. Đây là combo mình đang dùng và rất hài lòng.
  • ELK Stack (Elasticsearch + Logstash + Kibana) — mạnh nhưng tốn resource hơn.

Managed (ít vận hành):

  • AWS CloudWatch Logs — nếu đã trên AWS, dùng luôn cho đơn giản.
  • Datadog, Grafana Cloud — đắt hơn nhưng trải nghiệm tốt.

Với Docker/ECS, chỉ cần log ra stdout dạng JSON. Hạ tầng sẽ tự thu thập:

# docker-compose.yml
services:
  commerce:
    image: commerce:latest
    logging:
      driver: json-file
      options:
        max-size: "10m"
        max-file: "3"

Với Loki, thêm Promtail làm log collector:

  promtail:
    image: grafana/promtail:latest
    volumes:
      - /var/log:/var/log
      - /var/lib/docker/containers:/var/lib/docker/containers:ro
    command: -config.file=/etc/promtail/config.yml

Bước 5: Từ log đến alert

Log tập trung rồi, giờ đừng ngồi nhìn dashboard cả ngày. Hãy đặt alert cho những gì quan trọng:

# Grafana alert rule (ví dụ)
- alert: HighErrorRate
  expr: |
    sum(rate({service="commerce"} |= "error" [5m])) > 10
  for: 2m
  annotations:
    summary: "Commerce service error rate > 10/phút trong 2 phút liên tục"

Nguyên tắc mình theo:

  • Alert trên symptom, không phải cause: alert “error rate tăng đột biến” thay vì “database connection timeout” — vì cùng một symptom có thể do nhiều nguyên nhân.
  • Mỗi alert phải có action rõ ràng: nếu nhận alert mà không biết làm gì → alert đó vô dụng, bỏ đi.
  • Tránh alert fatigue: quá nhiều alert = không ai đọc. Chỉ giữ những alert thật sự cần hành động.

Những lỗi mình từng mắc

1. Log sensitive data

# SAI — lộ password trong log
logger.info("login_attempt", email=email, password=password)

# ĐÚNG — chỉ log những gì cần thiết
logger.info("login_attempt", email=email, success=False, reason="invalid_password")

Luôn review: log có chứa password, token, số thẻ, hay PII không? Nếu dùng structured logging, viết một processor để tự động mask:

SENSITIVE_KEYS = {"password", "token", "secret", "card_number", "ssn"}

def mask_sensitive(_, __, event_dict):
    for key in SENSITIVE_KEYS:
        if key in event_dict:
            event_dict[key] = "***MASKED***"
    return event_dict

2. Log quá nhiều trong hot path

Mỗi dòng log đều có cost — serialize JSON, write I/O, network transfer. Trong một endpoint xử lý 1000 req/s, thêm 5 dòng debug log có thể tăng latency đáng kể. Rule: hot path chỉ log info trở lên.

3. Không log đủ context

# Vô dụng khi debug
logger.error("Something went wrong")

# Hữu ích
logger.error("payment_charge_failed",
    user_id=user_id,
    order_id=order_id,
    provider="stripe",
    error_code=e.code,
    duration_ms=elapsed,
)

Mỗi dòng log error nên trả lời được: ai, làm gì, ở đâu, tại sao fail?

Checklist trước khi lên production

Trước khi deploy, mình thường check qua:

  • Tất cả log output JSON (không còn print/console.log thuần)
  • Correlation ID được truyền qua tất cả service
  • Sensitive data đã bị mask
  • Log level có thể thay đổi runtime, không cần redeploy
  • Log được gửi về hệ thống tập trung (Loki, CloudWatch, v.v.)
  • Có alert cho error rate bất thường
  • Hot path không log ở level debug

Kết

Structured logging không phải rocket science. Nó là một thay đổi nhỏ trong cách bạn viết log, nhưng mang lại khác biệt rất lớn khi cần debug production.

Thay vì SSH vào server, grep log file, rồi cầu nguyện tìm được dòng liên quan — bạn search correlation ID, filter theo service và time range, và có toàn bộ context trong vài giây.

Nếu bạn chưa dùng structured logging, hãy bắt đầu với một service nhỏ. Thêm structlog hoặc pino, cấu hình JSON output, thêm correlation ID. Chỉ cần vậy thôi là đã khác biệt rồi.

Happy debugging!

// reactions


cat comments.log


hoatq@dev : ~/blog $