파이썬 모듈 로깅
- 高洛峰원래의
- 2016-10-20 11:53:361499검색
실생활에서 로그를 유지하는 것은 매우 중요합니다. 은행 송금이 이루어지면 항공기 비행 중에 송금 기록이 남게 되며 비행 중 모든 것을 기록하는 블랙박스(비행 데이터 기록 장치)가 있게 됩니다. 문제가 발생하면 사람들은 로그 데이터를 보고 무슨 일이 일어났는지 알아낼 수 있습니다. 시스템 개발, 디버깅, 운영에 있어 로깅도 마찬가지로 중요합니다. 로깅 없이는 프로그램이 충돌했을 때 무슨 일이 일어났는지 파악하는 것이 거의 불가능합니다. 예를 들어, 서버 프로그램을 작성할 때 로깅은 매우 필요합니다. 아래는 EZComet.com 서버 로그 파일의 스크린샷입니다.
서비스가 중단된 후 로그가 없으면 무엇이 잘못되었는지 알 방법이 거의 없습니다. 로깅은 서버뿐만 아니라 데스크탑 그래픽 애플리케이션에도 중요합니다. 예를 들어, 클라이언트의 PC가 충돌하는 경우 문제가 무엇인지 파악할 수 있도록 로그 파일을 보내달라고 요청할 수 있습니다. 저를 믿으십시오. 다양한 PC 환경에서는 어떤 종류의 이상한 문제가 발생할 수 있는지 결코 알 수 없습니다. 이전에 이와 같은 오류 로그를 받은 적이 있습니다.
2011-08-22 17:52:54,828 - root - ERROR - [Errno 10104] getaddrinfo failed Traceback (most recent call last): File "<string>", line 124, in main File "<string>", 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 "<string>", 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 'Start reading database' records = model.read_recrods() print '# records', records print 'Updating record ...' model.update_records(records) print 'done'
이 방법은 간단한 스크립트 형태의 프로그램에는 유용하지만, 복잡한 시스템이라면 이 방법을 사용하지 않는 것이 좋습니다. 첫째, 매우 중요한 메시지만 로그 파일에 남길 수는 없습니다. 많은 메시지 로그가 표시됩니다. 하지만 유용한 정보는 찾을 수 없습니다. 출력 문을 제거하는 것 외에는 코드를 제어할 수 없지만 사용되지 않는 출력을 제거하는 것을 잊었을 가능성이 매우 높습니다. 더욱이 인쇄로 출력된 모든 정보는 표준 출력으로 이동하며 이는 표준 출력에서 다른 출력 데이터를 보는 기능에 심각한 영향을 미칩니다. 물론 메시지를 stderr로 출력할 수도 있지만 인쇄를 사용하는 것은 여전히 로깅을 수행하는 좋은 방법이 아닙니다.
파이썬의 표준 로깅 모듈을 사용하세요
그럼 로그를 올바르게 기록하려면 어떻게 해야 할까요? 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
이것이 인쇄를 사용하는 것과 어떻게 다른지 궁금할 것입니다. 다음과 같은 장점이 있습니다.
메시지 수준을 제어하고 중요하지 않은 메시지를 필터링할 수 있습니다.
출력할 위치와 출력 방법을 결정할 수 있습니다.
디버그, 정보, 경고, 오류, 중요 등 선택할 수 있는 중요한 수준이 많이 있습니다. 로거 또는 핸들러에 서로 다른 수준을 할당하면 특정 로그 파일에만 오류 메시지를 출력하거나 디버깅할 때 디버깅 정보만 로그할 수 있습니다. 로거 레벨을 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보시다시피 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_id=%s', 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 <module>
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 logger
logging.debug()、logging.info()、logging.warning()、logging.error()、logging.critical()：设定root logger的日志级别
logging.basicConfig():用默认Formatter为日志系统建立一个StreamHandler，设置基础配置并加到root logger中
每个程序在输出信息之前都要获得一个Logger。Logger通常对应了程序的模块名，比如聊天工具的图形界面模块可以这样获得它的Logger：
LOG=logging.getLogger(”chat.gui”)
而核心模块可以这样：
LOG=logging.getLogger(”chat.kernel”)
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()：可以设置的日志级别
设置logger的level， level有以下几个级别：
NOTSET 如果把looger的级别设置为INFO， 那么小于INFO级别的日志都不输出， 大于等于INFO级别的日志都输出
Handlers
handler对象负责发送相关的信息到指定目的地。Python的日志系统有多种Handler可以使用。有些Handler可以把信息输出到控制台，有些Logger可以把信息输出到文件，还有些 Handler可以把信息发送到网络上。如果觉得不够用，还可以编写自己的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常用的一些信息
设置过滤器
细心的朋友一定会发现前文调用logging.getLogger()时参数的格式类似于“A.B.C”。采取这样的格式其实就是为了可以配置过滤器。看一下这段代码：
LOG=logging.getLogger(”chat.gui.statistic”)
console = logging.StreamHandler()
console.setLevel(logging.INFO)
formatter = logging.Formatter(’%(asctime)s %(levelname)s %(message)s’)
console.setFormatter(formatter)
filter=logging.Filter(”chat.gui”)
console.addFilter(filter)
LOG.addHandler(console)
和前面不同的是我们在Handler上添加了一个过滤器。现在我们输出日志信息的时候就会经过过滤器的处理。名为“A.B”的过滤器只让名字带有 “A.B”前缀的Logger输出信息。可以添加多个过滤器，只要有一个过滤器拒绝，日志信息就不会被输出。当然名为“A”前缀的Logger会输出信息。另外，在Logger中也可以添加过滤器。
每个Logger可以附加多个Handler。接下来我们就来介绍一些常用的Handler：
1) logging.StreamHandler
使用这个Handler可以向类似与sys.stdout或者sys.stderr的任何文件对象(file object)输出信息。它的构造函数是：
StreamHandler([strm])
其中strm参数是一个文件对象。默认是sys.stderr
2) logging.FileHandler
和StreamHandler类似，用于向一个文件输出日志信息。不过FileHandler会帮你打开这个文件。它的构造函数是：
FileHandler(filename[,mode])
filename是文件名，必须指定一个文件名。
mode是文件的打开方式。参见Python内置函数open()的用法。默认是’a'，即添加到文件末尾。
3) logging.handlers.RotatingFileHandler
这个Handler类似于上面的FileHandler，但是它可以管理文件大小。当文件达到一定大小之后，它会自动将当前日志文件改名，然后创建 一个新的同名日志文件继续输出。比如日志文件是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并不会被更名，而是被删除。
4) logging.handlers.TimedRotatingFileHandler
这个Handler和RotatingFileHandler类似，不过，它没有通过判断文件大小来决定何时重新创建日志文件，而是间隔一定时间就 自动创建新的日志文件。重命名的过程与RotatingFileHandler类似，不过新的文件不是附加数字，而是当前时间。它的构造函数是：
TimedRotatingFileHandler( filename [,when [,interval [,backupCount]]])
其中filename参数和backupCount参数和RotatingFileHandler具有相同的意义。
interval是时间间隔。
when参数是一个字符串。表示时间间隔的单位，不区分大小写。它有以下取值：
S 秒
M 分
H 小时
D 天
W 每星期（interval==0时代表星期一）
midnight 每天凌晨
5) logging.handlers.SocketHandler
6) logging.handlers.DatagramHandler
以上两个Handler类似，都是将日志信息发送到网络。不同的是前者使用TCP协议，后者使用UDP协议。它们的构造函数是：
Handler(host, port)
其中host是主机名，port是端口名
7) logging.handlers.SysLogHandler
8) logging.handlers.NTEventLogHandler
9) logging.handlers.SMTPHandler
10) logging.handlers.MemoryHandler
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!")