Python CLog——打印日誌的同時打印被調用的方法、類和文件名

CLog的一個例子

我在文章開頭，先告訴你們，CLog是幹什麼的，看下面的例子：

__author__ = 'baniu.yao'

from CLog import CLog

class FooClass(object):

    def foo(self, text):
        log = CLog()
        log.write('hello world')

if __name__ == '__main__':
    fc = FooClass()
    fc.foo('def')

運行python example.py後，日誌以下：

2014-03-30 19:09:35,582 [example.py:FooClass() --> example.py:foo('def')] hello world

CLog的做用，就是在打印日誌的同時，把文件名，類名，方法名和方法的參數都打印出來了。而咱們在使用CLog的時候，是徹底透明的，不須要關心這些細節，這一切都是CLog完成的。

CLog在這裏：https://github.com/baniuyao/Python-CLog

爲何我要開發一個Python日誌模塊

以前我一直使用Python自帶的logging模塊來打印日誌，他功能強大，能夠定製很是多的東西，但惟一讓我不爽的，就是當我在看我打印的日誌的時候，我根本不知道這條日誌是在哪一個地方打印的。特別是最近我在開發一個報警系統，設計到報警規則的解析，算是一個比較複雜的系統。我須要一個強大的日誌可以幫我追蹤程序的每一次關鍵的邏輯判斷，簡而言之，我要知道個人這條日誌，是在哪一個文件的哪一個類裏的哪一個方法中打印的，最好還能知道方法調用的參數。

好比一個foo.py：

def Foo(object):
    def foo(self):
        log.log('hello world')
if __name__ == '__main__':
    f = Foo()
    f.foo()

而後日誌中是這樣的：
foo.py:Foo() --> foo.py:foo() hello world

是否是很棒？

基於這個需求，我開發了Python-CLog。其中的CLog是Chain Log的簡稱，由於CLog的目的是打印出整個調用鏈。

Python logging模塊和CLog對比

logging模塊支持打印調用logging方法的函數名和模塊名，但這個功能很是的簡陋，只支持當前調用這個logging方法所在的函數，不支持鏈式的追蹤。咱們看下面這個例子。

代碼Foo1_logging.py：

import logging
from Foo2 import Foo2

logging.basicConfig(filename="./use_logging.log", 
                    format='%(asctime)-6s: %(name)s - %(levelname)s - %(module)s - %(funcName)s - %(lineno)d - %(message)s', 
                    level=logging.DEBUG)

class Foo1(object):
    def foo(self, text):
        f2 = Foo2()
        f2.foo('foo2')
        logging.info('use logging in foo1')

if __name__ == '__main__':
    f = Foo1()
    f.foo('foo1')

代碼Foo2_logging.py:

import logging

logging.basicConfig(filename="./use_logging.log", 
                    format='%(asctime)-6s: %(name)s - %(levelname)s - %(module)s - %(funcName)s - %(lineno)d - %(message)s', 
                    level=logging.DEBUG)

class Foo2(object):
    def foo(self, text):
        logging.info('use logging in foo2')

使用logging模塊的結果

我運行了Foo1_logging.py，獲取到的use_logging.log以下：

2014-03-30 23:28:25,795: root - INFO - Foo2 - foo - 11 - use logging in foo2
2014-03-30 23:28:34,619: root - INFO - Foo2 - foo - 11 - use logging in foo2
2014-03-30 23:28:34,619: root - INFO - Foo1 - foo - 14 - use logging in foo1

若是說不看代碼內容，我想能看懂Foo1和Foo2的依賴關係是很是困難的吧。若是還有併發的請求，那麼日誌幾乎是沒有用處的。並且，Foo1和Foo2的foo方法都接受一個參數，這個參數，也沒有在日誌裏反應出來。

咱們看看CLog對於這種狀況，日誌是怎樣的，代碼有稍許變更。

Foo1_cl.py:

from Foo2_cl import Foo2
from CLog import CLog

class Foo1(object):
    def foo(self, text):
        f2 = Foo2()
        f2.foo('foo2')
        cl = CLog()
        cl.write('use CL in foo1')

if __name__ == '__main__':
    f = Foo1()
    f.foo('foo1')

Foo2_cl.py:

from CLog import CLog

class Foo2(object):
    def foo(self, text):
        cl = CLog()
        cl.write('use clog in foo2')

使用CLog的日誌：

2014-03-30 23:35:18,630 [Foo1_cl.py:Foo2() --> Foo1_cl.py:foo('foo1') --> Foo2_cl.py:foo('foo2')] use clog in foo2
2014-03-30 23:35:18,630 [Foo1_cl.py:Foo1() --> Foo1_cl.py:foo('foo1')] use CL in foo1

是否是清楚多了呢？調用鏈很是清楚，也知道foo的參數是什麼，相比logging的日誌，你們能夠比較一下。

CLog是怎麼工做的

不知道有多少人讀過《Python源碼分析》，Python在執行代碼的時候，有一個棧幀frame的概念，咱們把它理解成一張紙片，而運行一段Python代碼，就是用線把一串紙片串起來執行。CLog就是調用了Python自帶的inspect模塊，來獲取到執行時代碼的frame，從中找到咱們須要的信息，咱們仍是看example.py，此次我把CLog模塊的代碼改了一下，將調用write時候的frames所有打印出來：

(<frame object at 0xe0faef0>, '/python-chain-log/CLog.py', 28, 'get_meta_data', ['        frames = inspect.stack()\n'], 0)
(<frame object at 0xe0fad00>, '/python-chain-log/CLog.py', 46, 'write', ['        chain = self.get_meta_data()\n'], 0)
(<frame object at 0xe0f4280>, 'example.py', 9, 'foo', ["        log.write('hello world')\n"], 0)
(<frame object at 0xe088400>, 'example.py', 13, '<module>', ["    fc.foo('def')\n"], 0)

從裏面咱們獲取的信息，就可以獲得CLog獲取到的信息了。

TOOD

CLog是我在上週五花了半天開發的，下一步我會添加CLog在終端打印日誌的功能，目前僅僅支持打印到日誌文件。