python logging日志模块在多卡训练DDP中的使用

本文参考了以下资料：

 

一. 基本使用

logging 使用非常简单，使用 basicConfig() 方法就能满足基本的使用需要，如果方法没有传入参数，会根据默认的配置创建Logger 对象，默认的日志级别被设置为 WARNING。Python 标准库 logging 用作记录日志，默认分为六种日志级别（括号为级别对应的数值），NOTSET（0）、DEBUG（10）、INFO（20）、WARNING（30）、ERROR（40）、CRITICAL（50）

输出到终端：

import logging

logging.basicConfig(format="%(asctime)s %(name)s:%(levelname)s:%(message)s", datefmt="%d-%M-%Y %H:%M:%S", level=logging.DEBUG)
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

终端上的输出结果：

 

输出到日志文件中：

import logging

logging.basicConfig(filename="test.log", filemode="w", format="%(asctime)s %(name)s:%(levelname)s:%(message)s", datefmt="%d-%M-%Y %H:%M:%S", level=logging.DEBUG)
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

日志文件test.log上的输出结果：

 

二. 同时输出到终端和日志文件中

import logging
import logging.handlers

logger = logging.getLogger(__name__)   # 新建一个logger对象, 对象名是当前模块名称
logger.setLevel(logging.DEBUG)

formatter = logging.Formatter(fmt="%(asctime)s %(name)s:%(levelname)s:%(message)s", datefmt="%d-%M-%Y %H:%M:%S")

# 设置多个标准流处理器(handler)，用于控制向不同的地方输出日志（是输出到终端，还是文件中）
handler1 = logging.StreamHandler()
handler1.setLevel(logging.DEBUG)
handler1.setFormatter(formatter)

handler2 = logging.FileHandler(filename="test.log", mode="w")  # mode="w"表示从开头开始编辑，即原有内容会被删除。mode="a"表示追加写入，即新内容会写在原有内容后面。
handler2.setLevel(logging.DEBUG)
handler2.setFormatter(formatter)

logger.addHandler(handler1)
logger.addHandler(handler2)

logger.debug('This is a debug message')
logger.info('This is an info message')
logger.warning('This is a warning message')
logger.error('This is an error message')
logger.critical('This is a critical message')

终端上的输出结果：

日志文件test.log上的输出结果：

 

三. RootLogger和子logger概念解析

RootLogger是什么？是一个python程序内全局唯一的，所有Logger对象的祖先。它是怎么产生的呢？

logger = logging.getLogger()，这个logger就是RootLogger。如果我们给getLogger传一个参数name，它会生成一个非root的Logger。

logging.getLogger()方法有一个可选参数name，该参数表示将要返回的日志器的名称标识，如果不提供该参数，则其值为'root'，得到的就是RootLogger

  • logger的名称是一个以'.'分割的层级结构，每个'.'后面的logger都是'.'前面的logger的children，例如，有一个名称为 foo 的logger，其它名称分别为 foo.bar, foo.bar.baz 和 foo.bam都是 foo 的后代。
  • logger有一个"有效等级（effective level）"的概念。如果一个logger上没有被明确设置一个level，那么该logger就是使用它parent的level;如果它的parent也没有明确设置level则继续向上查找parent的parent的有效level，依次类推，直到找到个一个明确设置了level的祖先为止。需要说明的是，root logger总是会有一个明确的level设置（默认为 WARNING）。当决定是否去处理一个已发生的事件时，logger的有效等级将会被用来决定是否将该事件传递给该logger的handlers进行处理。
  • child loggers在完成对日志消息的处理后，默认会将日志消息传递给与它们的祖先loggers相关的handlers。因此，我们不必为一个应用程序中所使用的所有loggers定义和配置handlers，只需要为一个顶层的logger配置handlers，然后按照需要创建child loggers就可足够了。我们也可以通过将一个logger的propagate属性设置为False来关闭这种传递机制。

 

四. 使用pytorch的DDP进行多卡训练时如何保证只有主进程将信息发送到控制台和日志文件

举一个例子。如下所示。

首先新建三个文件。

新建第一个文件，文件名 logger_setup.py ，文件内容如下：

import logging
import sys
import os
import time

def setup_root_logger(save_log=False, save_path=None, distributed_rank=0, level=logging.INFO):
    # if current process is not master process, we create a child logger for it,
    # and don't propagate this child logger's message to the root logger.
    # We don't create any handlers to this child logger, so that no message will be ouput from this process.
    if distributed_rank > 0: 
        logger_not_root = logging.getLogger(name=__name__) 
        logger_not_root.propagate = False
        return logger_not_root
    
    # if current process is master process, we create a root logger for it,
    # and create handlers for the root logger.
    root_logger = logging.getLogger()
    root_logger.setLevel(level)
    ch = logging.StreamHandler(stream=sys.stdout)
    ch.setLevel(level)
    formatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s: %(message)s")
    ch.setFormatter(formatter)
    root_logger.addHandler(ch)

    if save_log and save_path:
        filename = os.path.basename(save_path)
        filename = time.strftime("%Y-%m-%d_%H.%M.%S", time.localtime()) + "_" + filename
        dirname = os.path.dirname(save_path)
        fh = logging.FileHandler(os.path.join(dirname, filename), mode='w')
        fh.setLevel(level)
        fh.setFormatter(formatter)
        root_logger.addHandler(fh)
    
    return root_logger

 

新建第二个文件，文件名为 train_main.py ，文件内容如下：

from logger_setup import setup_root_logger
from example_module import example

logger = setup_root_logger(save_log=True, save_path= './', distributed_rank = 0)

def main():
    logger.info('hello')
    example()


if __name__ == '__main__':
    main()

 

新建第三个文件，文件名为 example_module.py，文件内容如下：

import logging

def example():
    logging.info("this is a example module.")

 

运行第二个文件，即运行 train_main.py，然后，在控制台终端可以看到如下内容：

同时在同级目录下会生成一个名为 2023-03-27_15.15.26_test_new.log 的log文件，文件内容如下：

通过logger_setup.py的设置，即使是用多卡进行训练，也只有主卡的消息会被输出。

 

posted @ 2022-03-23 10:56  Picassooo  阅读(1197)  评论(0)    收藏  举报