python logging 日志多进程并发写单文件

󰃭 2017-05-16

原创作品：首发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)

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

事实上并非如此, 这就说明使用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

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

前面若干行展示如下

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

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

总结

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

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