python避坑指南02——logging模組日誌重複列印問題

標籤：module   val   util   hand   函數調用   equal   指南   print   lib   

目錄

[TOC]

一、問題拋出

        python的logging模組是python使用過程中列印日誌的利器。我們可以使用logging模組的logger、Handler、formatter對我們的日誌進行封裝，指定日誌輸出的路徑、格式以及位置。在聲明logger的時候可以傳一個字串作為這個logger的標籤。一直以為這個logger是以單例對象的設計模式設計的，只要這個標籤名是一樣的，那麼返回的logger就是同一個。在列印日誌的時候，想要實現日誌分層，定義類如下函數來封裝日誌列印函數（由於原始碼已經修改，用虛擬碼形式）

def print_log_info(msg):    # Logger是我定義的一個類，用來封裝日誌列印的    logger = Logger(‘INFO‘).getLogger()    logger.info(msg)

        在測試案例中用到了ddt，將測試案例參數化。關鍵代碼如下：

    @data(*test_datas[‘test_add‘])    @unpack    def test_add(self, *args, **kwargs):        data_path, err_num, test_id, p1, p2, value = args        result = Test(p1, p2).add()        try:            self.assertEqual(result, value, "在{err_num}行用例編號為{test_id}的測試中加法錯誤，請重新輸入" .format(                err_num = err_num,                test_id = test_id            ))            utils.print_log_info("在{err_num}行用例編號為{test_id}的測試中加法測試成功".format(err_num = err_num,test_id = test_id))        except AssertionError as err:            err_str = traceback.format_exc()            raise err

        執行完測試案例後，發現一條測試案例列印了多條，並且，重複列印次數由1一直增加到n（博主比較懶，這是原始碼出現的問題）。

二、問題解決

        一開始，一直以為是ddt的bug。但後來直接在外部定義了一個logger，調用這個logger列印日誌的時候，發現日誌沒有重複列印的情況，而當我偶然的情況下，兩次聲明了同一個logger的情況下，發現日誌列印了兩次。便開始思考這是不是logging模組本身的問題，由於第一章的代碼中，每次列印日誌，都需要print_log_info()函數，這個函數每次調用時，都申明了一次logger。每一條測試案例執行完，都需要列印日誌，再聲明一次logger，那麼聲明logger的次數就是1累計增加到n，是不是和我們上面重複日誌列印的情況類似？所以考慮問題的出現是由重複聲明logger造成的。為了驗證猜想，對代碼做如下修改（原始碼太長，粘部分關鍵代碼）。

info_logger = Logger(‘INFO‘).get_logger()error_logger = Logger(‘ERROR‘).get_logger()def print_log_info(msg):    ‘‘‘    列印測試案例執行的正常資訊以及控制台日誌    :param msg:需要列印的資訊    :return:    ‘‘‘    # 擷取函數調用者的資訊    caller_module, msg_lineno = trace_caller(2)    edit_msg = ‘[%s] : [%s]     %s‘ % (caller_module, msg_lineno, msg)    print(edit_msg)    info_logger.info(edit_msg)def print_log_error(msg):    ‘‘‘    用例出錯時，列印錯誤記錄檔以及控制台輸出    :param msg: 需要列印的資訊    :return:    ‘‘‘    edit_msg = msg    error_logger.error(edit_msg)

測試案例中，與第一章同樣的方式調用日誌列印的代碼，得到日誌如下，重複日誌的bug已經解決：

[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [82]     在3行用例編號為test_add01的測試中加法測試成功[2018-04-30 Monday 12:00:45] [ERROR] [MainThread:28980] 檔案：data\calculator.xls中測試案例出錯出錯用例行：4，用例編號：test_add02Traceback (most recent call last):  File "C:\Users\Think\PycharmProjects\InterfaceFrame\src\test\case\testExample.py", line 80, in test_add    test_id = test_id  File "C:\Python33\lib\unittest\case.py", line 641, in assertEqual    assertion_func(first, second, msg=msg)  File "C:\Python33\lib\unittest\case.py", line 634, in _baseAssertEqual    raise self.failureException(msg)AssertionError: 3 != 4 : 在4行用例編號為test_add02的測試中加法錯誤，請重新輸入[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [82]     在5行用例編號為test_add03的測試中加法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [82]     在6行用例編號為test_add04的測試中加法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [160]     在15行用例編號為test_div01的測試中除法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [160]     在16行用例編號為test_div02的測試中除法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [160]     在17行用例編號為test_div03的測試中除法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [160]     在18行用例編號為test_div04的測試中除法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [135]     在11行用例編號為test_multi01的測試中乘法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [135]     在12行用例編號為test_multi02的測試中乘法測試成功[2018-04-30 Monday 12:00:45] [INFO] [MainThread:28980] [src\test\case\testExample.py] : [135]     在13行用例編號為test_multi03的測試中乘法測試成功

python避坑指南02——logging模組日誌重複列印問題