PyCon 2018: 利用logging模塊輕鬆地進行Python日誌記錄

時間 2019-11-17

標籤 pycon 利用 logging 模塊輕鬆進行 python 日誌記錄欄目 Log4j 简体版

原文原文鏈接

在 PyCon 2018 上，Mario Corchero 介紹了在開發過程當中如何更方便輕鬆地記錄日誌的流程。html

整個演講的內容包括：python

爲何日誌記錄很是重要
日誌記錄的流程是怎樣的
怎樣來進行日誌記錄
怎樣進行日誌記錄相關配置
日誌記錄使用常見誤區

下面咱們來梳理一下整個演講的過程，其實其核心就是介紹了 logging 模塊的使用方法和一些配置。bash

日誌記錄的重要性

在開發過程當中，若是程序運行出現了問題，咱們是可使用咱們本身的 Debug 工具來檢測到究竟是哪一步出現了問題，若是出現了問題的話，是很容易排查的。但程序開發完成以後，咱們會將它部署到生產環境中去，這時候代碼至關因而在一個黑盒環境下運行的，咱們只能看到其運行的效果，是不能直接看到代碼運行過程當中每一步的狀態的。在這個環境下，運行過程當中不免會在某個地方出現問題，甚至這個問題多是咱們開發過程當中不曾遇到的問題，碰到這種狀況應該怎麼辦？服務器

若是咱們如今只能得知當前問題的現象，而沒有其餘任何信息的話，若是咱們想要解決掉這個問題的話，那麼只能根據問題的現象來試圖復現一下，而後再一步步去調試，這恐怕是很難的，很大的機率上咱們是沒法精準地復現這個問題的，並且 Debug 的過程也會耗費巨多的時間，這樣一旦生產環境上出現了問題，修復就會變得很是棘手。但這若是咱們當時有作日誌記錄的話，不管是正常運行仍是出現報錯，都有相關的時間記錄，狀態記錄，錯誤記錄等，那麼這樣咱們就能夠方便地追蹤到在當時的運行過程當中出現了怎樣的情況，從而能夠快速排查問題。架構

所以，日誌記錄是很是有必要的，任何一款軟件若是沒有標準的日誌記錄，都不能算做一個合格的軟件。做爲開發者，咱們須要重視並作好日誌記錄過程。框架

日誌記錄的流程框架

那麼在 Python 中，怎樣才能算做一個比較標準的日誌記錄過程呢？或許不少人會使用 print 語句輸出一些運行信息，而後再在控制檯觀察，運行的時候再將輸出重定向到文件輸出流保存到文件中，這樣實際上是很是不規範的，在 Python 中有一個標準的 logging 模塊，咱們可使用它來進行標註的日誌記錄，利用它咱們能夠更方便地進行日誌記錄，同時還能夠作更方便的級別區分以及一些額外日誌信息的記錄，如時間、運行模塊信息等。socket

接下來咱們先了解一下日誌記錄流程的總體框架。函數

如圖所示，整個日誌記錄的框架能夠分爲這麼幾個部分：工具

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 模塊的用法。url

日誌記錄的相關用法

總的來講 logging 模塊相比 print 有這麼幾個優勢：

能夠在 logging 模塊中設置日誌等級，在不一樣的版本（如開發環境、生產環境）上經過設置不一樣的輸出等級來記錄對應的日誌，很是靈活。
print 的輸出信息都會輸出到標準輸出流中，而 logging 模塊就更加靈活，能夠設置輸出到任意位置，如寫入文件、寫入遠程服務器等。
logging 模塊具備靈活的配置和格式化功能，如配置輸出當前模塊信息、運行時間等，相比 print 的字符串格式化更加方便易用。

下面咱們初步來了解下 logging 模塊的基本用法，先用一個實例來感覺一下：

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 信息，咱們看下輸出結果：

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 級別的日誌輸出了：

logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
複製代碼

輸出結果：

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，必須是可迭代的。

下面咱們再用一個實例來感覺一下：

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 的文件，內容以下：

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 級別的不會輸出。

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，而後對應輸出了五種不一樣級別的日誌信息，運行結果以下：

Critical Something
Error Occurred
Warning exists
複製代碼

能夠看到只有 CRITICAL、ERROR、WARNING 信息輸出了，DEBUG、INFO 信息沒有輸出。

Handler

下面咱們先來了解一下 Handler 的用法，看下面的實例：

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 中，內容以下：

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 服務器：

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 接口是用來接收日誌的接口。

運行以後控制檯輸出會輸出以下內容：

This is a log info
Debugging
Warning exists
Finish
複製代碼

output.log 文件會寫入以下內容：

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 的用法：

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 對象便可，輸出結果以下：

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 模塊咱們能夠很是方便地實現這個記錄，咱們用一個實例來感覺一下：

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 信息。

運行結果以下：

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 文件：

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，內容以下：

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 文件，內容以下：

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 配置文件：

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，內容以下：

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 以下：

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 三項，即輸出到控制檯、輸出到普通文件和回滾文件。

這樣運行以後，咱們即可以看到全部的運行結果輸出到了控制檯：

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 的運行結果：

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() 來構造一個字符串，但這其實並非一個好的方法，由於還有更好的方法，下面咱們對比兩個例子：

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 等表示便可，而後在後續參數添加對應的值就能夠了，推薦使用這種方法。

運行結果以下：

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 打印出來，示例以下：

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 信息了。

運行結果以下：

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
複製代碼