目錄

[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_add02
Traceback (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模塊日誌重復打印問題