这个坑值得记一笔。Python 3.12 的服务用 QueueHandler 加 QueueListener 异步写日志,容器收到 SIGTERM 后退出,最后 200 多条请求日志全丢;排查线上 502 时正好缺那一段,日志文件里最后一条比实际退出时间早 4 秒。
刚开始盯着「atexit 注册顺序在 logging.shutdown 之后」,折腾了半个多小时,排掉了。
原因不止一个,得分开看。退出时没有 stop listener,队列里剩余记录被丢弃;QueueListener 线程不是 daemon,进程被直接 kill;队列用了有界队列,满了以后直接丢记录。
动手时先确认退出时监听线程有没有停
python -c "import logging.handlers as h;print(hasattr(h.QueueListener,'stop'))"
再往下在 SIGTERM 处理里显式 stop 并 join
python -c "import signal;print('handler: listener.stop(); listener.join()')"
然后把队列改成无界并记录丢弃计数
python -c "import queue;print(queue.Queue())"
等前面都确认过,再用 docker stop 复现并核对日志条数
docker stop --time=10 app-test && grep -c 'request' app.log
别只看报错消失,验证要多做一步。docker stop 之后日志文件最后一条时间与退出时间相差不到 1 秒,请求条数与压测发送数一致,没有缺口。
QueueHandler 只是把写日志变成异步,进程退出时不会自动排空;信号处理里必须 stop 并 join,容器还要给足 terminationGracePeriod。监控比日志更早给出信号,事后回看经常能提前半小时发现异常。
