python

关注公众号 jb51net

关闭
首页 > 脚本专栏 > python > Python构建日志系统

使用Python构建一个高效的结构化日志系统

作者:铭渊老黄

这篇文章主要为大家详细介绍了如何使用Python构建一个高效的结构化日志系统,可以解决传统print日志的痛点,感兴趣的小伙伴可以跟随小编一起学习一下

“程序员有两种痛苦:一种是没有日志,另一种是日志太多却找不到有用的。”——每一位深夜排查线上故障的开发者

一、引言:日志,你真的用对了吗?

我曾经历过这样的深夜:线上服务突然报警,数千条 print 输出滚过终端,却没有一条告诉我哪里出了问题。那一晚,我把整个系统翻了个底朝天,最终发现是一个第三方 API 的超时没有被正确捕获。

那次事故之后,我下定决心:日志,不能只是 print 的替代品,它应该是系统的"黑匣子"。

Python 拥有功能强大的 logging 标准库,但大多数开发者只会用 logging.info("something happened"),而忽略了它真正的潜力——结构化日志、上下文追踪、集中式管理。本文将带你从零构建一套生产级的结构化日志系统,让每一条日志都精准、可查、可分析。

二、为什么说print是日志的大敌?

在项目初期,print 简单直接。但随着项目规模增长,你会面临以下问题:

# ❌ 反面教材:到处散落的 print
def process_order(order_id):
    print(f"开始处理订单: {order_id}")
    print("查询数据库...")
    print("订单处理完成")

上面的代码在生产环境几乎没有任何诊断价值。接下来,让我们一步步构建真正有用的日志系统。

三、Python logging 模块核心架构

在动手之前,先理解 logging 模块的四个核心组件:

Logger(记录器)
    ↓ 创建 LogRecord
Handler(处理器)
    ↓ 决定日志去向(文件/控制台/网络)
Formatter(格式化器)
    ↓ 决定日志格式
Filter(过滤器)
    ↓ 精细控制哪些日志被输出

日志级别(从低到高):

级别数值使用场景
DEBUG10开发调试,详细信息
INFO20正常运行流程记录
WARNING30潜在问题,程序仍可运行
ERROR40错误,某功能失败
CRITICAL50严重错误,系统可能崩溃

四、从零构建结构化日志系统

4.1 基础配置:告别 basicConfig

大多数教程只教 logging.basicConfig(),这在生产环境是远远不够的。

# logger_setup.py —— 基础版日志配置
import logging
import sys
from pathlib import Path

def create_logger(name: str, log_file: str = None, level: int = logging.DEBUG) -> logging.Logger:
    """
    创建一个既输出到控制台又写入文件的 Logger
    """
    logger = logging.getLogger(name)
    logger.setLevel(level)

    # 避免重复添加 Handler(多次调用时的常见坑)
    if logger.handlers:
        return logger

    # 格式化器:包含时间、级别、模块、行号
    formatter = logging.Formatter(
        fmt="%(asctime)s | %(levelname)-8s | %(name)s:%(lineno)d | %(message)s",
        datefmt="%Y-%m-%d %H:%M:%S"
    )

    # 控制台 Handler
    console_handler = logging.StreamHandler(sys.stdout)
    console_handler.setLevel(logging.INFO)
    console_handler.setFormatter(formatter)
    logger.addHandler(console_handler)

    # 文件 Handler(可选)
    if log_file:
        Path(log_file).parent.mkdir(parents=True, exist_ok=True)
        file_handler = logging.FileHandler(log_file, encoding="utf-8")
        file_handler.setLevel(logging.DEBUG)
        file_handler.setFormatter(formatter)
        logger.addHandler(file_handler)

    return logger


# 使用示例
logger = create_logger("myapp", log_file="logs/app.log")
logger.info("服务启动成功")
logger.debug("当前配置: host=localhost, port=8080")
logger.error("数据库连接失败")

输出效果:

2024-03-15 14:32:01 | INFO     | myapp:13 | 服务启动成功
2024-03-15 14:32:01 | ERROR    | myapp:15 | 数据库连接失败

4.2 结构化日志:JSON 格式让机器也能"读懂"日志

普通文本日志对人友好,但对日志聚合系统(ELK、Loki、Datadog)来说,JSON 格式才是最佳选择。

# json_logger.py —— JSON 结构化日志
import json
import logging
import traceback
from datetime import datetime, timezone

class JSONFormatter(logging.Formatter):
    """
    将日志格式化为 JSON,便于日志系统解析
    """
    def __init__(self, service_name: str = "app", env: str = "production"):
        super().__init__()
        self.service_name = service_name
        self.env = env

    def format(self, record: logging.LogRecord) -> str:
        log_data = {
            "timestamp": datetime.now(timezone.utc).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            "module": record.module,
            "function": record.funcName,
            "line": record.lineno,
            "service": self.service_name,
            "env": self.env,
        }

        # 附加异常信息
        if record.exc_info:
            log_data["exception"] = {
                "type": record.exc_info[0].__name__,
                "message": str(record.exc_info[1]),
                "traceback": traceback.format_exception(*record.exc_info)
            }

        # 支持额外的上下文字段(通过 extra 参数传入)
        if hasattr(record, "extra_fields"):
            log_data.update(record.extra_fields)

        return json.dumps(log_data, ensure_ascii=False)


# 配置 JSON Logger
def get_json_logger(name: str) -> logging.Logger:
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)

    if not logger.handlers:
        handler = logging.StreamHandler()
        handler.setFormatter(JSONFormatter(service_name="order-service", env="prod"))
        logger.addHandler(handler)

    return logger


# 实际使用
logger = get_json_logger("order_service")
logger.info("订单创建成功", extra={"extra_fields": {"order_id": "ORD-12345", "user_id": "U-001", "amount": 299.9}})

输出的 JSON:

{
  "timestamp": "2024-03-15T06:32:01.123456+00:00",
  "level": "INFO",
  "logger": "order_service",
  "message": "订单创建成功",
  "module": "app",
  "function": "create_order",
  "line": 42,
  "service": "order-service",
  "env": "prod",
  "order_id": "ORD-12345",
  "user_id": "U-001",
  "amount": 299.9
}

4.3 上下文追踪:用 contextvars 传递请求 ID

在微服务和 Web 应用中,同一时刻可能有数百个请求并发处理。如何在日志中区分它们?答案是请求追踪 ID(Trace ID)

# context_logger.py —— 基于 contextvars 的请求追踪
import logging
import uuid
from contextvars import ContextVar

# 存储当前请求的 trace_id(线程/协程安全)
_trace_id: ContextVar[str] = ContextVar("trace_id", default="N/A")


class TraceIDFilter(logging.Filter):
    """
    自动将 trace_id 注入每条日志记录
    """
    def filter(self, record: logging.LogRecord) -> bool:
        record.trace_id = _trace_id.get()
        return True


def set_trace_id(trace_id: str = None) -> str:
    """设置当前上下文的 trace_id"""
    tid = trace_id or str(uuid.uuid4())[:8]
    _trace_id.set(tid)
    return tid


def get_trace_logger(name: str) -> logging.Logger:
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)

    if not logger.handlers:
        handler = logging.StreamHandler()
        formatter = logging.Formatter(
            "%(asctime)s | %(levelname)-8s | [%(trace_id)s] | %(name)s | %(message)s",
            datefmt="%H:%M:%S"
        )
        handler.setFormatter(formatter)
        handler.addFilter(TraceIDFilter())
        logger.addHandler(handler)

    return logger


# 模拟 Web 请求处理
logger = get_trace_logger("web.handler")

def handle_request(request_data: dict):
    trace_id = set_trace_id()  # 每个请求生成唯一 ID
    logger.info(f"收到请求: {request_data.get('path')}")

    try:
        # 模拟业务处理
        process_business_logic(request_data)
        logger.info("请求处理完成")
    except Exception as e:
        logger.error(f"请求处理失败: {e}", exc_info=True)

def process_business_logic(data: dict):
    logger.debug(f"开始执行业务逻辑,参数: {data}")
    # ... 业务代码


handle_request({"path": "/api/orders", "method": "POST"})

输出效果:

14:32:01 | INFO     | [a3f7b2c1] | web.handler | 收到请求: /api/orders
14:32:01 | DEBUG    | [a3f7b2c1] | web.handler | 开始执行业务逻辑,参数: {...}
14:32:01 | INFO     | [a3f7b2c1] | web.handler | 请求处理完成

同一个 trace_id 串联了整个请求链路,排查问题时只需过滤这个 ID 即可。

4.4 日志轮转:避免磁盘爆满的生产级配置

# rotating_logger.py —— 生产环境日志轮转配置
import logging
from logging.handlers import RotatingFileHandler, TimedRotatingFileHandler

def setup_production_logger(name: str) -> logging.Logger:
    logger = logging.getLogger(name)
    logger.setLevel(logging.DEBUG)

    formatter = logging.Formatter(
        "%(asctime)s | %(levelname)-8s | %(name)s:%(lineno)d | %(message)s"
    )

    # 按大小轮转:单文件最大 10MB,保留最近 5 个备份
    size_handler = RotatingFileHandler(
        filename="logs/app.log",
        maxBytes=10 * 1024 * 1024,  # 10MB
        backupCount=5,
        encoding="utf-8"
    )
    size_handler.setLevel(logging.INFO)
    size_handler.setFormatter(formatter)

    # 按时间轮转:每天午夜切割,保留 30 天
    time_handler = TimedRotatingFileHandler(
        filename="logs/app_daily.log",
        when="midnight",
        interval=1,
        backupCount=30,
        encoding="utf-8"
    )
    time_handler.setLevel(logging.DEBUG)
    time_handler.setFormatter(formatter)

    # 错误日志单独存放,便于告警
    error_handler = RotatingFileHandler(
        filename="logs/error.log",
        maxBytes=5 * 1024 * 1024,
        backupCount=10,
        encoding="utf-8"
    )
    error_handler.setLevel(logging.ERROR)
    error_handler.setFormatter(formatter)

    logger.addHandler(size_handler)
    logger.addHandler(time_handler)
    logger.addHandler(error_handler)

    return logger

五、实战案例:为 FastAPI 应用配置完整日志系统

下面是一个贴近真实项目的完整示例,将以上所有技术整合到一个 FastAPI 应用中:

# main.py —— FastAPI 应用完整日志方案
import logging
import time
import uuid
from contextlib import asynccontextmanager
from contextvars import ContextVar

from fastapi import FastAPI, Request, Response

# ─── 日志初始化 ────────────────────────────────
_request_id: ContextVar[str] = ContextVar("request_id", default="-")

class RequestIDFilter(logging.Filter):
    def filter(self, record):
        record.request_id = _request_id.get()
        return True

def init_logging():
    root_logger = logging.getLogger()
    root_logger.setLevel(logging.DEBUG)

    handler = logging.StreamHandler()
    handler.setFormatter(logging.Formatter(
        "%(asctime)s | %(levelname)-8s | [%(request_id)s] | %(name)s | %(message)s",
        datefmt="%Y-%m-%d %H:%M:%S"
    ))
    handler.addFilter(RequestIDFilter())
    root_logger.addHandler(handler)

init_logging()
logger = logging.getLogger("api")

# ─── FastAPI 应用 ──────────────────────────────
app = FastAPI()

@app.middleware("http")
async def logging_middleware(request: Request, call_next) -> Response:
    """
    请求中间件:自动注入 request_id,记录请求耗时
    """
    request_id = request.headers.get("X-Request-ID") or str(uuid.uuid4())[:8]
    _request_id.set(request_id)

    start_time = time.perf_counter()
    logger.info(f"→ {request.method} {request.url.path}")

    response = await call_next(request)

    duration_ms = (time.perf_counter() - start_time) * 1000
    logger.info(
        f"← {request.method} {request.url.path} "
        f"status={response.status_code} duration={duration_ms:.1f}ms"
    )
    response.headers["X-Request-ID"] = request_id
    return response


@app.get("/orders/{order_id}")
async def get_order(order_id: str):
    logger.debug(f"查询订单详情: order_id={order_id}")
    # 模拟数据库查询
    logger.info(f"订单查询成功: order_id={order_id}")
    return {"order_id": order_id, "status": "completed"}

请求一次 /orders/123,日志输出:

2024-03-15 14:32:01 | INFO     | [4f8a1b2c] | api | → GET /orders/123
2024-03-15 14:32:01 | DEBUG    | [4f8a1b2c] | api | 查询订单详情: order_id=123
2024-03-15 14:32:01 | INFO     | [4f8a1b2c] | api | 订单查询成功: order_id=123
2024-03-15 14:32:01 | INFO     | [4f8a1b2c] | api | ← GET /orders/123 status=200 duration=2.3ms

六、最佳实践清单

经过多年项目实战,我总结了以下"日志黄金法则":

应该做的

为每个模块创建独立 Logger,而非全局共用一个

logger = logging.getLogger(__name__)  # 使用模块名,自动层级化

用参数化格式,避免提前字符串拼接(性能优化)

# ✅ 正确:logger 内部处理,级别不够时不拼接
logger.debug("处理用户 %s 的请求", user_id)

# ❌ 错误:无论级别是否达到,都会执行字符串格式化
logger.debug(f"处理用户 {user_id} 的请求")

异常日志用 exc_info=True logger.exception()

try:
    risky_operation()
except Exception:
    logger.exception("操作失败,完整堆栈如下:")  # 自动附加 traceback

在业务关键节点记录结构化数据

logger.info("支付完成", extra={"extra_fields": {
    "order_id": order.id,
    "amount": order.amount,
    "payment_method": order.payment_method,
    "duration_ms": elapsed
}})

避免的坑

七、工具推荐:更进一步

工具/库用途推荐指数
loguru更简洁的日志库,开箱即用⭐⭐⭐⭐⭐
structlog专业结构化日志方案⭐⭐⭐⭐⭐
ELK StackElasticsearch+Logstash+Kibana 日志分析⭐⭐⭐⭐
Grafana Loki轻量级日志聚合系统⭐⭐⭐⭐
Sentry错误追踪与告警⭐⭐⭐⭐⭐

loguru 简化日志配置的示例:

# loguru 版本:5行代码实现生产级日志
from loguru import logger

logger.remove()  # 移除默认 handler
logger.add("logs/app.log", rotation="10 MB", retention="30 days", 
           format="{time} | {level} | {name}:{line} | {message}",
           level="DEBUG", serialize=True)  # serialize=True 输出 JSON
logger.add(sys.stdout, level="INFO", colorize=True)

logger.info("启动成功 🚀")
logger.bind(user_id="U-001", order_id="ORD-123").info("绑定上下文的日志")

八、总结

好的日志系统,是开发者送给"未来自己"最好的礼物。回顾本文的核心要点:

日志不是调试的副产品,而是系统可观测性的核心资产。 每一条精心设计的日志,都可能在凌晨三点的故障排查中救你于水火之中。

互动讨论

你在项目中遇到过哪些令人抓狂的日志问题? 是满屏无意义的 DEBUG 输出,还是关键异常没有任何记录?欢迎在评论区分享你的"血泪史"和解决方案。

另一个值得思考的问题:随着 AI 辅助编程的普及,未来的日志系统是否应该内置"智能摘要"功能,让 AI 直接分析日志并给出修复建议? 这或许不是遥远的未来。

到此这篇关于使用Python构建一个高效的结构化日志系统的文章就介绍到这了,更多相关Python构建日志系统内容请搜索脚本之家以前的文章或继续浏览下面的相关文章希望大家以后多多支持脚本之家!

您可能感兴趣的文章:
阅读全文