原创作品:首发u3v3, 转载请保留

地址:https://www.u3v3.com/ar/1330

作者ID:Yi_Zhi_Yu

首发日期:2017.5.16

Python学习群:278529278 (欢迎交流)

logging 多进程写同一个文件

logging 包的官方文档中明确说过

Although logging is thread-safe, and logging to a single file from multiple threads in a single process is supported, logging to a single file from multiple processes is not supported, because there is no standard way to serialize access to a single file across multiple processes in Python

没有标准的方式让多进程写同一个日志文件

logging 包有一个FileHandler 实现了日志写入文件的操作, 但多进程并发写入时, 会产生数据截断, 覆盖等问题, 下面我们会进行这个实验

同时, 我们也自己简单实现了一个自定义的Handler, 希望能实现多进程并发写入而不会产生FileHandler时的问题, 并进行验证

FileHandler

这是logging包的一个处理模块, 负责将日志消息写入文件, 如果用多进程的方式写入, 会出现什么情况呢,

我们试试

代码如下

def process_log(p_off):
    logger_handler = logging.FileHandler('/tmp/one_file_log.log')
    logger = logging.getLogger('test')
    logger.addHandler(logger_handler)
    logger.setLevel(logging.DEBUG)
    for x in range(0, 100):
        d = datetime.datetime.now()
        t_str = '你好test' * 2000 # 每行数据较大时容易发现问题
        logger.info('{}:{}:p_off({}):pid({})'.format(t_str, d.strftime('%Y-%m-%d %H:%M:%S'), p_off, os.getpid()))

if __name__ == '__main__':
    # 多进程写日志
    p = Pool(4)
    for i in range(4):
        p.apply_async(process_log, args=(i,))
    print('waiting.....')
    p.close()
    p.join()
    print('done.....')

以上通过FileHandler, 多进程并发写同一个日志文件/tmp/one_file_log.log

理论上日志文件的每行的长度应该是一样的, 我们校验一下

f = open('/tmp/one_file_log.log', 'r')
r = f.readlines()
for r_row in r:
    print(len(r_row))
    time.sleep(1)

输出前若干行每行数据的长度:

24081
12041
1
24081
1
24081
1
12041
24081
1
12041
12041
12041
12041
12041
12041
12041
36121

事实上并非如此, 这就说明使用FileHandler多进程写同一个日志文件的时候会产生日志截断, 丢失等问题, 日志写入不能保证原子性

证明, 确实多进程写同一个日志文件会有问题

O_APPEND 写入文件Handler

在linux下, 我们通过o_append方式向文件中写入数据时, 在没有锁的情况下, 可以实现数据写入的原子性

我们直接在一个自定义的Handler中, 使用这种方式写日志文件

class MPFileLogHandler(logging.Handler):
    def __init__(self, file_path):
        self._fd = os.open(file_path, os.O_WRONLY | os.O_CREAT | os.O_APPEND)
        logging.Handler.__init__(self)

    def emit(self, record):
        msg = "{}\n".format(self.format(record))
        os.write(self._fd, msg.encode('utf-8'))

然后同样按照上面多进程的方式并发写入, 看看会不会丢数据或者被截断

def process_log(p_off):
    logger_handler = MPFileLogHandler('/tmp/one_file_log_2.log')
    logger = logging.getLogger('test')
    logger.addHandler(logger_handler)
    logger.setLevel(logging.DEBUG)
    for x in range(0, 100):
        d = datetime.datetime.now()
        t_str = '你好test' * 2000
        logger.info('{}:{}:p_off({}):pid({})'.format(t_str, d.strftime('%Y-%m-%d %H:%M:%S'), p_off, os.getpid()))

以上通过MPFileLogHandler, 多进程并发写同一个日志文件/tmp/one_file_log_2.log

理论上日志文件的每行的长度应该是一样的, 我们校验一下

前面若干行展示如下

12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041
12041

每行数据长度一致, 并没有数据丢失, 覆盖或者截断

全部行打印时也是如此, 酸爽

总结

通过 O_APPEND 写入文件的方式, 我们自定义了一个日志handler, 实现了多进程并发写入同一个文件的操作, 而且这个过程无锁实现, 方便快捷

以上是基于个人实验, 如有错误, 欢迎指出

right