【轉載】Python 之 logging 使用分析

      昨天 lord leatherface 問我為什麼使用了 suds 後，輸出日志變成了兩條。于是我仔細地研究了 logging 的日志處理機制，并且再次考慮了 uliweb 的日志處理，最終對 uliweb的 日志進行了重構，并且弄清楚了為什麼會有兩條日志的現象，是以以本文作一個記錄。

對于 logging 我想大家用得應該不少，那麼我先提幾個問題： 

logging 直接輸出日志，如 logging.info() 與 log = logging.getlogger('name') log.info() 有什麼不同？

“no handlers could be found for logger”是怎麼回事？

root logger 有什麼用，如何獲得？

形如 "a.b.c" 的 logger 名有什麼用？

如果一個 logger 執行多次 addhandler，那麼每個 handler 都會被執行嗎？

logger 的傳播（propagate）是怎麼回事？如何阻止它？

有時候帶着問題學習可能會更快。那麼下面根據我的了解一點點進行解釋。 

      logging 中 log 是可以分級的，它的級别與你使用 getlogger() 中的名字有關系。比如，你可以使用 "uliweb" 或 "uliweb.app"，它們的差別就是 "uliweb.app" 中有一個 '.' 。那麼 logging 會自動生成 "uliweb" 和 "uliweb.app" 的 logger，并且 "uliweb" 将是 "uliweb.app" 的 logger 的父對象。這一點可以這樣驗證： 

<a href="http://my.oschina.net/moooofly/blog/173993#">?</a>

1

2

3

4

<code>&gt;&gt;&gt;</code><code>import</code> <code>logging</code>

<code>&gt;&gt;&gt; log</code><code>=</code> <code>logging.getlogger(</code><code>'uliweb.app'</code><code>)</code>

<code>&gt;&gt;&gt; log.manager.loggerdict.items()</code>

<code>[(</code><code>'uliweb.app'</code><code>, &lt;logging.logger instance at</code><code>0x017ce238</code><code>&gt;), (</code><code>'uliweb'</code><code>, &lt;logging.placeholder instance at</code><code>0x017ce2d8</code><code>&gt;)]</code>

       這裡有一個挺有意思的問題，就是 'uliweb' 這個 logger 它的對象是 placeholder（占位對象），相當于是一個“虛”日志對象。logging 可以允許通過 getlogger() 來自動生成對應的 logger 對象。對于分級的日志名字，它會一級級地建立，如果父對象還不存在，則會自動建立一個占位對象。如果後續使用者又通過 getlogger() 建立一個父對象，則 logging 會自動對父子關系進行重新修訂，保證對象關系的正确性。

再看一看父子關系： 

5

6

7

<code>&gt;&gt;&gt; log.parent</code>

<code>&lt;logging.rootlogger instance at</code><code>0x017e3ad0</code><code>&gt;</code>

<code>&gt;&gt;&gt; log1</code><code>=</code> <code>logging.getlogger(</code><code>'uliweb'</code><code>)</code>

<code>&lt;logging.logger instance at</code><code>0x01820da0</code><code>&gt;</code>

<code>&gt;&gt;&gt; log.parent.name</code>

<code>'uliweb'</code>

      可以看到， 當我們直接通過 getlogger('uliweb.app') 獲得日志對象時，它的 parent 并不是占位對象 'uliweb'，而是 rootlogger 。這個 rootlogger 是在導入 logging 時自動由子產品建立的，它的建立代碼是： 

<code>root</code><code>=</code> <code>rootlogger(warning)</code>

<code>logger.root</code><code>=</code> <code>root</code>

<code>logger.manager</code><code>=</code> <code>manager(logger.root)</code>

       logger 是真正的 logger 的類。可以看它在運作時會給它賦予 root 和 manager 對象。而 manager 就是用來建立 logger 并進行管理的類。前面的代碼就是通過檢視 manager.loggerdict 來檢視所有已經定義的 logger 。是以從上面的代碼我們可以了解，在直接建立一個多級的 logger 時，如果父對象不存在，則父對象自然是root 對象。如果父對象被建立，則父子關系被修正。

      root 對象有什麼用呢？它就是預設的日志對象。使用 logging 的最簡單的方法是： 

<code>import</code> <code>logging</code>

<code>logging.info()</code>

可以直接輸出。這裡有什麼秘密？看一看代碼一切就都清楚了。 

<code>def</code> <code>info(msg,</code><code>*</code><code>args,</code><code>*</code><code>*</code><code>kwargs):</code>

<code>    </code><code>"""</code>

<code>    </code><code>log a message with severity 'info' on the root logger.</code>

<code>    </code><code>if</code> <code>len</code><code>(root.handlers)</code><code>=</code><code>=</code> <code>0</code><code>:</code>

<code>        </code><code>basicconfig()</code>

<code>    </code><code>root.info(</code><code>*</code><code>((msg,)</code><code>+</code><code>args),</code><code>*</code><code>*</code><code>kwargs)</code>

       這裡先對 root 的 handlers 進行判斷。那麼 handlers 是什麼東西？它就是用來處理每條日志的處理類的執行個體。每個 logger 可以有不止一個 handler 執行個體。并且每個 handler 對象可以有自已的日志輸出級别，可以和logger 的不同。handler 的處理我們後面再說。上面的代碼意思就是，如果 root 還沒有定義處理對象，則執行basicconfig() 進行預設配置。然後使用 root.info() 進行輸出。是以我們可以了解：logging.info() 其實就是使用 root來進行輸出的，你可以了解它是一個全局性的，預設的日志對象。并且可以自動進行配置。那麼，為什麼要配置？因為 rootlogger(warning) 隻是建立了 logger 類，但是還沒有添加任何的 handler，是以handlers 是空的。也就是說，建立了一個 logger，并不表示它就可以輸出日志。是不是有些奇怪？還是以代碼為上： 

8

9

10

11

12

13

14

15

16

<code>def</code> <code>callhandlers(</code><code>self</code><code>, record):</code>

<code>        </code><code>c</code><code>=</code> <code>self</code>

<code>        </code><code>found</code><code>=</code> <code>0</code>

<code>        </code><code>while</code> <code>c:</code>

<code>            </code><code>for</code> <code>hdlr</code><code>in</code> <code>c.handlers:</code>

<code>                </code><code>found</code><code>=</code> <code>found</code><code>+</code> <code>1</code>

<code>                </code><code>if</code> <code>record.levelno &gt;</code><code>=</code> <code>hdlr.level:</code>

<code>                    </code><code>hdlr.handle(record)</code>

<code>            </code><code>if</code> <code>not</code> <code>c.propagate:</code>

<code>                </code><code>c</code><code>=</code> <code>none</code>    <code>#break out</code>

<code>            </code><code>else</code><code>:</code>

<code>                </code><code>c</code><code>=</code> <code>c.parent</code>

<code>        </code><code>if</code> <code>(found</code><code>=</code><code>=</code> <code>0</code><code>)</code><code>and</code> <code>raiseexceptions</code><code>and</code> <code>not</code> <code>self</code><code>.manager.emittednohandlerwarning:</code>

<code>            </code><code>sys.stderr.write(</code><code>"no handlers could be found for logger"</code>

<code>                             </code><code>" \"%s\"\n"</code> <code>%</code> <code>self</code><code>.name)</code>

<code>            </code><code>self</code><code>.manager.emittednohandlerwarning</code><code>=</code> <code>1</code>

       上面的代碼是 logger 類中用來輸出日志的一個方法，所有的秘密都在這裡面了。這裡不一條條解決了，說一下我的了解吧。它首先設定了一個 found 的标志，它的作用就是如果找到了一個可用的 handler，則加 1，然後等最後判斷一下，如果 found 為 0，則表示你還沒有對 logger 進行配置，在最後會輸出“no handlers could be found for logger”的資訊。還記得 root 的事情嗎？建立了一個 logger 并不表示它就帶有 handler了，也就是無法進行處理。是以 logging.info() 代碼中，會當 root 沒有配置 handler 時，使用 basicconfig()來進行配置。那麼在 basicconfig() 的代碼中，你會看到它會根據傳入的參數自動生成相應的 handler 執行個體，添加到 root 中去。是以 logging.info() 不會報錯，是因為它自動配置了。而你自已認證 getlogger() 得到的某個日志對象，可沒有自動化的配置方式，是以有可能會報錯。是以現在我們可以就有一個印象，日志使用前要配置，主要是添加相應的 handler。那麼這段代碼還有什麼特殊的？一個就是 c.propagate（propagate 的中文意思是傳播），它是 logger 的一個屬性，預設為 1。從上面的代碼可以看出，如果 propagate 為 0 或假值，則循環就退出了。如果為 1，則循環會繼續從父對象開始，直到找不到或 propagate 為假。是以 logging 會利用propagate 和父對象進行遞歸處理或傳播處理。是以就樣就實作這樣一種效果：在傳播情況下，從子結點到父結點的handler都會被處理一番。當然，還有一個檢查點就是資訊輸出的日志級别要大于等于 handler 的日志級别。是以，如果父結點和子結點都定義了 handler，并且日志級别都符合要求，這樣的确會輸出兩條日志，但是由不同的 handler 輸出的。是以，如果子對象定義了自已的 handler，為了避免傳播，是以應該設定它的propagate=0 。但是，利用傳播，我們也可以實作，子日志對象不定義自已的 handler，是以最終是使用父對象的 handler。特别是對于父對象是 root 對象的情況，隻要執行了 basicconfig()，則一定會存在 handler，就可以複用 root 的 handler 了。上面的代碼還有一點要注意的就是，它會對 logger 的所有 handler 進行循環，當然同時要檢查日志輸出級别。是以，如果你為一個 logger 定義了多個 handler，那麼就有可能都會輸出。如果想區分不同的 handler，可以利用級别來控制。對于 root 對象，再說一點就是什麼時候要執行 basicconfig()進行配置？如果你沒有自定義 logger，隻是使用 logging 中已經提供的如：info(), debug() 之類的方法，的确不必特别調用 basicconfig()，因為這些函數在執行時都做了檢查，如果沒通過，則自動會調用 basicconfig()。但是，如果你不是這樣使用，而是使用自定義的 logger，是以還是建議你先執行 basicconfig() 進行預設的配置。在使用自定義的 logger，要注意的問題就是：handler 的添加與 propagate 的處理。

      那麼如果我想獲得 root 對象該如何做呢？使用 logging.root 嗎？常用的方法還是通過 getlogger('')來獲得。參數可以是 '' 或其它為假的值。

      通過上面的講解，我想你應該知道我提的幾個問題的答案了吧。下面再簡單總結一下：

logger 是分級的，有父子關系；

logger 的處理要靠 handler 來輸出；

獲得了 logger 并不一定會自動建立 handler，是以 logger 一般都需要配置；

在存在父子關系的情況下，日志是可以被傳播輸出的，并且可以通過 propagate 屬性來控制。