第四期 · 簡單了解logging模塊 ：結合Flask理解和使用try……except與logging模塊

前言

通過一段時間的學習，我們已經可以使用Python基於Flask框架寫一些小程序，甚至你可能已經買了一個域名和一台伺服器躍躍欲試，說不定已經發布了一個線上程序（個人博客）？！

在本機開發環境基於Flask框架寫代碼時，我們已經知道只要開啟Flask的Debug模式，一旦程序遇到什麼問題我們都可以獲得一個反饋界面，據此排查問題所在。同時我們也知道，對於發布到線上的程序一定要關閉Debug模式，否則會有一些安全隱患。

我在之前的文章里已經介紹了如何在線上伺服器上構建一個可以運行Flask程序的環境，那篇文章談到一個關鍵點，就是要做一個可以被其他人訪問的網站，需要伺服器上搭建一個HTTP伺服器（這是個軟體），在我的教程中給大家推薦的是Gunicorn，當然還有其他選擇。你在本機開發環境調試Flask程序時，是由Flask集成的一個HTTP伺服器來讓你運行程序的（然後一般通過http://127.0.0.1:5000訪問），但集成的這個通常不會在線上正式運行時去使用。

總而言之，你線上的程序一般情況下都用了一個類似Gunicorn的HTTP伺服器，然後Flask集成的HTTP伺服器會不再起作用，言下之意，實際上你開不開Debug模式，運行在線上的程序出錯都不會顯示你本機看到的那熟悉的報錯界面。

然而，如果你已經有充分的實踐，你一定會遇到過這種情況：在本地運行好好的程序，放到線上就出錯，而出錯界面幾乎沒有任何有價值的調試信息，但程序在本地又正常運行，這讓排查問題變得異常艱難。

今天，我們就來學習一下如何解決這個問題。

從print到log

我們初學Python時，機智的發現print還能用來調試程序。有些容易出錯的部分，我們會嘗試增加一個print方法列印一些內容，幫助我們確定程序的運行是否符合預期，以及定位錯誤所在。這個方法雖然簡單易行，但局限性也顯而易見，如果我們的程序是一個很多文件組織起來的結構，這個結構之中任何一個部分都可能出錯的話，用print方法去調試程序就顯得有點笨拙和麻煩，而且根本就不現實。

在比較通用的實踐中，一般採用log來替代print，也就是你可能見過，並在以後會經常見到的一個詞：日誌。

在很多文件組織起來的程序結構中，報錯信息至少需要告訴我們是哪個功能模塊報錯，甚至哪個文件的第幾行代碼引起的報錯，這樣我們才能定位問題所在並進行修正。那麼，用print你能滿足這個需求嗎？

我們無需糾結這個問題，因為一般而言，每一種程序語言都提供了自己的日誌功能模塊，實現了剛才所談到的為了排查程序問題所需要的功能，並且還簡單易用。

Python的logging

毫無疑問，Python也提供了自己的日誌功能模塊，這個模塊名字就叫logging。你可以現在就試試 import logging ，你看，logging是程序語言自帶的功能模塊。

我們現在不必深入了解Python的logging，因為以後你會知道Flask還結合這個模塊提供了自己的日誌系統，只要稍加配置就能做到滿足我們的需要。這裡我們先難後易，先學習使用獨立的logging模塊。

在Flask里用logging

老樣子，讓我們先從一段代碼開始：

from flask import Flasknimport loggingnnapp = Flask(__name__)nn# 日誌系統配置nhandler = logging.FileHandler(app.log, encoding=UTF-8)napp.logger.addHandler(handler)nnn@app.route(/)ndef index():n app.logger.info(有人訪問了本頁面喲~)n return Hello!nnnif __name__ == __main__:n app.run(debug=True)n

這一段代碼除去有關logging的部分，其餘的我們再熟悉不過。

前面我們知道使用logging的第一步是導入這個模塊，所以我們一開始進行了import logging。

緊接著，我們對logging作了一些初始化配置的工作。這包括：

1、日誌終歸是要存起來便於查看的，所以我們需要系統將日誌信息存為一個日誌文件，並存放在我們指定的地方。這是「#日誌系統配置」代碼塊里第一行代碼的作用：我們指定系統在相對於當前程序包根目錄的位置，將日誌信息寫入到「app.log」這個文件中，並且特別指定文件編碼格式為「UTF-8」，這樣有助於中文信息的展示。

2、我們已經很熟悉了，對於Flask應用一些第三方擴展總是要進行一些初始化操作，這便是「#日誌系統配置」代碼塊里第二行代碼的作用。經過這個操作，Flask將裝備上logging。

最後我們開始使用日誌功能，在首頁（index)視圖函數中我們增加了一個日誌埋點，他的效果是：一旦有用戶訪問到這個頁面，除了看到頁面上顯示Hello這個英文單詞，app.log里也會增加一項日誌信息。

以上就是一個完整的而基本的例子，你看，十分簡單不是？！ 你可以馬上運行一下程序，並會看到系統自己新建了一個app.log文件。

注意：如果你定義的日誌文件存儲位置和教程告訴你的不一致，比如加了目錄，你需要自己建立好這些目錄，否則會因為操作系統問題報錯（一般是許可權錯誤）。

想要更多

如果一個用戶訪問前面的頁面，只會產生一個展示「有人訪問了本頁面喲~」這樣一句話的，實在是單調且乏味的日誌記錄。並且事實上這種日誌看起來就沒什麼意義，似乎比print方法也先進不到哪裡去。起碼的，一旦發生什麼問題，我們最少需要知道問題發生的時間、引起問題的程序代碼位置、是什麼問題（報錯信息）。那麼，可以通過日誌系統做到嗎？我們先看結果：

from flask import Flaskn import loggingnn app = Flask(__name__)nn# 日誌系統配置nhandler = logging.FileHandler(app.log, encoding=UTF-8)nlogging_format = logging.Formatter(n %(asctime)s - %(levelname)s - %(filename)s - %(funcName)s - %(lineno)s - %(message)s)nhandler.setFormatter(logging_format)napp.logger.addHandler(handler)nnn@app.route(/)ndef index():n app.logger.info(有人訪問了本頁面喲~)n return Hello!nnnif __name__ == __main__:n app.run(debug=True)n

比起最開始得代碼，我們添加了兩小段：

1、我們新增了一個logging_format去調用logging.Formatter(）方法。

2、我們將logging_format最終作為參數傳給了handler.setFormatter(）。

如果你英文還行，通過Formatter這個英文單詞的意思就能猜出來這個方法的作用，難以理解的是這個方法被傳入的一長串參數，他們是什麼？

原來，在Python的logging模塊中，為了方便我們列印各種動態的日誌信息，非常貼心的預置了一些動態變數（屬性），我們通過調用這些變數來指定和組織日誌最終列印出來的內容。你能在官方文檔中查到全部可供使用的變數，這裡我們只解釋下上面我們用到的：

%(asctime)s 日誌記載時間。即前面說的需要的時間，精確到毫秒。

%(levelname)s 日誌報警級別。後面會馬上具體介紹。

%(filename)s 觸發日誌記錄的文件名。即出問題的程序代碼段所在文件的文件名。

%(funcName)s 觸發日誌記錄的函數名。比如上面觸發記錄日誌是靠用戶訪問路由函數index(),那麼這裡就會顯示為index這個名字。

%(lineno)s 觸發日誌記錄的代碼行號。即引起報錯的代碼所在行的行號。針對於上面的代碼，會顯示為「http://app.logger.info(有人訪問了本頁面喲~)」這行代碼所在的行號。代碼的行號你一般能通過編程軟體直觀看到。

%(message)s 觸發日誌的具體信息。即http://app.logger.info(有人訪問了本頁面喲~)中傳入的參數，這裡會顯示為「有人訪問了本頁面喲~」這行字。

我們再次運行程序，並訪問一下首頁（index)，我們會看到app.log里多了這行信息：

2016-10-31 16:52:14,997 - INFO - app.py - index - 15 - 有人訪問了本頁面喲~

恩，現在看起來這日誌算有模有樣了。

分而治之

在我們前面舉的例子中，當有用戶訪問首頁時，日誌會生成一條記錄，表示有人訪問了這個頁面，當時我們用的是http://app.logger.info()。實際上，「有人訪問了頁面」這個信息其實是件芝麻大的事兒。

在大型的程序日誌系統管理中，一般要對日誌進行一些區分，你可以理解為對信息的輕重緩急加以區別記錄，這會有利於對日誌進行分析。當然，我們現在還用不到這麼複雜的方式，但我們需要知道這個：在日誌管理中，有一個很重要的概念就是日誌的級別（level）。你可以通俗的理解成日誌的分類。

在logging模塊模塊中，比較常見的有：

INFO（http://app.logger.info()） 這前面我們已經見識過了，代表普通的信息。

WARNING（app.logger.warning()） 警告

ERROR (app.logger.error()) 錯誤

上面每一種級別都給出了對應的基於Flask的調用方式。你會發現這十分簡單，只需要把info改成別的級別的英文單詞就行了。在日誌的列印上，原來的INFO會顯示為對應級別的英文大寫字母，你可以試試。

到現在為止，我們學到的東西也不少了，話說我們可不想把時間浪費在怎麼記錄芝麻大的事兒身上。所以，我們該怎麼捕捉程序的報錯信息呢？

try……except

在學習Python的基礎語法時，我們見過Python中捕捉程序異常的語法try……except是如何工作的，先簡單回顧一下：

# 這是Python3的用法，Python2的用法有些不同。ntry:n 需要捕捉異常的程序代碼塊nexcept Exception as e:n print(e) # 列印異常信息n

最簡單的使用方式就是上面這樣：當被需要捕捉異常的代碼塊運行出錯時，出錯信息會被Python底層處理好，然後我們引用之後通過print()列印出來。結合前面的代碼片段，我們的修改版如下：

from flask import Flasknimport loggingnnapp = Flask(__name__)nn# 日誌系統配置nhandler = logging.FileHandler(app.log, encoding=UTF-8)nlogging_format = logging.Formatter(n %(asctime)s - %(levelname)s - %(filename)s - %(funcName)s - %(lineno)s - %(message)s)nhandler.setFormatter(logging_format)napp.logger.addHandler(handler)nnn@app.route(/)ndef index():n try:n no_thing = []n i = no_thing[0] # 這裡會報錯，因為列表根本是空的n return Hello!n except Exception as e:n app.logger.error(%s, e)nnif __name__ == __main__:n app.run(debug=True) n

上面我們做了什麼？

首先，我們故意犯了一個再明顯不過的錯誤，那就是試圖對一個空列表通過索引取出來東西。結果當然是取不出來任何東西，並引起程序報錯。

然後，我們通過try……except去捕捉錯誤，並且用了error的級別去接收錯誤信息，之後錯誤信息會在日誌里列印出來。

最終得到的日誌大致如下：

2016-11-14 14:32:51,445 - ERROR - run.py - index - 23 - list index out of range

如果你在本地運行上面的代碼，Flask還會在頁面上報一個錯。當你在伺服器上運行這段代碼時，除了網站不能正常訪問以外，頁面上不會展示任何有價值的信息，但在app.log里，你會發現這行極具價值的日誌。通過這段日誌，我們知道在2016-11-14 14:32:51時，由文件run.py里的index函數引發錯誤，錯誤信息是「list index out of range」，我們搜索一下這段話就知道其表達的意思就是空列表取值報錯，於是我們很容易的去排查程序問題了，哪怕程序是很多文件組成的。

綜上，我們總結一下，如果需要對程序加上日誌，只需要用try包圍住可能出問題的代碼塊，就如同以下形式：

# 這是Python3的用法，Python2的用法有些不同。ntry:n 需要捕捉異常的程序代碼塊nexcept Exception as e:n app.logger.error(%s, e)n

然後配置好日誌系統，只要程序出錯，我們便能在app.log里查到線索，這就是日誌系統完整的，最簡單的用法。

相信現在大家再也不用對本文開頭的問題那麼束手無措了吧！

參考：

Python logging 官方文檔： https://docs.python.org/3.5/library/logging.html

Flask logging 相關文檔片段：

http://docs.jinkan.org/docs/flask/quickstart.html#logging

http://docs.jinkan.org/docs/flask/errorhandling.html#logformat