在 PyCon 2018 上,Mario Corchero 介紹了在開發過程中如何更方便輕松地記錄日志的流程。
整個演講的內容包括:
- 為什么日志記錄非常重要
- 日志記錄的流程是怎樣的
- 怎樣來進行日志記錄
- 怎樣進行日志記錄相關配置
- 日志記錄使用常見誤區
下面我們來梳理一下整個演講的過程,其實其核心就是介紹了 logging 模塊的使用方法和一些配置。
日志記錄的重要性
在開發過程中,如果程序運行出現了問題,我們是可以使用我們自己的 Debug 工具來檢測到到底是哪一步出現了問題,如果出現了問題的話,是很容易排查的。但程序開發完成之后,我們會將它部署到生產環境中去,這時候代碼相當於是在一個黑盒環境下運行的,我們只能看到其運行的效果,是不能直接看到代碼運行過程中每一步的狀態的。在這個環境下,運行過程中難免會在某個地方出現問題,甚至這個問題可能是我們開發過程中未曾遇到的問題,碰到這種情況應該怎么辦?
如果我們現在只能得知當前問題的現象,而沒有其他任何信息的話,如果我們想要解決掉這個問題的話,那么只能根據問題的現象來試圖復現一下,然后再一步步去調試,這恐怕是很難的,很大的概率上我們是無法精准地復現這個問題的,而且 Debug 的過程也會耗費巨多的時間,這樣一旦生產環境上出現了問題,修復就會變得非常棘手。但這如果我們當時有做日志記錄的話,不論是正常運行還是出現報錯,都有相關的時間記錄,狀態記錄,錯誤記錄等,那么這樣我們就可以方便地追蹤到在當時的運行過程中出現了怎樣的狀況,從而可以快速排查問題。
因此,日志記錄是非常有必要的,任何一款軟件如果沒有標准的日志記錄,都不能算作一個合格的軟件。作為開發者,我們需要重視並做好日志記錄過程。
日志記錄的流程框架
那么在 Python 中,怎樣才能算作一個比較標准的日志記錄過程呢?或許很多人會使用 print 語句輸出一些運行信息,然后再在控制台觀察,運行的時候再將輸出重定向到文件輸出流保存到文件中,這樣其實是非常不規范的,在 Python 中有一個標准的 logging 模塊,我們可以使用它來進行標注的日志記錄,利用它我們可以更方便地進行日志記錄,同時還可以做更方便的級別區分以及一些額外日志信息的記錄,如時間、運行模塊信息等。
接下來我們先了解一下日志記錄流程的整體框架。
如圖所示,整個日志記錄的框架可以分為這么幾個部分:
- Logger:即 Logger Main Class,是我們進行日志記錄時創建的對象,我們可以調用它的方法傳入日志模板和信息,來生成一條條日志記錄,稱作 Log Record。
- Log Record:就代指生成的一條條日志記錄。
- Handler:即用來處理日志記錄的類,它可以將 Log Record 輸出到我們指定的日志位置和存儲形式等,如我們可以指定將日志通過 FTP 協議記錄到遠程的服務器上,Handler 就會幫我們完成這些事情。
- Formatter:實際上生成的 Log Record 也是一個個對象,那么我們想要把它們保存成一條條我們想要的日志文本的話,就需要有一個格式化的過程,那么這個過程就由 Formatter 來完成,返回的就是日志字符串,然后傳回給 Handler 來處理。
- Filter:另外保存日志的時候我們可能不需要全部保存,我們可能只需要保存我們想要的部分就可以了,所以保存前還需要進行一下過濾,留下我們想要的日志,如只保存某個級別的日志,或只保存包含某個關鍵字的日志等,那么這個過濾過程就交給 Filter 來完成。
- Parent Handler:Handler 之間可以存在分層關系,以使得不同 Handler 之間共享相同功能的代碼。
以上就是整個 logging 模塊的基本架構和對象功能,了解了之后我們詳細來了解一下 logging 模塊的用法。
日志記錄的相關用法
總的來說 logging 模塊相比 print 有這么幾個優點:
- 可以在 logging 模塊中設置日志等級,在不同的版本(如開發環境、生產環境)上通過設置不同的輸出等級來記錄對應的日志,非常靈活。
- print 的輸出信息都會輸出到標准輸出流中,而 logging 模塊就更加靈活,可以設置輸出到任意位置,如寫入文件、寫入遠程服務器等。
- logging 模塊具有靈活的配置和格式化功能,如配置輸出當前模塊信息、運行時間等,相比 print 的字符串格式化更加方便易用。
下面我們初步來了解下 logging 模塊的基本用法,先用一個實例來感受一下:
1
2
3
4
5
6
7
8
9
|
import logging
logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
logger = logging.getLogger(__name__)
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
|
在這里我們首先引入了 logging 模塊,然后進行了一下基本的配置,這里通過 basicConfig 配置了 level 信息和 format 信息,這里 level 配置為 INFO 信息,即只輸出 INFO 級別的信息,另外這里指定了 format 格式的字符串,包括 asctime、name、levelname、message 四個內容,分別代表運行時間、模塊名稱、日志級別、日志內容,這樣輸出內容便是這四者組合而成的內容了,這就是 logging 的全局配置。
接下來聲明了一個 Logger 對象,它就是日志輸出的主類,調用對象的 info() 方法就可以輸出 INFO 級別的日志信息,調用 debug() 方法就可以輸出 DEBUG 級別的日志信息,非常方便。在初始化的時候我們傳入了模塊的名稱,這里直接使用 __name__ 來代替了,就是模塊的名稱,如果直接運行這個腳本的話就是 __main__,如果是 import 的模塊的話就是被引入模塊的名稱,這個變量在不同的模塊中的名字是不同的,所以一般使用 __name__ 來表示就好了,再接下來輸出了四條日志信息,其中有兩條 INFO、一條 WARNING、一條 DEBUG 信息,我們看下輸出結果:
1
2
3
|
2018-06-03 13:42:43,526 - __main__ - INFO - This is a log info
2018-06-03 13:42:43,526 - __main__ - WARNING - Warning exists
2018-06-03 13:42:43,526 - __main__ - INFO - Finish
|
可以看到輸出結果一共有三條日志信息,每條日志都是對應了指定的格式化內容,另外我們發現 DEBUG 的信息是沒有輸出的,這是因為我們在全局配置的時候設置了輸出為 INFO 級別,所以 DEBUG 級別的信息就被過濾掉了。
這時如果我們將輸出的日志級別設置為 DEBUG,就可以看到 DEBUG 級別的日志輸出了:
1
|
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
|
輸出結果:
1
2
3
4
|
2018-06-03 13:49:22,770 - __main__ - INFO - This is a log info
2018-06-03 13:49:22,770 - __main__ - DEBUG - Debugging
2018-06-03 13:49:22,770 - __main__ - WARNING - Warning exists
2018-06-03 13:49:22,770 - __main__ - INFO - Finish
|
由此可見,相比 print 來說,通過剛才的代碼,我們既可以輸出時間、模塊名稱,又可以輸出不同級別的日志信息作區分並加以過濾,是不是靈活多了?
當然這只是 logging 模塊的一小部分功能,接下來我們首先來全面了解一下 basicConfig 的參數都有哪些:
- filename:即日志輸出的文件名,如果指定了這個信息之后,實際上會啟用 FileHandler,而不再是 StreamHandler,這樣日志信息便會輸出到文件中了。
- filemode:這個是指定日志文件的寫入方式,有兩種形式,一種是 w,一種是 a,分別代表清除后寫入和追加寫入。
- format:指定日志信息的輸出格式,即上文示例所示的參數,詳細參數可以參考:docs.python.org/3/library/l…,部分參數如下所示:
- %(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。
- %(processName)s:打印線程名稱。
- %(module)s:打印模塊名稱。
- %(message)s:打印日志信息。
- datefmt:指定時間的輸出格式。
- style:如果 format 參數指定了,這個參數就可以指定格式化時的占位符風格,如 %、{、$ 等。
- level:指定日志輸出的類別,程序會輸出大於等於此級別的信息。
- stream:在沒有指定 filename 的時候會默認使用 StreamHandler,這時 stream 可以指定初始化的文件流。
- handlers:可以指定日志處理時所使用的 Handlers,必須是可迭代的。
下面我們再用一個實例來感受一下:
1
2
3
4
5
6
7
8
9
10
11
12
|
import logging
logging.basicConfig(level=logging.DEBUG,
filename='output.log',
datefmt='%Y/%m/%d %H:%M:%S',
format='%(asctime)s - %(name)s - %(levelname)s - %(lineno)d - %(module)s - %(message)s')
logger = logging.getLogger(__name__)
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
|
這里我們指定了輸出文件的名稱為 output.log,另外指定了日期的輸出格式,其中年月日的格式變成了 %Y/%m/%d,另外輸出的 format 格式增加了 lineno、module 這兩個信息,運行之后便會生成一個 output.log 的文件,內容如下:
1
2
3
4
|
2018/06/03 14:43:26 - __main__ - INFO - 9 - demo3 - This is a log info
2018/06/03 14:43:26 - __main__ - DEBUG - 10 - demo3 - Debugging
2018/06/03 14:43:26 - __main__ - WARNING - 11 - demo3 - Warning exists
2018/06/03 14:43:26 - __main__ - INFO - 12 - demo3 - Finish
|
可以看到日志便會輸出到文件中,同時輸出了行號、模塊名稱等信息。
以上我們通過 basicConfig 來進行了一些全局的配置,我們同樣可以使用 Formatter、Handler 進行更靈活的處理,下面我們來了解一下。
Level
首先我們來了解一下輸出日志的等級信息,logging 模塊共提供了如下等級,每個等級其實都對應了一個數值,列表如下:
等級 | 數值 |
---|---|
CRITICAL | 50 |
FATAL | 50 |
ERROR | 40 |
WARNING | 30 |
WARN | 30 |
INFO | 20 |
DEBUG | 10 |
NOTSET | 0 |
這里最高的等級是 CRITICAL 和 FATAL,兩個對應的數值都是 50,另外對於 WARNING 還提供了簡寫形式 WARN,兩個對應的數值都是 30。
我們設置了輸出 level,系統便只會輸出 level 數值大於或等於該 level 的的日志結果,例如我們設置了輸出日志 level 為 INFO,那么輸出級別大於等於 INFO 的日志,如 WARNING、ERROR 等,DEBUG 和 NOSET 級別的不會輸出。
1
2
3
4
5
6
7
8
9
10
11
|
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.WARN)
# Log
logger.debug('Debugging')
logger.critical('Critical Something')
logger.error('Error Occurred')
logger.warning('Warning exists')
logger.info('Finished')
|
這里我們設置了輸出級別為 WARN,然后對應輸出了五種不同級別的日志信息,運行結果如下:
1
2
3
|
Critical Something
Error Occurred
Warning exists
|
可以看到只有 CRITICAL、ERROR、WARNING 信息輸出了,DEBUG、INFO 信息沒有輸出。
Handler
下面我們先來了解一下 Handler 的用法,看下面的實例:
1
2
3
4
5
6
7
8
9
10
11
12
13
|
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.INFO)
handler = logging.FileHandler('output.log')
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
|
這里我們沒有再使用 basicConfig 全局配置,而是先聲明了一個 Logger 對象,然后指定了其對應的 Handler 為 FileHandler 對象,然后 Handler 對象還單獨指定了 Formatter 對象單獨配置輸出格式,最后給 Logger 對象添加對應的 Handler 即可,最后可以發現日志就會被輸出到 output.log 中,內容如下:
1
2
3
|
2018-06-03 14:53:36,467 - __main__ - INFO - This is a log info
2018-06-03 14:53:36,468 - __main__ - WARNING - Warning exists
2018-06-03 14:53:36,468 - __main__ - INFO - Finish
|
另外我們還可以使用其他的 Handler 進行日志的輸出,logging 模塊提供的 Handler 有:
- StreamHandler:logging.StreamHandler;日志輸出到流,可以是 sys.stderr,sys.stdout 或者文件。
- FileHandler:logging.FileHandler;日志輸出到文件。
- BaseRotatingHandler:logging.handlers.BaseRotatingHandler;基本的日志回滾方式。
- RotatingHandler:logging.handlers.RotatingHandler;日志回滾方式,支持日志文件最大數量和日志文件回滾。
- TimeRotatingHandler:logging.handlers.TimeRotatingHandler;日志回滾方式,在一定時間區域內回滾日志文件。
- SocketHandler:logging.handlers.SocketHandler;遠程輸出日志到TCP/IP sockets。
- DatagramHandler:logging.handlers.DatagramHandler;遠程輸出日志到UDP sockets。
- SMTPHandler:logging.handlers.SMTPHandler;遠程輸出日志到郵件地址。
- SysLogHandler:logging.handlers.SysLogHandler;日志輸出到syslog。
- NTEventLogHandler:logging.handlers.NTEventLogHandler;遠程輸出日志到Windows NT/2000/XP的事件日志。
- MemoryHandler:logging.handlers.MemoryHandler;日志輸出到內存中的指定buffer。
- HTTPHandler:logging.handlers.HTTPHandler;通過”GET”或者”POST”遠程輸出到HTTP服務器。
下面我們使用三個 Handler 來實現日志同時輸出到控制台、文件、HTTP 服務器:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
|
import logging
from logging.handlers import HTTPHandler
import sys
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.DEBUG)
# StreamHandler
stream_handler = logging.StreamHandler(sys.stdout)
stream_handler.setLevel(level=logging.DEBUG)
logger.addHandler(stream_handler)
# FileHandler
file_handler = logging.FileHandler('output.log')
file_handler.setLevel(level=logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
# HTTPHandler
http_handler = HTTPHandler(host='localhost:8001', url='log', method='POST')
logger.addHandler(http_handler)
# Log
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
|
運行之前我們需要先啟動 HTTP Server,並運行在 8001 端口,其中 log 接口是用來接收日志的接口。
運行之后控制台輸出會輸出如下內容:
1
2
3
4
|
This is a log info
Debugging
Warning exists
Finish
|
output.log 文件會寫入如下內容:
1
2
3
|
2018-06-03 15:13:44,895 - __main__ - INFO - This is a log info
2018-06-03 15:13:44,947 - __main__ - WARNING - Warning exists
2018-06-03 15:13:44,949 - __main__ - INFO - Finish
|
HTTP Server 會收到控制台輸出的信息。
這樣一來,我們就通過設置多個 Handler 來控制了日志的多目標輸出。
另外值得注意的是,在這里 StreamHandler 對象我們沒有設置 Formatter,因此控制台只輸出了日志的內容,而沒有包含時間、模塊等信息,而 FileHandler 我們通過 setFormatter() 方法設置了一個 Formatter 對象,因此輸出的內容便是格式化后的日志信息。
另外每個 Handler 還可以設置 level 信息,最終輸出結果的 level 信息會取 Logger 對象的 level 和 Handler 對象的 level 的交集。
Formatter
在進行日志格式化輸出的時候,我們可以不借助於 basicConfig 來全局配置格式化輸出內容,可以借助於 Formatter 來完成,下面我們再來單獨看下 Formatter 的用法:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.WARN)
formatter = logging.Formatter(fmt='%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y/%m/%d %H:%M:%S')
handler = logging.StreamHandler()
handler.setFormatter(formatter)
logger.addHandler(handler)
# Log
logger.debug('Debugging')
logger.critical('Critical Something')
logger.error('Error Occurred')
logger.warning('Warning exists')
logger.info('Finished')
|
在這里我們指定了一個 Formatter,並傳入了 fmt 和 datefmt 參數,這樣就指定了日志結果的輸出格式和時間格式,然后 handler 通過 setFormatter() 方法設置此 Formatter 對象即可,輸出結果如下:
1
2
3
|
2018/06/03 15:47:15 - __main__ - CRITICAL - Critical Something
2018/06/03 15:47:15 - __main__ - ERROR - Error Occurred
2018/06/03 15:47:15 - __main__ - WARNING - Warning exists
|
這樣我們可以每個 Handler 單獨配置輸出的格式,非常靈活。
捕獲 Traceback
如果遇到錯誤,我們更希望報錯時出現的詳細 Traceback 信息,便於調試,利用 logging 模塊我們可以非常方便地實現這個記錄,我們用一個實例來感受一下:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
|
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.DEBUG)
# Formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# FileHandler
file_handler = logging.FileHandler('result.log')
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
# StreamHandler
stream_handler = logging.StreamHandler()
stream_handler.setFormatter(formatter)
logger.addHandler(stream_handler)
# Log
logger.info('Start')
logger.warning('Something maybe fail.')
try:
result = 10 / 0
except Exception:
logger.error('Faild to get result', exc_info=True)
logger.info('Finished')
|
這里我們在 error() 方法中添加了一個參數,將 exc_info 設置為了 True,這樣我們就可以輸出執行過程中的信息了,即完整的 Traceback 信息。
運行結果如下:
1
2
3
4
5
6
7
8
9
|
2018-06-03 16:00:15,382 - __main__ - INFO - Start print log
2018-06-03 16:00:15,382 - __main__ - DEBUG - Do something
2018-06-03 16:00:15,382 - __main__ - WARNING - Something maybe fail.
2018-06-03 16:00:15,382 - __main__ - ERROR - Faild to get result
Traceback (most recent call last):
File "/private/var/books/aicodes/loggingtest/demo8.py", line 23, in <module>
result = 10 / 0
ZeroDivisionError: division by zero
2018-06-03 16:00:15,383 - __main__ - INFO - Finished
|
可以看到這樣我們就非常方便地記錄下來了報錯的信息,一旦出現了錯誤,我們也能非常方便地排查。
配置共享
在寫項目的時候,我們肯定會將許多配置放置在許多模塊下面,這時如果我們每個文件都來配置 logging 配置那就太繁瑣了,logging 模塊提供了父子模塊共享配置的機制,會根據 Logger 的名稱來自動加載父模塊的配置。
例如我們這里首先定義一個 main.py 文件:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
import logging
import core
logger = logging.getLogger('main')
logger.setLevel(level=logging.DEBUG)
# Handler
handler = logging.FileHandler('result.log')
handler.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.info('Main Info')
logger.debug('Main Debug')
logger.error('Main Error')
core.run()
|
這里我們配置了日志的輸出格式和文件路徑,同時定義了 Logger 的名稱為 main,然后引入了另外一個模塊 core,最后調用了 core 的 run() 方法。
接下來我們定義 core.py,內容如下:
1
2
3
4
5
6
7
8
|
import logging
logger = logging.getLogger('main.core')
def run():
logger.info('Core Info')
logger.debug('Core Debug')
logger.error('Core Error')
|
這里我們定義了 Logger 的名稱為 main.core,注意這里開頭是 main,即剛才我們在 main.py 里面的 Logger 的名稱,這樣 core.py 里面的 Logger 就會復用 main.py 里面的 Logger 配置,而不用再去配置一次了。
運行之后會生成一個 result.log 文件,內容如下:
1
2
3
4
|
2018-06-03 16:55:56,259 - main - INFO - Main Info
2018-06-03 16:55:56,259 - main - ERROR - Main Error
2018-06-03 16:55:56,259 - main.core - INFO - Core Info
2018-06-03 16:55:56,259 - main.core - ERROR - Core Error
|
可以看到父子模塊都使用了同樣的輸出配置。
如此一來,我們只要在入口文件里面定義好 logging 模塊的輸出配置,子模塊只需要在定義 Logger 對象時名稱使用父模塊的名稱開頭即可共享配置,非常方便。
文件配置
在開發過程中,將配置在代碼里面寫死並不是一個好的習慣,更好的做法是將配置寫在配置文件里面,我們可以將配置寫入到配置文件,然后運行時讀取配置文件里面的配置,這樣是更方便管理和維護的,下面我們以一個實例來說明一下,首先我們定義一個 yaml 配置文件:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
|
version: 1
formatters:
brief:
format: "%(asctime)s - %(message)s"
simple:
format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
handlers:
console:
class : logging.StreamHandler
formatter: brief
level : INFO
stream : ext://sys.stdout
file:
class : logging.FileHandler
formatter: simple
level: DEBUG
filename: debug.log
error:
class: logging.handlers.RotatingFileHandler
level: ERROR
formatter: simple
filename: error.log
maxBytes: 10485760
backupCount: 20
encoding: utf8
loggers:
main.core:
level: DEBUG
handlers: [console, file, error]
root:
level: DEBUG
handlers: [console]
|
這里我們定義了 formatters、handlers、loggers、root 等模塊,實際上對應的就是各個 Formatter、Handler、Logger 的配置,參數和它們的構造方法都是相同的。
接下來我們定義一個主入口文件,main.py,內容如下:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
|
import logging
import core
import yaml
import logging.config
import os
def setup_logging(default_path='config.yaml', default_level=logging.INFO):
path = default_path
if os.path.exists(path):
with open(path, 'r', encoding='utf-8') as f:
config = yaml.load(f)
logging.config.dictConfig(config)
else:
logging.basicConfig(level=default_level)
def log():
logging.debug('Start')
logging.info('Exec')
logging.info('Finished')
if __name__ == '__main__':
yaml_path = 'config.yaml'
setup_logging(yaml_path)
log()
core.run()
|
這里我們定義了一個 setup_logging() 方法,里面讀取了 yaml 文件的配置,然后通過 dictConfig() 方法將配置項傳給了 logging 模塊進行全局初始化。
另外這個模塊還引入了另外一個模塊 core,所以我們定義 core.py 如下:
1
2
3
4
5
6
7
8
|
import logging
logger = logging.getLogger('main.core')
def run():
logger.info('Core Info')
logger.debug('Core Debug')
logger.error('Core Error')
|
這個文件的內容和上文是沒有什么變化的。
觀察配置文件,主入口文件 main.py 實際上對應的是 root 一項配置,它指定了 handlers 是 console,即只輸出到控制台。另外在 loggers 一項配置里面,我們定義了 main.core 模塊,handlers 是 console、file、error 三項,即輸出到控制台、輸出到普通文件和回滾文件。
這樣運行之后,我們便可以看到所有的運行結果輸出到了控制台:
1
2
3
4
5
6
|
2018-06-03 17:07:12,727 - Exec
2018-06-03 17:07:12,727 - Finished
2018-06-03 17:07:12,727 - Core Info
2018-06-03 17:07:12,727 - Core Info
2018-06-03 17:07:12,728 - Core Error
2018-06-03 17:07:12,728 - Core Error
|
在 debug.log 文件中則包含了 core.py 的運行結果:
1
2
3
|
2018-06-03 17:07:12,727 - main.core - INFO - Core Info
2018-06-03 17:07:12,727 - main.core - DEBUG - Core Debug
2018-06-03 17:07:12,728 - main.core - ERROR - Core Error
|
可以看到,通過配置文件,我們可以非常靈活地定義 Handler、Formatter、Logger 等配置,同時也顯得非常直觀,也非常容易維護,在實際項目中,推薦使用此種方式進行配置。
以上便是 logging 模塊的基本使用方法,有了它,我們可以方便地進行日志管理和維護,會給我們的工作帶來極大的方便。
日志記錄使用常見誤區
在日志輸出的時候經常我們會用到字符串拼接的形式,很多情況下我們可能會使用字符串的 format() 來構造一個字符串,但這其實並不是一個好的方法,因為還有更好的方法,下面我們對比兩個例子:
1
2
3
4
5
6
7
8
|
import logging
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# bad
logging.debug('Hello {0}, {1}!'.format('World', 'Congratulations'))
# good
logging.debug('Hello %s, %s!', 'World', 'Congratulations')
|
這里有兩種打印 Log 的方法,第一種使用了字符串的 format() 的方法進行構造,傳給 logging 的只用到了第一個參數,實際上 logging 模塊提供了字符串格式化的方法,我們只需要在第一個參數寫上要打印輸出的模板,占位符用 %s、%d 等表示即可,然后在后續參數添加對應的值就可以了,推薦使用這種方法。
運行結果如下:
1
2
|
2018-06-03 22:27:51,220 - root - DEBUG - Hello World, Congratulations!
2018-06-03 22:27:51,220 - root - DEBUG - Hello World, Congratulations!
|
另外在進行異常處理的時候,通常我們會直接將異常進行字符串格式化,但其實可以直接指定一個參數將 traceback 打印出來,示例如下:
1
2
3
4
5
6
7
8
9
10
11
12
13
|
import logging
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
try:
result = 5 / 0
except Exception as e:
# bad
logging.error('Error: %s', e)
# good
logging.error('Error', exc_info=True)
# good
logging.exception('Error')
|
如果我們直接使用字符串格式化的方法將錯誤輸出的話,是不會包含 Traceback 信息的,但如果我們加上 exc_info 參數或者直接使用 exception() 方法打印的話,那就會輸出 Traceback 信息了。
運行結果如下:
1
2
3
4
5
6
7
8
9
10
11
|
2018-06-03 22:24:31,927 - root - ERROR - Error: division by zero
2018-06-03 22:24:31,927 - root - ERROR - Error
Traceback (most recent call last):
File "/private/var/books/aicodes/loggingtest/demo9.py", line 6, in <module>
result = 5 / 0
ZeroDivisionError: division by zero
2018-06-03 22:24:31,928 - root - ERROR - Error
Traceback (most recent call last):
File "/private/var/books/aicodes/loggingtest/demo9.py", line 6, in <module>
result = 5 / 0
ZeroDivisionError: division by zero
|
以上便是整個對 logging 模塊的介紹。嗯,是時候拋棄 print 了,開始體驗下 logging 的便利吧!
參考內容
* https://docs.python.org/3/library/logging.html
* http://www.cnblogs.com/dahu-daqing/p/7040764.html
轉載:靜覓 » Python中logging模塊的基本用法