目录

Python3之logging模块浅析

很多程序都有记录日志的需求，并且日志中包含的信息即有正常的程序访问日志，还可能有错误、警告等信息输出，python的logging模块提供了标准的日志接口，你可以通过它存储各种格式的日志，logging的日志可以分为 debug(), info(), warning(), error() and critical()5个级别，下面我们看一下怎么用。

简单用法

• 在控制台进行显示 logging.info('xxxxx') 有以下五个级别：debug、info、warning、error、critical

import logginglogging.warning("warning:user/passwd is invalid")logging.critical("critical:server is down")

• 在日志中输出 logging.basicConfig()，日志级别同样是有五个

import logginglogging.basicConfig(filename='access.log',level=logging.INFO,format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') #basicConfig 方法对日志进本信息进行配置，文件名、日志级别、输出格式等，但必须以key-value形式使用logging.debug('This message should go to the log file?') # 由于上面已经将日志级别设置为INFO，故低于INFO的不会被打印logging.info('So should this')logging.warning('And this, too')

format自定义格式，下表中均支持

%(name)s	Logger的名字
%(levelno)s	数字形式的日志级别
%(levelname)s	文本形式的日志级别
%(pathname)s	调用日志输出函数的模块的完整路径名，可能没有
%(filename)s	调用日志输出函数的模块的文件名
%(module)s	调用日志输出函数的模块名
%(funcName)s	调用日志输出函数的函数名
%(lineno)d	调用日志输出函数的语句所在的代码行
%(created)f	当前时间，用UNIX标准的表示时间的浮 点数表示
%(relativeCreated)d	输出日志信息时的，自Logger创建以 来的毫秒数
%(asctime)s	字符串形式的当前时间。默认格式是 “2003-07-08 16:49:45,896”。逗号后面的是毫秒
%(thread)d	线程ID。可能没有
%(threadName)s	线程名。可能没有
%(process)d	进程ID。可能没有
%(message)s	用户输出的消息

日志与控制台同时输出

Python 使用logging模块记录日志涉及四个主要类，使用官方文档中的概括最为合适：

• logger提供了应用程序可以直接使用的接口；
• handler将(logger创建的)日志记录发送到合适的目的输出；
• filter提供了细度设备来决定输出哪条日志记录；
• formatter决定日志记录的最终输出格式

一个同时输出到屏幕、文件的完成例子

可按以下步骤进行创建

1. 生成logger对象
2. 生成handler 对象
3. 把handler 对象绑定到logger对象
4. 生成formatter 对象
5. 将formatter对象绑定到handler对象

实现代码如下：

# -*- coding:utf-8 -*-import loggingdef logger(log_obj):    logger = logging.getLogger(log_obj)    logger.setLevel(logging.INFO)    console_handle = logging.StreamHandler()    log_file = "access.log"    file_handle = logging.FileHandler(log_file)    file_handle.setLevel(logging.WARNING)    formatter = logging.Formatter(        '%(asctime)s - %(name)s - %(levelname)s - %(message)s')    console_handle.setFormatter(formatter)    file_handle.setFormatter(formatter)    logger.addHandler(console_handle)    logger.addHandler(file_handle)    return logger

日志文件截取

• 按照大小截取
  logging.handlers.RotatingFileHandler()
  当文件达到一定大小之后，它会自动将当前日志文件改名，然后创建 一个新的同名日志文件继续输出。比如日志文件是chat.log。当chat.log达到指定的大小之后，RotatingFileHandler自动把 文件改名为chat.log.1。不过，如果chat.log.1已经存在，会先把chat.log.1重命名为chat.log.2。。。最后重新创建 chat.log，继续输出日志信息。它的函数是：

RotatingFileHandler( filename[, mode[, maxBytes[, backupCount]]])

其中filename和mode两个参数和FileHandler一样。

maxBytes用于指定日志文件的最大文件大小。如果maxBytes为0，意味着日志文件可以无限大，这时上面描述的重命名过程就不会发生。

backupCount用于指定保留的备份文件的个数。比如，如果指定为2，当上面描述的重命名过程发生时，原有的chat.log.2并不会被更名，而是被删除。

• 按照时间截取
  logging.handlers.TimedRotatingFileHandler()
  这个Handler和RotatingFileHandler类似，不过，它没有通过判断文件大小来决定何时重新创建日志文件，而是间隔一定时间就 自动创建新的日志文件。重命名的过程与RotatingFileHandler类似，不过新的文件不是附加数字，而是当前时间。它的函数是：

TimedRotatingFileHandler( filename [,when [,interval [,backupCount]]])

其中filename参数和backupCount参数和RotatingFileHandler具有相同的意义。

interval是时间间隔。

when参数是一个字符串。表示时间间隔的单位，不区分大小写。它有以下取值：

S 秒

M 分

H 小时

D 天

W 每星期（interval==0时代表星期一）

midnight 每天凌晨

• 代码实现如下:

# -*- coding:utf-8 -*-import loggingfrom logging import handlerslogger = logging.getLogger(__name__)log_file_size = "sizelog.log"log_file_time = "timelog.log"file_handler_size = logging.handlers.RotatingFileHandler(filename=log_file_size,maxBytes=10,backupCount=3)file_handler_time = logging.handlers.TimedRotatingFileHandler(filename=log_file_time,when="S",interval=5,backupCount=3)formatter = logging.Formatter('%(asctime)s %(module)s:%(lineno)d %(message)s')file_handler_size.setFormatter(formatter)file_handler_time.setFormatter(formatter)logger.addHandler(file_handler_size)logger.addHandler(file_handler_time)logger.warning("test1")logger.warning("test12")logger.warning("test13")logger.warning("test14")

日志重复打印问题解决

• 以下内容根据同学分享内容进行整理

在python中函数编程可以大大的减少重复代码量，在打印日志时，为避免重复造轮子，可使用创建log函数进行调用。

# -*- coding:utf-8 -*-import loggingdef my_logger(log_obj):    print(logging._handlerList)    logger = logging.getLogger(log_obj)    logger.setLevel(logging.INFO)    console_handle = logging.StreamHandler()    formatter = logging.Formatter(        '%(asctime)s - %(name)s - %(levelname)s - %(message)s ')    console_handle.setFormatter(formatter)    logger.addHandler(console_handle)    return loggerif __name__ == '__main__':    my_logger('access').error('say 1 ')    my_logger('access').error('say 2 ')    my_logger('access').error('say 3 ')

恩就这样定义好了一个log 函数，那我们来执行一下：

2018-06-24 13:25:54,411 - access.log - ERROR - say 1  2018-06-24 13:25:54,412 - access.log - ERROR - say 2  2018-06-24 13:25:54,412 - access.log - ERROR - say 2  2018-06-24 13:25:54,412 - access.log - ERROR - say 3  2018-06-24 13:25:54,412 - access.log - ERROR - say 3  2018-06-24 13:25:54,412 - access.log - ERROR - say 3

What's the fuck！为什么日志输出依次递增!

问题分析

实际上logger = logging.getLogger(log_obj)在执行时，没有每次生成一个新的logger，而是先检查内存中是否存在一个叫做‘log_obj’的logger对象，存在则取出，不存在则新建。

• 实例化的logger对象具有‘handlers’这样一个属性来存储,我们打印看看存储的是什么信息

# -*- coding:utf-8 -*-import loggingdef my_logger(log_obj):        logger = logging.getLogger(log_obj)    print(logger.handlers)     logger.setLevel(logging.INFO)    console_handle = logging.StreamHandler()    formatter = logging.Formatter(        '%(asctime)s - %(name)s - %(levelname)s - %(message)s ')    console_handle.setFormatter(formatter)    logger.addHandler(console_handle)    return loggerif __name__ == '__main__':    my_logger('access').error('say 1 ')    my_logger('access').error('say 2 ')    my_logger('access').error('say 3 ')

[]2018-06-24 13:44:47,239 - access.log - ERROR - say 1  [
    
     
       (NOTSET)>]2018-06-24 13:45:22,597 - access.log - ERROR - say 2  2018-06-24 13:45:22,597 - access.log - ERROR - say 2  [
      
       
         (NOTSET)>, 
        
         
           (NOTSET)>]2018-06-24 13:45:32,877 - access.log - ERROR - say 3 2018-06-24 13:45:32,877 - access.log - ERROR - say 3 2018-06-24 13:45:32,877 - access.log - ERROR - say 3
         
        
       
      
     
    

从结果中可以看出：

1. logger.handlers最初是一个空列表，执行logger.addHandler(console_handle)添加一个StreamHandler，输出一条日志
2. 在第二次被调用时，logger.handlers已经存在一个StreamHandler，再次执行logger.addHandler(console_handle)就会再次添加一个StreamHandler，此时的logger有两个个StreamHandler，输出两条重复的日志
3. 在第三次被调用时，logger.handlers已经存在两个StreamHandler，再次执行logger.addHandler(console_handle)就会再次添加一个，此时的logger有三个StreamHandler，输出三条重复的日志

解决方案

1.使用不同的日志对象

# -*- coding:utf-8 -*-import loggingdef my_logger(log_obj):        logger = logging.getLogger(log_obj)    print(logger.handlers)     logger.setLevel(logging.INFO)    console_handle = logging.StreamHandler()    formatter = logging.Formatter(        '%(asctime)s - %(name)s - %(levelname)s - %(message)s ')    console_handle.setFormatter(formatter)    logger.addHandler(console_handle)    return loggerif __name__ == '__main__':    my_logger('access1').error('say 1 ')    my_logger('access2').error('say 2 ')    my_logger('access3').error('say 3 ')

运行结果：

2018-06-24 13:51:33,084 - access1 - ERROR - say 1  2018-06-24 13:51:33,084 - access2 - ERROR - say 2  2018-06-24 13:51:33,085 - access3 - ERROR - say 3

2.及时清理（logger.handlers.clear）

# -*- coding:utf-8 -*-import loggingdef my_logger(log_obj):    logger = logging.getLogger(log_obj)        logger.handlers.clear()    #print(logger.handlers)    logger.setLevel(logging.INFO)    console_handle = logging.StreamHandler()    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s ')    console_handle.setFormatter(formatter)    logger.addHandler(console_handle)    return loggerif __name__ == '__main__':    my_logger('access').error('say 1 ')    my_logger('access').error('say 2 ')    my_logger('access').error('say 3 ')

运行结果如下:

2018-06-24 13:56:38,357 - access - ERROR - say 1  2018-06-24 13:56:38,358 - access - ERROR - say 2  2018-06-24 13:56:38,358 - access - ERROR - say 3

还有一种通过清理handler的方法但是兼容性较差

# 这种写法下的可以使用removeHandler方法或logger.handlers.pop()(logger.handlers.clear也可以使用在这种写法的函数内)# -*- coding:utf-8 -*-import loggingdef my_logger(log_obj, msg):    logger = logging.getLogger(log_obj)    #print(logger.handlers)    logger.setLevel(logging.INFO)    console_handle = logging.StreamHandler()    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s ')    console_handle.setFormatter(formatter)    logger.addHandler(console_handle)    logger.error(msg)    logger.removeHandler(console_handle)    return loggerif __name__ == '__main__':    my_logger('access', 'say 1')    my_logger('access', 'say 2')    my_logger('access', 'say 3')

运行结果：

2018-06-24 14:02:08,390 - access - ERROR - say 1 2018-06-24 14:02:08,390 - access - ERROR - say 2 2018-06-24 14:02:08,390 - access - ERROR - say 3

3.使用前先判断是否有相同的handler对象

# -*- coding:utf-8 -*-import loggingdef my_logger(log_obj):    logger = logging.getLogger(log_obj)    logger.setLevel(logging.INFO)    # 判断logger是否已经添加过handler，是则直接返回logger对象，否则执行handler设定以及addHandler(console_handle)    if not logger.handlers:        console_handle = logging.StreamHandler()        formatter = logging.Formatter(            '%(asctime)s - %(name)s - %(levelname)s - %(message)s ')        console_handle.setFormatter(formatter)        logger.addHandler(console_handle)    return loggerif __name__ == '__main__':    my_logger('access').error('say 1')    my_logger('access').error('say 2')    my_logger('access').error('say 3')

总结：

第一次遇到这个问题的时候，没有找到原因，使用了创建多个日志对象的方法解决了问题，现在通过同学的分享已经搞清楚日志重复的原因：多次增加了相同的handler对象。

以后定要多积累，多请教。

---

参考内容：