Python技术迷

Python日志记录太复杂?这个利器让你从此爱上调试!

你是不是也有过这种体验:半夜线上出问题,同事在群里艾特你,「哥,接口又超时了,你帮忙看看日志」。你 ssh 上去一看,目录下面一堆 print.log、debug.log.bak、log.log.1.1.1,打开以后全是裸 print 打出来的对象,既没时间、也没级别,定位个 bug 得一行行往下翻,翻着翻着人都麻了。

更要命的是,开发环境用的是 print,线上又糊了个 logging.basicConfig,结果本地能看到的东西,线上根本没打;线上有的东西,本地又看不到,两边完全不是一套东西。调一次试,心态崩一次。

我之前也是这么过来的,直到后来项目重构,把日志系统一锅端了,才发现:其实不是「日志很难」,而是「你没用对工具」。

今天说的那个「利器」,就是 Python 里的一个第三方库:loguru。它不是唯一的选择,但是真的足够顺手,尤其适合嫌 logging 太啰嗦,又想把日志做利索一点的人。

下面我就一边聊场景,一边穿插点代码,你可以边看边对照自己项目里现在怎么写的。

先回忆一下:为什么大家讨厌原生 logging?

随便写一段最常见的 logging 配置,看着就头大:

import logging

logger = logging.getLogger("app")
logger.setLevel(logging.INFO)

# 控制台
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)

# 文件
file_handler = logging.FileHandler("app.log", encoding="utf-8")
file_handler.setLevel(logging.INFO)

# 格式
formatter = logging.Formatter(
"%(asctime)s - %(name)s - %(levelname)s - %(message)s"
)
console_handler.setFormatter(formatter)
file_handler.setFormatter(formatter)

logger.addHandler(console_handler)
logger.addHandler(file_handler)

logger.info("应用启动")

你仔细数数,这里为了打一句「应用启动」,我们写了多少行「仪式感代码」:拿 logger、设级别、建 handler、建 formatter、绑来绑去。对很多人来说,这些概念本身就已经劝退了,更别说后面什么 RotatingFileHandler、多进程安全、格式里加 trace id 之类的需求。

所以大量 Python 项目最后就退回了最原始的形态:print("xxx") 满天飞。

问题是,等你项目一上生产,才会发现:

  • 没有日志级别,全是一样的输出,想过滤 warning、error 根本做不到
  • 文件不滚动,不压缩,不清理,跑几个月磁盘就能被打满(Java 那边 SpringBoot 默认日志不滚动导致占满磁盘的事故,其实就经常发生)
  • 多进程 / 多线程场景下,日志内容交叉在一起,看不出一个完整请求链路

这时候你就会有一种很强烈的感觉:我只是想好好调个试,为什么这么难?

换个思路:如果日志「很好用」,应该长什么样?

我一般会这么想象一个理想的状态:

  1. 开发阶段写日志,就像写 print 一样简单,顺手、不费脑子
  2. 上线之后,日志自动分级、自动切分、自动保留 N 天,不用我天天去删文件
  3. 出了问题,可以很快按「请求 id」「用户 id」把一整条调用链的日志捞出来
  4. 尽量少写配置,最好一两行代码就搞定初始化

原生 logging 不是做不到,而是每一条都得你自己堆配置、堆代码,成本太高。

loguru 做的事,就是把这一坨复杂度干脆打包起来,换成一个你基本上不用动脑就能上手的 API。

上菜:用 loguru 两行搞定「看得见的日志」

先装一下:

pip install loguru

最简单的用法长这样:

from loguru import logger

logger.info("服务启动了,端口={}", 8000)
logger.warning("余额不足,user_id={},余额={}", 123, 9.9)
logger.error("下单失败,order_id={}", "A10001")

注意有两个小细节:

  • 占位符是 {},不是 %s,也不是 f-string,不过你也可以用 f-string
  • 不用先 getLogger,也不用设置 handler,logger 直接拿来就用

默认情况下,它会把日志打到控制台,而且带颜色、带时间、带级别,看着顺眼很多:

2025-01-01 12:00:00.123 | INFO  | __main__:<module>:3 - 服务启动了,端口=8000

如果你想把日志打到文件里,也是一行的事:

from loguru import logger

logger.add("app.log")  # 默认追加到文件

再加一点参数,就可以解决前面提到的「磁盘被打爆」的问题:

from loguru import logger

logger.add(
"logs/app_{time}.log",
    rotation="10 MB",      # 单个文件超过 10MB 自动切分
    retention="7 days",    # 日志只保留 7 天
    compression="zip",     # 旧日志自动压缩
    enqueue=True,          # 多进程安全
    encoding="utf-8"
)

到这一步,你其实已经比很多「用了 logging 但没认真配」的项目要健康多了。

最爽的功能之一:异常日志不用你「手动 try/except 打印」

有一个场景你肯定遇到过:接口报 500 了,你翻日志发现只有一行「调用失败」,然后就没然后了,压根不知道哪一行抛的异常。

比较靠谱的做法,当然是每个入口都包一层 try/except,然后打印 traceback。原生 logging 写起来大概是这样:

import logging
import traceback

logger = logging.getLogger(__name__)

defhandle_request():
try:
        do_something()
except Exception as e:
        logger.error("处理请求异常:%s\n%s", e, traceback.format_exc())
raise

用 loguru 可以直接:

from loguru import logger

defhandle_request():
try:
        do_something()
except Exception:
        logger.exception("处理请求异常")
raise

logger.exception 会自动把当前的堆栈信息、异常类型、行号全打出来,格式还挺好看。

如果你懒到不想每个函数都写 try/except,可以整一个装饰器:

from loguru import logger
from functools import wraps

deflog_exceptions(func):
    @wraps(func)
defwrapper(*args, **kwargs):
try:
return func(*args, **kwargs)
except Exception:
            logger.exception("函数 {} 执行异常", func.__name__)
raise
return wrapper

@log_exceptions
defhandle_request():
    do_something()

这样你只要在关键入口(比如 Web 框架的 handler、定时任务入口)上挂这个装饰器,就能自动捕获异常日志。

调试最痛的点:怎么把「关键变量」打印得又清晰又不污染代码?

很多人调试的时候习惯写:

print("user:", user)
print("order:", order)

调完又一个个删,删漏一两行就一直躺在线上代码里,几年后你自己都认不出那堆 print 是干嘛的。

用 loguru 你可以把这个动作「正规化」一点:

from loguru import logger

defpay(user, order):
    logger.debug("准备支付,user_id={},order_id={}", user.id, order.id)
# 真实逻辑...
    logger.info("支付成功,user_id={},order_id={}", user.id, order.id)

本地调试的时候,把全局日志级别设成 DEBUG:

logger.remove()  # 把默认的 handler 删掉
logger.add(sys.stderr, level="DEBUG")

线上环境只保留 INFO 以上的:

logger.remove()
logger.add("logs/app_{time}.log", level="INFO", rotation="10 MB", retention="7 days")

这样做有两个好处:

  1. 你不用删调试日志,只要靠级别控制它们「出不出来」
  2. 需要排线上疑难杂症的时候,你可以临时把某台机器的日志级别调低,重启一下服务,等问题抓到再调回来

loguru 还支持一种更方便的写法,用 named 参数绑定:

logger.debug("准备支付,user_id={user_id},order_id={order_id}", 
             user_id=user.id, order_id=order.id)

对阅读的人来说,比「位置参数」要直观一点。

真正救命的是这一招:给每个请求挂一个 trace_id

当你的系统稍微复杂一点,比如一个 HTTP 请求会串联调用缓存、数据库、RPC、MQ,你最不想面对的事情,就是日志里全是「孤立的行」,你根本分不清哪些日志属于同一个请求。

解决这个问题的关键,就是给每个请求绑一个「请求上下文」,比如 trace_id,然后在所有日志里都带上它。

在 loguru 里,这件事很简单:用 bind 和格式化字段。

先定义一个全局 logger:

from loguru import logger

logger.remove()
logger.add(
"logs/app_{time}.log",
    format="{time} | {level} | {extra[trace_id]} | {message}",
)

注意这里多了一个 {extra[trace_id]},这是 loguru 的「额外字段」。

然后,在每次请求进来的时候,生成一个带 trace_id 的子 logger:

import uuid
from loguru import logger

defhandle_http_request(request):
    trace_id = request.headers.get("X-Trace-Id") or uuid.uuid4().hex
    log = logger.bind(trace_id=trace_id)

    log.info("收到请求,path={},ip={}", request.path, request.client.host)
# 下面的日志都用 log,而不是全局 logger
    result = do_business(log, request)
    log.info("请求完成,result={}", result)
return result

defdo_business(log, request):
    log.debug("开始业务处理")
# ...
    log.debug("业务处理完成")

这样你在日志里看到的就是:

2025-01-01 12:00:00.123 | INFO  | 8f1234... | 收到请求,path=/api/pay,ip=10.0.0.1
2025-01-01 12:00:00.456 | DEBUG | 8f1234... | 开始业务处理
2025-01-01 12:00:00.789 | DEBUG | 8f1234... | 业务处理完成
2025-01-01 12:00:01.000 | INFO  | 8f1234... | 请求完成,result=ok

同一个 trace_id 的日志就是一整个「调用链」,线上排查问题的时候,你只要按 trace_id 搜一下,就能把这条链的所有行为看得清清楚楚。

如果你用的是 FastAPI / Starlette,可以写一个中间件统一处理:

import uuid
from loguru import logger
from fastapi import FastAPI, Request

app = FastAPI()

@app.middleware("http")
asyncdeflog_middleware(request: Request, call_next):
    trace_id = request.headers.get("X-Trace-Id") or uuid.uuid4().hex
    log = logger.bind(trace_id=trace_id)

    log.info("开始处理请求 {}", request.url.path)
try:
        response = await call_next(request)
        log.info("请求处理完成,status={}", response.status_code)
return response
except Exception:
        log.exception("请求处理异常")
raise

后面的业务代码只要 from loguru import logger,再 logger.bind 一下就行了。

你可能会问:项目已经用 logging 了,还能用 loguru 吗?

能,而且很常见的做法是「全部走 loguru,然后把标准 logging 的东西导流过来」。

比如很多第三方库会自己搞一个 logging.getLogger(__name__),然后打印各种日志。如果你不管它,这些日志要么直接撒在 stderr,要么按照它自己的配置走,很乱。

loguru 提供了一个「桥接器」,可以把 logging 模块的输出转发到 loguru:

import logging
from loguru import logger

classInterceptHandler(logging.Handler):
defemit(self, record):
# 获取对应的 loguru 级别
        level = logger.level(record.levelname).name if record.levelname in logger._core.levels else record.levelno
        logger.opt(depth=6, exception=record.exc_info).log(level, record.getMessage())

# 把 root logger 的 handler 清掉,换成我们的
logging.root.handlers = [InterceptHandler()]
logging.root.setLevel(logging.INFO)

# 然后正常配置 loguru 的输出
logger.add(
"logs/app_{time}.log",
    format="{time} | {level} | {message}",
    rotation="10 MB",
    retention="7 days",
)

这样,标准库、第三方库走 logging 打出来的日志,最后都会经由 loguru 写到你的文件里,而且格式统一。

最后再补几句「调试时日志的小习惯」

这部分更多是经验,不是硬性规则,你可以按自己项目的情况取舍:

  1. 错误日志里一定要带「关键业务标识」,比如 user_id、order_id,不要只写「下单失败」。
  2. 对于会频繁重复出现的 warning(比如外部接口偶尔超时),可以考虑在日志里加一个简单的「一次性 key」,避免刷屏的时候你根本看不见真正的异常。
  3. 请求日志和 SQL 日志最好分文件,不然你翻一堆 SQL 才能看到几行业务信息,效率很低。
  4. 线上默认 INFO 够用了,DEBUG 级别一般只在排查疑难问题时临时打开。

loguru 在这些事情上都提供了足够的能力:你可以加不同的 sink,把 DEBUG 打到单独文件里,或者把 ERROR 额外打一份到告警系统。

比如简单做一个「错误单独记录」:

from loguru import logger

# 普通业务日志
logger.add("logs/app_{time}.log", rotation="10 MB", retention="7 days", level="INFO")

# 错误日志单独文件
logger.add("logs/error_{time}.log", rotation="10 MB", retention="30 days", level="ERROR")

出问题的时候,直接去看 error_*.log,基本就能锁定范围。

说了这么多,你可以简单回忆一下你现在项目里的日志状况:

如果还是满屏 print,或者一个 logging.basicConfig 顶天,那真的可以找个时间,先在一个小服务上尝尝 loguru,把「写日志」这件事变成一种顺手的本能,而不是每次都在和配置、handler 搏斗。

调试这件事,本来就够折磨人的了,工具就别再拖后腿了。