以打印日誌爲榮之logging模塊詳細使用
啄木鳥社區裏的Pythonic八榮八恥有一條：python
以打印日誌爲榮 , 以單步跟蹤爲恥;json
不少程序都有記錄日誌的需求，而且日誌中包含的信息既有正常的程序訪問日誌，還可能有錯誤、警告等信息輸出，python的logging模塊提供了標準的日誌接口，你能夠經過它存儲各類格式的日誌，主要用於輸出運行日誌，能夠設置輸出日誌的等級、日誌保存路徑、日誌文件回滾等；api
爲何不用print打印輸出？安全
這種方式對於簡單腳本型程序有用，可是若是是複雜的系統，最好不要用。首先，這些print是沒用的輸出，大量使用頗有可能會被遺忘在代碼裏。再者，print 輸出的全部信息都到了標準輸出中，這將嚴重影響到你從標準輸出中查看其它輸出數據。restful
使用logging的優點：多線程
a）你能夠控制消息的級別，過濾掉那些並不重要的消息。app
b）你可決定輸出到什麼地方，以及怎麼輸出。有許多的重要性別級可供選擇，debug、info、warning、error 以及 critical。經過賦予 logger 或者 handler 不一樣的級別，你就能夠只輸出錯誤消息到特定的記錄文件中，或者在調試時只記錄調試信息。框架
下面讓咱們正式進入logging的世界：python2.7
1. logging日誌框架
主要包括四部分：ide
- 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)
獲取日誌級別對應的名稱。例如：
1 import logging 2 3 #下面的結果都爲DEBUG 4 print logging.getLevelName(10) 5 print logging.getLevelName(logging.DEBUG) 6 #下面的結果都爲ERROR 7 print logging.getLevelName(40) 8 print logging.getLevelName(logging.ERROR)
4）logging.shutdown()
當再也不使用日誌系統的時候，調用該方法，它會將日誌flush到對應的目標域上。通常在系統退出的時候調用。
Logger對象經過調用logging.getLogger(name)來建立，它有以下經常使用的方法和屬性：
2 - a）Logger.setLevel(lvl):
設置日誌的級別。對於低於該級別的日誌消息將被忽略。下面一個例子演示setLevel方法：
1 logger = logging.getLogger('root.test') 2 logger.setLevel(logging.INFO) 3 console_handler = logging.StreamHandler() 4 console_handler.setLevel(logging.WARNING) 5 logger.addHandler(console_handler) 6 7 logger.info('info') #不會記錄 8 logger.debug('debug') #不會記錄 9 logger.warning('warning') #記錄warning 10 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經過用在異常處理塊中，如：
1 #異常信息也會添加到日誌消息裏 2 try: 3 raise IOError, 'this is a winter testing IOError' 4 except IOError: 5 logger.exception('record this error') 6 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） 簡單的將日誌打印到屏幕
1 import logging 2 3 logging.debug('this is debug message') 4 logging.info('this is info message') 5 logging.warning('this is warning message') 6 7 #打印結果：WARNING:root:this is warning message
默認狀況下，logging將日誌打印到屏幕，日誌級別爲WARNING；
日誌級別大小關係爲：CRITICAL > ERROR > WARNING > INFO > DEBUG > NOTSET，固然也能夠本身定義日誌級別。
2）經過logging.basicConfig函數對日誌的輸出格式及方式作相關配置
1 import logging 2 3 logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(message)s') 4 5 logging.debug('this is debug message') 6 logging.info('this is info message') 7 logging.warning('this is warning message') 8 9 ''''' 10 結果： 11 2017-08-23 14:22:25,713 - root - this is debug message 12 2017-08-23 14:22:25,713 - root - this is info message 13 2017-08-23 14:22:25,714 - root - this is warning message 14 '''
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）將日誌同時輸出到文件和屏幕
1 import logging 2 logger = logging.getLogger(__name__) 3 logger.setLevel(level = logging.INFO) 4 handler = logging.FileHandler("log.txt") 5 handler.setLevel(logging.INFO) 6 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 7 handler.setFormatter(formatter) 8 9 console = logging.StreamHandler() 10 console.setLevel(logging.INFO) 11 12 logger.addHandler(handler) 13 logger.addHandler(console) 14 15 logger.info("Start print log") 16 logger.debug("Do something") 17 logger.warning("Something maybe fail.") 18 logger.info("Finish")
能夠在log.txt文件和控制檯中看到：
能夠發現，logging有一個日誌處理的主對象，其餘處理方式都是經過addHandler添加進去，logging中包含的handler主要有以下幾種：
4）傳給syslogserver，郵箱
1 from logging import handlers 2 3 #日誌傳送到syslog server 4 syslog_handler = handlers.SysLogHandler(address=('192.168.168.1', 514)) 5 6 #日誌傳送給郵箱 7 mail_handler = handlers.SMTPHandler('192.168.168.1', 'winter@126.com', 'elly@163.com', 'subject') 8 #郵件給多人 9 mail_handler = handlers.SMTPHandler('192.168.168.1', 'winter@126.com', （'elly@163.com', 'dxd@126.com'), 'subject')
5）日誌回滾
若是你用 FileHandler 寫日誌，文件的大小會隨着時間推移而不斷增大。最終有一天它會佔滿你全部的磁盤空間。爲了不這種狀況出現，你能夠在你的生成環境中使用 RotatingFileHandler 替代 FileHandler。
1 import logging 2 from logging.handlers import RotatingFileHandler 3 logger = logging.getLogger(__name__) 4 logger.setLevel(level = logging.INFO) 5 #定義一個RotatingFileHandler，最多備份3個日誌文件，每一個日誌文件最大1K 6 rHandler = RotatingFileHandler("log.txt",maxBytes = 1*1024,backupCount = 3) 7 rHandler.setLevel(logging.INFO) 8 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 9 rHandler.setFormatter(formatter) 10 11 console = logging.StreamHandler() 12 console.setLevel(logging.INFO) 13 console.setFormatter(formatter) 14 15 logger.addHandler(rHandler) 16 logger.addHandler(console) 17 18 logger.info("Start print log") 19 logger.debug("Do something") 20 logger.warning("Something maybe fail.") 21 logger.info("Finish")
5. 多模塊使用logging配置
1）經過繼承關係實現
1 import logging 2 3 logger = logging.getLogger('mainModule') 4 logger.setLevel(level=logging.INFO) 5 6 formatter = logging.Formatter( 7 '%(asctime)s - %(name)s - %(levelname)s - %(message)s') 8 9 handler = logging.FileHandler('log.txt') 10 handler.setLevel(logging.INFO) 11 handler.setFormatter(formatter) 12 13 console = logging.StreamHandler() 14 console.setLevel(logging.INFO) 15 console.setFormatter(formatter) 16 17 logger.addHandler(handler) 18 logger.addHandler(console) 19 20 # 在其餘模塊導入該日誌接口module_logger便可 21 module_logger = logging.getLogger('mainModule.sub') 22 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模塊配置日誌
1 #logger.conf 2 ############################################### 3 [loggers] 4 keys=root,example01,example02 5 [logger_root] 6 level=DEBUG 7 handlers=hand01,hand02 8 [logger_example01] 9 handlers=hand01,hand02 10 qualname=example01 11 propagate=0 12 [logger_example02] 13 handlers=hand01,hand03 14 qualname=example02 15 propagate=0 16 ############################################### 17 [handlers] 18 keys=hand01,hand02,hand03 19 [handler_hand01] 20 class=StreamHandler 21 level=INFO 22 formatter=form02 23 args=(sys.stderr,) 24 [handler_hand02] 25 class=FileHandler 26 level=DEBUG 27 formatter=form01 28 args=('myapp.log', 'a') 29 [handler_hand03] 30 class=handlers.RotatingFileHandler 31 level=INFO 32 formatter=form02 33 args=('myapp.log', 'a', 10*1024*1024, 5) 34 ############################################### 35 [formatters] 36 keys=form01,form02 37 [formatter_form01] 38 format=%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s 39 datefmt=%a, %d %b %Y %H:%M:%S 40 [formatter_form02] 41 format=%(name)-12s: %(levelname)-8s %(message)s 42 datefmt=%a, %d %b %Y %H:%M:%S
example01
1 import logging 2 import logging.config 3 4 logging.config.fileConfig("logger.conf") 5 logger = logging.getLogger("example01") 6 7 logger.debug('This is debug message') 8 logger.info('This is info message') 9 logger.warning('This is warning message')
example02
1 import logging 2 import logging.config 3 4 logging.config.fileConfig("logger.conf") 5 logger = logging.getLogger("example02") 6 7 logger.debug('This is debug message') 8 logger.info('This is info message') 9 logger.warning('This is warning message')
python2.7之後，能夠從字典中加載logging配置，也就意味着能夠經過JSON或者YAML文件加載日誌的配置
3）經過JSON加載日誌配置
1 { 2 "version":1, 3 "disable_existing_loggers":false, 4 "formatters":{ 5 "simple":{ 6 "format":"%(asctime)s - %(name)s - %(levelname)s - %(message)s" 7 } 8 }, 9 "handlers":{ 10 "console":{ 11 "class":"logging.StreamHandler", 12 "level":"DEBUG", 13 "formatter":"simple", 14 "stream":"ext://sys.stdout" 15 }, 16 "info_file_handler":{ 17 "class":"logging.handlers.RotatingFileHandler", 18 "level":"INFO", 19 "formatter":"simple", 20 "filename":"info.log", 21 "maxBytes":"10485760", 22 "backupCount":20, 23 "encoding":"utf8" 24 }, 25 "error_file_handler":{ 26 "class":"logging.handlers.RotatingFileHandler", 27 "level":"ERROR", 28 "formatter":"simple", 29 "filename":"errors.log", 30 "maxBytes":10485760, 31 "backupCount":20, 32 "encoding":"utf8" 33 } 34 }, 35 "loggers":{ 36 "my_module":{ 37 "level":"ERROR", 38 "handlers":["info_file_handler"], 39 "propagate":"no" 40 } 41 }, 42 "root":{ 43 "level":"INFO", 44 "handlers":["console","info_file_handler","error_file_handler"] 45 } 46 }
經過JSON加載配置文件，而後經過logging.dictConfig配置logging，
1 import json 2 import logging.config 3 import os 4 5 def setup_logging(default_path = "logging.json",default_level = logging.INFO,env_key = "LOG_CFG"): 6 path = default_path 7 value = os.getenv(env_key,None) 8 if value: 9 path = value 10 if os.path.exists(path): 11 with open(path,"r") as f: 12 config = json.load(f) 13 logging.config.dictConfig(config) 14 else: 15 logging.basicConfig(level = default_level) 16 17 def func(): 18 logging.info("start func") 19 20 logging.info("exec func") 21 22 logging.info("end func") 23 24 if __name__ == "__main__": 25 setup_logging(default_path = "logging.json") 26 func()
使用JSON的一個優勢就是json是一個標準庫，不須要額外安裝。可是，有人更喜歡YAML。不管讀起來仍是寫起來都比較容易
4）經過YAML文件配置
經過YAML文件進行配置，比JSON看起來更加簡介明瞭，
1 version: 1 2 disable_existing_loggers: False 3 formatters: 4 simple: 5 format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s" 6 handlers: 7 console: 8 class: logging.StreamHandler 9 level: DEBUG 10 formatter: simple 11 stream: ext://sys.stdout 12 info_file_handler: 13 class: logging.handlers.RotatingFileHandler 14 level: INFO 15 formatter: simple 16 filename: info.log 17 maxBytes: 10485760 18 backupCount: 20 19 encoding: utf8 20 error_file_handler: 21 class: logging.handlers.RotatingFileHandler 22 level: ERROR 23 formatter: simple 24 filename: errors.log 25 maxBytes: 10485760 26 backupCount: 20 27 encoding: utf8 28 loggers: 29 my_module: 30 level: ERROR 31 handlers: [info_file_handler] 32 propagate: no 33 root: 34 level: INFO 35 handlers: [console,info_file_handler,error_file_handler]
經過YAML加載配置文件，而後經過logging.dictConfig配置logging
1 import yaml 2 import logging.config 3 import os 4 5 def setup_logging(default_path = "logging.yaml",default_level = logging.INFO,env_key = "LOG_CFG"): 6 path = default_path 7 value = os.getenv(env_key,None) 8 if value: 9 path = value 10 if os.path.exists(path): 11 with open(path,"r") as f: 12 config = yaml.load(f) 13 logging.config.dictConfig(config) 14 else: 15 logging.basicConfig(level = default_level) 16 17 def func(): 18 logging.info("start func") 19 20 logging.info("exec func") 21 22 logging.info("end func") 23 24 if __name__ == "__main__": 25 setup_logging(default_path = "logging.yaml") 26 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
好比下面的例子：
1 try: 2 open('/path/to/does/not/exist', 'rb') 3 except (SystemExit, KeyboardInterrupt): 4 raise 5 except Exception, e: 6 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的源代碼來看一下：
1 def debug(msg, *args, **kwargs): 2 """ 3 Log a message with severity 'DEBUG' on the root logger. 4 """ 5 if len(root.handlers) == 0: 6 basicConfig() 7 root.debug(msg, *args, **kwargs)
大約能夠看到，若是rootLogger沒有配置handler，就會不帶參數運行basicConfig函數，咱們看一下basicConfig的源代碼：
1 def basicConfig(**kwargs): 2 #有幫助文檔，這裏不列出 3 _acquireLock() 4 try: 5 if len(root.handlers) == 0: 6 filename = kwargs.get("filename") 7 if filename: 8 mode = kwargs.get("filemode", 'a') 9 hdlr = FileHandler(filename, mode) 10 else: 11 stream = kwargs.get("stream") 12 hdlr = StreamHandler(stream) 13 fs = kwargs.get("format", BASIC_FORMAT) 14 dfs = kwargs.get("datefmt", None) 15 fmt = Formatter(fs, dfs) 16 hdlr.setFormatter(fmt) 17 root.addHandler(hdlr) 18 level = kwargs.get("level") 19 if level is not None: 20 root.setLevel(level) 21 finally: 22 _releaseLock()
由於參數爲空，因此咱們就看出了，該rootLoger使用了不帶參數的StreamHandler，也能夠看到諸如format之類的默認配置。以後咱們 跟蹤StreamHandler(由於咱們想看到日誌輸出目的地的配置，而handler就是控制日誌流向的，因此咱們要跟蹤它)的源代碼：
1 class StreamHandler(Handler): 2 """ 3 A handler class which writes logging records, appropriately formatted, 4 to a stream. Note that this class does not close the stream, as 5 sys.stdout or sys.stderr may be used. 6 """ 7 8 def __init__(self, stream=None): 9 """ 10 Initialize the handler. 11 12 If stream is not specified, sys.stderr is used. 13 """ 14 Handler.__init__(self) 15 if stream is None: 16 stream = sys.stderr 17 self.stream = stream
不帶參數的StreamHandler將會把日誌流定位到sys.stderr流，標準錯誤流一樣會輸出到控制檯。
2） basicConfig函數用來配置RootLogger
basicConfig函數僅用來配置RootLogger，rootLogger是全部Logger的祖先Logger，因此其餘一切Logger會繼承該Logger的配置。
3） 經過示例詳細討論Logger配置的繼承關係
首先準備下繼承條件：log2繼承自log1，logger的名稱能夠隨意，要注意‘.’表示的繼承關係。
1 # coding:utf-8 2 import logging 3 4 log1 = logging.getLogger("mydear") 5 6 log1.setLevel(logging.WARNING) 7 8 log1.addHandler(StreamHandler()) 9 10 log2 = logging.getLogger("mydear.app") 11 12 log2.error("display") 13 14 log2.info("not display")
a）level的繼承
原則：子logger寫日誌時，優先使用自己設置了的level；若是沒有設置，則逐層向上級父logger查詢，直到查詢到爲止。最極端的狀況是，使用rootLogger的默認日誌級別logging.WARNING。
從源代碼中看更爲清晰， 感謝python的所見即所得：
1 def getEffectiveLevel(self): 2 """ 3 Get the effective level for this logger. 4 5 Loop through this logger and its parents in the logger hierarchy, 6 looking for a non-zero logging level. Return the first one found. 7 """ 8 logger = self 9 while logger: 10 if logger.level: 11 return logger.level 12 logger = logger.parent 13 return NOTSET
b）handler的繼承
原則：先將日誌對象傳遞給子logger的全部handler處理，處理完畢後，若是該子logger的propagate屬性沒有設置爲0，則將日誌對象向上傳遞給第一個父Logger，該父logger的全部handler處理完畢後，若是它的propagate也沒有設置爲0，則繼續向上層傳遞，以此類推。最終的狀態，要麼遇到一個Logger，它的propagate屬性設置爲了0；要麼一直傳遞直到rootLogger處理完畢。
在上面實例代碼的基礎上，咱們再添加一句代碼，即：
1 import logging 2 3 log1 = logging.getLogger("mydear") 4 5 log1.setLevel(logging.WARNING) 6 7 log1.addHandler(logging.StreamHandler()) 8 9 log2 = logging.getLogger("mydear.app") 10 11 log2.error("display") 12 13 log2.info("not display") 14 15 print log2.handlers # 打印log2綁定的handler
輸出結果爲：
display
[]
說好的繼承，可是子logger居然沒有綁定父類的handler，what's wrong?
看到下面調用handler的源代碼，就真相大白了。能夠理解成，這不是真正的(類)繼承，只是"行爲上的繼承":
1 def callHandlers(self, record): 2 """ 3 Pass a record to all relevant handlers. 4 5 Loop through all handlers for this logger and its parents in the 6 logger hierarchy. If no handler was found, output a one-off error 7 message to sys.stderr. Stop searching up the hierarchy whenever a 8 logger with the "propagate" attribute set to zero is found - that 9 will be the last logger whose handlers are called. 10 """ 11 c = self 12 found = 0 13 while c: 14 for hdlr in c.handlers: 15 found = found + 1 16 if record.levelno >= hdlr.level: 17 hdlr.handle(record) 18 if not c.propagate: 19 c = None # break out 20 else: 21 c = c.parent 22 if (found == 0) and raiseExceptions and not self.manager.emittedNoHandlerWarning: 23 sys.stderr.write("No handlers could be found for logger" 24 " \"%s\"\n" % self.name) 25 self.manager.emittedNoHandlerWarning = 1
額，最簡單的樣例牽引出來這麼多後臺的邏輯，不過咱們懂一下也是有好處的。
8. logging遇到多進程
在handler中有一個class配置，可能有些讀者並非很懂。其實這個是logging裏面原先就寫好的一些handler類，你能夠在這裏直接調用。class指向的類至關於具體處理的Handler的執行者。在logging的文檔中能夠知道這裏全部的Handler類都是線程安全的(可是GIL的存在，多線程基本能夠無視)，你們能夠放心使用。因此通常狀況下python要實現並行操做或者並行計算的時候都是使用多進程。可是logging並非進程安全的，若是是用多進程來輸出日誌，則只有一個進程會切換，其餘進程會在原來的文件中繼續打，還有可能某些進程切換的時候早就有別的進程在新的日誌文件裏打入東西了，那麼他會無情刪掉之，再創建新的日誌文件。會很亂很亂，徹底無法開心的玩耍。
如今咱們就來解決這個問題，以日誌回滾使用的TimedRotatingFileHandler 這個類爲例：
1）線程不安全的緣由
在解決以前，咱們先看看爲何會致使這樣的緣由。
先將TimedRotatingFileHandler 的源代碼貼上來，這部分是切換時所做的操做：
1 def doRollover(self): 2 """ 3 do a rollover; in this case, a date/time stamp is appended to the filename 4 when the rollover happens. However, you want the file to be named for the 5 start of the interval, not the current time. If there is a backup count, 6 then we have to get a list of matching filenames, sort them and remove 7 the one with the oldest suffix. 8 """ 9 if self.stream: 10 self.stream.close() 11 self.stream = None 12 # get the time that this sequence started at and make it a TimeTuple 13 currentTime = int(time.time()) 14 dstNow = time.localtime(currentTime)[-1] 15 t = self.rolloverAt - self.interval 16 if self.utc: 17 timeTuple = time.gmtime(t) 18 else: 19 timeTuple = time.localtime(t) 20 dstThen = timeTuple[-1] 21 if dstNow != dstThen: 22 if dstNow: 23 addend = 3600 24 else: 25 addend = -3600 26 timeTuple = time.localtime(t + addend) 27 dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple) 28 if os.path.exists(dfn): 29 os.remove(dfn) 30 # Issue 18940: A file may not have been created if delay is True. 31 if os.path.exists(self.baseFilename): 32 os.rename(self.baseFilename, dfn) 33 if self.backupCount > 0: 34 for s in self.getFilesToDelete(): 35 os.remove(s) 36 if not self.delay: 37 self.stream = self._open() 38 newRolloverAt = self.computeRollover(currentTime) 39 while newRolloverAt <= currentTime: 40 newRolloverAt = newRolloverAt + self.interval 41 # If DST changes and midnight or weekly rollover, adjust for this. 42 if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc: 43 dstAtRollover = time.localtime(newRolloverAt)[-1] 44 if dstNow != dstAtRollover: 45 if not dstNow: # DST kicks in before next rollover, so we need to deduct an hour 46 addend = -3600 47 else: # DST bows out before next rollover, so we need to add an hour 48 addend = 3600 49 newRolloverAt += addend 50 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:
1 class SafeRotatingFileHandler(TimedRotatingFileHandler): 2 3 def __init__( self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False): 4 TimedRotatingFileHandler.__init__( self, filename, when, interval, backupCount, encoding, delay, utc) 5 6 """ 7 Override doRollover 8 lines commanded by "##" is changed by cc 9 """ 10 11 def doRollover(self): 12 """ 13 do a rollover; in this case, a date/time stamp is appended to the filename 14 when the rollover happens. However, you want the file to be named for the 15 start of the interval, not the current time. If there is a backup count, 16 then we have to get a list of matching filenames, sort them and remove 17 the one with the oldest suffix. 18 Override, 1. if dfn not exist then do rename 19 2. _open with "a" model 20 """ 21 22 if self.stream: 23 self.stream.close() 24 self.stream = None 25 # get the time that this sequence started at and make it a TimeTuple 26 currentTime = int(time.time()) 27 dstNow = time.localtime(currentTime)[-1] 28 t = self.rolloverAt - self.interval 29 if self.utc: 30 timeTuple = time.gmtime(t) 31 else: 32 timeTuple = time.localtime(t) 33 dstThen = timeTuple[-1] 34 if dstNow != dstThen: 35 if dstNow: 36 addend = 3600 37 else: 38 addend = -3600 39 timeTuple = time.localtime(t + addend) 40 dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple) 41 # if os.path.exists(dfn): 42 # os.remove(dfn) 43 # Issue 18940: A file may not have been created if delay is True. 44 # if os.path.exists(self.baseFilename): 45 if not os.path.exists(dfn) and os.path.exists(self.baseFilename): 46 os.rename(self.baseFilename, dfn) 47 if self.backupCount > 0: 48 for s in self.getFilesToDelete(): 49 os.remove(s) 50 if not self.delay: 51 self.mode = "a" 52 self.stream = self._open() 53 newRolloverAt = self.computeRollover(currentTime) 54 while newRolloverAt <= currentTime: 55 newRolloverAt = newRolloverAt + self.interval 56 # If DST changes and midnight or weekly rollover, adjust for this. 57 if (self.when == 'MIDNIGHT' or self.when.startswith('W')) and not self.utc: 58 dstAtRollover = time.localtime(newRolloverAt)[-1] 59 if dstNow != dstAtRollover: 60 if not dstNow: # DST kicks in before next rollover, so we need to deduct an hour 61 addend = -3600 62 else: # DST bows out before next rollover, so we need to add an hour 63 addend = 3600 64 newRolloverAt += addend 65 self.rolloverAt = newRolloverAt
不要覺得代碼那麼長，其實修改部分就是 「##」 註釋的地方而已，其餘都是照抄源代碼。這個類繼承了 TimedRotatingFileHandler 重寫了這個切分的過程。這個解決方案十分優雅，改換的地方很是少，也十分有效。但有網友提出，這裏有一處地方依然不完美，就是rename的那一步，若是就是這麼巧，同時兩個或者多個進程進入了 if 語句，前後開始 rename 那麼依然會發生刪除掉日誌的狀況。確實這種狀況確實會發生，因爲切分文件一天才一次，正好切分的時候同時有兩個Handler在操做，又正好同時走到這裏，也是蠻巧的，可是爲了完美，能夠加上一個文件鎖，if 以後加鎖，獲得鎖以後再判斷一次，再進行rename這種方式就完美了。代碼就不貼了，涉及到鎖代碼，影響美觀。
3）解決方案2
我認爲最簡單有效的解決方案。重寫FileHandler類（這個類是全部寫入文件的Handler都須要繼承的TimedRotatingFileHandler 就是繼承的這個類；咱們增長一些簡單的判斷和操做就能夠。
咱們的邏輯是這樣的：
a）判斷當前時間戳是否與指向的文件名是同一個時間
b）若是不是，則切換 指向的文件便可
結束，是否是很簡單的邏輯。
talking is cheap show me the code:
1 class SafeFileHandler(FileHandler): 2 3 def __init__(self, filename, mode, encoding=None, delay=0): 4 """ 5 Use the specified filename for streamed logging 6 """ 7 if codecs is None: 8 encoding = None 9 FileHandler.__init__(self, filename, mode, encoding, delay) 10 self.mode = mode 11 self.encoding = encoding 12 self.suffix = "%Y-%m-%d" 13 self.suffix_time = "" 14 def emit(self, record): 15 """ 16 Emit a record. 17 Always check time 18 """ 19 try: 20 if self.check_baseFilename(record): 21 self.build_baseFilename() 22 FileHandler.emit(self, record) 23 except (KeyboardInterrupt, SystemExit): 24 raise 25 except: 26 self.handleError(record) 27 def check_baseFilename(self, record): 28 """ 29 Determine if builder should occur. 30 record is not used, as we are just comparing times, 31 but it is needed so the method signatures are the same 32 """ 33 timeTuple = time.localtime() 34 if self.suffix_time != time.strftime(self.suffix, timeTuple) or not os.path.exists( 35 self.baseFilename + '.' + self.suffix_time): 36 return 1 37 else: 38 return 0 39 def build_baseFilename(self): 40 """ 41 do builder; in this case, 42 old time stamp is removed from filename and 43 a new time stamp is append to the filename 44 """ 45 if self.stream: 46 self.stream.close() 47 self.stream = None 48 # remove old suffix 49 if self.suffix_time != "": 50 index = self.baseFilename.find("." + self.suffix_time) 51 if index == -1: 52 index = self.baseFilename.rfind(".") 53 self.baseFilename = self.baseFilename[:index] 54 # add new suffix 55 currentTimeTuple = time.localtime() 56 self.suffix_time = time.strftime(self.suffix, currentTimeTuple) 57 self.baseFilename = self.baseFilename + "." + self.suffix_time 58 self.mode = 'a' 59 if not self.delay: 60 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）使用案例一
1 def init_log(): 2 logfile = "/data1/restful_log/restful_api_thread.log" 3 filesize = 800*1024*1024 4 log = getLogger() 5 rotate_handler = ConcurrentRotatingFileHandler(logfile, "a", filesize, encoding="utf-8") 6 7 datefmt_str = '%Y-%m-%d %H:%M:%S' 8 format_str = '%(asctime)s\t%(levelname)s\t%(message)s ' 9 formatter = Formatter(format_str, datefmt_str) 10 rotate_handler.setFormatter(formatter) 11 12 log.addHandler(rotate_handler) 13 log.setLevel(WARN) 14 15 return log
ConcurrentRotatingFileHandler參數說明： filename: 日誌文件地址，相對地址或絕對地址都可
mode: 默認爲"a"
maxBytes：文件長度，超過最大長度自動分片，最初日誌都會寫入filename裏面，到達設置的最大長度以後進行分片，分片後文件名爲filename.1 filename.2，以此類推
backupCount：最大日誌文件保留數量，默認爲0即不會刪除日誌文件
encoding：日誌文件編碼格式，默認爲gbk
b）使用案例二
建一個目錄，下面的文件都放到這個目錄中：
logging-config.yaml
1 version: 1 2 3 formatters: 4 simple: 5 format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s' 6 7 handlers: 8 console: 9 class: logging.StreamHandler 10 level: DEBUG 11 formatter: simple 12 stream: ext://sys.stdout 13 14 loggers: 15 simpleExample: 16 level: DEBUG 17 handlers: [console] 18 propagate: no 19 20 root: 21 level: DEBUG 22 handlers: [console]
testlogging.py
1 #!/usr/bin/python2.7 2 #-*- coding: UTF-8 -*- 3 # 4 # Using ConcurrentLogHandler: 5 # wget https://pypi.python.org/packages/fd/e5/0dc4f256bcc6484d454006b02f33263b20f762a433741b29d53875e0d763/ConcurrentLogHandler-0.9.1.tar.gz#md5=9609ecc4c269ac43f0837d89f12554c3 6 # cd ConcurrentLogHandler-0.9.1 7 # python2.7 setup.py install 8 ########################################################### 9 import logging, logging.config 10 import cloghandler 11 12 import yaml 13 14 ########################################################### 15 # create logger 16 # 使用代碼建立logger 17 logger = logging.getLogger('simple_example') 18 logger.setLevel(logging.DEBUG) 19 20 # create console handler and set level to debug 21 ch = logging.StreamHandler() 22 ch.setLevel(logging.DEBUG) 23 24 # create formatter 25 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 26 27 # add formatter to ch 28 ch.setFormatter(formatter) 29 30 # add ch to logger 31 logger.addHandler(ch) 32 33 # 'application' code 34 logger.debug('debug message') 35 logger.info('info message') 36 logger.warn('warn message') 37 logger.error('error message') 38 logger.critical('critical message') 39 40 41 ########################################################### 42 # basicConfig 43 logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p') 44 logging.warning('is when this event was logged.') 45 46 47 ########################################################### 48 # using yaml config file 49 f = open("logging-config.yaml") 50 dictcfg = yaml.load(f) 51 f.close() 52 53 logging.config.dictConfig(dictcfg) 54 55 #logging.config.fileConfig("logging.config") 56 log = logging.getLogger("root") 57 log.info("==YAML== Here is a very exciting log message") 58 59 ########################################################### 60 # using ini config file 61 logging.config.fileConfig("logging-config.ini") 62 log = logging.getLogger("simpleExample") 63 log.info("==INI== Here is a very exciting log message") 64 65 66 ########################################################### 67 # using inline code config 68 logging.config.dictConfig({ 69 'version': 1, 70 'disable_existing_loggers': True, 71 'formatters': { 72 'verbose': { 73 'format': "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s", 74 'datefmt': "%Y-%m-%d %H:%M:%S", 75 }, 76 'simple': { 77 'format': '%(levelname)s %(message)s', 78 }, 79 }, 80 'handlers': { 81 'null': { 82 'level': 'DEBUG', 83 'class': 'logging.NullHandler', 84 }, 85 'console': { 86 'level': 'DEBUG', 87 'class': 'logging.StreamHandler', 88 'formatter': 'verbose', 89 }, 90 'file': { 91 'level': 'DEBUG', 92 'class': 'cloghandler.ConcurrentRotatingFileHandler', 93 'maxBytes': 1024 * 1024 * 10, # 當達到10MB時分割日誌 94 'backupCount': 10, # 最多保留10份文件 95 'delay': True, # If delay is true, file opening is deferred until the first call to emit 96 'filename': 'sample-site.log', 97 'formatter': 'verbose', 98 }, 99 'file2': { 100 'level': 'DEBUG', 101 'class': 'cloghandler.ConcurrentRotatingFileHandler', 102 'maxBytes': 1024 * 1024 * 10, # 當達到10MB時分割日誌 103 'backupCount': 10, # 最多保留10份文件 104 'delay': True, # If delay is true, file opening is deferred until the first call to emit 105 'filename': 'sample-site2.log', 106 'formatter': 'verbose', 107 }, 108 }, 109 'loggers': { 110 '': { 111 'handlers': ['file'], 112 'level': 'INFO', 113 }, 114 'root': { 115 'handlers': ['console'], 116 'level': 'INFO', 117 'propagate': 0, 118 }, 119 'root2': { 120 'handlers': ['console'], 121 'level': 'INFO', 122 'propagate': 1, 123 }, 124 }, 125 }) 126 127 logger = logging.getLogger("root") 128 logger.info("==== Here is a very exciting log message") 129 130 logger = logging.getLogger("root2") 131 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('')
暫時就到這裏，之後繼續擴展
- 1. logging模塊打印日誌
- 2. 【Python模塊】logging模塊打印日誌
- 3. Django 如何使用logging打印日誌
- 4. okHttp詳細日誌打印
- 5. logging日誌模塊
- 6. Logging日誌模塊
- 7. logging 日誌模塊
- 8. python日誌打印模塊
- 9. logging模塊，還在使用print打印？
- 10. python logging日誌模塊的使用
- 更多相關文章...
- • 爲什麼使用 XML Schemas? - XML Schema 教程
- • 爲什麼使用 Web Services? - Web Services 教程
- • 爲了進字節跳動，我精選了29道Java經典算法題，帶詳細講解
- • 委託模式
-
每一个你不满意的现在，都有一个你没有努力的曾经。
- 1. logging模塊打印日誌
- 2. 【Python模塊】logging模塊打印日誌
- 3. Django 如何使用logging打印日誌
- 4. okHttp詳細日誌打印
- 5. logging日誌模塊
- 6. Logging日誌模塊
- 7. logging 日誌模塊
- 8. python日誌打印模塊
- 9. logging模塊，還在使用print打印？
- 10. python logging日誌模塊的使用