以打印日志為榮之logging模塊詳細使用

啄木鳥社區里的Pythonic八榮八恥有一條：

以打印日志為榮 , 以單步跟蹤為恥;

很多程序都有記錄日志的需求，並且日志中包含的信息既有正常的程序訪問日志，還可能有錯誤、警告等信息輸出，python的logging模塊提供了標准的日志接口，你可以通過它存儲各種格式的日志，主要用於輸出運行日志，可以設置輸出日志的等級、日志保存路徑、日志文件回滾等；

為什么不用print打印輸出？

這種方式對於簡單腳本型程序有用，但是如果是復雜的系統，最好不要用。首先，這些print是沒用的輸出，大量使用很有可能會被遺忘在代碼里。再者，print 輸出的所有信息都到了標准輸出中，這將嚴重影響到你從標准輸出中查看其它輸出數據。

使用logging的優勢：

a）你可以控制消息的級別，過濾掉那些並不重要的消息。

b）你可決定輸出到什么地方，以及怎么輸出。有許多的重要性別級可供選擇，debug、info、warning、error 以及 critical。通過賦予 logger 或者 handler 不同的級別，你就可以只輸出錯誤消息到特定的記錄文件中，或者在調試時只記錄調試信息。

下面讓我們正式進入logging的世界：

1. logging日志框架

主要包括四部分：

• Loggers: 可供程序直接調用的接口，app通過調用提供的api來記錄日志
• Handlers: 決定將日志記錄分配至正確的目的地
• Filters:對日志信息進行過濾， 提供更細粒度的日志是否輸出的判斷
• Formatters: 制定最終記錄打印的格式布局

1）loggers

loggers 就是程序可以直接調用的一個日志接口，可以直接向logger寫入日志信息。logger並不是直接實例化使用的，而是通過logging.getLogger(name)來獲取對象，事實上logger對象是單例模式，logging是多線程安全的，也就是無論程序中哪里需要打日志獲取到的logger對象都是同一個。但是不幸的是logger並不支持多進程，這個在后面的章節再解釋，並給出一些解決方案。

【注意】loggers對象是有父子關系的，當沒有父logger對象時它的父對象是root，當擁有父對象時父子關系會被修正。舉個例子，logging.getLogger("abc.xyz") 會創建兩個logger對象，一個是abc父對象，一個是xyz子對象，同時abc沒有父對象，所以它的父對象是root。但是實際上abc是一個占位對象（虛的日志對象），可以沒有handler來處理日志。但是root不是占位對象，如果某一個日志對象打日志時，它的父對象會同時收到日志，所以有些使用者發現創建了一個logger對象時會打兩遍日志，就是因為他創建的logger打了一遍日志，同時root對象也打了一遍日志。

2）Handlers

Handlers 將logger發過來的信息進行准確地分配，送往正確的地方。舉個栗子，送往控制台或者文件或者both或者其他地方(進程管道之類的)。它決定了每個日志的行為，是之后需要配置的重點區域。

每個Handler同樣有一個日志級別，一個logger可以擁有多個handler也就是說logger可以根據不同的日志級別將日志傳遞給不同的handler。當然也可以相同的級別傳遞給多個handlers這就根據需求來靈活的設置了。

3）Filters

Filters 提供了更細粒度的判斷，來決定日志是否需要打印。原則上handler獲得一個日志就必定會根據級別被統一處理，但是如果handler擁有一個Filter可以對日志進行額外的處理和判斷。例如Filter能夠對來自特定源的日志進行攔截or修改甚至修改其日志級別（修改后再進行級別判斷）。

logger和handler都可以安裝filter甚至可以安裝多個filter串聯起來。

4） Formatters

Formatters 指定了最終某條記錄打印的格式布局。Formatter會將傳遞來的信息拼接成一條具體的字符串，默認情況下Format只會將信息%(message)s直接打印出來。Format中有一些自帶的LogRecord屬性可以使用，如下表格:

一個Handler只能擁有一個Formatter 因此如果要實現多種格式的輸出只能用多個Handler來實現。

上圖只是一部分，更詳細的在docs.python.org里找logging模塊：

2. 日志級別

在記錄日志時, 日志消息都會關聯一個級別(“級別”本質上是一個非負整數)。系統默認提供了6個級別，它們分別是：

可以給日志對象(Logger Instance)設置日志級別，低於該級別的日志消息將會被忽略，也可以給Hanlder設置日志級別，對於低於該級別的日志消息, Handler也會忽略。

3. 常用函數

如果想要快速碼代碼，可以直接看第4節，基本使用

1）logging.basicConfig([**kwargs]):

為日志模塊配置基本信息。設置后可以直接使用logging來打印日志

kwargs 支持如下幾個關鍵字參數：
filename ：日志文件的保存路徑。如果配置了些參數，將自動創建一個FileHandler作為Handler；
filemode ：日志文件的打開模式。 默認值為’a’，表示日志消息以追加的形式添加到日志文件中。如果設為’w’, 那么每次程序啟動的時候都會創建一個新的日志文件；
format ：設置日志輸出格式；
datefmt ：定義日期格式；
level ：設置日志的級別.對低於該級別的日志消息將被忽略；
stream ：設置特定的流用於初始化StreamHandler；

 

logging.basicConfig(level=log_level, format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s', datefmt='%a, %d %b %Y %H:%M:%S', filename='parser_result.log', filemode='w')

logging.debug('This is debug message')
logging.info('This is info message')
logging.warning('This is warning message')

 

注意打印日志時logging后跟的是小寫的等級，設置等級時跟的時大寫的等級

 

2）logging.getLogger([name])

創建Logger對象。日志記錄的工作主要由Logger對象來完成。在調用getLogger時要提供Logger的名稱（注：多次使用相同名稱來調用getLogger，返回的是同一個對象的引用。），Logger實例之間有層次關系，這些關系通過Logger名稱來體現，如：

p = logging.getLogger(“root”)

c1 = logging.getLogger(“root.c1”)

c2 = logging.getLogger(“root.c2”)

例子中，p是父logger, c1,c2分別是p的子logger。c1, c2將繼承p的設置。如果省略了name參數, getLogger將返回日志對象層次關系中的根Logger。

3）logging.getLevelName(lvl)

獲取日志級別對應的名稱。例如：

import logging  
  
#下面的結果都為DEBUG  
print logging.getLevelName(10)  
print logging.getLevelName(logging.DEBUG)  
#下面的結果都為ERROR  
print logging.getLevelName(40)  
print logging.getLevelName(logging.ERROR)  

4）logging.shutdown()

當不再使用日志系統的時候，調用該方法，它會將日志flush到對應的目標域上。一般在系統退出的時候調用。

Logger對象通過調用logging.getLogger(name)來創建，它有如下常用的方法和屬性：

2 - a）Logger.setLevel(lvl):

設置日志的級別。對於低於該級別的日志消息將被忽略。下面一個例子演示setLevel方法：

logger = logging.getLogger('root.test')  
logger.setLevel(logging.INFO)  
console_handler = logging.StreamHandler()  
console_handler.setLevel(logging.WARNING)  
logger.addHandler(console_handler)  
  
logger.info('info') #不會記錄  
logger.debug('debug') #不會記錄  
logger.warning('warning') #記錄warning  
logger.error('error')   #記錄error  

2 - b）打印消息

Logger.debug(msg [ ,*args [, **kwargs]])

記錄DEBUG級別的日志信息。參數msg是信息的格式，args與kwargs分別是格式參數。

Logger.info(msg[ , *args[ , **kwargs] ] )

Logger.warnning(msg[ , *args[ , **kwargs] ] )

Logger.error(msg[ , *args[ , **kwargs] ] )

Logger.critical(msg[ , *args[ , **kwargs] ] )

記錄相應級別的日志信息。參數的含義與Logger.debug一樣。

2 - c）增加移除處理器

Logger.addHandler(hdlr)

Logger.removeHandler(hdlr)

添加/移除日志消息處理器。在講述Handler時具體介紹。

2 - d）Logger.log(lvl, msg[ , *args[ , **kwargs] ] )

記錄日志，參數lvl用戶設置日志信息的級別。參數msg, *args, **kwargs的含義與Logger.debug一樣。

2 - e）Logger.exception(msg[, *args])

以ERROR級別記錄日志消息，異常跟蹤信息將被自動添加到日志消息里。Logger.exception通過用在異常處理塊中，如：

#異常信息也會添加到日志消息里
try:
    raise IOError, 'this is a winter testing IOError'
except IOError:
    logger.exception('record this error')
    logger.warning(''.center(50,'-'))

2 - f）

Logger.addFilter(filt)

Logger.removeFilter(filt)

添加/移除日志消息過濾器。在講述Filter時具體介紹。

2 - g）Logger.makeRecord(name, lvl, fn, lno, msg, args, exc_info[, func, extra])

創建LogRecord對象。日志消息被實例為一個LogRecord對象，並在日志類內處理。

4.基本使用

1） 簡單的將日志打印到屏幕

import logging  
  
logging.debug('this is debug message')  
logging.info('this is info message')  
logging.warning('this is warning message')  
  
#打印結果：WARNING:root:this is warning message  

默認情況下，logging將日志打印到屏幕，日志級別為WARNING；
日志級別大小關系為：CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET，當然也可以自己定義日志級別。

2）通過logging.basicConfig函數對日志的輸出格式及方式做相關配置

import logging  
  
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(message)s')  
  
logging.debug('this is debug message')  
logging.info('this is info message')  
logging.warning('this is warning message')  
  
''''' 
結果： 
2017-08-23 14:22:25,713 - root - this is debug message 
2017-08-23 14:22:25,713 - root - this is info message 
2017-08-23 14:22:25,714 - root - this is warning message 
'''  

logging.basicConfig函數各參數:
filename: 指定日志文件名
filemode: 和file函數意義相同，指定日志文件的打開模式，'w'或'a'
format: 指定輸出的格式和內容，format可以輸出很多有用信息，如上例所示:
 %(levelno)s: 打印日志級別的數值
 %(levelname)s: 打印日志級別名稱
 %(pathname)s: 打印當前執行程序的路徑，其實就是sys.argv[0]
 %(filename)s: 打印當前執行程序名
 %(funcName)s: 打印日志的當前函數
 %(lineno)d: 打印日志的當前行號
 %(asctime)s: 打印日志的時間
 %(thread)d: 打印線程ID
 %(threadName)s: 打印線程名稱
 %(process)d: 打印進程ID
 %(message)s: 打印日志信息
datefmt: 指定時間格式，同time.strftime()
level: 設置日志級別，默認為logging.WARNING
stream: 指定將日志的輸出流，可以指定輸出到sys.stderr,sys.stdout或者文件，默認輸出到sys.stderr，當stream和filename同時指定時，stream被忽略

3）將日志同時輸出到文件和屏幕

import logging
logger = logging.getLogger(__name__)
logger.setLevel(level = logging.INFO)
handler = logging.FileHandler("log.txt")
handler.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
 
console = logging.StreamHandler()
console.setLevel(logging.INFO)
 
logger.addHandler(handler)
logger.addHandler(console)
 
logger.info("Start print log")
logger.debug("Do something")
logger.warning("Something maybe fail.")
logger.info("Finish")

可以在log.txt文件和控制台中看到：

可以發現，logging有一個日志處理的主對象，其他處理方式都是通過addHandler添加進去，logging中包含的handler主要有如下幾種：

4）傳給syslogserver，郵箱

from logging import handlers  
  
#日志傳送到syslog server  
syslog_handler = handlers.SysLogHandler(address=('192.168.168.1', 514))  
  
#日志傳送給郵箱  
mail_handler = handlers.SMTPHandler('192.168.168.1', '[e-mail]', '[e-mail]', 'subject')
#郵件給多人
mail_handler = handlers.SMTPHandler('192.168.168.1', '[e-mail]', （'[e-mail]', '[e-mail]'), 'subject')

5）日志回滾

如果你用 FileHandler 寫日志，文件的大小會隨着時間推移而不斷增大。最終有一天它會占滿你所有的磁盤空間。為了避免這種情況出現，你可以在你的生成環境中使用 RotatingFileHandler 替代 FileHandler。

import logging  
from logging.handlers import RotatingFileHandler  
logger = logging.getLogger(__name__)  
logger.setLevel(level = logging.INFO)  
#定義一個RotatingFileHandler，最多備份3個日志文件，每個日志文件最大1K  
rHandler = RotatingFileHandler("log.txt",maxBytes = 1*1024,backupCount = 3)  
rHandler.setLevel(logging.INFO)  
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')  
rHandler.setFormatter(formatter)  
   
console = logging.StreamHandler()  
console.setLevel(logging.INFO)  
console.setFormatter(formatter)  
   
logger.addHandler(rHandler)  
logger.addHandler(console)  
   
logger.info("Start print log")  
logger.debug("Do something")  
logger.warning("Something maybe fail.")  
logger.info("Finish")  

5. 多模塊使用logging配置

1）通過繼承關系實現

import logging

logger = logging.getLogger('mainModule')
logger.setLevel(level=logging.INFO)

formatter = logging.Formatter(
    '%(asctime)s - %(name)s - %(levelname)s - %(message)s')

handler = logging.FileHandler('log.txt')
handler.setLevel(logging.INFO)
handler.setFormatter(formatter)

console = logging.StreamHandler()
console.setLevel(logging.INFO)
console.setFormatter(formatter)

logger.addHandler(handler)
logger.addHandler(console)

# 在其他模塊導入該日志接口module_logger即可
module_logger = logging.getLogger('mainModule.sub')
module_logger.info('this is another module using logging')

說明：

首先定義了logger'mainModule'，並對它進行了配置，就可以在解釋器進程里面的其他地方通過getLogger('mainModule')得到的對象都是一樣的，不需要重新配置，可以直接使用。定義的該logger的子logger，都可以共享父logger的定義和配置，所謂的父子logger是通過命名來識別，任意以'mainModule'開頭的logger都是它的子logger，例如'mainModule.sub'。

實際開發一個application，首先可以通過logging配置文件編寫好這個application所對應的配置，可以生成一個根logger，如'PythonAPP'，然后在主函數中通過fileConfig加載logging配置，接着在application的其他地方、不同的模塊中，可以使用根logger的子logger，如'PythonAPP.Core'，'PythonAPP.Web'來進行log，而不需要反復的定義和配置各個模塊的logger。

2）通過logging.config模塊配置日志

#logger.conf  
###############################################  
[loggers]  
keys=root,example01,example02  
[logger_root]  
level=DEBUG  
handlers=hand01,hand02  
[logger_example01]  
handlers=hand01,hand02  
qualname=example01  
propagate=0  
[logger_example02]  
handlers=hand01,hand03  
qualname=example02  
propagate=0  
###############################################  
[handlers]  
keys=hand01,hand02,hand03  
[handler_hand01]  
class=StreamHandler  
level=INFO  
formatter=form02  
args=(sys.stderr,)  
[handler_hand02]  
class=FileHandler  
level=DEBUG  
formatter=form01  
args=('myapp.log', 'a')  
[handler_hand03]  
class=handlers.RotatingFileHandler  
level=INFO  
formatter=form02  
args=('myapp.log', 'a', 10*1024*1024, 5)  
###############################################  
[formatters]  
keys=form01,form02  
[formatter_form01]  
format=%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s  
datefmt=%a, %d %b %Y %H:%M:%S  
[formatter_form02]  
format=%(name)-12s: %(levelname)-8s %(message)s  
datefmt=%a, %d %b %Y %H:%M:%S  

example01

import logging  
import logging.config  
   
logging.config.fileConfig("logger.conf")  
logger = logging.getLogger("example01")  
   
logger.debug('This is debug message')  
logger.info('This is info message')  
logger.warning('This is warning message')  

example02

import logging  
import logging.config  
   
logging.config.fileConfig("logger.conf")  
logger = logging.getLogger("example02")  
   
logger.debug('This is debug message')  
logger.info('This is info message')  
logger.warning('This is warning message')  

python2.7以后，可以從字典中加載logging配置，也就意味着可以通過JSON或者YAML文件加載日志的配置

3）通過JSON加載日志配置

{  
    "version":1,  
    "disable_existing_loggers":false,  
    "formatters":{  
        "simple":{  
            "format":"%(asctime)s - %(name)s - %(levelname)s - %(message)s"  
        }  
    },  
    "handlers":{  
        "console":{  
            "class":"logging.StreamHandler",  
            "level":"DEBUG",  
            "formatter":"simple",  
            "stream":"ext://sys.stdout"  
        },  
        "info_file_handler":{  
            "class":"logging.handlers.RotatingFileHandler",  
            "level":"INFO",  
            "formatter":"simple",  
            "filename":"info.log",  
            "maxBytes":"10485760",  
            "backupCount":20,  
            "encoding":"utf8"  
        },  
        "error_file_handler":{  
            "class":"logging.handlers.RotatingFileHandler",  
            "level":"ERROR",  
            "formatter":"simple",  
            "filename":"errors.log",  
            "maxBytes":10485760,  
            "backupCount":20,  
            "encoding":"utf8"  
        }  
    },  
    "loggers":{  
        "my_module":{  
            "level":"ERROR",  
            "handlers":["info_file_handler"],  
            "propagate":"no"  
        }  
    },  
    "root":{  
        "level":"INFO",  
        "handlers":["console","info_file_handler","error_file_handler"]  
    }  
}  

通過JSON加載配置文件，然后通過logging.dictConfig配置logging，

import json  
import logging.config  
import os  
   
def setup_logging(default_path = "logging.json",default_level = logging.INFO,env_key = "LOG_CFG"):  
    path = default_path  
    value = os.getenv(env_key,None)  
    if value:  
        path = value  
    if os.path.exists(path):  
        with open(path,"r") as f:  
            config = json.load(f)  
            logging.config.dictConfig(config)  
    else:  
        logging.basicConfig(level = default_level)  
   
def func():  
    logging.info("start func")  
   
    logging.info("exec func")  
   
    logging.info("end func")  
   
if __name__ == "__main__":  
    setup_logging(default_path = "logging.json")  
    func()  

使用JSON的一個優點就是json是一個標准庫，不需要額外安裝。但是，有人更喜歡YAML。無論讀起來還是寫起來都比較容易

4）通過YAML文件配置

通過YAML文件進行配置，比JSON看起來更加簡介明了，

version: 1  
disable_existing_loggers: False  
formatters:  
        simple:  
            format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s"  
handlers:  
    console:  
            class: logging.StreamHandler  
            level: DEBUG  
            formatter: simple  
            stream: ext://sys.stdout  
    info_file_handler:  
            class: logging.handlers.RotatingFileHandler  
            level: INFO  
            formatter: simple  
            filename: info.log  
            maxBytes: 10485760  
            backupCount: 20  
            encoding: utf8  
    error_file_handler:  
            class: logging.handlers.RotatingFileHandler  
            level: ERROR  
            formatter: simple  
            filename: errors.log  
            maxBytes: 10485760  
            backupCount: 20  
            encoding: utf8  
loggers:  
    my_module:  
            level: ERROR  
            handlers: [info_file_handler]  
            propagate: no  
root:  
    level: INFO  
    handlers: [console,info_file_handler,error_file_handler]  

通過YAML加載配置文件，然后通過logging.dictConfig配置logging

import yaml  
import logging.config  
import os  
   
def setup_logging(default_path = "logging.yaml",default_level = logging.INFO,env_key = "LOG_CFG"):  
    path = default_path  
    value = os.getenv(env_key,None)  
    if value:  
        path = value  
    if os.path.exists(path):  
        with open(path,"r") as f:  
            config = yaml.load(f)  
            logging.config.dictConfig(config)  
    else:  
        logging.basicConfig(level = default_level)  
   
def func():  
    logging.info("start func")  
   
    logging.info("exec func")  
   
    logging.info("end func")  
   
if __name__ == "__main__":  
    setup_logging(default_path = "logging.yaml")  
    func()  

 接下來，你就可以在運行程序的時候調用setup_logging來啟動日志記錄了。它默認會讀取logging.json或logging.yaml文件。你也可以設置環境變量LOG_CFG從指定的路徑加載日志配置，例如：

LOG_CFG = my_logging.json python my_server.py

如果你喜歡YAML：

LOG_CFG = my_logging.yaml python my_server.py

 

注意：配置文件中“disable_existing_loggers” 參數設置為 False；如果不設置為False，創建了 logger，然后你又在加載日志配置文件之前就導入了模塊。logging.fileConfig 與 logging.dictConfig 默認情況下會使得已經存在的 logger 失效。那么，這些配置信息就不會應用到你的 Logger 上。“disable_existing_loggers” = False解決了這個問題

 

 6. 捕捉異常並使用traceback記錄它

出問題時記錄下來是個好習慣，python中的traceback模塊用於記錄異常信息，我們可以在logger中記錄下traceback

比如下面的例子：

try:  
    open('/path/to/does/not/exist', 'rb')  
except (SystemExit, KeyboardInterrupt):  
    raise  
except Exception, e:  
    logger.error('Failed to open file', exc_info=True)  

結果為：

ERROR:__main__:Failed to open file  
Traceback (most recent call last):  
  File "example.py", line 6, in <module>  
    open('/path/to/does/not/exist', 'rb')  
IOError: [Errno 2] No such file or directory: '/path/to/does/not/exist'  

你也可以調用 logger.exception(msg, _args)，它等價於 logger.error(msg, exc_info=True, _args)。

將

 logger.error('Failed to open file', exc_info=True)  

替換為：

logger.exception('Failed to open file')  

7. logger間的繼承關系

1） logger間存在繼承關系

logger 通過名字來決定繼承關系，如果一個logger的名字是"mydest"，另一個logger的名字是"mydest.dest1" （getLogger("mydest.dest1")）,那么就稱后者是前者的子logger，會繼承前者的配置。上面的代碼沒有指定logger，直接調用logging.debug等方法時，會使用所有logger的祖先類RootLogger。

從上面的代碼運行結果可以猜測出，該RootLogger設置的日志級別是logging.WARN，輸出目的地是標准流。從源碼可以更清楚的看出來：

root = RootLogger(WARNING)  #設置root用戶的日志級別為WARNING  

至於rootLogger的輸出目的地的配置，我們跟蹤logging.debug的源代碼來看一下：

def debug(msg, *args, **kwargs):
    """ 
    Log a message with severity 'DEBUG' on the root logger. 
    """
if len(root.handlers) == 0:
    basicConfig()
root.debug(msg, *args, **kwargs) 

大約可以看到，如果rootLogger沒有配置handler，就會不帶參數運行basicConfig函數，我們看一下basicConfig的源代碼：

def basicConfig(**kwargs):
    #有幫助文檔，這里不列出
    _acquireLock()
    try:
        if len(root.handlers) == 0:
            filename = kwargs.get("filename")
            if filename:
                mode = kwargs.get("filemode", 'a')
                hdlr = FileHandler(filename, mode)
            else:
                stream = kwargs.get("stream")
                hdlr = StreamHandler(stream)
            fs = kwargs.get("format", BASIC_FORMAT)
            dfs = kwargs.get("datefmt", None)
            fmt = Formatter(fs, dfs)
            hdlr.setFormatter(fmt)
            root.addHandler(hdlr)
            level = kwargs.get("level")
            if level is not None:
                root.setLevel(level)
    finally:
        _releaseLock()

因為參數為空，所以我們就看出了，該rootLoger使用了不帶參數的StreamHandler，也可以看到諸如format之類的默認配置。之后我們 跟蹤StreamHandler(因為我們想看到日志輸出目的地的配置，而handler就是控制日志流向的，所以我們要跟蹤它)的源代碼：

class StreamHandler(Handler):
    """
    A handler class which writes logging records, appropriately formatted,
    to a stream. Note that this class does not close the stream, as
    sys.stdout or sys.stderr may be used.
    """

    def __init__(self, stream=None):
        """
        Initialize the handler.

        If stream is not specified, sys.stderr is used.
        """
        Handler.__init__(self)
        if stream is None:
            stream = sys.stderr
        self.stream = stream

不帶參數的StreamHandler將會把日志流定位到sys.stderr流，標准錯誤流同樣會輸出到控制台。

2） basicConfig函數用來配置RootLogger

basicConfig函數僅用來配置RootLogger，rootLogger是所有Logger的祖先Logger，所以其他一切Logger會繼承該Logger的配置。

3） 通過示例詳細討論Logger配置的繼承關系

首先准備下繼承條件：log2繼承自log1，logger的名稱可以隨意，要注意‘.’表示的繼承關系。

# coding:utf-8   
import logging  
  
log1 = logging.getLogger("mydear")  
  
log1.setLevel(logging.WARNING)  
  
log1.addHandler(StreamHandler())  
  
log2 = logging.getLogger("mydear.app")  
  
log2.error("display")  
  
log2.info("not display")   

a）level的繼承

原則：子logger寫日志時，優先使用本身設置了的level；如果沒有設置，則逐層向上級父logger查詢，直到查詢到為止。最極端的情況是，使用rootLogger的默認日志級別logging.WARNING。

從源代碼中看更為清晰， 感謝python的所見即所得：

def getEffectiveLevel(self):
    """
    Get the effective level for this logger.

    Loop through this logger and its parents in the logger hierarchy,
    looking for a non-zero logging level. Return the first one found.
    """
    logger = self
    while logger:
        if logger.level:
            return logger.level
        logger = logger.parent
    return NOTSET

b）handler的繼承

原則：先將日志對象傳遞給子logger的所有handler處理，處理完畢后，如果該子logger的propagate屬性沒有設置為0，則將日志對象向上傳遞給第一個父Logger，該父logger的所有handler處理完畢后，如果它的propagate也沒有設置為0，則繼續向上層傳遞，以此類推。最終的狀態，要么遇到一個Logger，它的propagate屬性設置為了0；要么一直傳遞直到rootLogger處理完畢。

在上面實例代碼的基礎上，我們再添加一句代碼，即：

import logging

log1 = logging.getLogger("mydear")

log1.setLevel(logging.WARNING)

log1.addHandler(logging.StreamHandler())

log2 = logging.getLogger("mydear.app")

log2.error("display")

log2.info("not display")

print log2.handlers  # 打印log2綁定的handler

輸出結果為：

display
[]

說好的繼承，但是子logger竟然沒有綁定父類的handler，what's wrong?

看到下面調用handler的源代碼，就真相大白了。可以理解成，這不是真正的(類)繼承，只是"行為上的繼承":

def callHandlers(self, record):  
    """ 
    Pass a record to all relevant handlers. 
 
    Loop through all handlers for this logger and its parents in the 
    logger hierarchy. If no handler was found, output a one-off error 
    message to sys.stderr. Stop searching up the hierarchy whenever a 
    logger with the "propagate" attribute set to zero is found - that 
    will be the last logger whose handlers are called. 
    """  
    c = self  
    found = 0  
    while c:  
        for hdlr in c.handlers:  
            found = found + 1  
            if record.levelno >= hdlr.level:  
                hdlr.handle(record)  
        if not c.propagate:  
            c = None  # break out  
        else:  
            c = c.parent  
    if (found == 0) and raiseExceptions and not self.manager.emittedNoHandlerWarning:  
        sys.stderr.write("No handlers could be found for logger"  
                         " \"%s\"\n" % self.name)  
        self.manager.emittedNoHandlerWarning = 1  

額，最簡單的樣例牽引出來這么多后台的邏輯，不過我們懂一下也是有好處的。

8. logging遇到多進程

在handler中有一個class配置，可能有些讀者並不是很懂。其實這個是logging里面原先就寫好的一些handler類，你可以在這里直接調用。class指向的類相當於具體處理的Handler的執行者。在logging的文檔中可以知道這里所有的Handler類都是線程安全的(但是GIL的存在，多線程基本可以無視)，大家可以放心使用。所以一般情況下python要實現並行操作或者並行計算的時候都是使用多進程。但是logging並不是進程安全的，如果是用多進程來輸出日志，則只有一個進程會切換，其他進程會在原來的文件中繼續打，還有可能某些進程切換的時候早就有別的進程在新的日志文件里打入東西了，那么他會無情刪掉之，再建立新的日志文件。會很亂很亂，完全沒法開心的玩耍。

現在我們就來解決這個問題，以日志回滾使用的TimedRotatingFileHandler 這個類為例：

1）線程不安全的原因

在解決之前，我們先看看為什么會導致這樣的原因。
先將TimedRotatingFileHandler 的源代碼貼上來，這部分是切換時所作的操作：

def doRollover(self):
    """
    do a rollover; in this case, a date/time stamp is appended to the filename
    when the rollover happens.  However, you want the file to be named for the
    start of the interval, not the current time.  If there is a backup count,
    then we have to get a list of matching filenames, sort them and remove
    the one with the oldest suffix.
    """
    if self.stream:
        self.stream.close()
        self.stream = None
    # get the time that this sequence started at and make it a TimeTuple
    currentTime = int(time.time())
    dstNow = time.localtime(currentTime)[-1]
    t = self.rolloverAt - self.interval
    if self.utc:
        timeTuple = time.gmtime(t)
    else:
        timeTuple = time.localtime(t)
        dstThen = timeTuple[-1]
        if dstNow != dstThen:
            if dstNow:
                addend = 3600
            else:
                addend = -3600
            timeTuple = time.localtime(t + addend)
    dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
    if os.path.exists(dfn):
        os.remove(dfn)
    # Issue 18940: A file may not have been created if delay is True.
    if os.path.exists(self.baseFilename):
        os.rename(self.baseFilename, dfn)
    if self.backupCount > 0:
        for s in self.getFilesToDelete():
            os.remove(s)
    if not self.delay:
        self.stream = self._open()
    newRolloverAt = self.computeRollover(currentTime)
    while newRolloverAt <= currentTime:
        newRolloverAt = newRolloverAt + self.interval
    # If DST changes and midnight or weekly rollover, adjust for this.
    if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:
        dstAtRollover = time.localtime(newRolloverAt)[-1]
        if dstNow != dstAtRollover:
            if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour
                addend = -3600
            else:  # DST bows out before next rollover, so we need to add an hour
                addend = 3600
            newRolloverAt += addend
    self.rolloverAt = newRolloverAt

我們觀察 if os.path.exists(dfn) 這一行開始，這里的邏輯是如果 dfn 這個文件存在，則要先刪除掉它，然后將 baseFilename 這個文件重命名為 dfn 文件。然后再重新打開 baseFilename這個文件開始寫入東西。那么這里的邏輯就很清楚了

a）假設當前日志文件名為 current.log 切分后的文件名為 current.log.2016-06-01

b）判斷 current.log.2016-06-01 是否存在，如果存在就刪除

c）將當前的日志文件名 改名為current.log.2016-06-01

d）重新打開新文件（我觀察到源代碼中默認是”a” 模式打開，之前據說是”w”）

於是在多進程的情況下，一個進程切換了，其他進程的句柄還在 current.log.2016-06-01 還會繼續往里面寫東西。又或者一個進程執行切換了，會把之前別的進程重命名的 current.log.2016-06-01 文件直接刪除。又或者還有一個情況，當一個進程在寫東西，另一個進程已經在切換了，會造成不可預估的情況發生。還有一種情況兩個進程同時在切文件，第一個進程正在執行第3步，第二進程剛執行完第2步，然后第一個進程 完成了重命名但還沒有新建一個新的 current.log 第二個進程開始重命名，此時第二個進程將會因為找不到 current 發生錯誤。如果第一個進程已經成功創建了 current.log 第二個進程會將這個空文件另存為 current.log.2016-06-01。那么不僅刪除了日志文件，而且，進程一認為已經完成過切分了不會再切，而事實上他的句柄指向的是current.log.2016-06-01。
好了這里看上去很復雜，實際上就是因為對於文件操作時，沒有對多進程進行一些約束，而導致的問題。
那么如何優雅地解決這個問題呢。我提出了兩種方案，當然我會在下面提出更多可行的方案供大家嘗試。

2）解決方案1

先前我們發現 TimedRotatingFileHandler 中邏輯的缺陷。我們只需要稍微修改一下邏輯即可：

a）判斷切分后的文件 current.log.2016-06-01 是否存在，如果不存在則進行重命名。（如果存在說明有其他進程切過了，我不用切了，換一下句柄即可）

b）以”a”模式 打開 current.log
發現修改后就這么簡單~
talking is cheap show me the code:

class SafeRotatingFileHandler(TimedRotatingFileHandler):  
  
def __init__( self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False):  
    TimedRotatingFileHandler.__init__( self, filename, when, interval, backupCount, encoding, delay, utc)  
  
""" 
Override doRollover 
lines commanded by "##" is changed by cc 
"""  
  
def doRollover(self):  
    """ 
    do a rollover; in this case, a date/time stamp is appended to the filename 
    when the rollover happens.  However, you want the file to be named for the 
    start of the interval, not the current time.  If there is a backup count, 
    then we have to get a list of matching filenames, sort them and remove 
    the one with the oldest suffix. 
    Override,   1. if dfn not exist then do rename 
                2. _open with "a" model 
    """  
  
    if self.stream:  
        self.stream.close()  
        self.stream = None  
    # get the time that this sequence started at and make it a TimeTuple  
    currentTime = int(time.time())  
    dstNow = time.localtime(currentTime)[-1]  
    t = self.rolloverAt - self.interval  
    if self.utc:  
        timeTuple = time.gmtime(t)  
    else:  
        timeTuple = time.localtime(t)  
        dstThen = timeTuple[-1]  
        if dstNow != dstThen:  
            if dstNow:  
                addend = 3600  
            else:  
                addend = -3600  
            timeTuple = time.localtime(t + addend)  
    dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)  
    # if os.path.exists(dfn):  
    # os.remove(dfn)  
    # Issue 18940: A file may not have been created if delay is True.  
    # if os.path.exists(self.baseFilename):  
    if not os.path.exists(dfn) and os.path.exists(self.baseFilename):  
        os.rename(self.baseFilename, dfn)  
    if self.backupCount > 0:  
        for s in self.getFilesToDelete():  
            os.remove(s)  
    if not self.delay:  
        self.mode = "a"  
        self.stream = self._open()  
    newRolloverAt = self.computeRollover(currentTime)  
    while newRolloverAt <= currentTime:  
        newRolloverAt = newRolloverAt + self.interval  
    # If DST changes and midnight or weekly rollover, adjust for this.  
    if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc:  
        dstAtRollover = time.localtime(newRolloverAt)[-1]  
        if dstNow != dstAtRollover:  
            if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour  
                addend = -3600  
            else:  # DST bows out before next rollover, so we need to add an hour  
                addend = 3600  
            newRolloverAt += addend  
    self.rolloverAt = newRolloverAt  

不要以為代碼那么長，其實修改部分就是 “##” 注釋的地方而已，其他都是照抄源代碼。這個類繼承了 TimedRotatingFileHandler 重寫了這個切分的過程。這個解決方案十分優雅，改換的地方非常少，也十分有效。但有網友提出，這里有一處地方依然不完美，就是rename的那一步，如果就是這么巧，同時兩個或者多個進程進入了 if 語句，先后開始 rename 那么依然會發生刪除掉日志的情況。確實這種情況確實會發生，由於切分文件一天才一次，正好切分的時候同時有兩個Handler在操作，又正好同時走到這里，也是蠻巧的，但是為了完美，可以加上一個文件鎖，if 之后加鎖，得到鎖之后再判斷一次，再進行rename這種方式就完美了。代碼就不貼了，涉及到鎖代碼，影響美觀。

3）解決方案2

我認為最簡單有效的解決方案。重寫FileHandler類（這個類是所有寫入文件的Handler都需要繼承的TimedRotatingFileHandler 就是繼承的這個類；我們增加一些簡單的判斷和操作就可以。
我們的邏輯是這樣的：

a）判斷當前時間戳是否與指向的文件名是同一個時間

b）如果不是，則切換 指向的文件即可
結束，是不是很簡單的邏輯。
talking is cheap show me the code:

class SafeFileHandler(FileHandler):  
  
def __init__(self, filename, mode, encoding=None, delay=0):  
    """  
    Use the specified filename for streamed logging  
    """  
    if codecs is None:  
        encoding = None  
    FileHandler.__init__(self, filename, mode, encoding, delay)  
    self.mode = mode  
    self.encoding = encoding  
    self.suffix = "%Y-%m-%d"  
    self.suffix_time = ""  
def emit(self, record):  
    """ 
    Emit a record. 
    Always check time 
    """  
    try:  
        if self.check_baseFilename(record):  
            self.build_baseFilename()  
        FileHandler.emit(self, record)  
    except (KeyboardInterrupt, SystemExit):  
        raise  
    except:  
        self.handleError(record)  
def check_baseFilename(self, record):  
    """ 
    Determine if builder should occur. 
    record is not used, as we are just comparing times, 
    but it is needed so the method signatures are the same 
    """  
    timeTuple = time.localtime()  
    if self.suffix_time != time.strftime(self.suffix, timeTuple) or not os.path.exists(  
                            self.baseFilename + '.' + self.suffix_time):  
        return 1  
    else:  
        return 0  
def build_baseFilename(self):  
    """ 
    do builder; in this case, 
    old time stamp is removed from filename and 
    a new time stamp is append to the filename 
    """  
    if self.stream:  
        self.stream.close()  
        self.stream = None  
    # remove old suffix  
    if self.suffix_time != "":  
        index = self.baseFilename.find("." + self.suffix_time)  
        if index == -1:  
            index = self.baseFilename.rfind(".")  
        self.baseFilename = self.baseFilename[:index]  
    # add new suffix  
    currentTimeTuple = time.localtime()  
    self.suffix_time = time.strftime(self.suffix, currentTimeTuple)  
    self.baseFilename = self.baseFilename + "." + self.suffix_time  
    self.mode = 'a'  
    if not self.delay:  
        self.stream = self._open()  

check_baseFilename 就是執行邏輯1判斷；build_baseFilename 就是執行邏輯2換句柄。就這么簡單完成了。
這種方案與之前不同的是，當前文件就是 current.log.2016-06-01 ，到了明天當前文件就是current.log.2016-06-02 沒有重命名的情況，也沒有刪除的情況。十分簡潔優雅。也能解決多進程的logging問題。

4）解決方案3---進程安全的ConcurrentLogHandler

如果多進程多線程使用，推薦 ConcurrentLogHandler，需要安裝

安裝： 

pip install ConcurrentLogHandler

a）使用案例一

def init_log():
    logfile = "/data1/restful_log/restful_api_thread.log"
    filesize = 800*1024*1024
    log = getLogger()
    rotate_handler = ConcurrentRotatingFileHandler(logfile, "a", filesize, encoding="utf-8")

    datefmt_str = '%Y-%m-%d %H:%M:%S'
    format_str = '%(asctime)s\t%(levelname)s\t%(message)s '
    formatter = Formatter(format_str, datefmt_str)
    rotate_handler.setFormatter(formatter)

    log.addHandler(rotate_handler)
    log.setLevel(WARN)

    return log

ConcurrentRotatingFileHandler參數說明： 
filename: 日志文件地址，相對地址或絕對地址均可

mode: 默認為"a"

maxBytes：文件長度，超過最大長度自動分片，最初日志都會寫入filename里面，到達設置的最大長度之后進行分片，分片后文件名為filename.1 filename.2，以此類推

backupCount：最大日志文件保留數量，默認為0即不會刪除日志文件

encoding：日志文件編碼格式，默認為gbk

b）使用案例二

建一個目錄，下面的文件都放到這個目錄中：

logging-config.yaml

version: 1    
    
formatters:    
    simple:    
        format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'    
    
handlers:    
    console:    
        class: logging.StreamHandler    
        level: DEBUG    
        formatter: simple    
        stream: ext://sys.stdout    
    
loggers:    
    simpleExample:    
        level: DEBUG    
        handlers: [console]    
        propagate: no    
    
root:    
    level: DEBUG    
    handlers: [console]    

 testlogging.py

#!/usr/bin/python2.7    
#-*- coding: UTF-8 -*-    
#    
# Using ConcurrentLogHandler:    
#   wget https://pypi.python.org/packages/fd/e5/0dc4f256bcc6484d454006b02f33263b20f762a433741b29d53875e0d763/ConcurrentLogHandler-0.9.1.tar.gz#md5=9609ecc4c269ac43f0837d89f12554c3    
#   cd ConcurrentLogHandler-0.9.1    
#   python2.7 setup.py install    
###########################################################    
import logging, logging.config    
import cloghandler    
    
import yaml    
    
###########################################################    
# create logger    
# 使用代碼創建logger    
logger = logging.getLogger('simple_example')    
logger.setLevel(logging.DEBUG)    
    
# create console handler and set level to debug    
ch = logging.StreamHandler()    
ch.setLevel(logging.DEBUG)    
    
# create formatter    
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')    
    
# add formatter to ch    
ch.setFormatter(formatter)    
    
# add ch to logger    
logger.addHandler(ch)    
    
# 'application' code    
logger.debug('debug message')    
logger.info('info message')    
logger.warn('warn message')    
logger.error('error message')    
logger.critical('critical message')    
    
    
###########################################################    
# basicConfig    
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')    
logging.warning('is when this event was logged.')    
    
    
###########################################################    
# using yaml config file    
f = open("logging-config.yaml")    
dictcfg = yaml.load(f)    
f.close()    
    
logging.config.dictConfig(dictcfg)    
    
#logging.config.fileConfig("logging.config")    
log = logging.getLogger("root")    
log.info("==YAML== Here is a very exciting log message")    
    
###########################################################    
# using ini config file    
logging.config.fileConfig("logging-config.ini")    
log = logging.getLogger("simpleExample")    
log.info("==INI== Here is a very exciting log message")    
    
    
###########################################################    
# using inline code config    
logging.config.dictConfig({    
    'version': 1,    
    'disable_existing_loggers': True,    
    'formatters': {    
        'verbose': {    
            'format': "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s",    
            'datefmt': "%Y-%m-%d %H:%M:%S",    
        },    
        'simple': {    
            'format': '%(levelname)s %(message)s',    
        },    
    },    
    'handlers': {    
        'null': {    
            'level': 'DEBUG',    
            'class': 'logging.NullHandler',    
        },    
        'console': {    
            'level': 'DEBUG',    
            'class': 'logging.StreamHandler',    
            'formatter': 'verbose',    
        },    
        'file': {    
            'level': 'DEBUG',    
            'class': 'cloghandler.ConcurrentRotatingFileHandler',    
            'maxBytes': 1024 * 1024 * 10,   # 當達到10MB時分割日志    
            'backupCount': 10,              # 最多保留10份文件    
            'delay': True,                  # If delay is true, file opening is deferred until the first call to emit    
            'filename': 'sample-site.log',    
            'formatter': 'verbose',    
        },    
        'file2': {    
            'level': 'DEBUG',    
            'class': 'cloghandler.ConcurrentRotatingFileHandler',    
            'maxBytes': 1024 * 1024 * 10,   # 當達到10MB時分割日志    
            'backupCount': 10,              # 最多保留10份文件    
            'delay': True,                  # If delay is true, file opening is deferred until the first call to emit    
            'filename': 'sample-site2.log',    
            'formatter': 'verbose',    
        },    
    },    
    'loggers': {    
        '': {    
            'handlers': ['file'],    
            'level': 'INFO',    
        },    
        'root': {    
            'handlers': ['console'],    
            'level': 'INFO',    
            'propagate': 0,    
        },    
        'root2': {    
            'handlers': ['console'],    
            'level': 'INFO',    
            'propagate': 1,    
        },    
    },    
})    
    
logger = logging.getLogger("root")    
logger.info("==== Here is a very exciting log message")    
    
logger = logging.getLogger("root2")    
logger.info("==== Here is a very exciting log message2")   

9. 小知識點

1）使用__name__作為logger的名稱

雖然不是非得將 logger 的名稱設置為 __name__ ，但是這樣做會給我們帶來諸多益處。在 python 中，變量 __name__ 的名稱就是當前模塊的名稱。比如，在模塊 “foo.bar.my_module” 中調用 logger.getLogger(__name__) 等價於調用logger.getLogger(“foo.bar.my_module”) 。當你需要配置 logger 時，你可以配置到 “foo” 中，這樣包 foo 中的所有模塊都會使用相同的配置。當你在讀日志文件的時候，你就能夠明白消息到底來自於哪一個模塊。

 2）全局共享logging配置

其實很簡單，只需要執行：

logging.basicConfig(filename=‘', level=logging.DEBUG, filemode='w', format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')

然后就可以在任何地方打印日志即可

logging.leve('')

暫時就到這里，以后繼續擴展