1. 程式人生 > >分析python日誌重複輸出問題

分析python日誌重複輸出問題

問題起源:

​ 在學習了python的函數語言程式設計後,又接觸到了logging這樣一個強大的日誌模組。為了減少重複程式碼,應該不少同學和我一樣便迫不及待的寫了一個自己的日誌函式,比如下面這樣:

import logging


# 這裡為了便於理解,簡單的展示了一個輸出到螢幕的日誌函式
def my_log():
    logger = logging.getLogger('mysql.log')

    ch = logging.StreamHandler()
    ch.setLevel(logging.ERROR)
    fmt = logging.Formatter('
%(asctime)s - %(name)s - %(levelname)s - %(message)s') ch.setFormatter(fmt) logger.addHandler(ch) return logger my_log().error('run one') my_log().error('run two') my_log().error('run three')

函式寫好了,看起來似乎也沒有問題,我們來執行一下!

結果如下:

2018-06-21 13:06:37,569 - mysql.log - ERROR - run one
2018-06-21 13:06:37,569 - mysql.log - ERROR - run two
2018-06-21 13:06:37,569 - mysql.log - ERROR - run two
2018-06-21 13:06:37,569 - mysql.log - ERROR - run three
2018-06-21 13:06:37,569 - mysql.log - ERROR - run three
2018-06-21 13:06:37,569 - mysql.log - ERROR - run three

日誌居然重複輸出了,且數量遞增。


問題解析

  • 實際上logger = logging.getLogger('mysql.log')在執行時,沒有每次生成一個新的logger,而是先檢查記憶體中是否存在一個叫做‘mysql.log’的logger物件,存在則取出,不存在則新建。

  • 例項化的logger物件具有‘handlers’這樣一個屬性來儲存 Handler,程式碼演示如下:

import logging


def my_log():
    logger = logging.getLogger('mysql.log')
    # 每次被呼叫後打印出logger的handlers列表
print(logger.handlers) ch = logging.StreamHandler() ch.setLevel(logging.ERROR) fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') ch.setFormatter(fmt) logger.addHandler(ch) return logger my_log().error('run one') my_log().error('run two') my_log().error('run three')

執行結果:

[]
2018-06-21 13:26:14,059 - mysql.log - ERROR - run one
[<StreamHandler <stderr> (ERROR)>]
2018-06-21 13:26:14,060 - mysql.log - ERROR - run two
2018-06-21 13:26:14,060 - mysql.log - ERROR - run two
[<StreamHandler <stderr> (ERROR)>, <StreamHandler <stderr> (ERROR)>]
2018-06-21 13:26:14,060 - mysql.log - ERROR - run three
2018-06-21 13:26:14,060 - mysql.log - ERROR - run three
2018-06-21 13:26:14,060 - mysql.log - ERROR - run three

  1.  logger.handlers 最初是一個空列表,執行 ‘logger.addHandler(ch)’ 新增一個 ‘StreamHandler’ ,輸出一條日誌
  2. 在第二次被呼叫時, logger.handlers 已經存在一個 ‘StreamHandler’ ,再次執行 ‘logger.addHandler(ch)’ 就會再次新增一個 ‘StreamHandler’ ,此時的logger有兩個 ‘StreamHandler’ ,輸出兩條重複的日誌
  3. 在第三次被呼叫時, logger.handlers 已經存在兩個 ‘StreamHandler’ ,再次執行 ‘logger.addHandler(ch)’ 就會再次新增一個,此時的logger有三個 ‘StreamHandler’ ,輸出三條重複的日誌

解決辦法

1.改名換姓

 1 import logging
 2 
 3 
 4 # 為日誌函式新增一個name,每次呼叫時傳入不同的日誌名
 5 def my_log(name):
 6     logger = logging.getLogger(name)
 7 
 8     ch = logging.StreamHandler()
 9     ch.setLevel(logging.ERROR)
10     fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
11     ch.setFormatter(fmt)
12     logger.addHandler(ch)
13 
14     return logger
15 
16 
17 my_log('log1').error('run one')
18 my_log('log2').error('run two')
19 my_log('log3').error('run three')

執行結果:

2018-06-21 13:40:51,685 - log1 - ERROR - run one
2018-06-21 13:40:51,685 - log2 - ERROR - run two
2018-06-21 13:40:51,685 - log3 - ERROR - run three

2.及時清理(logger.handlers.clear)

 1 import logging
 2 
 3 
 4 def my_log():
 5     logger = logging.getLogger('mysql.log')
 6     # 每次被呼叫後,清空已經存在handler
 7     logger.handlers.clear()
 8 
 9     ch = logging.StreamHandler()
10     ch.setLevel(logging.ERROR)
11     fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
12     ch.setFormatter(fmt)
13 
14     logger.addHandler(ch)
15 
16     return logger
17 
18 
19 my_log().error('run one')
20 my_log().error('run two')
21 my_log().error('run three')

ps:removeHandler方法(相容性較差)

 1 # 這種寫法下的可以使用removeHandler方法(logger.handlers.clear也可以使用在這種寫法的函式內)
 2 import logging
 3 
 4 
 5 def my_log(msg):
 6     logger = logging.getLogger('mysql.log')
 7 
 8     ch = logging.StreamHandler()
 9     ch.setLevel(logging.ERROR)
10     fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
11     ch.setFormatter(fmt)
12 
13     logger.addHandler(ch)
14     logger.error(msg)
15     
16     # 在使用完ch後從移除Handler
17     logger.removeHandler(ch)
18 
19 
20 my_log('run one')
21 my_log('run two')
22 my_log('run three')

3.用前判斷

 1 import logging
 2 
 3 
 4 def my_log():
 5     logger = logging.getLogger('mysql.log')
 6     # 判斷logger是否已經新增過handler,是則直接返回logger物件,否則執行handler設定以及addHandler(ch)
 7     if not logger.handlers:
 8         ch = logging.StreamHandler()
 9         ch.setLevel(logging.ERROR)
10         fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
11         ch.setFormatter(fmt)
12 
13         logger.addHandler(ch)
14 
15     return logger
16 
17 
18 my_log().error('run one')
19 my_log().error('run two')
20 my_log().error('run three')

總結

​ 第一次遇到日誌重複輸出問題,那時還沒有學習到面向物件程式設計的內容,當時並沒有真正理解logging模組。學習完面向物件程式設計後,回過頭來再思考這些問題有了豁然開朗的感覺。

​ 比如起初對logging.getLogger的實際原理不是很理解,在學習了面向物件程式設計中的hasattr、getattr、setattr這樣一些方法後就恍然大悟了。所以諸君如果現在還是對logging模組不太理解,不妨先不糾結於這些細節,繼續學下去。

​ 知識面擴充後,曾經的一些難題自然就會迎刃而解:)


參考內容:

luffycity : https://www.luffycity.com/home

The Python Standard Library

huilan_same :https://blog.csdn.net/huilan_same/article/details/51858817