Python中的logging模块
MaiRRV
8年前
<p>最近修改了项目里的logging相关功能，用到了python标准库里的logging模块，在此做一些记录。主要是从官方文档和stackoverflow上查询到的一些内容。</p> <h2><strong>本用法</strong></h2> <p>下面的代码展示了logging最基本的用法。</p> <pre> <code class="language-python"># -*- coding: utf-8 -*- import logging import sys # 获取logger实例，如果参数为空则返回root logger logger = logging.getLogger("AppName") # 指定logger输出格式 formatter = logging.Formatter('%(asctime)s %(levelname)-8s: %(message)s') # 文件日志 file_handler = logging.FileHandler("test.log") file_handler.setFormatter(formatter) # 可以通过setFormatter指定输出格式 # 控制台日志 console_handler = logging.StreamHandler(sys.stdout) console_handler.formatter = formatter # 也可以直接给formatter赋值 # 为logger添加的日志处理器 logger.addHandler(file_handler) logger.addHandler(console_handler) # 指定日志的最低输出级别，默认为WARN级别 logger.setLevel(logging.INFO) # 输出不同级别的log logger.debug('this is debug info') logger.info('this is information') logger.warn('this is warning message') logger.error('this is error message') logger.fatal('this is fatal message, it is same as logger.critical') logger.critical('this is critical message') # 2016-10-08 21:59:19,493 INFO : this is information # 2016-10-08 21:59:19,493 WARNING : this is warning message # 2016-10-08 21:59:19,493 ERROR : this is error message # 2016-10-08 21:59:19,493 CRITICAL: this is fatal message, it is same as logger.critical # 2016-10-08 21:59:19,493 CRITICAL: this is critical message # 移除一些日志处理器 logger.removeHandler(file_handler)</code></pre> <p>除了这些基本用法，还有一些常见的小技巧可以分享一下。</p> <h3><strong>格式化输出日志</strong></h3> <pre> <code class="language-python"># 格式化输出 service_name = "Booking" logger.error('%s service is down!' % service_name) # 使用python自带的字符串格式化，不推荐 logger.error('%s service is down!', service_name) # 使用logger的格式化，推荐 logger.error('%s service is %s!', service_name, 'down') # 多参数格式化 logger.error('{} service is {}'.format(service_name, 'down')) # 使用format函数，推荐 # 2016-10-08 21:59:19,493 ERROR : Booking service is down!</code></pre> <h3><strong>记录异常信息</strong></h3> <p>当你使用logging模块记录异常信息时，不需要传入该异常对象，只要你直接调用 logger.error() 或者 logger.exception() 就可以将当前异常记录下来。</p> <pre> <code class="language-python"># 记录异常信息 try: 1 / 0 except: # 等同于error级别，但是会额外记录当前抛出的异常堆栈信息 logger.exception('this is an exception message') # 2016-10-08 21:59:19,493 ERROR : this is an exception message # Traceback (most recent call last): # File "D:/Git/py_labs/demo/use_logging.py", line 45, in <module> # 1 / 0 # ZeroDivisionError: integer division or modulo by zero</code></pre> <h3><strong>logging配置要点</strong></h3> <p>GetLogger()方法</p> <p>这是最基本的入口，该方法参数可以为空，默认的logger名称是root，如果在同一个程序中一直都使用同名的logger，其实会拿到同一个实例，使用这个技巧就可以跨模块调用同样的logger来记录日志。</p> <p>另外你也可以通过日志名称来区分同一程序的不同模块，比如这个例子。</p> <pre> <code class="language-python">logger = logging.getLogger("App.UI") logger = logging.getLogger("App.Service")</code></pre> <p>Formatter日志格式</p> <p>Formatter对象定义了log信息的结构和内容，构造时需要带两个参数：</p> <ul> <li> <p>一个是格式化的模板 fmt ，默认会包含最基本的 level 和 message 信息</p> </li> <li> <p>一个是格式化的时间样式 datefmt ，默认为 2003-07-08 16:49:45,896 (%Y-%m-%d %H:%M:%S)</p> </li> </ul> <p>fmt 中允许使用的变量可以参考下表。</p> <ul> <li> <p>%(name)sLogger的名字</p> </li> <li> <p>%(levelno)s数字形式的日志级别</p> </li> <li> <p>%(levelname)s文本形式的日志级别</p> </li> <li> <p>%(pathname)s调用日志输出函数的模块的完整路径名，可能没有</p> </li> <li> <p>%(filename)s调用日志输出函数的模块的文件名</p> </li> <li> <p>%(module)s调用日志输出函数的模块名|</p> </li> <li> <p>%(funcName)s调用日志输出函数的函数名|</p> </li> <li> <p>%(lineno)d调用日志输出函数的语句所在的代码行</p> </li> <li> <p>%(created)f当前时间，用UNIX标准的表示时间的浮点数表示|</p> </li> <li> <p>%(relativeCreated)d输出日志信息时的，自Logger创建以来的毫秒数|</p> </li> <li> <p>%(asctime)s字符串形式的当前时间。默认格式是“2003-07-08 16:49:45,896”。逗号后面的是毫秒</p> </li> <li> <p>%(thread)d线程ID。可能没有</p> </li> <li> <p>%(threadName)s线程名。可能没有</p> </li> <li> <p>%(process)d进程ID。可能没有</p> </li> <li> <p>%(message)s用户输出的消息</p> </li> </ul> <p>SetLevel 日志级别</p> <p>Logging有如下级别: DEBUG，INFO，WARNING，ERROR，CRITICAL</p> <p>默认级别是WARNING，logging模块只会输出指定level以上的log。这样的好处, 就是在项目开发时debug用的log，在产品release阶段不用一一注释，只需要调整logger的级别就可以了，很方便。</p> <p>Handler 日志处理器</p> <p>最常用的是StreamHandler和FileHandler, Handler用于向不同的输出端打log。</p> <p>Logging包含很多handler, 可能用到的有下面几种</p> <ul> <li> <p>StreamHandlerinstances send error messages to streams (file-like objects).</p> </li> <li> <p>FileHandlerinstances send error messages to disk files.</p> </li> <li> <p>RotatingFileHandlerinstances send error messages to disk files, with support for maximum log file sizes and log file rotation.</p> </li> <li> <p>TimedRotatingFileHandlerinstances send error messages to disk files, rotating the log file at certain timed intervals.</p> </li> <li> <p>SocketHandlerinstances send error messages to TCP/IP sockets.</p> </li> <li> <p>DatagramHandlerinstances send error messages to UDP sockets.</p> </li> <li> <p>SMTPHandlerinstances send error messages to a designated email address.</p> </li> </ul> <p>Configuration 配置方法</p> <p>logging的配置大致有下面几种方式。</p> <ol> <li> <p>通过代码进行完整配置，参考开头的例子，主要是通过getLogger方法实现。</p> </li> <li> <p>通过代码进行简单配置，下面有例子，主要是通过basicConfig方法实现。</p> </li> <li> <p>通过配置文件，下面有例子，主要是通过 logging.config.fileConfig(filepath)</p> </li> </ol> <p>logging.basicConfig</p> <p>basicConfig() 提供了非常便捷的方式让你配置logging模块并马上开始使用，可以参考下面的例子。</p> <pre> <code class="language-python">import logging logging.basicConfig(filename='example.log',level=logging.DEBUG) logging.debug('This message should go to the log file') logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG) logging.debug('This message should appear on the console') logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') logging.warning('is when this event was logged.')</code></pre> <p>备注： 其实你甚至可以什么都不配置直接使用默认值在控制台中打log，用这样的方式替换print语句对日后项目维护会有很大帮助。</p> <p>通过文件配置logging</p> <p>如果你希望通过配置文件来管理logging，在log4net或者log4j中这是很常见的方式。</p> <pre> <code class="language-python"># logging.conf [loggers] keys=root [logger_root] level=DEBUG handlers=consoleHandler #,timedRotateFileHandler,errorTimedRotateFileHandler ################################################# [handlers] keys=consoleHandler,timedRotateFileHandler,errorTimedRotateFileHandler [handler_consoleHandler] class=StreamHandler level=DEBUG formatter=simpleFormatter args=(sys.stdout,) [handler_timedRotateFileHandler] class=handlers.TimedRotatingFileHandler level=DEBUG formatter=simpleFormatter args=('debug.log', 'H') [handler_errorTimedRotateFileHandler] class=handlers.TimedRotatingFileHandler level=WARN formatter=simpleFormatter args=('error.log', 'H') ################################################# [formatters] keys=simpleFormatter, multiLineFormatter [formatter_simpleFormatter] format= %(levelname)s %(threadName)s %(asctime)s: %(message)s datefmt=%H:%M:%S [formatter_multiLineFormatter] format= ------------------------- %(levelname)s ------------------------- Time: %(asctime)s Thread: %(threadName)s File: %(filename)s(line %(lineno)d) Message: %(message)s datefmt=%Y-%m-%d %H:%M:%S</code></pre> <p>假设以上的配置文件放在和模块相同的目录，代码中的调用如下。</p> <pre> <code class="language-python">import os filepath = os.path.join(os.path.dirname(__file__), 'logging.conf') logging.config.fileConfig(filepath) return logging.getLogger()</code></pre> <h3><strong>日志重复输出的坑</strong></h3> <p>你有可能会看到你打的日志会重复显示多次，可能的原因有很多，但总结下来无非就一个，日志中使用了重复的handler。</p> <p>第一坑</p> <pre> <code class="language-python">import logging logging.basicConfig(level=logging.DEBUG) fmt = '%(levelname)s:%(message)s' console_handler = logging.StreamHandler() console_handler.setFormatter(logging.Formatter(fmt)) logging.getLogger().addHandler(console_handler) logging.info('hello!') # INFO:root:hello! # INFO:hello!</code></pre> <p>上面这个例子出现了重复日志，因为在第3行调用 basicConfig() 方法时系统会默认创建一个handler，如果你再添加一个控制台handler时就会出现重复日志。</p> <p>第二坑</p> <pre> <code class="language-python">import logging def get_logger(): fmt = '%(levelname)s:%(message)s' console_handler = logging.StreamHandler() console_handler.setFormatter(logging.Formatter(fmt)) logger = logging.getLogger('App') logger.setLevel(logging.INFO) logger.addHandler(console_handler) return logger def call_me(): logger = get_logger() logger.info('hi') call_me() call_me() # INFO:hi # INFO:hi # INFO:hi</code></pre> <p>在这个例子里 hi 居然打印了三次，如果再调用一次 call_me() 呢？我告诉你会打印6次。why? 因为你每次调用 get_logger() 方法时都会给它加一个新的handler，你是自作自受。正常的做法应该是全局只配置logger一次。</p> <p>第三坑</p> <pre> <code class="language-python">import logging def get_logger(): fmt = '%(levelname)s: %(message)s' console_handler = logging.StreamHandler() console_handler.setFormatter(logging.Formatter(fmt)) logger = logging.getLogger('App') logger.setLevel(logging.INFO) logger.addHandler(console_handler) return logger def foo(): logging.basicConfig(format='[%(name)s]: %(message)s') logging.warn('some module use root logger') def main(): logger = get_logger() logger.info('App start.') foo() logger.info('App shutdown.') main() # INFO: App start. # [root]: some module use root logger # INFO: App shutdown. # [App]: App shutdown.</code></pre> <p>为嘛最后的 App shutdown 打印了两次？所以在Stackoverflow上很多人都问，我应该怎么样把root logger关掉，root logger太坑爹坑妈了。只要你在程序中使用过root logger，那么默认你打印的所有日志都算它一份。上面的例子没有什么很好的办法，我建议你招到那个没有经过大脑就使用root logger的人，乱棍打死他或者开除他。</p> <p>如果你真的想禁用root logger，有两个不是办法的办法：</p> <pre> <code class="language-python">logging.getLogger().handlers = [] # 删除所有的handler logging.getLogger().setLevel(logging.CRITICAL) # 将它的级别设置到最高</code></pre> <h3><strong>小结</strong></h3> <p>Python中的日志模块作为标准库的一部分，功能还是比较完善的。个人觉得上手简单，另外也支持比如过滤，文件锁等高级功能，能满足大多数项目需求。</p> <p> </p> <p> </p> <p>来自：https://segmentfault.com/a/1190000007581128</p> <p> </p>