Python多进程日志场景下子进程print影响主进程性能问题咨询

数据老陈

2026-8-28

问题背景

我正在使用python-can库实现CAN总线文件下载功能，场景下消息发送速率极高，约为每毫秒2-3条消息。我希望在不影响消息发送速率的前提下将这些消息记录到文件中，但直接执行文件I/O会因日志开销拖慢发送速度。

我尝试过多种优化方案：

使用队列搭配独立线程读取队列写入日志，但受GIL影响优化效果有限
基于Python标准logging模块，测试过QueueHandler/QueueListener、MemoryHandler等多种处理器，均未达到理想效果

将文件I/O操作迁移到独立子进程后，性能提升显著。最初遇到跨进程数据传输开销过高的问题，因此新增了缓冲机制：对比主进程直接写文件导致耗时增加150%的基线，优化后的方案仅带来约20%的耗时增长。

我原本认为日志逻辑运行在独立子进程中，就可以同时通过print()将数据输出到控制台（我清楚该操作开销相对较高），但实际测试发现该操作会导致文件下载耗时大幅上升。

核心疑问：为何运行在子进程中的print()操作会对主进程的运行效率产生影响？

相关说明：

file_logger_mp()由主进程调用，负责启动执行日志操作的子进程；主进程通过log_hdl函数将消息添加到缓冲区，当缓冲区大小达到阈值100时，批量将数据发送到子进程，完成文件写入或控制台打印操作。
运行设备为树莓派4（RPi4），主进程基于asyncio实现，该特性可能对问题存在影响。

相关代码

import multiprocessing
import atexit

def file_logger_mp(logger_name: str, log_file_pth: str):

    conn_rec, conn_send = multiprocessing.Pipe()
    log_hdl_c = MyLogger(conn_send)
    log_hdl = log_hdl_c.log_hdl    # 主进程调用该方法向子进程传递日志消息
    
    listener = MyProcess(conn_rec, log_file_pth)
    atexit.register(log_hdl_c.final_flush, listener)
    listener.start()    # 启动日志子进程

    return log_hdl, listener

class MyLogger():
    def __init__(self, conn_send) -> None:
        self.buffer = []
        self.conn_send = conn_send

    def log_hdl(self, msg):
        self.buffer.append(msg)
        if len(self.buffer) > 100:
            self.conn_send.send(self.buffer)
            self.buffer.clear()

    def final_flush(self, listener):
        self.conn_send.send(self.buffer)
        listener.terminate()

class MyProcess(multiprocessing.Process):

    def __init__(self, queue, f_hdl):
        multiprocessing.Process.__init__(self)
        self.exit = multiprocessing.Event()
        self.queue = queue
        self.f_hdl = f_hdl

    def run(self):
        f = open(self.f_hdl, "w+")
        while not self.exit.is_set():
            try:
                record = self.queue.recv()

                for msg in record:
                    output = str(msg)
                    f.write(output+'\n')
                    print(output) # 该行print会导致主进程出现严重延迟
                record.clear()
            except Exception:
                import sys, traceback
                print('Whoops! Problem:', file=sys.stderr)
                traceback.print_exc(file=sys.stderr)
        # 进程退出前刷写剩余日志
        for msg in record:
            f.write(str(msg)+'\n')
        f.close()

    def terminate(self):
        self.exit.set()

原因分析

子进程的print()拖慢主进程，是三个机制共同作用的结果：

终端输出的全局锁竞争
Linux系统下（包括RPi4运行的Raspberry Pi OS），进程向控制台（tty/pty）输出内容时，内核会持有全局的终端输出锁，保证不同进程的输出不会乱序穿插。子进程调用print()向控制台写数据时，会和主进程争抢这把锁——主进程哪怕不主动打日志，asyncio事件循环、Python解释器本身的异常/状态输出、甚至CAN驱动的内核日志输出都可能触发锁竞争，直接打断主进程的实时发送逻辑。
Pipe发送的隐式同步阻塞
你用的multiprocessing.Pipe默认是阻塞模式，且Pipe的内核缓冲区大小有限（Linux下默认一般是64KB）。子进程执行print()的速度远慢于写文件的速度：写普通文件是页缓存写入，几乎是内存操作速度；而写控制台的print()需要等终端驱动处理完所有字符、如果是SSH连接还要等网络传输完成才会返回。一旦子进程被print()阻塞，就会迟迟不调用recv()消费Pipe里的数据，Pipe缓冲区很快被填满，此时主进程调用conn_send.send()就会直接阻塞，直到子进程消费完缓冲区数据，自然拖慢主进程的CAN消息发送逻辑。
树莓派4的IO性能瓶颈
RPi4的SD卡IO、控制台输出本身性能就弱于x86设备，高频率的控制台输出会占满IO带宽，进一步放大上述阻塞问题。另外asyncio的事件循环是单线程运行的，一旦主进程卡在Pipe发送的阻塞调用上，整个事件循环都会暂停，直接影响CAN消息的定时发送精度。

优化方案

子进程内的控制台输出也做批量缓冲，不要每收到一条消息就print()，攒够一定量或者间隔固定时间再一次性输出，减少锁竞争和IO调用次数
如果不需要实时看控制台输出，可以把print()的输出重定向到专门的日志文件，或者关闭控制台打印，彻底避免终端锁竞争
把Pipe替换成容量更大的multiprocessing.Queue，或者给Pipe设置非阻塞模式，搭配更大的应用层缓冲区，避免主进程被发送操作阻塞
子进程内写文件和控制台输出分开处理，控制台输出放到更低优先级的队列里，优先保证文件写入的消费速度，避免Pipe缓冲区被打满

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

Python多进程日志场景下子进程print影响主进程性能问题咨询

相关代码 #

相关代码