解決Python中由于logging模塊誤用導致的內存泄露

首先介紹下怎么發現的吧, 線上的項目日志是通過 logging 模塊打到 syslog 里, 跑了一段時間后發現 syslog 的 UDP 連接超過了 8W, 沒錯是 8 W. 主要是 logging 模塊用的不對

我們之前有這么一個需求, 就是針對每一個連接日志輸出當前連接的信息, 所以每一個 連接就創建了一個日志實例, 并分配一個 Formatter, 創建日志實例為了區分其他連接 所以我就簡單粗暴的用了當前對象的 id 來作為日志名稱:    
import logging
 
 
class Connection(object):
  def __init__(self):
    self._logger_name = "Connection.{}".format(id(self))
    self.logger = logging.getLogger(self._logger_name)

當然測試環境是開 DEBUG, 開 DEBUG 就不會往 syslog 里打, 所以不會出現 UDP 連接數 過多, 也就不會知道有內存泄露的, 我們來看看這樣為什么會導致內存泄露, 首先看看 getLogger 的代碼:    
def getLogger(name=None):
  """
  Return a logger with the specified name, creating it if necessary.
 
  If no name is specified, return the root logger.
  """
  if name:
    return Logger.manager.getLogger(name)
  else:
    return root

主要調用了 Logger.manager.getLogger, 這個函數有下面一段代碼片段    
if name in self.loggerDict:
  rv = self.loggerDict[name]
  if isinstance(rv, PlaceHolder):
    ph = rv
    rv = (self.loggerClass or _loggerClass)(name)
    rv.manager = self
    self.loggerDict[name] = rv
    self._fixupChildren(ph, rv)
    self._fixupParents(rv)
else:
  rv = (self.loggerClass or _loggerClass)(name)
  rv.manager = self
  self.loggerDict[name] = rv
  self._fixupParents(rv)

logging 模塊為了保證同一個名稱引用同一個日志實例,所以就把所有的日志實例全部存 在了一個 loggerDict 的字典里, 所以除非程序退出, 創建的日志實例引用是不會釋放的, 所以日志實例里的 handlers 也不會釋放. 之前我又用的對象的 id 來作為日志名稱 的一部分, 所以 SyslogHandler 創建的 UDP 連接就一直被占用導致了過多的 UDP 連接.

為了解決這個問題我在連接關閉的時候加入了如下代碼:    
logging.Logger.manager.loggerDict.pop(self._logger_name)
self.logger.manager = None
self.logger.handlers = []

按說只加上上面第一行的代碼就應該釋放了, 但是沒有, 所以又有了第三行代碼, SyslogHandler 才最終釋放, 這個問題暫時還不知道為什么, 還需要再查查.

2015-03-30 更新 如果日志名稱是以 . 分隔, logging 模塊則會將最后一部分作為日志名, 并往上去尋找 父 Logger, 如果找不到則創建 PlaceHolder 對象作為父, 并引用 Logger.

比如創建的 Logger 名稱為 a.b.c, 那么實際的名稱則為 c, 并將 b 作為 c 的父, a 作為 b 的 父, 如果沒有該名稱的 Logger 則創建 PlaceHolder 對象作為代替, PlaceHolder 會創建對當前 Logger 的引用. 所以需要被回收的日志對象名稱里不應包含 .