在写Python程序的时候不论老手或者新手一般都会用print 函数去console中打印信息，可以用来调试，警告，等等，的确很方便。写小程序的时候没有什么问题，当你的程序很庞大的时候，是不是为打印出来的信息过多而烦恼，时不时的要注释掉或者反注释print函数，而且有些信息不仅仅是希望打印在console中，而且也希望记录下log文件中，或者kafka中呢。 其实python 自带的logging 模块就非常的好用，基本可以满足所有需求。

Python logging 模块的官方文档地址为：https://docs.python.org/2/howto/logging.html#logging-basic-tutorial

一个简单的例子

import logging
logging.warning('Watch out!')  # will print a message to the console
logging.info('I told you so')  # will not print anything

如果你输入上面程序，你会看到什么呢？ 下面的信息会打印出来：

WARNING:root:Watch out!

你会发现Info的信息并没有打印出来，这是因为logging 默认的Level是warning，只有在比warning更严重的message才会打印出来。 logging模块中各个Level日志级别关系为：CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET，当然也可以自定义。

logging to file

一个简单的例子

import logging
logging.basicConfig(filename='example.log',level=logging.DEBUG)
logging.debug('This message should go to the log file')
logging.info('So should this')
logging.warning('And this, too')

结果就是，产生一个example.log 文件，内容为

DEBUG:root:This message should go to the log file
INFO:root:So should this
WARNING:root:And this, too

Logging from multiple modules

如果你的程序包含很多的模块，那么该如何使用和配置logging 模块呢，看下面的例子

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

# mylib.py
import logging

def do_something():
    logging.info('Doing something')

如果你跑上面的程序，在myapp.log文件里面的内容为

INFO:root:Started
INFO:root:Doing something
INFO:root:Finished

格式化log

在log中我们经常可以看到时间戳，机器名等信息，这些会使我们的log 更加的专业，python的logging 模块当然也支持这种功能。 看下面的例子

import logging
logging.basicConfig(format='%(asctime)s %(message)s')
logging.warning('is when this event was logged.')

输出结果为

2010-12-12 11:41:42,612 is when this event was logged.

其中时间格式是可以调整的，比如

import logging
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
logging.warning('is when this event was logged.')

输出为

12/12/2010 11:46:36 AM is when this event was logged.

logging.basicConfig 函数中各个参数的说明如下：

• filename: 指定日志文件名
• filemode: 和file函数意义相同，指定日志文件的打开模式，'w'或'a'。 如果指定为'w'，日志文件每次会被覆盖。默认为'a'
• format: 指定输出的格式和内容，format可以输出很多有用信息，如上例所示:
  %(levelno)s: 打印日志级别的数值
  %(levelname)s: 打印日志级别名称
  %(pathname)s: 打印当前执行程序的路径，其实就是sys.argv[0]
  %(filename)s: 打印当前执行程序名
  %(funcName)s: 打印日志的当前函数
  %(lineno)d: 打印日志的当前行号
  %(asctime)s: 打印日志的时间
  %(thread)d: 打印线程ID
  %(threadName)s: 打印线程名称
  %(process)d: 打印进程ID
  %(message)s: 打印日志信息
• datefmt: 指定时间格式，同time.strftime()
• level: 设置日志级别，默认为logging.WARNING
• stream: 指定将日志的输出流，可以指定输出到sys.stderr,sys.stdout或者文件，默认输出到sys.stderr，当stream和filename同时指定时，stream被忽略

上面为基本的简单用法，可以满足大部分的需求

logging高级用法

python的logging其实是由下面四个部分组成:

• Loggers : 这个给用户用接口
• Hanlders： logger生成的log内容由Handler发送到指定的地方，比如console，log文件，kafka等等
• Filters：
• Formatters : 制定log最后输出的格式

看个例子

import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)

# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# add formatter to ch
ch.setFormatter(formatter)

# add ch to logger
logger.addHandler(ch)

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')

输出结果是：

$ python simple_logging_module.py
2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
2005-03-19 15:10:26,620 - simple_example - INFO - info message
2005-03-19 15:10:26,695 - simple_example - WARNING - warn message
2005-03-19 15:10:26,697 - simple_example - ERROR - error message
2005-03-19 15:10:26,773 - simple_example - CRITICAL - critical message

过程比较清晰，先建logger，handler， formatter。然后给handler指定formatter，再给logger添加handler。 一个logger其实可以添加多个handler，而每个handler的formatter可以不同。这样你就可以既在console 中打印信息，又在log文件中记录信息。

下面这个例子就是这样：

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='myapp.log',
filemode='w')

#定义一个StreamHandler，将INFO级别或更高的日志信息打印到标准错误，并将其添加到当前的日志处理对象#
console = logging.StreamHandler()
console.setLevel(logging.INFO)
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
console.setFormatter(formatter)
logging.getLogger('').addHandler(console)

logging.debug('This is debug message')
logging.info('This is info message')
logging.warning('This is warning message')

输出为：

屏幕上打印:
root : INFO This is info message
root : WARNING This is warning message
./myapp.log文件中内容为:
Sun, 24 May 2009 21:48:54 demo2.py[line:11] DEBUG This is debug message
Sun, 24 May 2009 21:48:54 demo2.py[line:12] INFO This is info message
Sun, 24 May 2009 21:48:54 demo2.py[line:13] WARNING This is warning message

回滚日志

你可能不希望日子文件太大，所以你可能需要用到回滚日志的handler，看下面的例子

import logging
from logging.handlers import RotatingFileHandler
#################################################################################################
#定义一个RotatingFileHandler，最多备份5个日志文件，每个日志文件最大10M
Rthandler = RotatingFileHandler('myapp.log', maxBytes=10*1024*1024,backupCount=5)
Rthandler.setLevel(logging.INFO)
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
Rthandler.setFormatter(formatter)
logging.getLogger('').addHandler(Rthandler)
################################################################################################

python logging 模块提供下面几种handlers

• StreamHandler instances send messages to streams (file-like objects).
• FileHandler
  instances send messages to disk files.
• BaseRotatingHandler
  is the base class for handlers that rotate log files at a certain point. It is not meant to be instantiated directly. Instead, use RotatingFileHandler
  or TimedRotatingFileHandler
  .
• RotatingFileHandler
  instances send messages to disk files, with support for maximum log file sizes and log file rotation.
  TimedRotatingFileHandler
  instances send messages to disk files, rotating the log file at certain timed intervals.
• SocketHandler
  instances send messages to TCP/IP sockets.
• DatagramHandler
  instances send messages to UDP sockets.
  SMTPHandler
  instances send messages to a designated email address.
  SysLogHandler
  instances send messages to a Unix syslog daemon, possibly on a remote machine.
• NTEventLogHandler
  instances send messages to a Windows NT/2000/XP event log.
• MemoryHandler
  instances send messages to a buffer in memory, which is flushed whenever specific criteria are met.
• HTTPHandler
  instances send messages to an HTTP server using either GET
  or POST
  semantics.
• WatchedFileHandler
  instances watch the file they are logging to. If the file changes, it is closed and reopened using the file name. This handler is only useful on Unix-like systems; Windows does not support the underlying mechanism used.
• NullHandler
  instances do nothing with error messages. They are used by library developers who want to use logging, but want to avoid the ‘No handlers could be found for logger XXX’ message which can be displayed if the library user has not configured logging. See Configuring Logging for a Library for more information.

自己创建handler

当然你可以自己创建一个handler去处理，比如kafka， 看下面的例子

from kafka.client import KafkaClient
from kafka.producer import SimpleProducer,KeyedProducer
import logging,sys

class KafkaLoggingHandler(logging.Handler):

    def __init__(self, host, port, topic, key=None):
        logging.Handler.__init__(self)
        self.kafka_client = KafkaClient(host, port)
        self.key = key
        if key is None:
            self.producer = SimpleProducer(self.kafka_client, topic)
        else:
            self.producer = KeyedProducer(self.kafka_client, topic)

    def emit(self, record):
        #drop kafka logging to avoid infinite recursion
        if record.name == 'kafka':
            return
        try:
            #use default formatting
            msg = self.format(record)
            #produce message
            if self.key is None:
                self.producer.send_messages(msg)
            else:
                self.producer.send(self.key, msg)
        except:
            import traceback
            ei = sys.exc_info()
            traceback.print_exception(ei[0], ei[1], ei[2], None, sys.stderr)
            del ei

    def close(self):
        self.producer.stop()
        logging.Handler.close(self)

kh = KafkaLoggingHandler("localhost", 9092, "test_log")
#OR
#kh = KafkaLoggingHandler("localhost", 9092, "test_log", "key1")

logger = logging.getLogger("")
logger.setLevel(logging.DEBUG)
logger.addHandler(kh)
logger.info("The %s boxing wizards jump %s", 5, "quickly")
logger.debug("The quick brown %s jumps over the lazy %s", "fox",  "dog")
try:
    import math
    math.exp(1000)
except:
    logger.exception("Problem with %s", "math.exp")

P.S. The handler uses this Kafka client: https://github.com/mumrah/kafka-python

通过logging.config模块配置日志

logging模块的配置其实可以通过文件来配置，这样更加方便，看下面的例子

#logger.conf
###############################################
[loggers]
keys=root,example01,example02
[logger_root]
level=DEBUG
handlers=hand01,hand02
[logger_example01]
handlers=hand01,hand02
qualname=example01
propagate=0
[logger_example02]
handlers=hand01,hand03
qualname=example02
propagate=0
###############################################
[handlers]
keys=hand01,hand02,hand03
[handler_hand01]
class=StreamHandler
level=INFO
formatter=form02
args=(sys.stderr,)
[handler_hand02]
class=FileHandler
level=DEBUG
formatter=form01
args=('myapp.log', 'a')
[handler_hand03]
class=handlers.RotatingFileHandler
level=INFO
formatter=form02
args=('myapp.log', 'a', 10*1024*1024, 5)
###############################################
[formatters]
keys=form01,form02
[formatter_form01]
format=%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s
datefmt=%a, %d %b %Y %H:%M:%S
[formatter_form02]
format=%(name)-12s: %(levelname)-8s %(message)s
datefmt=

import logging
import logging.config
logging.config.fileConfig("logger.conf")
logger = logging.getLogger("example01")
logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')