（十六）Flask 學習 —— 調試，測試以及優化
調試，測試以及優化
咱們小型的 microblog 應用程序已經足夠的完善了，所以是時候準備儘量地清理不用的東西。近來，一個讀者反映了一個奇怪的數據庫問題，咱們今天將會調試它。這也提醒咱們不論咱們是多當心以及測試咱們應用程序多仔細，咱們仍是會遺漏一些 bug。用戶是很擅長髮現它們的！html
不是僅僅修復此錯誤，而後忘記它，直到咱們遇到另外一個。咱們會採起一些積極的措施，以更好地準備下一個。node
在本章的第一部分，咱們將會涉及到 調試，我將會展現一些我平時調試複雜問題的技巧。python
接着咱們想要看看如何衡量咱們的測試策略的效果。咱們想要清楚地知道咱們的測試可以覆蓋到應用程序的多少，有時候稱之爲 測試覆蓋率。git
最後，咱們將會研究下許多應用程序遭受過的一類問題，性能糟糕。咱們將會看到 調優 技術，而且發現咱們應用程序中哪些部分最慢。github
聽起來不錯吧？讓咱們開始吧！web
Bug
這個問題是由本系列的一個讀者發現，他實現了一個容許用戶刪除本身的 blog 的新函數後遇到這個問題。咱們正式的 microblog 版本是沒有這個功能的，所以咱們快速的加上它，以便咱們能夠調試這個問題。sql
咱們使用刪除 blog 的視圖函數以下(文件 app/views.py):數據庫
@app.route('/delete/<int:id>')
@login_required
def delete(id):
post = Post.query.get(id)
if post == None:
flash('Post not found.')
return redirect(url_for('index'))
if post.author.id != g.user.id:
flash('You cannot delete this post.')
return redirect(url_for('index'))
db.session.delete(post)
db.session.commit()
flash('Your post has been deleted.')
return redirect(url_for('index'))
爲了調用這個函數，咱們將會在模板中添加這個刪除連接(文件 app/templates/post.html):flask
{% if post.author.id == g.user.id %}
<div><a href="{{ url_for('delete', id = post.id) }}">{{ _('Delete') }}</a></div>
{% endif %}
如今咱們接着繼續，在生產模式下運行咱們的應用程序。Linux 和 Mac 用戶能夠這麼作:api
$ ./runp.py
Windows 用戶這麼作:
flask/Scripts/python runp.py
如今做爲一個用戶，撰寫一篇 blog，接着改變主意刪除它。當你點擊刪除連接的時候，錯誤出現了！
咱們獲得了一個簡短的消息說，應用程序已經遇到了一個錯誤，並已通知管理員。其實這個消息就是咱們的 500.html 模版。在生產模式下，當在處理請求的時候出現一個異常錯誤，Flask 會返回一個 500 錯誤模版給客戶端。由於咱們是處於生產模式下，咱們看不到錯誤信息或者堆棧軌跡。
現場調試問題
回想 單元測試 這一章，咱們開啓了一些調試服務在應用程序中的生產模式版本。當時咱們創造了一個寫入到日誌文件的日誌記錄器，以便應用程序能夠在運行時寫入調試或診斷信息。Flask 自身會在結束一個錯誤 500 代碼請求以前寫入不能處理的任何異常的堆棧軌跡。做爲一個額外的選項，咱們也開啓了基於日誌的郵件通知服務，它將會向管理員列表發送日誌信息郵件當一個錯誤寫入日誌信息的時候。
所以像上面的 bug，咱們可以從兩個地方，日誌文件和發送的郵件，得到捕獲的調試信息。
一個堆棧軌跡並不足夠，可是總比沒有好吧。假設咱們對問題一點都不知道，咱們須要單從堆棧軌跡中之處發生些什麼。這是這個特別的堆棧軌跡的副本:
127.0.0.1 - - [03/Mar/2013 23:57:39] "GET /delete/12 HTTP/1.1" 500 - Traceback (most recent call last): File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1701, in __call__ return self.wsgi_app(environ, start_response) File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1689, in wsgi_app response = self.make_response(self.handle_exception(e)) File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1687, in wsgi_app response = self.full_dispatch_request() File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1360, in full_dispatch_request rv = self.handle_user_exception(e) File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1358, in full_dispatch_request rv = self.dispatch_request() File "/home/microblog/flask/lib/python2.7/site-packages/flask/app.py", line 1344, in dispatch_request return self.view_functions[rule.endpoint](**req.view_args) File "/home/microblog/flask/lib/python2.7/site-packages/flask_login.py", line 496, in decorated_view return fn(*args, **kwargs) File "/home/microblog/app/views.py", line 195, in delete db.session.delete(post) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/scoping.py", line 114, in do return getattr(self.registry(), name)(*args, **kwargs) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1400, in delete self._attach(state) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1656, in _attach state.session_id, self.hash_key)) InvalidRequestError: Object '<Post at 0xff35e7ac>' is already attached to session '1' (this is '3')
若是你習慣讀別的語言的堆棧軌跡，請注意 Python 的堆棧軌跡是反序的，最下面的是引發異常的發生點。
從上面的堆棧軌跡中咱們能夠看到異常是被 SQLAlchemy 會話處理代碼觸發的。在堆棧軌跡中，對找出咱們代碼最後的執行語句也是十分有幫助的。咱們會最後定位到咱們的 app/views.py 文件中的 delete() 函數中的db.session.delete(post) 語句。
咱們從上面的狀況中能夠知道 SQLAlchemy 是不能在數據庫會話中註冊刪除操做。可是咱們不知道爲何。
若是你仔細看看堆棧軌跡的最下面，你會發現問題好像在 Post 對象最開始綁定在會話 ‘1’，如今咱們試着綁定同一對象到會話 ‘3’ 中。
若是你搜索這個問題的話，你會發現不少用戶都會遇到這個問題，尤爲是使用一個多線程網頁服務器，它們獲得兩個請求嘗試同時把同一對象添加到不一樣的會話。可是咱們使用的是 Python 開發網頁服務器，它是一個單線程服務器，所以這不是咱們問題的緣由。這可能的緣由是不知道什麼操做致使兩個會話在同一時間活躍。
若是咱們想要了解更多的問題，咱們應該嘗試以一種更可控的環境下重現錯誤。幸運的是，在開發模式下的應用程序試圖重現這個問題，它確實重現了。在開發模式中，當發生異常時，咱們獲得是 Flask web 的堆棧軌跡，而不是500.html 模板。
web 的堆棧軌跡是十分好的，由於它容許你檢查代碼而且從服務器上計算表達式。沒有真正理解在這段代碼中到底爲何會發生這種事情，咱們只是知道某些緣由致使一個請求在結束的時候沒有正常刪除會話。所以更好的方案就是找出究竟是誰建立這個會話。
使用 Python 調試器
最容易找出誰建立一個對象的方式就是在對象構建中設置斷點。斷點是一個當知足必定條件的時候中斷程序的命令。此時此刻，這是可以檢查程序，好比獲取中斷時的堆棧軌跡，檢查或者甚至改變變量值，等等。斷點是 調試器 的特點之一。此次咱們將會使用 Python 內置模塊，叫作 pdb。
可是咱們該檢查哪一個類？讓咱們回到基於 Web 的堆棧軌跡，再仔細找找。在最底層的堆棧幀中，咱們能使用代碼瀏覽器和 Python 控制檯來找出使用會話的類。在代碼中，咱們看到咱們是在 Session 類中。這像是 SQLAlchemy 中的數據庫會話的基礎類。由於如今在最底層的堆棧幀正是在會話對象裏，咱們可以在控制檯中獲得會話實際的類，經過運行:
>>> print self <flask_sqlalchemy._SignallingSession object at 0xff34914c>
如今咱們知道使用中的會話是經過 Flask-SQLAlchemy 定義的，所以這個擴展可能定義本身的會話類，做爲 SQLAlchemy 會話的一個子類。
如今咱們能夠到 Flask-SQLAlchemy 擴展的 flask/lib/python2.7/site-packages/flask_sqlalchemy.py 中檢查源代碼而且定位到類 _SignallingSession 和它的 __init__() 構造函數，如今咱們準備用調試器工做。
有不少方式在 Python 應用程序中設置斷點。最簡單的一種就是在咱們想要中斷的程序中寫入以下代碼:
import pdb; pdb.set_trace()
所以咱們繼續向前而且暫時在 _SignallingSession 類的構造函數插入斷點(文件 flask/lib/python2.7/site-packages/flask_sqlalchemy.py):
class _SignallingSession(Session):
def __init__(self, db, autocommit=False, autoflush=False, **options):
import pdb; pdb.set_trace() # <-- this is temporary!
self.app = db.get_app()
self._model_changes = {}
Session.__init__(self, autocommit=autocommit, autoflush=autoflush,
extension=db.session_extensions,
bind=db.engine,
binds=db.get_binds(self.app), **options)
# ...
讓咱們繼續運行看看會發生什麼:
$ ./run.py > /home/microblog/flask/lib/python2.7/site-packages/flask_sqlalchemy.py(198)__init__() -> self.app = db.get_app() (Pdb)
由於沒有打印出 「Running on ...」 的信息咱們知道服務器實際上並無完成啓動過程。中斷可能已經發生了在內部某些神祕的代碼裏面。
最重要的問題是咱們須要回答應用程序如今處於哪裏，由於這將會告訴咱們誰在請求建立會話 ‘1’。咱們將會使用 bt 來獲取堆棧軌跡:
(Pdb) bt /home/microblog/run.py(2)<module>() -> from app import app /home/microblog/app/__init__.py(44)<module>() -> from app import views, models /home/microblog/app/views.py(6)<module>() -> from forms import LoginForm, EditForm, PostForm, SearchForm /home/microblog/app/forms.py(4)<module>() -> from app.models import User /home/microblog/app/models.py(92)<module>() -> whooshalchemy.whoosh_index(app, Post) /home/microblog/flask/lib/python2.6/site-packages/flask_whooshalchemy.py(168)whoosh_index() -> _create_index(app, model)) /home/microblog/flask/lib/python2.6/site-packages/flask_whooshalchemy.py(199)_create_index() -> model.query = _QueryProxy(model.query, primary_key, /home/microblog/flask/lib/python2.6/site-packages/flask_sqlalchemy.py(397)__get__() -> return type.query_class(mapper, session=self.sa.session()) /home/microblog/flask/lib/python2.6/site-packages/sqlalchemy/orm/scoping.py(54)__call__() -> return self.registry() /home/microblog/flask/lib/python2.6/site-packages/sqlalchemy/util/_collections.py(852)__call__() -> return self.registry.setdefault(key, self.createfunc()) > /home/microblog/flask/lib/python2.6/site-packages/flask_sqlalchemy.py(198)__init__() -> self.app = db.get_app() (Pdb)
像以前作的，咱們會發如今 models.py 的 92 行中存在問題，那裏是咱們全文搜索引擎初始化的地方:
whooshalchemy.whoosh_index(app, Post)
奇怪，在這個階段咱們並無作觸發數據庫會話建立的事情，這看起來好像是初始化 Flask-WhooshAlchemy 的行爲，它建立了一個數據庫會話。
這感受就像這畢竟不是咱們的錯誤，也許某種形式的交互在兩個 Flask 擴展 SQLAlchemy 和 Whoosh 之間。咱們能停留在這裏而且尋求兩個擴展的開發者的幫助。或者是咱們繼續調試看能不能找出問題的真正所在。我將會繼續，若是你們不感興趣的話，能夠跳過下面的內容。
讓咱們多看這個堆棧軌跡一眼。咱們調用了 whoosh_index()，它反過來調用了 _create_index()。在 _create_index() 中的一行代碼是這樣的:
model.query = _QueryProxy(model.query, primary_key, searcher, model)
在這裏的 model 的變量被設置成咱們的 Post 類，咱們在調用 whoosh_index() 的時候傳入的 Post 類。考慮到這一點，這看起來像是 Flask-WhooshAlchemy 建立了一個 Post.query 封裝，它把原始的 Post.query 做爲參數，而且附加些其它的 Whoosh 特別的東西。接着是最讓人感興趣的一部分。根據上面的堆棧軌跡，下一個調用的函數是 __get__()，這是一個 Python 的 描述符。
__get__() 方法是用於實現描述符，它是一個與它們行爲關聯的屬性而不僅是一個值。每次被引用,描述符 __get__() 的函數被調用。函數被支持返回屬性的值。在這行代碼中惟一被說起的的屬性就是 query，因此如今咱們知道，這個看似簡單的屬性，咱們已經在過去使用的生成咱們的數據庫查詢不是一個真正的屬性，而是一個描述符。
讓咱們繼續往下看看接下來發生什麼。在 __get__() 中的代碼是這個:
return type.query_class(mapper, session=self.sa.session())
這是一個至關暴露一段代碼。好比，User.query.get(id) 咱們間接調用 __get__() 方法來提供查詢對象，這裏咱們可以看到這個查詢對象會暗暗地帶來一個數據庫會話。
當 Flask-WhooshAlchemy 使用 model.query 一樣會觸發一個會話，這個會話被建立和與查詢對象關聯。可是這個查詢對象與運行在咱們視圖函數中的查詢對象不同，Flask-WhooshAlchemy 請求並非短暫的。Flask-WhooshAlchemy 把這個查詢對象傳入做爲本身的查詢對象，而且存入到 model.query。因爲沒有 __set__() 方法對應，新的對象將被存儲爲一個屬性。對於咱們的 Post 類，這就意味着在 Flask-WhooshAlchemy 完成初始化，咱們將會有名稱相同的描述符和屬性。根據優先級，在這種狀況下，屬性勝出。
這一切最重要的方面是，這段代碼設置一個持久的屬性，裏面有咱們的會話 ‘1’ 。即便應用程序處理的第一個請求將使用這個會話，而後忘掉它，會話不會消失，由於它仍然是引用由 Post.query 屬性。這是咱們的錯誤！
該錯誤是因爲混淆（我認爲）描述的類型而形成的。它們看起來像常規屬性，因此人們每每就這樣使用它們。Flask-WhooshAlchemy 開發者只是想建立一個加強的查詢對象用來爲 Whoosh 查詢存儲一些有用的狀態，可是他們沒有意識到引用一個模型的 query 屬性不像看起來的同樣，背後隱藏與一個啓動數據庫的會話的屬性關聯。
迴歸測試
既然如今已經清楚了發生問題的緣由所在，咱們是否是能夠試着重現下問題，爲修復問題作一些準備。若是不肯意這麼作的話，那可能只能等到 Flask-WhooshAlchemy 的開發者們去修復，那若是修復版本要等到一年之後？咱們是否是要一直等待着，或者直接取消刪除這個功能。
所以爲了準備修復這個問題，咱們能夠試着去重現這個問題，咱們能夠試着去建立針對這個問題的測試。爲了建立這個測試，咱們須要模擬兩個請求，第一個請求就是查詢一個 Post 對象，模擬咱們請求數據爲了在首先顯示 blog。由於這是第一個會話，咱們準備命名這個會話爲 ‘1’。接着咱們須要忘記這個會話建立一個新的會話，就像 Flask-SQLAlchemy 所作的。試着刪除 Post 對象在第二個會話中，這時候應該會觸發這個 bug:
def test_delete_post(self): # create a user and a post u = User(nickname = 'john', email = 'john@example.com') p = Post(body = 'test post', author = u, timestamp = datetime.utcnow()) db.session.add(u) db.session.add(p) db.session.commit() # query the post and destroy the session p = Post.query.get(1) db.session.remove() # delete the post using a new session db.session = db.create_scoped_session() db.session.delete(p) db.session.commit()
如今當咱們運行測試的時候失敗會出現:
$ ./tests.py .E.... ====================================================================== ERROR: test_delete_post (__main__.TestCase) ---------------------------------------------------------------------- Traceback (most recent call last): File "./tests.py", line 133, in test_delete_post db.session.delete(p) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/scoping.py", line 114, in do return getattr(self.registry(), name)(*args, **kwargs) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1400, in delete self._attach(state) File "/home/microblog/flask/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1656, in _attach state.session_id, self.hash_key)) InvalidRequestError: Object '<Post at 0xff09b7ac>' is already attached to session '1' (this is '3') ---------------------------------------------------------------------- Ran 6 tests in 3.852s FAILED (errors=1)
修復
爲了解決這個問題，咱們須要找到一種鏈接 Flask-WhooshAlchemy 查詢對象到模型的替代方式。
Flask-SQLAlchemy 的文檔上提到過有一個 model.query_class 屬性包含了用於查詢的類。這其實是一個更乾淨的方式使得 Flask-SQLAlchemy 使用自定義的查詢類而不是 Flask-WhooshAlchemy 所作的。若是咱們配置 Flask-SQLAlchemy 來建立查詢使用 Whoosh 啓用查詢類(它已是 Flask-SQLAlchemy BaseQuery 的子類)，接着咱們應該獲得跟之前同樣的結果，可是沒有 bug。
咱們在 github 上建立了一個 Flask-WhooshAlchemy 項目的分支，那裏我已經實現上面這些修改。若是你想要看這些改變的話，請訪問 github diff，或者下載 修改的擴展 而且安裝它在原始的 flask_whooshalchemy.py 文件所在地。
測試覆蓋率
雖然咱們已經有了測試應用程序的測試代碼，可是咱們並不知道咱們的應用程序有多少地方被測試到。咱們須要一個測試覆蓋率的工具來檢查一個應用程序，在執行這個工具後咱們能獲得一個咱們的代碼如今哪些地方被測試到的報告。
Python 有一個測試覆蓋率的工具，咱們稱之爲 coverage。讓咱們安裝它:
flask/bin/pip install coverage
這個工具能夠做爲一個命令行使用或者能夠放在腳本里面。咱們如今能夠先不用考慮如何啓動它。
這有些改變咱們須要加入到測試代碼中爲了生成一個覆蓋率的報告(文件 tests.py):
from coverage import coverage cov = coverage(branch = True, omit = ['flask/*', 'tests.py']) cov.start() # ... if __name__ == '__main__': try: unittest.main() except: pass cov.stop() cov.save() print "\n\nCoverage Report:\n" cov.report() print "HTML version: " + os.path.join(basedir, "tmp/coverage/index.html") cov.html_report(directory = 'tmp/coverage') cov.erase()
咱們開始在腳本的最開始初始化 coverage 模塊。branch = True 參數要求除了常規的覆蓋率分析還須要作分支分析。omit 參數確保不會去得到咱們安裝在虛擬環境和測試框架自身的覆蓋率報告，咱們只作咱們的應用程序代碼的覆蓋。
爲了收集覆蓋率統計咱們只要調用 cov.start()，接着運行咱們的單元測試。咱們必須從咱們的單元測試框架中捕獲以及經過異常，若是腳本不結束的話是沒有機會生成一個覆蓋率報告。在咱們從測試中回來後，咱們將會用cov.stop() 中止覆蓋率統計，而且用 cov.save() 生成結果。最後，cov.report() 把結果輸出到控制檯，cov.html_report() 生成一個好看的 HTML 報告，cov.erase() 刪除數據文件。
這是運行後的報告例子:
$ ./tests.py .....F ====================================================================== FAIL: test_translation (__main__.TestCase) ---------------------------------------------------------------------- Traceback (most recent call last): File "./tests.py", line 143, in test_translation assert microsoft_translate(u'English', 'en', 'es') == u'Inglés' AssertionError ---------------------------------------------------------------------- Ran 6 tests in 3.981s FAILED (failures=1) Coverage Report: Name Stmts Miss Branch BrMiss Cover Missing ------------------------------------------------------------ app/__init__ 39 0 6 3 93% app/decorators 6 2 0 0 67% 5-6 app/emails 14 6 0 0 57% 9, 12-15, 21 app/forms 30 14 8 8 42% 15-16, 19-30 app/models 63 8 10 1 88% 32, 37, 47, 50, 53, 56, 78, 90 app/momentjs 12 5 0 0 58% 5, 8, 11, 14, 17 app/translate 33 24 4 3 27% 10-36, 39-56 app/views 169 124 46 46 21% 16, 20, 24-30, 34-37, 41, 45-46, 53-67, 75-81, 88-109, 113-114, 120-125, 132-143, 149-164, 169-183, 188-198, 203-205, 210-211, 218 config 22 0 0 0 100% ------------------------------------------------------------ TOTAL 388 183 74 61 47% HTML version: /home/microblog/tmp/coverage/index.html
從上面的報告上能夠看到咱們測試 47% 的應用程序。咱們也從上面獲得沒有被測試執行的函數的列表，所以咱們必須從新看看這些行，考慮下咱們還能編寫些哪些測試。
咱們能看到 app/models.py 覆蓋率是比較高(88%),由於咱們的測試集中在咱們的模型。app/views.py 覆蓋率是比較低(21%)由於咱們沒有在測試代碼中執行視圖函數。
咱們新增長些測試爲了提升覆蓋率:
def test_user(self):
# make valid nicknames
n = User.make_valid_nickname('John_123')
assert n == 'John_123'
n = User.make_valid_nickname('John_[123]\n')
assert n == 'John_123'
# create a user
u = User(nickname = 'john', email = 'john@example.com')
db.session.add(u)
db.session.commit()
assert u.is_authenticated() == True
assert u.is_active() == True
assert u.is_anonymous() == False
assert u.id == int(u.get_id())def test_make_unique_nickname(self):
# create a user and write it to the database
u = User(nickname = 'john', email = 'john@example.com')
db.session.add(u)
db.session.commit()
nickname = User.make_unique_nickname('susan')
assert nickname == 'susan'
nickname = User.make_unique_nickname('john')
assert nickname != 'john'
#...
性能調優
下一個話題就是性能。有什麼比用戶等待很長時間加載頁面更使人沮喪的。咱們想要確保咱們的應用程序的速度，咱們須要一些標準或者尺寸來衡量和分析。
咱們使用的技術稱爲 profiling。一個代碼分析器監視正在運行的程序，很像覆蓋工具，而是注意到不是行執行而是多少時間花在每一個函數上。在分析階段結束的時候會生成一個報告，裏面列出了全部執行的函數以及每一個函數執行了多久。對這個列表從最大到最小的時間排序是一個很好的注意，這樣能夠得出咱們須要優化的地方。
Python 有一個稱爲 cProfile 的代碼分析器。咱們可以把這個分析器直接嵌入到咱們的代碼中，但咱們作任何工做以前，搜索是否有人已經完成了集成工做是一個好注意。一個對 「Flask profiler」 的快速搜索得出 Flask 使用的 Werkzeug 模塊有一個分析器的插件，咱們將直接使用它。
爲了啓用 Werkzeug 分析器，咱們能建立一個像 run.py 的另一個啓動腳本。讓咱們稱它爲 profile.py:
#!flask/bin/python from werkzeug.contrib.profiler import ProfilerMiddleware from app import app app.config['PROFILE'] = True app.wsgi_app = ProfilerMiddleware(app.wsgi_app, restrictions = [30]) app.run(debug = True)
一旦這個腳本運行，每個請求將會顯示分析器的摘要。這裏就是其中一個例子:
--------------------------------------------------------------------------------
PATH: '/'
95477 function calls (89364 primitive calls) in 0.202 seconds
Ordered by: internal time, call count
List reduced from 1587 to 30 due to restriction <30>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.061 0.061 0.061 0.061 {method 'commit' of 'sqlite3.Connection' objects}
1 0.013 0.013 0.018 0.018 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/pysqlite.py:278(dbapi)
16807 0.006 0.000 0.006 0.000 {isinstance}
5053 0.006 0.000 0.012 0.000 flask/lib/python2.7/site-packages/jinja2/nodes.py:163(iter_child_nodes)
8746/8733 0.005 0.000 0.005 0.000 {getattr}
817 0.004 0.000 0.011 0.000 flask/lib/python2.7/site-packages/jinja2/lexer.py:548(tokeniter)
1 0.004 0.004 0.004 0.004 /usr/lib/python2.7/sqlite3/dbapi2.py:24(<module>)
4 0.004 0.001 0.015 0.004 {__import__}
1 0.004 0.004 0.009 0.009 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/__init__.py:7(<module>)
1808/8 0.003 0.000 0.033 0.004 flask/lib/python2.7/site-packages/jinja2/visitor.py:34(visit)
9013 0.003 0.000 0.005 0.000 flask/lib/python2.7/site-packages/jinja2/nodes.py:147(iter_fields)
2822 0.003 0.000 0.003 0.000 {method 'match' of '_sre.SRE_Pattern' objects}
738 0.003 0.000 0.003 0.000 {method 'split' of 'str' objects}
1808 0.003 0.000 0.006 0.000 flask/lib/python2.7/site-packages/jinja2/visitor.py:26(get_visitor)
2862 0.003 0.000 0.003 0.000 {method 'append' of 'list' objects}
110/106 0.002 0.000 0.008 0.000 flask/lib/python2.7/site-packages/jinja2/parser.py:544(parse_primary)
11 0.002 0.000 0.002 0.000 {posix.stat}
5 0.002 0.000 0.010 0.002 flask/lib/python2.7/site-packages/sqlalchemy/engine/base.py:1549(_execute_clauseelement)
1 0.002 0.002 0.004 0.004 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/base.py:124(<module>)
1229/36 0.002 0.000 0.008 0.000 flask/lib/python2.7/site-packages/jinja2/nodes.py:183(find_all)
416/4 0.002 0.000 0.006 0.002 flask/lib/python2.7/site-packages/jinja2/visitor.py:58(generic_visit)
101/10 0.002 0.000 0.003 0.000 flask/lib/python2.7/sre_compile.py:32(_compile)
15 0.002 0.000 0.003 0.000 flask/lib/python2.7/site-packages/sqlalchemy/schema.py:1094(_make_proxy)
8 0.002 0.000 0.002 0.000 {method 'execute' of 'sqlite3.Cursor' objects}
1 0.002 0.002 0.002 0.002 flask/lib/python2.7/encodings/base64_codec.py:8(<module>)
2 0.002 0.001 0.002 0.001 {method 'close' of 'sqlite3.Connection' objects}
1 0.001 0.001 0.001 0.001 flask/lib/python2.7/site-packages/sqlalchemy/dialects/sqlite/pysqlite.py:215(<module>)
2 0.001 0.001 0.002 0.001 flask/lib/python2.7/site-packages/wtforms/form.py:162(__call__)
980 0.001 0.000 0.001 0.000 {id}
936/127 0.001 0.000 0.008 0.000 flask/lib/python2.7/site-packages/jinja2/visitor.py:41(generic_visit)
--------------------------------------------------------------------------------
127.0.0.1 - - [09/Mar/2013 19:35:49] "GET / HTTP/1.1" 200 -
在這個報告中每一行的含義以下:
ncalls : 這個函數被調用的次數。
tottime : 在這個函數中所花費全部時間。
percall : 是 tottime 除以 ncalls 的結果。
cumtime : 花費在這個函數以及任何它調用的函數的時間。
percall : cumtime 除以 ncalls。
filename:lineno(function) : 函數名以及位置。
有趣的是咱們的模板也是做爲函數出現的。這是由於 Jinja2 的模板是被編譯成 Python 代碼。如今看來暫時咱們的應用程序還不存在性能的瓶頸。
數據庫性能
爲告終束這篇，咱們最後看看數據庫性能。從上一部份內容中數據庫的處理是在性能分析的報告中，所以咱們只須要在數據庫變得愈來愈慢的時候可以得到提醒。
Flask-SQLAlchemy 文檔提到了 get_debug_queries 函數，它返回在請求執行期間全部的查詢的列表。
這是一個頗有用的信息。咱們能夠充分利用這個信息來獲得提醒。爲了充分利用這個功能，咱們在配置文件中須要啓動它(文件 config.py):
SQLALCHEMY_RECORD_QUERIES = True
咱們須要設置一個閥值，超過這個值咱們認爲是一個慢的查詢(文件 config.py):
# slow database query threshold (in seconds)DATABASE_QUERY_TIMEOUT = 0.5
爲了檢查是否須要發送警告，咱們須要在每個請求結束的時候進行處理。在 Flask 中，咱們只須要設置一個 after_request 函數(文件 app/views.py):
from flask.ext.sqlalchemy import get_debug_queries
from config import DATABASE_QUERY_TIMEOUT
@app.after_request
def after_request(response):
for query in get_debug_queries():
if query.duration >= DATABASE_QUERY_TIMEOUT:
app.logger.warning("SLOW QUERY: %s\nParameters: %s\nDuration: %fs\nContext: %s\n" % (query.statement, query.parameters, query.duration, query.context))
return response
結束語
本章到這裏就算結束了，原本打算爲這個系列再寫關於部署的內容，可是因爲官方的教程已經很詳細了，這裏再也不囉嗦了。有須要請訪問 部署選擇。
若是你想要節省時間的話，你能夠下載 microblog-0.16.zip。
本系列準備到這裏就結束了，但願你們喜歡！
- 1. Flask 學習 十六 部署
- 2. 性能測試及優化
- 3. 調試優化
- 4. 2016及以後的自動化測試趨勢 -《測試技術六月刊》
- 5. 深度學習--超參調試-正則化及優化3
- 6. 深度學習--超參調試-正則化及優化2
- 7. 深度學習--超參調試-正則化及優化1
- 8. JMeter學習（三十四）測試報告優化
- 9. 【轉】 JMeter學習（三十四）測試報告優化
- 10. 如何學習自動化測試？——手工測試轉向自動化測試？
- 更多相關文章...
- • Lua 調試(Debug) - Lua 教程
- • Eclipse Debug 調試 - Eclipse 教程
- • Tomcat學習筆記（史上最全tomcat學習筆記）
- • Kotlin學習（二）基本類型
-
每一个你不满意的现在，都有一个你没有努力的曾经。