使用concurrent.futures.ThreadPoolExecutor时日志消息顺序不符合预期

问题本质 #

print和logging的底层实现逻辑存在差异：

• print 本身不是线程安全的，多线程环境下调用print时，输出内容可能被其他线程的print或logging操作打断，导致内容交错。
• logging模块的默认Handler（如StreamHandler）是线程安全的，会保证单条日志的完整性，但如果和非线程安全的print混用，依然会因为print的无锁输出打乱整体顺序。

解决方案 #

方案1：完全统一使用logging输出 #

这是最可靠的解决方式，彻底避免混用带来的问题。logging的线程安全特性会保证每条日志完整输出，同时ThreadPoolExecutor的上下文管理器默认会调用shutdown(wait=True)，主线程会等待所有子线程执行完毕，因此主线程的"Before tpe"和"After tpe"会自然处于正确的首尾位置，仅线程内部日志顺序可能随调度变化。

示例代码：

import logging
import concurrent.futures
import time

logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(threadName)s - %(message)s')

def thread_function(name):
    logging.info(f"Thread {name}: starting")
    time.sleep(2)
    logging.info(f"Thread {name}: finishing")

if __name__ == "__main__":
    logging.info("Before tpe")
    
    with concurrent.futures.ThreadPoolExecutor(max_workers=3) as executor:
        executor.map(thread_function, range(3))
    
    logging.info("After tpe")

方案2：必须用print时，添加线程锁 #

如果因特殊需求必须保留print，需要给所有print操作加锁，确保同一时间只有一个线程执行print，避免输出交错。同时要保证主线程的print语句在所有子线程执行完成后再调用。

示例代码：

import logging
import concurrent.futures
import time
import threading

print_lock = threading.Lock()

logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(threadName)s - %(message)s')

def thread_function(name):
    logging.info(f"Thread {name}: starting")
    time.sleep(2)
    logging.info(f"Thread {name}: finishing")
    # 使用锁保护print输出
    with print_lock:
        print(f"Thread {name}: print output")

if __name__ == "__main__":
    logging.info("Before tpe")
    
    with concurrent.futures.ThreadPoolExecutor(max_workers=3) as executor:
        executor.map(thread_function, range(3))
    
    # 主线程的print同样加锁，并在executor完成后执行
    with print_lock:
        print("out here")
    logging.info("After tpe")

关键说明 #

• 无论采用哪种方案，核心是保证主线程的收尾操作（After/print）必须在所有子线程执行完成后执行，ThreadPoolExecutor的上下文管理器已经帮你自动实现了等待逻辑。
• 尽量避免混用logging和print，不仅会引发顺序问题，还会导致日志格式不统一、后续难以扩展管理（比如无法统一输出到文件）。

内容的提问来源于stack exchange，提问作者Sebastian