为什么使用日志

使用日志来看程序的输入，相比于print，多了一个层级的概念。并且可以将不同层级的日志信息，进行不同的处理。比如正常的debug信息，就可以正常记录到log文件中，供以后日志挖掘使用。critical级别的可能就需要发送一封邮件给运维人员，及时提醒。

日志的级别

日志一共分成5个等级，从低到高分别是：DEBUG INFO WARNING ERROR CRITICAL。

DEBUG：详细的信息,通常只出现在诊断问题上
INFO：确认一切按预期运行
WARNING：一个迹象表明,一些意想不到的事情发生了,或表明一些问题在不久的将来(例如。磁盘空间低”)。这个软件还能按预期工作。
ERROR：更严重的问题,软件没能执行一些功能
CRITICAL：一个严重的错误,这表明程序本身可能无法继续运行

默认的是WARNING，当在WARNING或之上时才被跟踪。

开发应用程序或部署开发环境时，可以使用DEBUG或INFO级别的日志获取尽可能详细的日志信息来进行开发或部署调试；
应用上线或部署生产环境时，应该使用WARNING或ERROR或CRITICAL级别的日志来降低机器的I/O压力和提高获取错误日志信息的效率。
日志级别的指定通常都是在应用程序的配置文件中进行指定的。

logging模块的简单使用

打印日志信息到屏幕上

这其实是开发过程中，最简单的一项需求。并且可以通过这个取代print。

import logging

logging.debug('debug message')
logging.info('info message')
logging.warning('warning message')
logging.critical('citical message')
logging.error('error message')

输出为：

1
2
3

WARNING:root:warning message
CRITICAL:root:citical message
ERROR:root:error message

可以看到只用warning以上的日志被打印出来了，而且默认的日志格式为：

1	日志级别：Logger名称：用户输出消息。

打印日志到文件中

一般详细的日志都会存入日志文件中，本次实现需要另外开启一个python解释器。


import logging

logging.basicConfig(level=logging.DEBUG,  
                    format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s',  
                    datefmt='%a, %d %b %Y %H:%M:%S',  
                    filename='test.log',  
                    filemode='w')  

logging.debug('debug message')
logging.info('info message')
logging.warning('warning message')
logging.critical('citical message')
logging.error('error message')

下面执行

cat test.log

可以得到日志的输出

一, 02 10 2017 16:47:19 test.py[line:17] DEBUG debug message
一, 02 10 2017 16:47:19 test.py[line:18] INFO info message
一, 02 10 2017 16:47:19 test.py[line:19] WARNING warning message
一, 02 10 2017 16:47:19 test.py[line:20] CRITICAL citical message
一, 02 10 2017 16:47:19 test.py[line:21] ERROR error message

下面有几点basicConfig参数说明：
level：只用大于等于日志级别的日志才会被处理
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用户输出的消息

datefmt：时间的格式

打印日志既到屏幕上又打印到文件中

这就需要引入logger对象的概念，实际上原先直接使用logging是相当远使用一个默认的logger，名字为root。所以原先两次实验，需要使用两个python解释器来分别执行，因为都是使用了一个root的logger。

import logging

# 第一步，创建一个logger
logger = logging.getLogger()
logger.setLevel(logging.DEBUG) # logger的总开关，只有大于Debug的日志才能被logger对象处理


# 第二步，创建一个handler，用于写入日志文件  
file_handler = logging.FileHandler('test.log',mode='w')
file_handler.setLevel(logging.INFO) # 输出到file的log等级的开关
# 创建该handler的formatter
file_handler.setFormatter(
        logging.Formatter(
                fmt='%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s',
                datefmt='%Y-%m-%d %H:%M:%S')
        )
# 添加handler到logger中
logger.addHandler(file_handler)

# 第三步，创建一个handler，用于输出到控制台
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.CRITICAL) # 输出到控制台的log等级的开关
# 创建该handler的formatter
console_handler.setFormatter(
        logging.Formatter(
                fmt='%(asctime)s - %(levelname)s: %(message)s',
                datefmt='%Y-%m-%d %H:%M:%S')
        )
logger.addHandler(console_handler)

#日志
logger.debug('this is a logger debug message')  
logger.info('this is a logger info message')  
logger.warning('this is a logger warning message')  
logger.error('this is a logger error message')  
logger.critical('this is a logger critical message')

所以使用logger对象可以分为几个步骤：先创建一个logger对象，并指定其level，否则默认为warning。然后再创建需要的handler对象，并设置level和format，然后添加到logger对象中。

logging库采取了模块化的设计，提供了许多组件：记录器、处理器、过滤器和格式化器。
Logger 暴露了应用程序代码能直接使用的接口。
Filter提供了更好的粒度控制，它可以决定输出哪些日志记录。
Handler将（记录器产生的）日志记录发送至合适的目的地。
Formatter 指明了最终输出中日志记录的布局。

logging在多模块中的使用

logging模块保证在同一个python解释器内，多次调用logging.getLogger(‘log_name’)都会返回同一个logger实例，即使是在多个模块的情况下。

所以典型的多模块场景下使用logging的方式是在main模块中配置logging，这个配置会作用于多个的子模块，然后在其他模块中直接通过getLogger获取Logger对象即可。
通过logger的命名也能体现出logger的树形结构。

handlers.py

import logging
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.DEBUG) # 输出到控制台的log等级的开关
# 创建该handler的formatter
console_handler.setFormatter(
        logging.Formatter(
                fmt='%(asctime)s - %(name)s - %(levelname)s: %(message)s',
                datefmt='%H:%M:%S')
        )

main.py

import logging
from handlers import console_handler

root_logger = logging.getLogger('root')
root_logger.setLevel(logging.INFO)


root_logger.addHandler(console_handler)
root_logger.info('root logger begin')

logger = logging.getLogger('root.main')
logger.setLevel(logging.DEBUG)
logger.addHandler(console_handler)
logger.debug('main logger begin')

import mod
logger.debug('let\'s test mod.testLogger()') 
mod.testLogger()    

logger.debug('main logger end')
root_logger.info('root logger end')

mod.py

import logging
from handlers import console_handler

logger = logging.getLogger('root.main.mod')
logger.setLevel(logging.DEBUG)
logger.addHandler(console_handler)
logger.debug('mod logger begin')

def testLogger():
    logger.debug('this is testlogger')

运行main.py输出为：

18:17:07 - root - INFO: root logger begin
18:17:07 - root.main - DEBUG: main logger begin
18:17:07 - root.main - DEBUG: main logger begin
18:17:07 - root.main.mod - DEBUG: mod logger begin
18:17:07 - root.main.mod - DEBUG: mod logger begin
18:17:07 - root.main.mod - DEBUG: mod logger begin
18:17:07 - root.main - DEBUG: let's test mod.testLogger()
18:17:07 - root.main - DEBUG: let's test mod.testLogger()
18:17:07 - root.main.mod - DEBUG: this is testlogger
18:17:07 - root.main.mod - DEBUG: this is testlogger
18:17:07 - root.main.mod - DEBUG: this is testlogger
18:17:07 - root.main - DEBUG: main logger end
18:17:07 - root.main - DEBUG: main logger end
18:17:07 - root - INFO: root logger end

可以看到存在层级关系，子logger的日子还会交给祖辈logger的handler进行处理。

具体logger处理的流程图：

logging模块，还在使用print打印？