Python logging模块的学习与使用

1. 为什么打算使用logging模块

最近在重构手头的一个项目，其中有一个类Log是将软件运行过程中产生的重要的trace记录下来，用以在出错时分析使用。这个类主要就是write函数，将trace以一定的格式记录到不同的文档并在屏幕上输出：

log_file=open(log_path, "a")
log_file.write(current_time+":"+log_str+"\n")
log_file.close()

Log类有以下缺点：

1. 没有log级别定义，不管是在debug状态还是在平稳运行状态，产生的log都是一样的；
2. Log是一个类，每次都需要产生一个对象，或者将该对象以参数形式穿来穿去。这就导致在使用某些工具类之前必须传进来一个Log对象，反而让工具类使用变复杂了。
3. 以前是每个模块的log分开记录，现在想都记录到一个地方，因此Log中log文件管理的部分就不需要了。

综上考虑，与其修改Log类，不如使用经过千锤百炼的logging模块。

我希望使用logging模块实现：（1）将log记录到文件；（2）将log显示到屏幕；（3）将ERROR级别的log添加到邮件中。

2. Logging模块基础知识

上网查了N久，发现大部分都是源自一篇python的日志logging模块学习的文章，这篇文章对Python中logging部分的使用做了简单的描述，也成功的帮助我使用logging记录了一些log，但这似乎是不满足需求的。

python的日志logging模块学习：http://blog.csdn.net/yatere/article/details/6655445

（1）将log记录到文件：

按照刚刚提到的博文，以下代码可以实现此功能：

logging.basicConfig(filename =os.path.join(logging_fd,logging_fn),level =logging_level, filemode = 'a',format = '%(asctime)s - %(levelname)s: %(message)s') 

（2）将log显示到屏幕：

按照刚刚提到的博文，以下代码可以实现此功能：

console = logging.StreamHandler()
console.setLevel(logging_level)
formatter = logging.Formatter('%(asctime)s - %(levelname)s:%(message)s')
console.setFormatter(formatter)
logging.getLogger('').addHandler(console)

（3）将ERROR级别的log添加到邮件中，这个该如何实现呢？

打开Pythonmanual，找到logging这一页，开始阅读。Logging模块是由很多部分组成的。

Loggers，有三个功能： 1. 暴露出一些方法，使其能够在运行时logmessage；2.根据log级别和filter决定log哪些message；3. 将message传给所有的handler。

Handler对象就根据message的级别将message发送到特定的终端，如FileHandler记录到文件中，SocketHandler通过TCP/IP协议传送至另一终端，SMTPHandler将message发送给某个地址等。每个Handler对象可以设置自己的级别和message记录格式，一个Logger对象可以通过addHandler()添加多个handler对象。如果没有Handler对象，就默认将message输送至stderr。

 Formatters用来设置最终message的log格式。

在这里我们发现了一个类叫做SMTPHandler，它可以将message通过邮件发送。然后可以仿照之前添加handler的过程使用这个hander。

console = SMTPHandler(mailhost=("host",port), fromaddr="test@xxx.com", toaddrs="test_new@xxx.com", subject="error email",credentials=("user name","password"))
console.setLevel(logging.ERROR)
formatter = logging.Formatter('%(asctime)s - %(levelname)s: %(message)s')
console.setFormatter(formatter)
logging.getLogger('').addHandler(console)

得到的结果是：每个需要log的message都会发一封邮件出来，这个虽然能发邮件了，但并不是我想要结果。于是，我想到仿照SMTPHandler自定义一个handler。

3. 自定义Handler

查看SMTPHandler的源码可知，这个类中__init__，getSubject，date_time和emit几个函数，其中进行发送邮件操作的就是emit函数。也就是说，我想对每个error进行什么操作直接在这个函数里进行就可以了。因为之前已经有email的类了，因此我只需要在emit函数中，调用email的对象，将error message添加到邮件正文即可。

class MyHandler(logging.Handler):
    """
    A handler class which add error info to email content.
    """
    def __init__(self,e_obj):
        logging.Handler.__init__(self)
        self.e_obj=e_obj
        
    def emit(self, record):
        message=record.getMessage()
        self.e_obj.add_error_line(message)

本以为很难的自定义Handler就如此简单的初步实现了。使用自定义Handler的方法与使用其它Handler完全一致。

console = MyHandler(e_obj)
console.setLevel(<strong>logging.ERROR</strong>)
formatter = logging.Formatter('%(asctime)s - %(levelname)s: %(message)s')
console.setFormatter(formatter)
logging.getLogger('').addHandler(console)

将log的等级设置为ERROR就可以确保只有ERROR的message会添加到ERROR邮件正文中了。

4. logging源码学习

以logging.error()为例，说明一下调用关系：

def error(msg, *args, **kwargs):
    """
    Log a message withseverity 'ERROR' on the root logger.
    """
    if len(root.handlers) == 0:
        basicConfig()
   root.error(*((msg,)+args), **kwargs)

logging的py文件下有一个root，root是Logger的一个子类RootLogger的对象。当我们用error函数 logmessage时，首先会检查root是不是有handler，如果没有的话就调用basicConfig函数创建并新加一个；如果实在没有handler的话，则会设置向sys.stderr输出。之后则调用root的error函数来logmessage。

def error(self, msg, *args, **kwargs):
        ifself.isEnabledFor(ERROR):
           self._log(ERROR, msg, args, **kwargs)

Logger的error函数，首先检查Logger的级别，然后调用self._log来记录message。查看其它函数，如info，最后也都是调用self._log来记录message。

    def _log(self, level, msg, args, exc_info=None, extra=None):
        if _srcfile:
            fn, lno, func = self.findCaller()
        else:
            fn, lno, func = "(unknown file)", 0, "(unknown function)"
        if exc_info:
            if type(exc_info) != types.TupleType:
                exc_info = sys.exc_info()
        record = self.makeRecord(self.name, level, fn, lno, msg, args, exc_info, func, extra)
        self.handle(record)

这就是_log函数了，通过看它的代码，可以知道，这个函数首先汇集需要的各种信息，生成一个record对象，然后调用handle函数来handle这个record对象。

    def handle(self, record):
        if (not self.disabled) and self.filter(record):
            self.callHandlers(record)

handle函数很简单，就是再次检查权限，并检查是不是filter了。Filter就是在这里起作用的。再之后就是调用callHandlers处理record对象。

    def callHandlers(self, record):
        c = self
        found = 0
        while c:
            for hdlr in c.handlers:
                found = found + 1
                if record.levelno >= hdlr.level:
                    hdlr.handle(record)
            if not c.propagate:
                c = None    #break out
            else:
                c = c.parent
        if (found == 0) and raiseExceptions and not self.manager.emittedNoHandlerWarning:
            sys.stderr.write("No handlers could be found for logger"
                             " \"%s\"\n" % self.name)
            self.manager.emittedNoHandlerWarning = 1

在这个函数，就可以很清楚的看出，是将自身所有的handler一个个循环，调用每个handler的handle函数来处理record了。如果实在没有handler了，就只好报NoHandlerWarning的错了。

    def handle(self, record):
        rv = self.filter(record)
        if rv:
            self.acquire()
            try:
                self.emit(record)
            finally:
                self.release()
        return rv

打开Handle类的handle函数，可以看出，这里还是先对record对象进行一下过滤，过滤后在调用emit函数对record对象进行处理。这也就是为什么在自定义handler时需要重写emit函数了。

另外Logger和Handler都继承自Filterer，因此都可以对record进行过滤，是作为子类后才有了不同的分工。