[TOC] # 淺析python日志重復輸出問題 ## 問題起源： ? 在學習了python的函數式編程后，又接觸到了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，代碼演示如下： ``` 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 > \[ (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 > \[ (ERROR)>, (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.改名換姓 ``` # 為日志函數添加一個name，每次調用時傳入不同的日志名 def my_log(name): logger = logging.getLogger(name) 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('log1').error('run one') my_log('log2').error('run two') 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） ``` def my_log(): logger = logging.getLogger() # 每次被調用后，清空已經存在handler logger.handlers.clear() 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') ``` ### 3.用前判斷 ``` import logging def my_log(): logger = logging.getLogger('mysql.log') # 判斷logger是否已經添加過handler，是則直接返回，否則才執行 if not 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') ``` * * *