Python 在多线程状态下打印日志,是否会存在死锁问题?

如题,线上环境使用 thread.start_new_thread 启动了 10 个线程,每个线程读取数据库后,都在往同一个文件里面写入日

志,使用的是 Python 的 logging 模块

运行一段时间后,发现有 2 个线程没有写入日志了,但是其他八个线程仍然正常在写入,htop 查看该线程仍然是存在

的,这是死锁导致的吗?

网上查了下资料,logging 是线程安全的,应该是有 GIL 锁的,但是如果是死锁导致的话,其他八个线程应该也拿不

到锁才对,为什么能够继续写入呢?还是说在查数据库的时候连接超时导致的?


Python 在多线程状态下打印日志,是否会存在死锁问题?

23 回复

看日志吧;

以前试过,日志倒是正常,当时忘记几个线程了


在多线程环境下打印日志,确实有可能出现死锁,但这通常不是Python logging模块本身导致的,而是由日志处理程序(Handler)的I/O操作线程同步机制相互作用引起的。

最常见的情况是:

  1. 你的代码在持有某个锁A(比如线程锁、数据库连接锁等)时,去执行日志记录。
  2. 而配置的日志处理器(例如 FileHandlerSocketHandler)在写入时,其内部或底层I/O操作可能需要获取另一个锁B(例如,GIL的竞争、文件系统锁、或网络I/O阻塞)。
  3. 如果此时另一个线程正持有锁B,并在等待锁A,就会形成经典的交叉死锁(A等B,B等A)。

Python标准库的 logging 模块在设计时考虑了线程安全,其核心的 Logger 对象在记录日志时使用了线程锁(threading.RLock)来保护共享状态。但是,这个锁只保护日志记录过程中的“记录动作”本身(例如,决定是否要记录、调用过滤器、格式化消息等),并不保护处理器(Handler)执行最终的输出操作

关键点:死锁风险主要来自于:

  • 自定义的日志过滤器(Filter)或格式化器(Formatter) 中如果包含了需要获取其他锁的代码(例如访问共享资源)。
  • 某些特定的日志处理器,尤其是在执行同步阻塞I/O(如写入网络套接字、操作某些特殊设备文件)时,可能会在内部或系统层面产生阻塞和锁竞争。
  • 信号处理(signal handling) 与日志记录混合使用时,在某些平台上可能引发复杂锁问题(较罕见)。

如何避免?

  1. 保持日志处理简单:尽量不要在自定义的过滤器、格式化器或处理器中执行复杂的、可能阻塞或需要获取其他锁的操作。
  2. 使用 QueueHandlerQueueListener:这是官方推荐的、用于将日志记录与处理解耦的高效方式。工作线程通过 QueueHandler 将日志消息放入一个 queue.Queue,然后由一个单独的、专用的后台线程(QueueListener)从队列中取出消息,并交给真正的处理器(如 FileHandler)处理。这样,工作线程的日志记录操作就简化为快速的入队操作,避免了在持有业务锁时执行可能阻塞的I/O。
  3. 检查自定义代码:审查所有与日志相关的自定义组件,确保它们没有引入额外的锁依赖。

示例:使用 QueueHandlerQueueListener 避免潜在死锁

import logging
import logging.handlers
import queue
import threading
import time

def worker(thread_id, logger):
    """模拟一个工作线程,它持有某个业务锁并记录日志。"""
    # 模拟业务锁
    with threading.Lock():
        # 在持有业务锁的同时记录日志
        logger.info(f"Thread {thread_id} is doing work with lock held.")
        time.sleep(0.01)  # 模拟一些工作
        logger.info(f"Thread {thread_id} finished work.")

def setup_logging():
    """设置使用队列的日志配置。"""
    # 创建一个队列
    log_queue = queue.Queue(-1)  # 无限大小队列

    # 创建真正的处理器(例如写入文件)
    file_handler = logging.FileHandler('app.log')
    formatter = logging.Formatter('%(asctime)s - %(threadName)s - %(levelname)s - %(message)s')
    file_handler.setFormatter(formatter)

    # 创建 QueueListener,用一个后台线程监听队列并处理日志
    listener = logging.handlers.QueueListener(log_queue, file_handler)
    listener.start()

    # 创建根记录器,并添加 QueueHandler
    root_logger = logging.getLogger()
    root_logger.setLevel(logging.INFO)
    queue_handler = logging.handlers.QueueHandler(log_queue)
    root_logger.addHandler(queue_handler)

    return listener, root_logger

def main():
    # 设置日志
    listener, logger = setup_logging()

    # 创建并启动多个工作线程
    threads = []
    for i in range(5):
        t = threading.Thread(target=worker, args=(i, logger), name=f"Worker-{i}")
        threads.append(t)
        t.start()

    # 等待所有线程完成
    for t in threads:
        t.join()

    # 停止监听器
    listener.stop()
    print("所有线程执行完毕,日志写入完成。")

if __name__ == "__main__":
    main()

在这个例子中,工作线程(worker)通过 QueueHandler 将日志消息快速放入队列,然后立即返回继续执行(包括释放业务锁)。独立的 QueueListener 线程负责从队列中取出消息,并调用真正的 FileHandler 执行文件写入。这样就解耦了日志的“产生”和“输出”,极大降低了因日志I/O阻塞而导致死锁的风险。

总结:标准logging模块本身是线程安全的,但死锁风险源于I/O操作与业务锁的交叉,使用QueueHandler/Listener是推荐的最佳实践。

查了日志,也没啥特殊的异常报出来,很奇怪

你当时也是死锁了吗?

没,当时日志挺正常的

后来有解决吗?

python 的多线程不是假的么?还会出现打 log 死锁?我都是使用的多进程,通信极其麻烦,

The logging module is intended to be thread-safe without any special work needing to be done by its clients. It achieves this though using threading locks; there is one lock to serialize access to the module ’ s shared data, and each handler also creates a lock to serialize access to its underlying I/O.
文档有写。

io 操作时候多线程是真的,会释放 gil 的

线程安全的

建议搞清楚文件锁和 gil 锁的区别。logging 写日志是用 append 模式打开的文件,写入时会加锁。问题在于你的使用方式下这个锁是不是线程安全的?

建议单个日志线程,其他线程把 log 信息都发送到日志线程。

append 还能死锁?长见识。。。

等待下文

正常设置下 linux Python 多进城写日志都是安全的

建议,用 async 吧

做了异常处理没有, 有可能是那两个线程异常退出了

可以看 logging 模块的源码,是做了线程同步的。实际使用中也从未发现有 logging 导致的死锁发生。

异常处理做了,但是只看到了数据库连接超时的日志,超时的话,数据库恢复正常时,会自动重连上去的
线程异常退出的话,不知道怎么样算退出,从 htop 里面看线程还是存在的

logging 是 thread-safe 的,我们的库在 logging 的基础上实现了 cup.log 模块( https://github.com/baidu/CUP/blob/master/cup/log.py ) ,在线上跑了很久了,没问题的哈。

感觉还是楼主的代码逻辑哪儿有问题导致卡住了,肯定不是 logging 导致的。

我也觉得,如果是 logging 死锁了的话,其他几个线程不会继续正常写入的,
那个线程里面里面就做了 3 件事情 :1.读取远程数据库的数据 2.打印日志 3.开启或者关闭 socket 端口
第一件事情实际测试过,数据库挂掉过几分钟又重新启动后,线程是不会阻塞的,可以继续正常读取数据
打印了异常日志,也没发现什么特别的,就数据库挂掉后,读取超时的日志,
但是现在就出现个玄学问题了,怎么能排查出来问题在哪?

可以检查下线程有没有访问相同的数据资源,比如同一个全局量或同一个对象之类的

二分法增加 log 试试。

这样缩小范围到具体是哪儿卡住了。 我调试多线程一般就是靠日志,哈哈。 一般玄学问题大部分都是代码逻辑问题。 真遇到编辑器或者库缺陷的,太少了,除非你直接操作了非常非常底层的东西

回到顶部