使用Dask时Python logging模块日志文件出现空值问题求助

解决方案1：将日志配置移至主进程块内 #

把所有日志相关的配置代码放到if __name__ == '__main__'块中，确保只有主进程会初始化日志handler，避免worker进程继承已打开的文件句柄：

import logging
from dask.distributed import LocalCluster as Cluster

logfile_name='test.log'

if __name__=='__main__':
    logger=logging.getLogger(__name__)
    logger.setLevel('DEBUG')
    log_format=logging.Formatter(
            '%(asctime)s %(levelname)s: %(message)s',
            datefmt='%Y-%m-%d %H:%M:%S',
            )
    console_handler=logging.StreamHandler()
    console_handler.setLevel('DEBUG')
    console_handler.setFormatter(log_format)
    file_handler=logging.FileHandler(logfile_name, mode='w')
    file_handler.setLevel('DEBUG')
    file_handler.setFormatter(log_format)
    logger.addHandler(file_handler)
    logger.addHandler(console_handler)

    logger.info('First log message')

    cluster=Cluster(
            name='test', n_workers=1,
            threads_per_worker=1, memory_limit='1GiB',
            dashboard_address=':8000',
            )
    logger.info('Second log message')
    logger.info('Third log message')
    logger.info('Fourth log message')
    logger.info('Fifth log message')

    cluster.close()
    logging.shutdown()

解决方案2：启用FileHandler的延迟打开参数 #

给FileHandler添加delay=True，让文件在第一次写入日志时才打开，避免fork出的worker进程继承未使用的文件句柄：

修改原代码中的FileHandler创建代码：

file_handler=logging.FileHandler(logfile_name, mode='w', delay=True)

问题原因分析 #

问题源于Dask LocalCluster的进程fork机制：

• 原代码在全局作用域创建FileHandler，主进程会立即以mode='w'截断并打开日志文件；
• 启动集群时，Dask会fork出worker子进程，这些子进程会继承主进程已打开的文件句柄；
• 子进程初始化时，会重置文件指针或因共享句柄产生写入冲突，直接覆盖了主进程写入的第一条日志内容，表现为文件首行的大量\00空值。

而使用mode='a'时，文件不会被截断，冲突的表现不明显，但并未解决句柄共享的根本问题。

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