python71这个系列写到这一篇讲的是打印日志而且标题里特意强调“醒目”两个字。说实话日志打出来是给人看的不是为了凑行数。我见过太多项目日志拉出来一大片灰蒙蒙的文字出错的时候根本找不到哪一行才是关键最后只能 ctrlF 搜 ERROR。花十分钟把打印日志这件事做漂亮后面排查问题能省下几个小时这笔账怎么算都划算。这篇适合谁看正在写 Python 脚本、后端服务、定时任务或者维护老项目的同学都适用。核心就三件事搞明白为什么用 logging 而不是 print给日志加上颜色和结构化信息再把控制台输出和文件落盘做成一套开工就能用的配置。1. 先搞清楚print 和 logging 到底差在哪1.1 什么场景下日志必须“醒目”你写一个爬虫脚本每天凌晨跑一遍抓完数据写入数据库。脚本跑完没报错谁也看不出问题。等到某天数据没更新你打开日志文件面对的是几百行没有任何级别标识、没有任何时间戳的 print 输出你甚至分不清哪一行是“抓取完成”哪一行是“异常跳过”。这种时候你就知道日志不够醒目本质上等于没有日志。服务端排查问题更典型。一个接口出错了你希望日志里第一眼能看到什么时间、哪个模块、什么级别、什么错误信息、堆栈有没有。而不是在一堆毫无层次感的文字里大海捞针。所谓“醒目”核心就是这四点级别标得清楚、关键信息靠前、颜色区分明显、重要上下文不丢。还有一类场景是命令行工具。一个部署脚本执行到一半卡住了用户盯着终端看最需要的是那种“一眼扫过去就知道当前走到哪一步”的感觉。比如“正在拉取依赖”“配置已写入”“启动成功”这种阶段性输出如果全是一个颜色、一个格式用户在终端前等着心里完全没底。把阶段信息刷成高亮色体验完全不一样。1.2 logging 相比 print 的核心优点print 解决的是“把字符串输出到屏幕”而 logging 解决的是“把程序运行状态记录下来在需要的时候能看、能筛、能转存”。这不是一回事。logging 自带五个级别DEBUG、INFO、WARNING、ERROR、CRITICAL。这意味着你可以控制“开发时多看细节生产时只关心异常”。print 做不到这一点要么全打出来要么全删掉没有中间状态。logging 可以把同一条日志同时送到控制台、文件、远程日志服务每个目标各自独立配置。print 想做到这个得自己写文件操作、自己拼格式、自己管异常工作量不小。logging 的格式化能力很强可以自动带上时间、进程号、线程名、模块名、行号。print 想要这些每个输出点都得手动拼一遍拼着拼着就有人偷懒不写了。还有一点经常被忽略logging 的格式化是惰性求值。log.debug(value %s, expensive_func()) 只有在这条日志真正需要输出时才去调用 expensive_func()而 f-string 写法 log.debug(fvalue {expensive_func()}) 是无论级别达不达标都会执行。高并发程序里这个差异会被放大得很明显。对比项printlogging输出级别控制不支持支持 DEBUG 到 CRITICAL同时输出到多个目标需要自己写逻辑Handler 天然支持自动附带时间/位置信息不支持全靠手写Formatter 内置惰性格式化不支持支持 %s 风格线程安全不保证标准库实现线程安全第三方库适配无法拦截可以统一接管第三方日志结论很简单正式项目里日志输出一律用 loggingprint 只适合临时调试或者写一次性小脚本。2. 给日志上颜色核心实现与底层原理2.1 ANSI 转义序列终端颜色的底层机制终端能显示颜色靠的是 ANSI 转义序列。这个东西说穿了就是一个特殊的字符序列\033[ 开头后面跟数字和字母最后以 m 结尾。比如 \033[32m 表示把当前输出改成绿色\033[0m 表示重置回默认颜色。所谓“给日志上色”本质就是在日志文本的前后拼上对应的转义序列。输出到控制台时终端看到这些序列就解析成颜色写入文件时这些序列反而会成为噪音所以文件日志一般不用颜色。常用颜色值并不复杂前景色从 30 到 37背景色从 40 到 47加粗是 1关闭所有属性是 0。常见的做法是前景 31红色适合 ERROR前景 32绿色适合 INFO 或成功提示前景 33黄色适合 WARNING前景 36青色适合 DEBUG 或次要信息前景 35紫色适合 CRITICAL这里有个细节不同终端的实际显示效果不完全一样有的终端默认背景是深色有的是浅色所以颜色选择要尽量保证在两种背景上都能看清。黄色和深红在浅色背景下表现会差一些白色背景终端建议直接把 ERROR 的整行背景刷成红色。2.2 按日志级别配色的完整实现实现思路很简单写一个继承自 logging.Formatter 的子类在 format 方法里根据 levelname 给消息加上颜色。import logging class ColoredFormatter(logging.Formatter): COLORS { DEBUG: \033[36m, # 青色 INFO: \033[32m, # 绿色 WARNING: \033[33m, # 黄色 ERROR: \033[31m, # 红色 CRITICAL: \033[35m, # 紫色 } RESET \033[0m def format(self, record): color self.COLORS.get(record.levelname, ) message super().format(record) if color: return f{color}{message}{self.RESET} return message用法也简单先创建 handler把这个 formatter 挂上去再看情况绑定到 logger。handler logging.StreamHandler() handler.setFormatter(ColoredFormatter(%(asctime)s [%(levelname)s] %(name)s: %(message)s)) logging.basicConfig(levellogging.INFO, handlers[handler])这样设置之后INFO 日志整行是绿色ERROR 日志整行是红色。整行着色比只给级别加颜色更醒目特别是在日志量很大的时候扫一眼颜色就能定位问题区间。如果你只想要级别字段带颜色那就别在 format 里给整个消息加颜色改成在 format 方法里先拿到原始消息再单独匹配 levelname 做替换这种局部着色虽然细节上更“克制”但实际排查时效果不如整行着色直观。我个人的习惯是控制台日志整行按级别着色文件日志不带颜色但保留级别文字。3. 实战一套开箱即用的“醒目日志”配置3.1 单文件脚本最快的上手版本如果你只是写一个跑完就结束的脚本不需要复杂的包结构那直接配置 root logger 就够了。下面这段是我日常写脚本最常用的一套包含了时间、级别、模块名、行号和消息内容并且按级别着色。import logging import sys def setup_console_logger(): fmt %(asctime)s | %(levelname)-8s | %(name)s:%(lineno)d | %(message)s handler logging.StreamHandler(sys.stdout) handler.setFormatter(ColoredFormatter(fmt)) logging.basicConfig(levellogging.INFO, handlers[handler], forceTrue) setup_console_logger() logger logging.getLogger(__name__) logger.info(开始处理任务) try: 1 / 0 except ZeroDivisionError: logger.error(计算过程出现除零错误, exc_infoTrue)输出效果大致是2025-01-10 22:31:08 | INFO | __main__:13 | 开始处理任务 2025-01-10 22:31:08 | ERROR | __main__:16 | 计算过程出现除零错误 Traceback (most recent call last): File stdin, line 15, in module ZeroDivisionError: division by zero注意 basicConfig 里的 forceTrue。这个参数会把 root logger 上已有的 handler 清掉再重新配置避免在交互式环境或者多次执行时重复打印。Python 3.8 开始支持这个参数如果你的环境比较老可以先手动清理for h in logging.root.handlers[:]: logging.root.removeHandler(h)。还有一个容易忽略的小点StreamHandler 默认输出到 stderr我上面显式指定了 sys.stdout。脚本里把日志打到 stdout 有个好处就是可以把正常日志和错误输出分流在 shell 里用 2/dev/null 就能把错误日志单独过滤出来用 1/dev/null 屏蔽普通日志只看错误。3.2 模块化项目版控制台与文件分开配置到了真实的项目里光有控制台输出远远不够。日志要有“留痕”出了问题要能追到昨天、前天的日志。控制台和文件的需求不一样控制台要颜色、要简洁文件要干净、要详细、要持久化。所以我的做法是配两个 handler各用各的 formatter。def setup_logging(log_fileapp.log, levellogging.INFO): fmt_console %(asctime)s %(levelname)-8s %(name)s: %(message)s fmt_file %(asctime)s %(levelname)-8s %(name)s:%(lineno)d [%(process)d:%(thread)d] %(message)s console_handler logging.StreamHandler(sys.stdout) console_handler.setFormatter(ColoredFormatter(fmt_console)) file_handler logging.FileHandler(log_file, encodingutf-8) file_handler.setFormatter(logging.Formatter(fmt_file)) logging.basicConfig(levellevel, handlers[console_handler, file_handler], forceTrue)文件 formatter 特意加了 %(lineno)d、%(process)d、%(thread)d。遇到多进程或多线程的 bug没有这些字段基本上没法定位。控制台就不需要这么啰嗦因为人在终端前看可以按需切换详细级别。为什么文件日志不带颜色因为颜色转义序列是终端专用协议写进纯文本文件里只会变成 \033[31m 这种乱码。如果哪天想用 grep、awk 处理日志这些转义序列会严重影响结果。所以统一原则控制台上颜色文件里干净文本。3.3 打印启动横幅让日志一开门就醒目日志不止是排错工具也可以是程序的门面。每次服务启动或者脚本开始执行打出一个醒目的横幅既方便确认版本也给日志加了一层“仪式感”。我见过不少项目这么干效果确实好。def print_banner(logger, app_name, version): logger.info( * 60) logger.info( %s v%s, app_name, version) logger.info( 启动时间: %s, time.strftime(%Y-%m-%d %H:%M:%S)) logger.info( Python: %s, sys.version.split()[0]) logger.info( 平台: %s, sys.platform) logger.info( * 60)可能有人会问这不就是多打了几行 INFO 吗有什么值得说的。关键在“约定”。统一了启动横幅格式之后任何人打开日志第一屏就能确认这确实是我们要找的那个进程、版本对不对、什么时候启动的。多服务部署的时候尤其实用否则打开日志看到满屏 INFO还得想半天这是哪个服务的。横幅用 logger 而不是 print是为了让这段输出也走统一格式带时间带级别写入文件时能完整保留。如果你希望横幅更抢眼可以临时用 CRITICAL 级别打一个边框但那会污染监控告警不建议在生产环境这么干。4. 第三方库日志整合与输出细节调优4.1 管理 requests、urllib3 等第三方库的日志噪音Python 生态里很多库都基于 logging 输出日志最典型的是 urllib3包括 requests 底层就是用它。默认情况下 urllib3 的日志级别是 WARNING也就是只有警告和错误级别才会打印。但某些场景下你想看到 HTTP 请求的 URL、状态码、耗时就可以把它调成 INFO。logging.getLogger(urllib3).setLevel(logging.INFO) logging.getLogger(urllib3.connectionpool).setLevel(logging.INFO)反过来有些库非常啰嗦DEBUG 级别下可能每个响应体都会打一遍。项目里接的第三方 SDK 多了以后日志会被刷得完全没法看。处理办法就是给这些库单独设置一个更高的级别甚至直接禁止它们向 root logger 冒泡。noisy logging.getLogger(some_sdk) noisy.setLevel(logging.CRITICAL) noisy.propagate False这里 propagate False 是个关键。子 logger 默认会把 record 向上传递给祖辈 logger最后流到 root 的 handler 那里。如果你只setLevel 不关 propagate第三方库的日志还是能通过 root 的 handler 打到你的终端上。只有把 propagate 关掉才算真正“物理静音”。4.2 文件日志的编码与轮转文件日志最常见的坑之一就是中文乱码。Python 的 FileHandler 默认编码是系统区域设置Windows 下很容易是 gbk 或者 cp936到时候日志里的中文全变成问号。所以创建 FileHandler 时务必写上 encodingutf-8。另一个坑是日志文件越滚越大磁盘被撑爆。日志文件动辄几个 GB打开都费劲排查问题更是灾难。解决办法是用 RotatingFileHandler 或者 TimedRotatingFileHandler。from logging.handlers import RotatingFileHandler file_handler RotatingFileHandler( app.log, maxBytes10 * 1024 * 1024, backupCount5, encodingutf-8, )maxBytes10485760 表示单个日志文件超过 10MB 就轮转backupCount5 表示保留最近 5 个轮转文件。也就是说磁盘上最多出现 app.log、app.log.1、app.log.2……总共大约 60MB 的日志。这种“总量可控、文件可追溯”的状态对长期运行的服务非常省心。4.3 异常堆栈的格式化与保留日志最核心的价值之一就是记录异常堆栈。logger.exception(msg) 等价于 logger.error(msg, exc_infoTrue)它在输出错误消息的同时把当前异常堆栈完整打出来。没有堆栈的错误日志是半个残废只能告诉你“出错了”却没法告诉你在哪出错的。有一种情况很多人忽略在 try/except 里手动组装异常信息时只记录了错误消息没记录堆栈。比如try: result api_call() except Exception as e: logger.error(f调用失败: {e})这样写等真出了问题时日志里只有一句话“调用失败: 超时”。到底在哪一行超时、调用链是什么样的一概不知。正确做法是import traceback try: result api_call() except Exception: logger.error(调用失败:\n%s, traceback.format_exc())traceback.format_exc() 会把当前线程的异常堆栈格式化成字符串这样日志里可以完整保留堆栈。还有一种场景是想把堆栈单独存到一个追溯文件方便后续分析也可以用它配合 FileHandler 实现。在异步或者多线程环境里最好在 except 块里第一时间把 exc_info 捕住否则经过几层封装后原始堆栈可能就丢了。我自己写装饰器做统一异常捕获时都会在装饰器最外层记录 exc_infoTrue保证任何异常都能留下完整的现场。5. 常见问题与坑我从实际项目里踩过的5.1 Windows 终端颜色失效在同一套 ColoredFormatter 代码跑在 Linux 终端上完全没有问题换到 Windows 的 cmd 或者 PowerShell 里颜色序列直接原样打印出来变成一堆 \033[32m 之类的乱码。原因很简单老版本 Windows 控制台默认不支持 ANSI 转义序列。解决办法是启动时对 Windows 做一次适配手动开启终端虚拟终端处理能力import os import sys if os.name nt: import ctypes kernel32 ctypes.windll.kernel32 handle kernel32.GetStdHandle(-11) # STD_OUTPUT_HANDLE mode ctypes.c_uint32() kernel32.GetConsoleMode(handle, ctypes.byref(mode)) kernel32.SetConsoleMode(handle, mode.value | 0x0004) # ENABLE_VIRTUAL_TERMINAL_PROCESSING这段代码在脚本开头执行一次之后 ANSI 转义序列就能在 Windows 10 及以上的终端里正常显示了。如果你不想搞这么复杂也可以检测环境变量比如 NO_COLOR约定俗成的禁用颜色标志、CI持续集成环境中一般不要颜色不满足条件就直接用无色 formatter。这属于细节习惯但生产环境里处理好了会让同事省心很多。5.2 Handler 重复输出一个非常经典的坑代码里多次调用 logging.basicConfig 或者手动 addHandler日志突然打了两遍甚至三遍。原因就是 logger 对象是全局单例root logger 上可能已经挂了好几个 handler你又加了一个重复打印就出现了。排查方法很简单打印 logging.getLogger().handlers看看 root logger 上挂了多少 handler。处理方式前面提过最省事的是 basicConfig(forceTrue)它会清掉之前的 handlers。如果你用的是自定义 logger 而不是 root可以手动 removeHandlerlogger logging.getLogger(__name__) for handler in logger.handlers[:]: logger.removeHandler(handler)还有一个相关问题是子 logger 传播导致父 logger 再打一遍。默认情况下子 logger 会把日志冒泡到 root而 root 的 handler 会再次处理。项目里很多人习惯 getLogger(name)但忘了配 root结果发现日志不输出就是因为子 logger 自己的 handler 没配而上层的 logger 级别又太高。这类问题的排查思路是先看 logger.getEffectiveLevel()再看 logger.handlers 和 logger.propagate把这三个状态弄明白重复打印和“不打印”的问题基本能一次定位。5.3 别在日志里用 f-string 强拼接我知道 f-string 写起来舒服但日志场景里一定要用 %s 惰性格式化。比如logger.debug(用户信息: %s, expensive_json_serialize(user))当日志级别高于 DEBUG 时这行代码根本不执行 expensive_json_serialize完全没有性能损耗。但如果写成logger.debug(f用户信息: {expensive_json_serialize(user)})即使日志级别是 INFOf-string 也会先执行序列化再判断要不要输出。假设这个方法一次要几十毫秒日志量大时服务性能直接被打爆。这条不是玄学是真实发生过的高并发事故。有些项目为了提高日志可读性会在参数特别多时故意用 f-string我能理解但建议用一个中间变量保存计算结果再传给 logger至少要保证不会在没人看日志的情况下白算一遍。5.4 日志级别失效先查 root 的 handler设置了 logger.setLevel(logging.DEBUG)却发现 DEBUG 日志还是不出来这是新手最爱踩的坑。原因其实不复杂logger.setLevel 只是给这个 logger 设了门槛但日志最终要经过 handler如果 handler 自己的 level 比 logger 级别还高照样被过滤掉。比如你给 root logger 的 handler 设了 levellogging.INFO然后某个模块里 logger.setLevel(logging.DEBUG)结果 DEBUG 日志永远看不到。正确做法是同时检查 logger 和 handler 两个 level谁的限制高日志就得达到谁的级别。用 basicConfig(level...) 时它会同时设置 root logger 和默认 handler 的级别所以平时感觉不到这个问题。一旦自定义 handler就容易踩。5.5 多线程日志的顺序与线程安全logging 模块本身是线程安全的标准库在 Handler.emit 上做了锁保护所以多个线程同时写日志不会串行输出或互相覆盖。但有一个现象需要注意多线程下日志的“时间序”和“代码序”不一定完全一致。因为不同线程竞争同一把锁先 getLogger 的不一定先拿到锁输出。如果你需要在日志里严格还原操作顺序就得自己在线程内部记录一个序号或者把关键操作收敛到单线程执行。大多数项目其实不用做到这一步但要心里有数别看到日志顺序乱了就以为程序逻辑错了。还有一点是多进程场景。每个进程有自己独立的 logging 配置如果多个进程同时写同一个文件用普通 FileHandler 偶尔会出现日志交错甚至内容覆盖。标准做法是使用 QueueHandler QueueListener或者干脆让每个进程写各自的文件。涉及分布式日志收集的话再往 HTTP/远端服务上对接也不迟。6. 额外心得日志这块还能怎么玩6.1 给日志加个“请求 ID”上下文服务端排查问题最头疼的场景是日志混杂了多个请求。用户报了一个 bug你根本分不清日志里的哪几行是他那次请求产生的。这就要给每条日志附加一个请求 ID。最简单的办法是借助 logging 的 filter 或 LoggerAdapter 给 record 注入额外字段。class ContextFilter(logging.Filter): def filter(self, record): record.request_id getattr(threading.local(), request_id, -) return True然后把 filter 挂到 handler 上格式化串里加一个 %(request_id)s。每次请求进来时在入口处给 thread local 设置一个 UUID。这样所有日志都会自动带上当前请求的 ID排查的时候 grep 一下就能还原一条完整的请求链路。这个方案的好处是不需要引入任何第三方库纯粹的 threading.local 和 logging filter 就能搞定。更复杂的情况可以用 contextvars 配合异步框架原理是一样的。6.2 把整套配置封装成一个 setup_logging如果你在多个项目里反复做同样的日志配置不如把它封装成一个函数放到公共工具包里。每次新项目直接调用省得重新踩一遍上面说的那些坑。def setup_logging( console_levellogging.INFO, file_levellogging.DEBUG, log_fileapp.log, max_bytes10 * 1024 * 1024, backup_count5, ): if os.name nt: try: import ctypes kernel32 ctypes.windll.kernel32 handle kernel32.GetStdHandle(-11) mode ctypes.c_uint32() kernel32.GetConsoleMode(handle, ctypes.byref(mode)) kernel32.SetConsoleMode(handle, mode.value | 0x0004) except Exception: pass fmt_console %(asctime)s %(levelname)-8s %(name)s: %(message)s fmt_file %(asctime)s %(levelname)-8s %(name)s:%(lineno)d [%(process)d:%(thread)d] %(message)s console logging.StreamHandler(sys.stdout) console.setLevel(console_level) console.setFormatter(ColoredFormatter(fmt_console)) file_handler RotatingFileHandler( log_file, maxBytesmax_bytes, backupCountbackup_count, encodingutf-8 ) file_handler.setLevel(file_level) file_handler.setFormatter(logging.Formatter(fmt_file)) logging.basicConfig(levelmin(console_level, file_level), handlers[console, file_handler], forceTrue)这里有个细节root logger 的 level 要取 console_level 和 file_level 的较低值否则文件里想记录 DEBUG但控制台只显示 INFOroot 的级别却是 INFO那 DEBUG 日志连 handler 都到不了。这个坑我踩过一次花了一个多小时才反应过来写在这里给后来人排雷。6.3 关于日志颜色与可读性的个人偏好最后说一点纯粹个人的经验。颜色不是越花哨越好五颜六色的日志看久了眼睛容易累而且会削弱真正关键信息的辨识度。我一般只在 DEBUG、INFO、WARNING、ERROR、CRITICAL 五个级别上各用一个颜色INFO 用绿色但不要太鲜艳WARNING 用黄色ERROR 用红色CRITICAL 加粗再加背景色。日常开发环境里日志级别开 DEBUG能看到很多细节生产环境只开到 INFO 甚至 WARNING减少噪音。另一个建议是统一项目里所有模块的 logger 命名。强烈推荐每个模块开头写 logger logging.getLogger(name)这样日志里天然带模块路径不用自己手动拼接模块名。配合行号字段 %(lineno)d定位代码位置基本是秒级。养成这个习惯之后你会发现自己排查 bug 的速度会上一个台阶。日志这件事做的时候花不了多少时间但回报在深夜排查线上问题时体现得淋漓尽致。下次写项目别再用 print 凑合了花十分钟把 logging 配好值得的。