在现实生活中,记录日志非常重要。银行转账时会有转账记录;飞机飞行过程中,会有黑盒子(飞行数据记录器)记录飞行过程中的一切。如果有出现什么问题,人们可以通过日志数据来搞清楚到底发生了什么。对于系统开发、调试以及运行,记录日志都是同样的重要。如果没有日志记录,程序崩溃时你几乎就没办法弄明白到底发生了什么事情。举个例子,当你在写一个服务器程序时,记录日志是非常有必要的。下面展示的就是 ezcomet.com 服务器的日志文件截图。
服务崩溃后,如果没有日志,我几乎没办法知道到底发生了错误。日志不仅对于服务器很重要,对于桌面图形应用同样十分重要。比如,当你的客户的 pc 机程序崩溃时,你可以让他们把日志文件发给你,这样你就可以找到问题到底出在哪儿。相信我,在不同的 pc 环境下,你永远不会知道会有怎样奇怪的问题。我曾经就接收到过这样的错误日志。
2011-08-22 17:52:54,828 – root – error – [errno 10104] getaddrinfo failed
traceback (most recent call last):
file “”, line 124, in main
file “”, line 20, in __init__
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/wx._core”, line 7978, in __init__
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/wx._core”, line 7552, in _bootstrapapp
file “”, line 84, in oninit
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/twisted.internet.wxreactor”, line 175, in install
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/twisted.internet._threadedselect”, line 106, in __init__
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/twisted.internet.base”, line 488, in __init__
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/twisted.internet.posixbase”, line 266, in installwaker
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/twisted.internet.posixbase”, line 74, in __init__
file “h:workspaceprojectbuildpyi.win32mrdjoutpyz1.pyz/socket”, line 224, in meth
gaierror: [errno 10104] getaddrinfo failed
我最终发现,这个客户的 pc 机被一种病毒感染,导致了调用 gethostname 函数失败。看吧,如果没有日志可以查你怎么可能知道这些。
打印输出不是个好办法
尽管记录日志非常重要,但是并不是所有的开发者都能正确地使用它。我曾看到一些开发者是这样记录日志的,在开发的过程中插入 print 语句,开发结束后再将这些语句移除。就像这样:
print ‘start reading database’
records = model.read_recrods()
print ‘# records’, records
print ‘updating record …’
model.update_records(records)
print ‘done’
这种方式对于简单脚本型程序有用,但是如果是复杂的系统,你最好不要使用这样的方式。首先,你没办法做到在日志文件中只留下极其重要的消息。你会看到大量的消息日志。但是你却找不到任何有用的信息。你除了移除这输出语句这外,没别的办法控制代码,但是极有可能的是你忘记了移出那些没用的输出。再者,print 输出的所有信息都到了标准输出中,这将严重影响到你从标准输出中查看其它输出数据。当然,你也可以把消息输出到 stderr ,但是用 print 做日志记录的方式还是不好。
使用 python 的标准日志模块
那么,怎么样记录日志才是正确的呢?其实非常简单,使用 python 的标准日志模块。多亏 python 社区将日志做成了一个标准模块。它非常简单易用且十分灵活。你可以像这样使用日志系统:
import logging
logging.basicconfig(level=logging.info)
logger = logging.getlogger(__name__)
logger.info(‘start reading database’)
# read database here
records = {‘john’: 55, ‘tom’: 66}
logger.debug(‘records: %s’, records)
logger.info(‘updating records …’)
# update records here
logger.info(‘finish updating records’)
运行的时候就可看到:
info:__main__:start reading database
info:__main__:updating records …
info:__main__:finish updating records
你可能会问这与使用 print 有什么不同呢。它有以下的优势:
你可以控制消息的级别,过滤掉那些并不重要的消息。
你可决定输出到什么地方,以及怎么输出。
有许多的重要性别级可供选择,debug、info、warning、error 以及 critical。通过赋予 logger 或者 handler 不同的级别,你就可以只输出错误消息到特定的记录文件中,或者在调试时只记录调试信息。让我们把 logger 的级别改成 debug 再看一下输出结果:
logging.basicconfig(level=logging.debug)
输出变成了:
info:__main__:start reading database
debug:__main__:records: {‘john’: 55, ‘tom’: 66}
info:__main__:updating records …
info:__main__:finish updating records
正如看到的那样,我们把 logger 的等级改为 debug 后,调试记录就出现在了输出当中。你也可以选择怎么处理这些消息。例如,你可以使用 filehandler 把记录写进文件中:
import logging
logger = logging.getlogger(__name__)
logger.setlevel(logging.info)
# create a file handler
handler = logging.filehandler(‘hello.log’)
handler.setlevel(logging.info)
# create a logging format
formatter = logging.formatter(‘%(asctime)s – %(name)s – %(levelname)s – %(message)s’)
handler.setformatter(formatter)
# add the handlers to the logger
logger.addhandler(handler)
logger.info(‘hello baby’)
以合适的等级输出日志记录
有了灵活的日志记录模块后,你可以按适当的等级将日志记录输出到任何地方然后配置它们。那么你可能会问,什么是合适的等级呢?在这儿我将分享一些我的经验。
大多数的情况下,你都不想阅读日志中的太多细节。因此,只有你在调试过程中才会使用 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)
在处理请求或者服务器状态变化等日常事务中,我会使用 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 。比如,当用户登录密码错误时,或者连接变慢时。
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
有错误发生时肯定会使用 error 等级了。比如抛出异常,io 操作失败或者连接问题等。
def get_user_by_id(user_id):
user = db.read_user(user_id)
if user is none:
logger.error(‘cannot find user with user_, user_id)
return user
return user
我很少使用 critical 。当一些特别糟糕的事情发生时,你可以使用这个级别来记录。比方说,内存耗尽,磁盘满了或者核危机(希望永远别发生 :s)。
虽然不是非得将 logger 的名称设置为 __name__ ,但是这样做会给我们带来诸多益处。在 python 中,变量 __name__ 的名称就是当前模块的名称。比如,在模块 “foo.bar.my_module” 中调用 logger.getlogger(__name__) 等价于调用logger.getlogger(“foo.bar.my_module”) 。当你需要配置 logger 时,你可以配置到 “foo” 中,这样包 foo 中的所有模块都会使用相同的配置。当你在读日志文件的时候,你就能够明白消息到底来自于哪一个模块。
捕捉异常并使用 traceback 记录它
出问题的时候记录下来是个好习惯,但是如果没有 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 调用 logger 方法, traceback 会输出到 logger 中。你可以看到下面的结果
error:__main__:failed to open file
traceback (most recent call last):
file “example.py”, line 6, in
open(‘/path/to/does/not/exist’, ‘rb’)
ioerror: [errno 2] no such file or directory: ‘/path/to/does/not/exist’
python 使用logging模块记录日志涉及四个主要类,使用官方文档中的概括最为合适:
logger提供了应用程序可以直接使用的接口;
handler将(logger创建的)日志记录发送到合适的目的输出;
filter提供了细度设备来决定输出哪条日志记录;
formatter决定日志记录的最终输出格式。
logging模块是在2.3新引进的功能,下面是一些常用的类和模块级函数模块级函数logging.getlogger([name]):返回一个logger对象,如果没有指定名字将返回root loggerlogging.debug()、logging.info()、logging.warning()、logging.error()、logging.critical():设定root logger的日志级别logging.basicconfig():用默认formatter为日志系统建立一个streamhandler,设置基础配置并加到root logger中
11) logging.handlers.httphandler
# encoding:utf-8
#import logging
#format = ‘%(asctime)-15s %(clientip)s %(user)-8s %(message)s’
#logging.basicconfig(format=format)
#d = {‘clientip’: ‘192.168.0.1’, ‘user’: ‘fbloggs’}
#logger = logging.getlogger(‘tcpserver’)
#logger.warning(‘protocol problem: %s’, ‘connection reset’, extra=d)
#format = ‘%(asctime)-15s %(message)s’
#logging.basicconfig(filename = “c:\\users\\june\\desktop\\1.txt”, level = logging.debug, filemode = “a”, format=format)
#logging.debug(‘this is a message’)
#logging.debug(‘test’)
#import logging
#import datetime
#
#curdate = datetime.date.today() – datetime.timedelta(days=0)
#logname = ‘c:\\users\\june\\desktop\\error_%s.log’ %curdate
#
#logging.basicconfig(level=logging.info,
# format=’%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s’,
# #datefmt=’%a, %d %b %y %h:%m:%s’,
# filename=logname,
# filemode=’a’)
#
##2013-10-21 03:25:51,509 writelog.py[line:14] info this is info message
##2013-10-21 03:25:51,510 writelog.py[line:15] warning this is warning message
#logging.debug(‘this is debug message’)
#logging.info(‘this is info message’)
#logging.warning(‘this is warning message’)import logging
import logging.config
logging.config.fileconfig(“logging.conf”)
#create logger
loggerinfo = logging.getlogger(“infologger”)
#”application” code
loggerinfo.debug(“debug message”)
loggerinfo.info(“info message”)
loggerinfo.warn(“warn message”)
loggerinfo.error(“error message”)
loggerinfo.critical(“critical message”)
loggererror = logging.getlogger(“errorlogger”)
loggererror.error(“error: hello world!”)#coding=utf-8
import logging
import datetime
format=’%(asctime)s – %(filename)s – [line:%(lineno)d] – %(levelname)s – %(message)s’
curdate = datetime.date.today() – datetime.timedelta(days=0)
infologname = r’c:/users/june/desktop/info_%s.log’ %curdate
errorlogname = r’c:/users/june/desktop/error_%s.log’ %curdate
formatter = logging.formatter(format)
infologger = logging.getlogger(“infolog”)
errorlogger = logging.getlogger(“errorlog”)
infologger.setlevel(logging.info)
errorlogger.setlevel(logging.error)
infohandler = logging.filehandler(infologname, ‘a’)
infohandler.setlevel(logging.info)
infohandler.setformatter(formatter)
errorhandler = logging.filehandler(errorlogname, ‘a’)
errorhandler.setlevel(logging.error)
errorhandler.setformatter(formatter)
testhandler = logging.streamhandler()
testhandler.setformatter(formatter)
testhandler.setlevel(logging.error)
infologger.addhandler(infohandler)
infologger.addhandler(testhandler)
errorlogger.addhandler(errorhandler)
#infologger.debug(“debug message”)
#infologger.info(“info message”)
#infologger.warn(“warn message”)
# # 下面这行会同时打印在文件和终端上
#infologger.error(“error message”)
#
#errorlogger.error(“error message”)
#errorlogger.critical(“critical message”)”’
created on 2016年8月18日
@author: apple
”’
#-*- coding:utf-8 -*-
#开发出一个日志系统,既要把日志输出到控制台,还要写入日志文件
import logging
import time
import os
import os.path
class logger():
def __init__(self, log_name, logger_name):
”’
指定保存日志的文件路径,日志级别以及调用文件
将日志 存入到指定的文件中
”’
#设置日志文件名称:time.time()取得当前时间;time.localtime()取得本地时间;time.strftime()格式化日期;
time_str = time.strftime(“%y_%m_%d_%h_%m_%s”, time.localtime(time.time()))
logname = time_str + ‘_’ + log_name + ‘.log’
#设置日志文件所在的路径
log_filedir = ‘log’
if not os.path.isdir(log_filedir):
print(“日志文件夹 %s 不存在,开始创建此文件夹” %log_filedir)
os.mkdir(‘log’)
else:
print(“日志文件夹 %s 存在” %log_filedir)
os.chdir(‘log’)
#创建一个logger以及设置日志级别
#logging有6个日志级别:notset, debug, info, warning, error, critical对应的值分别为:0,10,20,30,40,50
#例如:logging.debug和10是等价的表示方法
#可以给日志对象(logger instance)设置日志级别,低于该级别的日志消息将会被忽略,也可以给hanlder设置日志级别
#对于低于该级别的日志消息, handler也会忽略。
self.logger = logging.getlogger(logger_name)
self.logger.setlevel(logging.debug)
#创建文件handler,用于写入日志文件并设置文件日志级别
file_handler = logging.filehandler(logname)
file_handler.setlevel(logging.debug)
#创建控制端输出handler,用于输出到控制端并设置输出日志级别
console_handler = logging.streamhandler()
console_handler.setlevel(logging.debug)
#在控制端handler添加过滤器,将含有chat或者gui的handler信息输出
filter = logging.filter(“chat.gui”)
console_handler.addfilter(filter)
#定义handler的输出格式并将格式应用到handler
formatter = logging.formatter(‘%(asctime)s-%(name)s-%(levelname)s-%(message)s’)
file_handler.setformatter(formatter)
console_handler.setformatter(formatter)
#将handler加入到logger
self.logger.addhandler(file_handler)
self.logger.addhandler(console_handler)
self.logger.debug(“这个是debug日志信息”)
self.logger.info(“欢迎大家来到 python的世界”)
#将handler从logger中移除
self.logger.removehandler(file_handler)
self.logger.removehandler(console_handler)
if __name__ == ‘__main__’:
print(os.getcwd())
log = logger(‘create_log’, “chat.gui.statistic”)
# 模块级函数
#
# logging.getlogger([name]):返回一个logger对象,如果没有指定名字将返回root logger
# logging.debug()、logging.info()、logging.warning()、logging.error()、logging.critical():设定root logger的日志级别
# logging.basicconfig():用默认formatter为日志系统建立一个streamhandler,设置基础配置并加到root logger中
#
# loggers
#
# logger.setlevel(lel):指定最低的日志级别,低于lel的级别将被忽略。debug是最低的内置级别,critical为最高
# logger.addfilter(filt)、logger.removefilter(filt):添加或删除指定的filter
# logger.addhandler(hdlr)、logger.removehandler(hdlr):增加或删除指定的handler
# logger.debug()、logger.info()、logger.warning()、logger.error()、logger.critical():可以设置的日志级别
# handlers
#
# handler对象负责发送相关的信息到指定目的地。可以通过addhandler()方法添加多个多handler
# handler.setlevel(lel):指定被处理的信息级别,低于lel级别的信息将被忽略
# handler.setformatter():给这个handler选择一个格式
# handler.addfilter(filt)、handler.removefilter(filt):新增或删除一个filter对象
# formatters
#
# formatter对象设置日志信息最后的规则、结构和内容,默认的时间格式为%y-%m-%d %h:%m:%s,下面是formatter常用的一些信息
# %(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 用户输出的消息”’
created on 2016年8月25日
@author: apple
”’
import logging
logging.basicconfig(level=logging.info,
format=’%(asctime)s %(name)s %(levelname)s %(message)s’,
datefmt=’%m-%d %h:%m’,
filename=’./autoupdate.log’,
filemode=’w’)
console = logging.streamhandler()
console.setlevel(logging.info)
formatter = logging.formatter(‘%(name)s: %(levelname)-8s %(message)s’)
console.setformatter(formatter)
logging.getlogger(”).addhandler(console)
logging.info(“hello world!”)