Python logging使用指南

Python logging使用指南

在开发程序过程中，打一手好的日志，对我们事后追根索源，排查问题至关重要．
在初学c或者python时，我们的代码中通常充斥着这样的代码片段：

printf("a is %d",a);

或者

print 'Start reading database'
records = model.read_recrods()
print '# records', records
print 'Updating record ...'
model.update_records(records)
print 'done'

本文总结了python自带的日志模块logging使用，并给出几个实例．虽然在现实的产品代码中，也偶尔会看到类似这种代码，但通常一个成熟的产品，都会有一个单独的日志模块供整个系统使用，我们应当保持正确的姿势来打日志．

1.python logging实例

python中logging是一个单独的模块．使用灵活方便，支持以本地文件／socket／http等多种形式输出日志．
以下是一些最简单的logging使用实例．
实例１：输出日志到控制台

import logging
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)
logging.debug('this log should not be output,for the log level is logging.INFO')
logger.info('Start of test logging')
# do some logic
logger.error('something goes wrong')
logger.warning('please be careful')
logger.info('end of test logging')

输出如下：

INFO:__main__:Start of test logging
ERROR:__main__:something goes wrong
WARNING:__main__:please be careful
INFO:__main__:end of test logging

实例１中的使用方式与我们直接使用print打印信息相比，除了日志级别控制外，并没有什么用．通常一个使用的日志信息，都会包含日志产生时间，产生该日志的源文件，代码所在行数等等这些信息．实例２中就将这两个东西
实例２：输出日志到指定文档

import logging
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)
# create a file handler
handler = logging.FileHandler('test.log')
handler.setLevel(logging.INFO)
# create a logging format
formatter = logging.Formatter('%(asctime)s - %(filename)s:%(lineno)d - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(handler)
logger.info('hello,python!')

当然，很多时候，我们并不仅仅是像实例２中那样，讲日志写入本地文档，我们可以有一个日志分析／处理中心，不同的系统需要将各自的日志发送到特定的日志中心．此时，我们便需要使用到logging.handlers.HTTPHandler/logging.handlers.SocketHandler／logging.handlers.SMTPHandler等更高级的日志处理器来进行日志发送．使用方式详见python官方文档．上述代码通过引入handler和formatter来实现讲日志以特定的格式输出到指定日志文件中．

2.如何正确的设置日志级别

在合适的时候使用合适的日志输出级别．因为日志的输出是需要耗性能的，我们不能将所有情况都设为DEBUG级别，过多的日志也不便于我们进行分析．
以下搬运了一些他人的经验，仅供参考：

1.使用DEBUG级别．
在开发调式阶段，通常使用debug级别日志．例如，我们想查看一个算法执行过程中，中间变量的详细变换过程．例如：

def complex_algorithm(items):
for i, item in enumerate(items):
# do some complex algorithm computation
logger.debug('%s iteration, item=%s', i, item)

2.使用INFO级别
在web开发中，进行路由时输出info级别的日志．例如处理接受到的请求，服务器状态改变时等．

def handle_request(request):
logger.info('Handling request %s', request)
# handle request here
result = 'result'
logger.info('Return result: %s', result)
def start_service():
logger.info('Starting service at port %s ...', port)
service.start()
logger.info('Service is started')

在一些比较重要的情形下可以输出warning级别的日志，例如，在用户登录输入的密码错误时，可以输出warning级别，此时需要引起注意，需查看是不是有人在蓄意进行暴力破旧等破坏操作．

3.使用WARNING级别

def authenticate(user_name, password, ip_address):
if user_name != USER_NAME and password != PASSWORD:
logger.warn('Login attempt to %s from IP %s', user_name, ip_address)
return False
# do authentication here

程序出现可预期的错误时，应当抛出一个错误日志．例如，数据库连接失败，IO读取出错等．4.使用ERROR级别

def get_user_by_id(user_id):
user = db.read_user(user_id)
if user is None:
logger.error('Cannot find user with user_id=%s', user_id)
return user
return user

critical级别的日志，通常使用的很少，只有在极个别情况下才会使用到．例如配置文件解析出错，磁盘满，内存不够等．

5.使用CRITICAL级别

3.几个Tips

1.使用__name__作为logger的名字

logger = logging.getLogger(__name__)

2.捕获异常，并使用traceback记录异常的详细信息
在实践中就会发现，大部分情况下，仅仅输出大概的出错信息并不能定位到具体出错原因，使用traceback方便定位具体原因．例如：

try:
open('/path/to/does/not/exist', 'rb')
except (SystemExit, KeyboardInterrupt):
raise
except Exception, e:
logger.error('Failed to open file', exc_info=True)

通过设置exc_info=True,则traceback信息会被输出到日志文件中．

import logging
import logging.handlers
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO)
# create a file handler
handler = logging.FileHandler('test.log')
handler.setLevel(logging.INFO)
# create a logging format
formatter = logging.Formatter('[%(levelname)s] %(asctime)s - %(filename)s:%(lineno)d  - %(message)s')
handler.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(handler)
try:
open('/path/to/does/not/exist', 'rb')
except (SystemExit, KeyboardInterrupt):
raise
except Exception, e:
logger.error('Failed to open file', exc_info=True)

上述程序的日志输出信息如下：

[ERROR] 2015-06-27 21:32:24,127 - test.py:23  - Failed to open file
Traceback (most recent call last):
File "/home/jay/ITService/apps/ITBots/ITBots/test.py", line 19, in <module>
open('/path/to/does/not/exist', 'rb')
IOError: [Errno 2] No such file or directory: '/path/to/does/not/exist'

参考：
https://docs.python.org/2/howto/logging.html#logging-advanced-tutorial
http://victorlin.me/posts/2012/08/26/good-logging-practice-in-python
https://docs.python.org/2/howto/logging.htm
l