python最重要的模块logging

logging模块

这个模块是目前最重要的模块！！！我一定给讲透彻一点

很多程序都有记录日志的需求，并且日志中包含的信息即有正常的程序访问日志，还可能有错误、警告等信息输出，python中的logging模块提供了标准的日志接口，你可以通过它存储各种级别的日志，Logging的日志可以分为以下5个级别：

• debug():调试模式,出问题了需要调试,方便调试
• info():普通的记录,没错误,例如:某某登陆了访问了哪个界面
• warning():没有发生错误,但是有可能有潜在的问题
• error():出问题了
• critical():很严重的那种

注意:windows电脑中的字符编码时GBK,所以在日志文件中,如果出现乱码,请修改编码为GBK

最简单用法,将日志信息输出到屏幕(终端)

import logging

# 将下面3条日志信息输出到屏幕(不是我说的输出到屏幕,是默认输出到屏幕)
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

# 运行结果如下
ERROR:root:this is error info
CRITICAL:root:this is critical info

# 问题1.想想root代表的是什么?
root代表这个程序默认是以root用户执行的

# 问题2.为什么我输出3条日志消息,却输出到屏幕两条?
答案在下面,请继续看

那么?就光光只能把日志信息输出到屏幕吗,我想输出到文件里哎,怎么办呢?不要着急,我告诉你怎么办:

import logging  # 导入logging这个模块

logging.basicConfig(  # logging.basicConfig表示给这个日志文件加一个配置,以后往文件里输就可以了
    filename = 'logging练习.log',  # 要往这个文件里面输入日志
    level = logging.DEBUG,  # 设置级别,大于等于DEBUG级别的才会输出到文件中
    format = '%(asctime)s %(message)s',  # 日志的格式
    datefmt = '%m/%d/%Y %I:%M:%S %p'  # 时间的格式
)  # 整体表示打开这个文件

logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

那么此时就会在当面路径下产生一个"logging练习.log"的文件,文件中赫赫的写着以下内容:
05/15/2018 10:23:27 PM this is debug info  # 由asctime和message组成
05/15/2018 10:23:27 PM this is error info
05/15/2018 10:23:27 PM this is critical info

那么那么,如果这个程序我再运行一下会怎么样呢?实话告诉你吧,只会去追加而不会覆盖,哪有日志刚写入就被覆盖的呢?

此时,你的同事提出了一个需求:日志的级别我想用数字来代替,天天没事就给我输出个error,就和我开玩笑样,我不想看见它,就用数字来代替吧(error级别代表已经出问题了,这上级也不想去修服务器),你给我实现它,然后你就找到了我,我就告诉你是怎么实现的:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s %(levelno)s %(message)s',  # 此时你的输出格式改成了这个样子,让我们看看效果吧
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)

# 同样还是输入3条日志信息
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

那么在"logging练习.log"文件中表现是这个样子的:
05/15/2018 10:34:04 PM 10 this is debug info
05/15/2018 10:34:04 PM 40 this is error info
05/15/2018 10:34:04 PM 50 this is critical info

好了,你的上级放心了,error不会再输出了,你的同事安心的去吃鸡了.
终于get到了,原来%(levelno)s代表的是数字显示形式的显示日志级别

......过了一个月......

突然有一天早上你去上班,发现开发炸开了锅,打听了才了解,他们的服务器宕机了,而且查日志竟然没问题,这时候你的同事偷偷的跑过来说:飞哥,快去给日志的格式换回来,我老老实实的去修服务器就好了吧,可是一个月之前的东西了怎么能记住呢?然后你上百度找到了这个说法:%(levelname)s表示文本形式的显示日志级别,你迫不及待的给%(levelno)s删了,代码是这样的:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s %(levelname)s %(message)s',  # 修改了格式
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)

# 输出3条日志消息到文件中
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

此时你的日志文件已经恢复过来了,输出到文件是这个样子的:
05/15/2018 10:43:43 PM DEBUG this is debug info
05/15/2018 10:43:43 PM ERROR this is error info
05/15/2018 10:43:43 PM CRITICAL this is critical info

你的同事这种行为终究被查了出来,你的同事不幸的被辞掉,而你也扣了一年的奖金,过了两天,认识又帮你招了一个运维,运维刚来的什么都不懂,看了看日志文件说:飞哥呀,我新来的,还不知道这个日志文件(logging练习.log)是哪个程序运行的呀,你能告诉我吗?你说,没问题,刷刷刷写了几行代码:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s %(pathname)s %(message)s',  # 修改称为%(pathname)s
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)

# 输出3条日志消息到文件中
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

此时输出到文件中的日志长这个样子:
05/15/2018 10:50:05 PM D:/py_study/day14-subprocess模块开始/logging练习.py this is debug info
05/15/2018 10:50:05 PM D:/py_study/day14-subprocess模块开始/logging练习.py this is error info
05/15/2018 10:50:05 PM D:/py_study/day14-subprocess模块开始/logging练习.py this is critical info

你的同事说:原来是这个程序在运行不断的输出日志到文件中啊,这个%(pathname)s好神奇呀,打印出来调用日志输出函数的模块的完整路径名,膜拜膜拜.

在你仰慕你飞哥的时候,突然想到一个问题,有没有情况可能不会输出路径名的呢?飞哥装逼的清了清嗓子,当然有,如果在交互器下就没有,你迫不及待的尝试下果然就没有:

05/15/2018 10:55:38 PM logging练习.py this is debug info
05/15/2018 10:55:38 PM logging练习.py this is error info
05/15/2018 10:55:38 PM logging练习.py this is critical info

然后,你的同事不经意的问了一下:那能不能不打印路径,只打印文件名呢?你啪唧的一下懵逼了,但还是很装逼的说,有!(此时的内心活动是:虽然我不知道,但是不装逼我很难受,晚上不睡觉我也给你找到)

结果经过一夜的奋战,第二天到了公司,立马给你同事叫过来,来来来,我和你说怎么写,你拿出了熬了一夜写出的代码:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s %(module)s %(message)s',  # 这里改了%(module)s
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)

# 输出3条日志消息到文件中
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

打印到文件中是这个样子的:
05/15/2018 11:02:21 PM logging练习 this is debug info
05/15/2018 11:02:21 PM logging练习 this is error info
05/15/2018 11:02:21 PM logging练习 this is critical info

你那可爱的同事,看了半天代码没发生任何改变,你仙人一指,那xxx行的%(pathname)s不是改成了%(module)s了嘛?同事恍然大悟,原来%(module)s就是调用日志输出函数的模块名呀.

同事昨晚睡的并不好,迷迷糊糊的在这个代码中添加了一个函数,代表:每次输出日志到文件中的时候都要和他打招呼,但是他写了之后不知道怎么把函数里的问候打印出来,也运行了呀也运行了怎么不行呢,然后就跑过去问你了,以下是他写的函数代码:

def sayhi():
    print('hello,西楚霸王')  # 问候

sayhi()  # 执行

此时你刚好泡了一杯茶在你的办公桌上,看到你的同事跑了过来,问他怎么了,他就和你说了,你笑了笑,说,小case,看我帮你解决:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s %(funcName)s %(message)s',  # 修改成了%(funcName)s
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)
def sayhi():
    logging.error('hello,西楚霸王')

sayhi()

# 输出3条日志消息到文件中
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

此时输出到日志文件中是这样的
05/15/2018 11:13:04 PM sayhi hello,西楚霸王  # 函数名 + 日志输出的东西
05/15/2018 11:13:04 PM <module> this is debug info
05/15/2018 11:13:04 PM <module> this is error info
05/15/2018 11:13:04 PM <module> this is critical info

于是,你就改口喊你的同事称西楚霸王了,但是是如何修改的呢?那就是%(funcName)s,它代表的意思就是调用日志输出的函数的函数名

此时你发现,logging.error('hello,西楚霸王')这个是error,表示出问题了,输出的3条日志消息也是debug,error,critical,但就不知道问题出在哪一行,回去翻了翻python-book,找到了答案:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s %(funcName)s - %(lineno)d %(message)s',  # 添加了%(lineno)d
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)
def sayhi():
    logging.error('hello,西楚霸王')

sayhi()

# 输出3条日志消息到文件中
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

输出到日志文件中是这样的:
05/15/2018 11:20:39 PM sayhi - 16 hello,西楚霸王
05/15/2018 11:20:39 PM <module> - 21 this is debug info
05/15/2018 11:20:39 PM <module> - 22 this is error info
05/15/2018 11:20:39 PM <module> - 23 this is critical info

哪行出错了,就给所在的哪行打印出来,你的领导看见了你如此刻苦给你发了个20块的红包,并告诉你:给我买包烟去~~~

哈哈笑死我了

原来%(lineno)d就是表示调用日志输出函数的语句所在的代码行

下一个:%(process)d表示进程ID,示范代码如下:

import logging

logging.basicConfig(
    filename = 'logging练习.log',
    level = logging.DEBUG,
    format = '%(asctime)s  %(lineno)d %(message)s - - %(process)d',
    datefmt = '%m/%d/%Y %I:%M:%S %p'
)
def sayhi():
    logging.error('hello,西楚霸王')

sayhi()

# 输出3条日志消息到文件中
logging.debug('this is debug info')
logging.error('this is error info')
logging.critical('this is critical info')

输出到日志文件中是这样的,其中2404代表的是进程ID
05/15/2018 11:27:09 PM  16 hello,西楚霸王 - - 2404
05/15/2018 11:27:09 PM  21 this is debug info - - 2404
05/15/2018 11:27:09 PM  22 this is error info - - 2404
05/15/2018 11:27:09 PM  23 this is critical info - - 2404

好了,实在编不下去了,大致说下下面几个不常用的:

• %(created)f,代表当前时间,用UNIX标准的表示时间的浮点数表示
• %(relativeCreated)d,代表输出日志信息时,自logger创建以来的毫秒数
• %(thread)d,线程ID,可能没有
• %(threadName)s,线程名,可能没有
• %(message)s,用户输入的消息

以上都是logging模块的基础部分,请认真学习!

logging模块高级部分

此时提出一个需求：让日志文件同时输出到文件和屏幕中，怎么办？

如果想达到这个效果，那么简单的输出日志就实现不了了，就需要了解一些复杂的知识了。

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

• logger,记录器，提供了应用程序可以直接使用的接口；
• handler，处理器，将(logger创建的)日志记录发送到合适的目的输出；
• filter，过滤器，提供了过滤来决定输出哪条日志记录
• formatter，格式化器，决定日志记录的最终输出格式

logger组件

每个程序在输出信息之前，都要获得一个logger。logger通常对应了程序的模块名，比如聊天工具的图形界面模块可以这样获得它的logger：

logger = logging.getLogger('chat.gui')

而核心模块可以这样：

logger = logging.getLogger('chat.kernel')

简单的说就是给这个logger起一个名字。

还可以绑定handler和filter

logger.setLevel(level)：指定最低的日志级别，低于level的级别都会被忽略。DEBUG是最低，CRITICAL是最高。
logger.addFilter(filter),logger.removeFilter(filter)：增加或删除指定的filter。
logger.addHandler(hdlr),logger.removeHandler(hdlr)：增加或删除指定的handler。

handler组件

handler对象负责发送相关的信息到指定目的地，python日志系统有多种handler可以使用，有些handler可以把信息输出到控制台，有些handler可以把信息输出到文件， 还有些handler可以把信息发送到网络上。如果觉得不够用，还可以编写自己的handler，可以通过addHandler()方法添加多个handler。

handler.setLevel(level)：指定被处理的信息级别，低于level级别的信息将被忽略。
handler.setFormatter():给handler设置一个格式。
handler.addFilter(filter),handler.remove(filter)：新增或删除一个filter对象。

每个logger都可以附加多个handler。接下来介绍下常用的handler：

1. logging.StreamHandler:使用这个handler可以向类似与sys.stdout或者sys.stderr的任何文件对象输出信息
2. logging.FileHandler：和StreamHandler类似，用于向一个文件输出日志信息，不过FileHandler会帮你打开这个文件

formatter组件

日志的formatter是个独立的组件，可以跟Handler组合
fh = logging.FileHandler('access.log')
formatter = logging.formatter('%(asctime)s-%(name)s-%(levelname)s-%(message)s')
fh.setFormatter(fotmatter) # 把formatter绑定到fh上

filter组件

如果你想对日志文件进行过滤，就可以自定义一个filter

class filter_test(logging.Filter):
    ''' 忽略带有db backup的日志'''
    def filter(self,record):
        return "db backup" not in record.getMessage()

注意filter函数会返回True和False，logger根据此值决定是否输出日志

然后把这个filter添加到logger中

logger.addFilter(filter_test())

那么下面的日志就会把符合filter条件的过滤掉

logger.debug("test ....")
logger.info("test info ....")
logger.warning("start to run db backup job ....")
logger.error("test error ....")

现在开始写一个同时输出到屏幕和文件的例子,按照国际惯例一步一步来，先打好框架

import logging  # 导入logging模块

# 1.创建logger


# 2.创建handler


# 3.创建formatter

第一步，创建logger对象

# 1.创建logger
logger = logging.getLogger('web')  # 创建一个叫web的logger
# 1.1设置全局输出日志的等级
logger.setLevel(logging.DEBUG)  # 允许DEBUG及以上级别的日志输出

第二步，创建handler对象

# 2.创建handler
# 2.1屏幕handler
screen = logging.StreamHandler()
# 2.2文件handler
file = logging.FileHandler('web.log')  # 日志都输出到web.log中

第三步，创建formatter对象

# 3.创建formatter
# 3.1创建输出到屏幕的格式
screen_formatter = logging.Formatter('%(asctime)s -- %(lineno)s -- %(message)s')
# 3.2创建输出到文件的格式
file_formatter = logging.Formatter('%(asctime)s -- %(name)s -- %(levelname)s -- %(message)s')

第四步，开始输出

# 这个为要输出的日志
logger.debug('this is DEBUG ingo')
logger.info('this is INFO ingo')
logger.warning('this is WARNING ingo')
logger.error('this is error ingo')

运行以下试试看

此时屏幕中输出为：
this is WARNING ingo
this is error ingo

文件中输出为：空

此时我们发现，我们想要的结果和打印出来的结果不是一样的，这是啥原因？那么我们就可以想到是因为没有格式，刚刚我们说formatter是可以和handler结合的，但是怎么结合呢？

# 4.绑定handler
screen.setFormatter(screen_formatter)
file.setFormatter(file_formatter)

那么我们绑定之后，再运行下看看打印什么，我可以准确的和你说，和刚刚的结果是一样的

此时屏幕中输出为：
this is WARNING ingo
this is error ingo

文件中输出为：空

为什么？

看看上面讲几个组件的作用，formatter对象主要用于输出日志的格式，handler对象负责发送相关的信息到指定目的地，理论上没有错误，有了格式formatter，有了发送信息的handler，那么我问你，在最前面我们创建logger对象的作用是什么?每个程序在输出信息之前，都要获得一个logger。那么这是那种操作呢？

# 5.绑定logger
logger.addHandler(screen)
logger.addHandler(file)

运行结果

# 屏幕上
2018-05-16 14:20:58,848 -- 41 -- this is DEBUG ingo
2018-05-16 14:20:58,849 -- 42 -- this is INFO ingo
2018-05-16 14:20:58,849 -- 43 -- this is WARNING ingo
2018-05-16 14:20:58,849 -- 44 -- this is error ingo

# 文件中
2018-05-16 14:20:58,848 -- web -- DEBUG -- this is DEBUG ingo
2018-05-16 14:20:58,849 -- web -- INFO -- this is INFO ingo
2018-05-16 14:20:58,849 -- web -- WARNING -- this is WARNING ingo
2018-05-16 14:20:58,849 -- web -- ERROR -- this is error ingo

这个完整代码是这样的:

import logging  # 导入logging模块

# 1.创建logger
logger = logging.getLogger('web')  # 创建一个叫web的logger
# 1.1设置全局输出日志的等级
logger.setLevel(logging.DEBUG)  # 允许DEBUG及以上级别的日志输出

# 2.创建handler
# 2.1屏幕handler
screen = logging.StreamHandler()
# 2.2文件handler
file = logging.FileHandler('web.log')  # 日志都输出到web.log中

# 2.3设置输出到屏幕和文件的等级
# screen.setLevel(logging.INFO)
# file.setLevel(logging.WARNING)

# 3.创建formatter
# 3.1创建输出到屏幕的格式
screen_formatter = logging.Formatter('%(asctime)s -- %(lineno)s -- %(message)s')
# 3.2创建输出到文件的格式
file_formatter = logging.Formatter('%(asctime)s -- %(name)s -- %(levelname)s -- %(message)s')


# 4.绑定handler
screen.setFormatter(screen_formatter)
file.setFormatter(file_formatter)


# 5.绑定logger
logger.addHandler(screen)
logger.addHandler(file)

logger.debug('this is DEBUG ingo')
logger.info('this is INFO ingo')
logger.warning('this is WARNING ingo')
logger.error('this is error ingo')

现在还有一个filter组件没有说，为什么呢，因为平时用的是很少，那我们也看看吧

# 定义一个类,类名可以随便，写法固定
class filter_test(logging.Filter):
    '''用来过滤 this is 的日志'''
    def filter(self, record):
        return "this is" not in record.getMessage()  # record.getMessage()获取日志输出的信息

和logger对象绑定

# 6.绑定filter
logger.addFilter(filter_test())

运行结果是：

输出到文件:空
输出到屏幕：空

因为我们把它给过滤掉了，换成这个试一下：

logger.debug('thisis DEBUG ingo')
logger.info('thisis INFO ingo')
logger.warning('thisis WARNING ingo')
logger.error('thisis error ingo')

运行结果为：
2018-05-16 14:44:29,335 -- 47 -- thisis DEBUG ingo
2018-05-16 14:44:29,336 -- 48 -- thisis INFO ingo
2018-05-16 14:44:29,336 -- 49 -- thisis WARNING ingo
2018-05-16 14:44:29,336 -- 50 -- thisis error ingo

文件中:
2018-05-16 14:44:29,335 -- web -- DEBUG -- thisis DEBUG ingo
2018-05-16 14:44:29,336 -- web -- INFO -- thisis INFO ingo
2018-05-16 14:44:29,336 -- web -- WARNING -- thisis WARNING ingo
2018-05-16 14:44:29,336 -- web -- ERROR -- thisis error ingo

大功告成！

日志的分割

• 按照文件大小的切割
• 按照时间间隔的切割

按照文件大小的切割logging.handlers.RotatingFileHandler

这个handler类似于FileHandler，但是它可以管理文件大小。当文件达到一定大小之后，它会自动将当前日志文件改名，然后创建一个新的同名日志文件继续输出。比如日志的文件是web.log,那么当web.log到达指定大小后，RotatingFileHandler会自动把文件名改为web.log.1，如果web.log.1存在，那么就会创建web.log.2......最后创建web.log，所以web.log文件是最新的日志，它的函数是：

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

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

• msxBytes用于指定日志文件的最大文件大小。如果maxBytes为0，意味着日志文件可以无限大，这时上面描述的重命名过程就不会发生
• backupCount用于指定保留的文件的备份的个数，如果指定的是2，当上面的重命名过程发生时,web.log.2就不会改名，而是被直接删除

代码演示:

import logging  # 导入logging模块
from logging import handlers

# 1.创建logger
logger = logging.getLogger('web')  # 创建一个叫web的logger
# 1.1设置全局输出日志的等级
logger.setLevel(logging.DEBUG)  # 允许DEBUG及以上级别的日志输出

# 2.按照文件大小去切割
log_file = '按照文件大小切割.log'
file = handlers.RotatingFileHandler(filename=log_file,maxBytes=100,backupCount=3)  # 最大字节为100，备份文件为3份
# 3.创建formatter
# 3.1创建输出到文件的格式
file_formatter = logging.Formatter('%(asctime)s -- %(name)s -- %(levelname)s -- %(message)s')

# 4.绑定handler
file.setFormatter(file_formatter)

# 5.绑定logger对象
logger.addHandler(file)

logger.debug('this is DEBUG ingo')
logger.info('this is INFO ingo')
logger.warning('this is WARNING ingo')
logger.error('this is error ingo')

在这里就不打印文件效果了，有兴趣的可以直接复制过去看看

按照时间间隔的切割logging.handlers.TimedRotatingFileHandler

这个hanlder和RotatingFileHandler类似，不过，它没有判断文件大小来决定何时重新创建日志文件，而是间隔一定时间就自动创建新的日志文件。重命名的过程与RotatingFileHandler类似，不过新的文件不是附加数字，而是当前时间，它的函数是：

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

其中，filename参数和backupCount参数和RotatingFileHandler具有相同的意义
interval表示时间间隔
when参数代表的是一个字符串，表示时间建个单位，不区分大小写

• S:秒
• M：分
• H：小时
• D：天
• W：每星期（interval==0代表星期一）
• midnight：每天凌晨

# 代码并无多大改动
import logging  # 导入logging模块
from logging import handlers

# 1.创建logger
logger = logging.getLogger('web')  # 创建一个叫web的logger
# 1.1设置全局输出日志的等级
logger.setLevel(logging.DEBUG)  # 允许DEBUG及以上级别的日志输出

# 2.按照文件大小去切割
log_file = '按照文件大小切割.log'
file = handlers.TimedRotatingFileHandler(filename=log_file,when='S',interval=5,backupCount=3)
# 3.创建formatter
# 3.1创建输出到文件的格式
file_formatter = logging.Formatter('%(asctime)s -- %(name)s -- %(levelname)s -- %(message)s')


# 4.绑定handler
file.setFormatter(file_formatter)


# 5.绑定logger对象
logger.addHandler(file)


logger.debug('this is DEBUG ingo')
logger.info('this is INFO ingo')
logger.warning('this is WARNING ingo')
logger.error('this is error ingo')