ARTICLE DETAIL

资讯详情

深耕网站视觉设计与运营推广的一线实战洞察。

Python Web 开发中 Uvicorn 热重启与 JSON 日志配置实战

Python Web 开发中 Uvicorn 热重启与 JSON 日志配置实战 先说个有意思的细节你搜的是“python 中 unicorn”但Python生态里真正干“热重启”这活儿的绝大多数情况下是 uvicorn。unicorn 是 Ruby 那边的服务器跟 Python 不是一家人。这个拼写错误我在各种群里见过太多次了尤其是刚接触 FastAPI、又用过几天 Ruby 的人最容易把这俩搞混。所以这篇文章我先按 uvicorn 讲后面会提一嘴如果你真是想用 Ruby 的 unicorn 做热重启那是另一套逻辑。至于“debug 的 json”结合热词里的搜索记录看大概率是两个意思叠加一是 uvicorn 在 debug 模式下的日志输出很乱想把访问日志、错误日志改成 JSON 结构化格式二是自己业务代码里 print 出来的一堆 dict在终端里挤成一坨根本没法看。这两个痛点其实都能在一套方案里解决我直接把配置和踩坑过程写给你。1. 热重启为什么“有时灵有时不灵”1.1 先搞清楚 uvicorn 热重启的底层机制uvicorn 的--reload参数看着简单背后其实是两条独立的进程链路在工作。主进程reloader process只负责一件事用 watchfiles 库盯着文件系统的事件。一旦有文件变动主进程会杀掉当前的 worker 进程再重新拉起一个新的 worker 进程。这个设计是刻意的因为 worker 里跑着你的应用代码、数据库连接池、第三方客户端这些状态如果在一个进程内“原地重启”基本不可能做到干净。所以 uvicorn 选择了最稳妥的方式进程级重启。这里有个关键点很多人不知道--reload一旦开启uvicorn 是强制单 worker 的。你就算同时加了--workers 4reload 模式下也只会起一个 worker。原因是多 worker 热重启会导致请求被随机分发到旧代码和新代码进程上行为完全不可预期。官方直接把这个组合禁用掉了宁可牺牲并发能力也要保证开发环境的确定性。这不是 bug是设计决策。还有一个容易被忽略的细节默认的 reload 监听范围是整个工作目录但它是通过 watchfiles 的DefaultFilter来排除目录的。像.git、__pycache__、.venv、venv、node_modules这些目录默认就已经被排除了。我见过不少人改了.venv里的包代码发现不触发重启以为是热重启坏了其实是被过滤规则挡了。触发链路的完整过程是这样的文件写入事件 - watchfiles 的 Rust 后端内置的watchfiles库底层不是纯 Python拿到事件 - 事件里包含文件路径和变更类型 - 过滤规则判断是否有效 - 有效则通知 reloader 进程 - reloader 执行Process.terminate()然后重新spawnworker。整个链路任何一个环节出问题表现就是“改了代码没反应”。1.2 为什么改了代码却没触发重启我实际排查过的典型情况有以下几种你可以对着检查文件被写入但不产生“修改”事件。比如有些编辑器在保存文件时是“原子替换”——先写临时文件再 rename 覆盖目标文件。这种操作在 Linux 上用 inotify 会拿到IN_MOVED_TO之类的 rename 事件watchfiles 能处理。但如果你的文件系统是网络挂载盘比如 NFS、SMB或者用的是 Docker Desktop 在 Windows/Mac 上的文件共享事件通知很可能延迟甚至根本不来。这是最常见的“热重启失灵”来源不是代码问题是环境问题。改的文件根本不在监听范围。uvicorn 默认监听的是你启动命令所在的目录。如果你用--app-dir指定了代码目录但项目里还有别的目录存配置、静态文件那些目录的变动不会被监听到。需要明确用--reload-dir参数把多个目录都加进来。杀进程失败导致端口被占用。worker 进程被 terminate 之后旧进程可能还握着 8000 端口没释放。新的 worker 起不来表现就是终端里反复报address already in use看起来像热重启循环失败。这种情况通常跟旧 worker 里的子进程比如开了多线程、子进程收发任务没有跟着退出有关。编辑器保存时没有真实写盘。有些远程开发方案比如通过 VS Code 的 Remote-SSH 编辑文件保存后文件确实更新了但如果你同时开着自动保存和某种“延迟写入”功能事件会合并、延迟。极端情况下你会看到终端每隔几十秒才触发一次重启。还有一个大家不太注意的点修改“被 import 到的模块”和修改“入口跑起来的脚本”触发效果完全一样但修改“被动态加载的数据文件”比如 JSON 配置、YAML 配置不会触发热重启除非你显式把它加进 reload 目录并且让加载逻辑在启动时读取。修改数据文件后需要手动重启否则进程里缓存的还是旧配置。2. 热重启的进阶玩法与 Debug 模式细节2.1 什么时候不要用热重启热重启是开发利器但不少人在 Docker 容器里也用--reload这就要警惕了。容器里用热重启有几个硬伤第一容器外的文件挂载到容器内时事件传递经过 Docker Desktop 的 osxfs/gRPC-FUSE 通道在 macOS 和部分 Windows 环境下延迟明显你保存代码后可能要等两秒到五秒才看到重启动作体感很差。第二容器内的 reloader 进程会额外吃掉一小块 CPU 和内存不重但没必要。第三Kubernetes 环境里如果配置了 liveness 探针频繁重启 worker 过程中可能短暂无响应运气不好会触发探针失败导致 Pod 被重新调度。我的建议是容器内跑开发环境如果挂载卷是本地目录且文件量不大可以在requirements.txt装完依赖后把--reload留着但把--reload-dir收缩到最小的代码目录如果文件量大比如前端构建产物也在里面宁可放弃热重启改用外部工具比如 watchdog 脚本自动触发容器内重启或者干脆手动重启。2.2 debug 模式里到底开了什么uvicorn 的--debug参数内容比很多人理解的“多打印点日志”要多。它开启之后主要做三件事将日志等级调整为 DEBUG输出更底层的信息包括 watchfiles 的 reload 触发日志、请求的更多细节。在错误处理上使用更宽松的模式方便你看到具体的堆栈而不是只返回 500。对 ASGI 的 lifespan 事件startup/shutdown给出更详细的输出。但要注意--debug不等于--reload。两者可以同时用也可以分开用。很多人误以为 debug 模式会自动热重启其实不会。debug 只是把日志级别放开了文件改动后的重启还得靠--reload这个独立开关。我在实际项目中经常只开--reload不开--debug因为默认 INFO 级别下uvicorn 已经会打印每次访问的日志和错误堆栈对绝大多数调试场景已经够了。--debug的额外日志主要用处在于排查 reloader 自身的问题比如想知道有没有监听到文件事件、过滤规则有没有生效。如果你用了--reload却发现日志里完全没有 reload 相关的 DEBUG 输出那大概率是日志配置被你的项目自定义配置覆盖了后面讲日志处理的时候会详细说。3. 把 debug 和日志输出改成 JSON 格式3.1 为什么默认日志格式让人抓狂默认的 uvicorn 访问日志长这样INFO: 127.0.0.1:54321 - GET /api/users HTTP/1.1 200 OK这个格式对肉眼还算友好但你要做日志聚合ELK、Loki、云日志服务就麻烦了。各字段是空格分隔的解析规则写起来又脆又容易错。更麻烦的是如果你在业务代码里用print或者默认的logging输出一个 dict终端里会显示成 Python 的 repr 格式带引号带括号单行日志里混着多层嵌套根本没法用 jq 这类工具去加工。这种“debug 的 json”一眼就能看出的问题是结构缺失。实际的痛苦场景是这样一个请求失败服务端的错误堆栈、客户端的请求 ID、数据库的慢查询日志分散在三四条日志里每条的字段格式还各自为政。排障的时候你得睁大眼睛手工把这些信息拼起来。万一日志量上去了靠人眼从几千行里捞那一条几乎不可能。所以把日志输出统一成 JSON不是“追求时髦”而是后续一切自动化的前提。3.2 用 LogConfig 给 uvicorn 配上 JSON 输出要把 uvicorn 的 access log 改成 JSON最常见的方式是自定义log_config。你在项目里写一个字典结构传给 uvicorn 的log_config参数dict 形式或 JSON 文件路径都行。核心配置长这样import logging import json class JsonFormatter(logging.Formatter): def format(self, record: logging.LogRecord) - str: log_entry { time: self.formatTime(record, self.datefmt), level: record.levelname, logger: record.name, message: record.getMessage(), } # 把 extra 字段也塞进去 for key, value in record.__dict__.items(): if key not in (message, asctime, levelname, name, args, exc_info, exc_text, stack_info, filename, module, funcName, lineno, created, msecs, relativeCreated, thread, threadName, processName, process, taskName): log_entry[key] value if record.exc_info: log_entry[exc_info] self.formatException(record.exc_info) return json.dumps(log_entry, ensure_asciiFalse)然后用这个 formatter 替换 uvicorn 默认的 formatterimport logging import uvicorn class JsonFormatter(logging.Formatter): # ... 上面的实现 ... def make_log_config(): formatter_name json log_config { version: 1, disable_existing_loggers: False, formatters: { formatter_name: { (): JsonFormatter, }, default: { (): logging.Formatter, fmt: %(levelprefix)s %(message)s, use_colors: None, }, }, handlers: { default: { formatter: formatter_name, class: logging.StreamHandler, stream: ext://sys.stderr, }, access: { formatter: formatter_name, class: logging.StreamHandler, stream: ext://sys.stdout, }, }, loggers: { uvicorn: {handlers: [default], level: INFO, propagate: False}, uvicorn.error: {handlers: [default], level: INFO, propagate: False}, uvicorn.access: {handlers: [access], level: INFO, propagate: False}, }, } return log_config if __name__ __main__: uvicorn.run(main:app, host0.0.0.0, port8000, reloadTrue, debugFalse, log_configmake_log_config())这里有个细节必须提醒你uvicorn 内部有两个 logger分别叫uvicorn.error和uvicorn.access。如果你只想把访问日志改成 JSON只配uvicorn.access就够了。但你如果没显式配置uvicorn.error错误堆栈还是默认格式。所以我在配置里把uvicorn根 logger 也统一处理了避免出现“访问日志是 JSON错误日志是纯文本”这种精神分裂局面。还有一点disable_existing_loggers一定要设成False。如果你设成True你自己的业务模块里logger logging.getLogger(__name__)创建的那些 logger 会被置为禁用状态日志直接消失排查的时候特别诡异。3.3 业务代码里怎么让 dict 输出也能被 JSON 化很多人发现配完 uvicorn 的 access log自己代码里的logger.info({user_id: 123, action: login})打出来却是一长串像这样INFO: {user_id: 123, action: login}仔细看看会发现这个“JSON”前面带了INFO:这个前缀而且如果你传入的不是纯字典而是带日期、Decimal、bytes 等类型的对象json.dumps 会直接报错或者丢字段。这才叫真正的“debug 的 json 痛点”。正确的做法是别直接传 dict 进去要么把字段塞进extra要么让自定义 formatter 里做类型强转。我更推荐用extraimport logging logger logging.getLogger(app.biz) logger.info(user login, extra{user_id: 123, action: login, ip: 127.0.0.1})这样在 formatter 里统一遍历record.__dict__把所有 extra 字段收集进 JSON。优势是日志内容里 message 保持纯文本extra 保持结构化两者解耦后续解析不用费劲去区分哪部分是原文哪部分是字段。不过要小心个别变量名跟 LogRecord 自带属性冲突比如args、msg、message、asctime所以我在遍历时有一串排除名单。至于datetime、Decimal、UUID这类没法直接 JSON 序列化的类型formatter 里做一次兜底转换def safe_serialize(value): if isinstance(value, datetime.datetime): return value.isoformat() if isinstance(value, (datetime.date, datetime.time)): return value.isoformat() if isinstance(value, decimal.Decimal): return float(value) if isinstance(value, uuid.UUID): return str(value) if isinstance(value, bytes): return value.decode(utf-8, errorsreplace) return str(value)在json.dumps的default参数里传这个函数日志输出就永远不会因为某个字段类型特殊而崩掉。3.4 热重启和 debug 同时开启时的日志坑我前面提到--reload时 worker 是被重新 spawn 的这带来一个隐藏问题每次热重启之后日志配置会重新加载一遍。如果你的日志配置是写在模块顶部的模块级别只执行一次的代码并且 reload 之后新的 worker 进程会重新导入一次代码那没啥问题。但如果你用某种“长驻内存”的方式保存了 logger 实例或 handler有可能出现 handler 重复绑定、日志输出双倍的问题。遇到重复日志先看是不是 reload 之后进程没有完全退出旧进程的 logger 还在监听同一个输出流。检查方法很简单ps aux | grep uvicorn看看是不是有多个 worker 进程同时活着。如果有问题不在日志配置而在旧进程没被清理干净。这种情况通常和“旧 worker 里有不能被打断的阻塞任务”有关。解决办法是在代码里给阻塞任务加超时或设置 daemon 线程别让进程在 terminate 时卡住。另外--debug模式下日志量大增每次热重启还会额外打印 reload 信息和 lifespan 事件。如果这些日志进了 JSON 管道而你的下游系统对 JSON 格式比较严格比如要求每行一个 JSON 对象要注意把 uvicorn 的 reload 日志也统一交给 JSON formatter 处理否则会混入非 JSON 行导致采集端报错。我的做法是所有 uvicorn 相关 logger 都用同一个 json formatter宁可全部结构化也不要混着来。4. 典型坑reload 进程和日志丢失的组合拳4.1 “改了代码但日志还在旧的格式”之谜这个坑我印象太深了。有阵子我在一个项目里配置完 JSON 日志--reload跑得很好代码改动后 worker 确实重启了但新打印的日志还是老格式。折腾一圈才发现改的是业务代码文件触发了 reload但log_config是在启动命令里由 uvicorn 加载的——也就是 reloader 进程持有的是启动时的配置。业务代码的热重启不会重载配置本身。要让日志格式变化生效必须重启整个 server 进程让它重新读取log_config。这个现象特别容易让人误以为“配置没生效”或者“热重启坏了”其实热重启是好的只是它只替换了 worker 的代码没有替换 reloader 进程的配置。如果你把log_config放在业务代码里动态计算逻辑上依然不会被 reloader 重建。所以改日志配置的正确姿势是停掉整个进程重新uvicorn.run。如果你实在不想手动重启可以给 reloader 进程也加一个“配置热加载”的机制——但这已经超出 uvicorn 的默认能力了需要外部工具比如 watchdog直接 kill 整个进程组再拉起Uvicorn 本身不支持“配置也热更新”。别去翻文档找这个功能没有。4.2 reload 造成的端口占用与 state 丢失再来一个高频事故--reload模式下如果你同时用某个子进程比如 multiprocessing、subprocess 起外部服务worker 被 terminate 时如果代码里没有显式结束子进程子进程会变成孤儿进程继续跑并占用你本来要用的端口。新 worker 启动时发现端口被占直接报错。日志里能看到类似[Errno 48] error while attempting to bind on address (0.0.0.0, 8000): address already in use。这种情况在 Windows 上更多见因为 Windows 下文件被占用时进程不能像 Linux 那样“文件还在但标记删除”。SQLite 数据库文件也一样旧 worker 的连接没释放干净新 worker 一启动就可能报database is locked。我的经验是在项目里写一个on_shutdown的 lifespan 钩子把子进程、线程、连接都清理掉from contextlib import asynccontextmanager import uvicorn asynccontextmanager async def lifespan(app): # startup yield # shutdown # 这里释放子进程、关闭连接池、清理临时文件 app FastAPI(lifespanlifespan) if __name__ __main__: uvicorn.run(app, host0.0.0.0, port8000, reloadTrue)有些人不喜欢写这些清理逻辑觉得开发环境无所谓。但热重启本身就是开发环境里的重操作来回 kill/start 特别容易把你的进程池拖进半死状态。宁可多写几行清理代码也别在开发到一半的时候被端口占用搞得没法继续。4.3 debug JSON 日志里的中文和转义问题日志 JSON 化以后中文内容默认会被json.dumps转成\uXXXX形式。这在机器读取层面完全没问题但人的肉眼看去全是转义序列调试体验很差。上面代码里我写了ensure_asciiFalse就是为了保留中文可读性。但这里有个取舍ensure_asciiFalse输出的 JSON 在按行解析时是合法的但如果你把日志文件直接丢给某些老旧的、不认 UTF-8 的采集工具可能出乱码。现在的日志系统基本都支持 UTF-8我建议保留ensure_asciiFalse同时确保你的日志 Handler 输出时用的是 UTF-8 编码。如果发现 Windows 终端下中文乱码通常不是 JSON 配置的问题而是终端代码页问题在项目里把PYTHONIOENCODINGutf-8设置到启动环境里就解决了。4.4 日志轮转和多行堆栈的纠正JSON 日志还有一种特殊情况异常堆栈是多行的。默认的formatException返回的字符串里包含换行符导致一条日志记录里出现多个物理行破坏“一行一条 JSON”的约定。解决思路有两个要么把异常堆栈里的换行替换成转义形式比如\\n让整条日志保持在单行内要么在日志采集端配置多行合并规则。我更推荐第一种简单粗暴且下游查询时用.*正则就能匹配。exc_text self.formatException(record.exc_info) log_entry[exc_info] exc_text.replace(\n, \\n).replace(\r, \\r)别小看这一步很多 JSON 日志管道都栽在“堆栈跨行”上。我见过有系统因为采集端没办法合并多行日志直接丢一半最后排障全靠猜。宁可把堆栈压成一行也不要让它真的跨物理行。5. 热重启和 JSON debug 配置的总览与推荐参数5.1 一份能直接抄的项目配置参考把这些内容拼起来一份我实际用下来比较顺手的开发环境启动配置大概长这样uvicorn main:app \ --host 0.0.0.0 \ --port 8000 \ --reload \ --reload-dir ./app \ --reload-dir ./tests \ --log-config log_config.json \ --log-level info对应的log_config.json把 formatter、handler、logger 三个部分写清楚启动时不需要写 Python 代码命令行直接指定文件路径即可。这里有个小细节--log-config支持 JSON 文件路径或 YAML 文件路径需要 PyYAML但如果你用了自定义(), 类JSON 文件里一样可以写(): module:ClassName形式。只是 uvicorn 在解析时会尝试 import 对应类所以要保证类在sys.path里能找到。我在实际项目里建议的是把 JSON formatter 放在一个独立的logging_config.py模块里然后用--log-config logging_config.py或者直接在uvicorn.run(log_config...)传 dict。这样你就拥有代码内修改 formatter 的灵活性同时启动命令依然干净。5.2 哪些参数该调该不调看使用场景参数/做法开发环境容器开发环境生产环境--reload开配合--reload-dir收窄范围谨慎开确认挂载卷事件能到达必须关--debug默认不开排查 reload 自身问题时开不开必须关--workersreload 下恒为 11按 CPU 核数设置JSON 格式日志建议开建议开必须开--log-levelinfoinfoinfo访问日志建议开方便看请求建议开按需求开表里的建议是我个人偏好不是官方硬性规定。生产环境不开--reload是底线因为热重启的“快速反馈”诉求在生产环境不存在反而会因为文件变动导致不可控的闪断。--debug同理它会把太多内部的细节暴露在日志里既占空间又没必要。5.3 环境变量与 reload 的联动有个细节值得单独说很多项目用os.environ.get(DEBUG)来决定要不要开热重启比如import os import uvicorn if __name__ __main__: debug_mode os.environ.get(APP_DEBUG, 0) 1 uvicorn.run(main:app, reloaddebug_mode, debugdebug_mode, log_configmake_log_config())这个模式本身没问题但要注意reload开启时环境变量会被 reloader 进程继承然后传给新 worker。如果你在业务代码里动态读取环境变量改环境变量并不会触发热重启。要改环境变量后生效同样得重启整个进程。这和前面说的“配置不热更新”是同一回事。我见过有人写.env文件改完环境变量等着热重启自动生效结果半天没反应最后气得重启电脑其实只要重启 uvicorn 进程就够了。6. 常见问题速查与排查工具6.1 高频问题速查表症状可能原因排查思路改代码不触发重启文件系统事件传不到看 reload 日志里的 DEBUG 信息确认是否收到FileEvent触发重启但端口占用旧 worker 未完全退出ps aux /grep uvicorn看残留进程手动 kill日志还是默认格式配置未重载确认停止整个进程后重新启动日志输出双份handler 重复绑定或旧进程未退检查进程数量检查是否多处logging.basicConfigJSON 字段中文乱码终端编码/输出流编码问题设置PYTHONIOENCODINGutf-8dict 序列化失败字段类型不是 JSON 原生类型给 json.dumps 加 default 函数兜底reload 模式下无法多 workeruvicorn 设计限制开发环境单 worker生产环境不带 reload 多 worker访问日志有 JSON错误日志没有logger 覆盖不全把uvicorn根 logger 也统一配置6.2 排查热重启问题的三个命令当热重启“感觉坏了”我的第一反应不是翻代码而是先在终端里跑三个命令确认现场# 看看当前有哪些 uvicorn 进程 ps aux | grep uvicorn # 看看有没有进程占着端口把 8000 换成你的端口 lsof -i :8000 -P -n # 直接在前台启动并打开 reload 调试日志 uvicorn main:app --host 0.0.0.0 --port 8000 --reload --reload-dir ./app --log-level debug第三个命令特别有用。--log-level debug时 uvicorn 会打印类似WatchFilesReloader detected changes in xxx.py的日志。如果你看到这个日志说明事件管道是通的问题在 worker 重启阶段如果没看到说明文件事件根本没到 reloader。两种情况后续的排查方向完全不同。这一条经验能省掉大量瞎猜时间。6.3 最后一个容易翻车的点VSCode / PyCharm 的调试器和 reload如果你习惯用 IDE 的 debug 功能比如 VSCode 的 Run and Debug 里的 FastAPI 配置或者 PyCharm 的 Python Debugger再叠加 uvicorn 的--reload会有一个隐藏问题IDE 附加的调试器通常绑定在第一个进程reloader 进程上reload 触发后新 worker 是全新的进程调试器不会自动附加到新进程上。因此你会发现断点只在启动时第一次生效代码一改动重启后断点就全断了。处理方案有两种。第一种开发时在 IDE 里不加--reload靠 IDE 自带的“重启调试会话”按钮来重新启动。第二种如果坚持要热重启就把调试器配置改成 attach 模式让 worker 启动后主动等待调试器连接。第二种配置在不同的工具里差异太大不展开了但思路是通用的。如果你对断点调试依赖度很高我更推荐第一种省心不折腾。7. 实操总结一套能长期用的开发启动模板最后给你一份我自己的开发模板作为收尾。我每个 Python Web 项目的根目录都会放一个dev.py或者run_dev.pyimport os import logging import uvicorn from pathlib import Path # 日志目录 LOG_DIR Path(__file__).parent / logs LOG_DIR.mkdir(exist_okTrue) def build_log_config(): # 这里放前面定义的 JsonFormatter 和 log_config 字典 pass if __name__ __main__: # 开发环境默认开启 reload uvicorn.run( main:app, hostos.environ.get(HOST, 127.0.0.1), portint(os.environ.get(PORT, 8000)), reloadTrue, reload_dirs[./app], log_configbuild_log_config(), )这个模板的好处是所有跟环境相关的细节host、port、reload 目录、日志格式都在一个文件里集中管理团队成员跑起来的行为完全一致不会出现“你改了端口我改了 reload 目录”这种配置分叉。热重启里碰到的绝大多数问题在这个统一入口下都更容易复现和排查。我个人的体会是热重启和 JSON 日志这两件事单看哪一件都不复杂但放在一起就会出现“修改配置后不生效”“日志格式混搭”“进程残留导致端口占用”这类全是细节的组合坑。把这些细节提前在项目里固化好后面省下的时间是当初配置时的好几倍。如果你也在给团队搭 Python Web 的开发环境建议把这套配置直接纳入项目模板省得每个人踩一遍同样的坑。
返回列表