日志性能损耗主要来自参数求值、格式化、时间戳获取和栈帧解析。debug级别下即使不输出,参数仍会执行;应使用isenabledfor或延迟计算;basicconfig默认配置不适用于生产;高频日志需限流;%(pathname)s等字段性能差;异步环境中需防丢日志。

日志级别设为 DEBUG 时,字符串拼接本身就会拖慢程序
很多同学以为“只要没输出,日志就不耗性能”,其实不对。Python 的 logging.debug() 在调用时,哪怕日志器最终丢弃这条消息(因为级别不够),debug() 的参数仍会照常求值——包括字符串格式化、函数调用、变量访问。比如:
logging.debug("user_id=%s, balance=%.2f", user.id, get_balance(user))
即使当前日志级别是 WARNING,user.id 和 get_balance(user) 依然会被执行。
- 真正安全的写法是用
logger.isEnabledFor(logging.DEBUG)包一层,或者直接用 lazy 格式:用 lambda 或方法引用延迟计算 - 更推荐的惯用写法是把复杂表达式移到条件块里:
if logger.isEnabledFor(logging.DEBUG): logger.debug("…", expensive_value()) - 别依赖
%或.format()的“惰性”——它们不惰性;f-string更危险,它在调用前就完成了所有求值
logging.basicConfig() 的默认行为在生产环境几乎总是错的
本地调试时随手加一句 logging.basicConfig(level=logging.INFO) 很方便,但它会悄悄创建一个 StreamHandler 绑定到 root logger,并且没有设置 formatter 或 filter。上线后问题就来了:
- 多模块导入时,
basicConfig()只生效一次,后续模块的日志可能被静默吞掉或重复输出 - 它默认用
sys.stderr,而容器或 systemd 环境中 stderr 写入可能触发锁或缓冲问题,尤其高并发时 - 没有设置
propagate=False,子 logger 会向上冒泡到 root,导致同一条日志打两遍
线上应该显式配置 handler,比如:
立即学习“Python免费学习笔记(深入)”;
handler = logging.FileHandler("/var/log/app.log")<br>handler.setFormatter(logging.Formatter("%(asctime)s %(levelname)s %(name)s: %(message)s"))<br>logger.addHandler(handler)<br>logger.setLevel(logging.INFO)<br>logger.propagate = False
频繁调用 logger.info() 但内容不变,CPU 花在哪儿了?
看起来只是打一行固定字符串,比如 logger.info("request started"),但每次调用仍要走完整路径:检查级别 → 获取线程/进程 ID → 获取时间戳 → 格式化 → 编码 → 写入 buffer。其中最重的是时间戳获取和 formatter 调用。
- 如果某条日志高频出现(如每毫秒一次),建议先用
time.time()或time.monotonic()做粗粒度限流,而不是靠日志级别压制 - 避免在循环内无条件打 info 日志;改用计数器 + 条件触发,例如 “每 100 次请求打一次 summary”
- formatter 中的
%(pathname)s、%(funcName)s会触发栈帧解析,比%(message)s慢 3–5 倍,生产环境应禁用
异步框架(如 FastAPI / Quart)里用标准 logging 不会阻塞,但可能丢日志
标准 logging 是同步的,但在 asyncio 场景下,它不会阻塞 event loop——因为写文件或 socket 是系统调用,Python 的 logging 模块本身不主动 await。真正的问题是生命周期错配:
- 协程退出时,handler 的 buffer 可能还没 flush,尤其用
RotatingFileHandler时,最后几条日志永远不落地 - 多 worker 进程(如 uvicorn --workers 4)共用一个 log 文件,若没加
delay=True和文件锁,会出现日志截断或乱序 - 推荐做法:用
QueueHandler+ 后台线程消费,或直接切到structlog+asyncio.Queue,避免主线程和 I/O 线程争抢
最常被忽略的一点:日志不是越全越好,而是要在可追溯性和性能损耗之间做显式取舍。比如 trace_id 可以用 extra 传入,但别每次都在 formatter 里调用 trace.get_current_span() —— 那个函数本身就要查上下文、加锁、生成新对象。











