python的tornado框架用到了io多路復用和協(xié)程的技術捞稿。由于tornado是單線程的異步框架点把,如果運行過程中產生了阻塞粉捻,后續(xù)的其它任務也就需要等待。在生產過程中雪侥,如果tornado進程產生了假死問題該如何排查呢碗殷?
問題描述
運營在使用后臺的時候,偶爾會反饋后臺報錯速缨,而且是大部分時候是好的锌妻,只是有時會出問題,刷新之后可能不會報錯旬牲,可能還會報錯从祝。
問題排查
1.nginx
我們在后端服務之前加了nginx代理,所以先查看nginx日志引谜,發(fā)現upstream到特定的進程時就會報錯,如果其它進程處理則不會報錯擎浴,而且報錯的錯誤是timeout
2.tornado
后端服務底層框架是tornado员咽。使用curl http://127.0.0.1:port 時超時。查看該進程對應的日志贮预,發(fā)現有一段時間沒有輸出日志了贝室。利用ls -l查看日志最后的更新時間,發(fā)現停留在1個小時之前仿吞。
3.strace
使用strace -p pid命令查看tornado進程當時的系統(tǒng)調用滑频,輸出fcntl(0x...,),并且一直停留在該系統(tǒng)調用唤冈。利用fcntl系統(tǒng)調用可以實現文件鎖的功能峡迷,所以大致可以確定該tornado進程產生了死鎖。
4.pyrasite
pyrasite是python進程注入的工具你虹。pip install pyrasite安裝之后绘搞,pyrasite-shell pid注入到tornado進程,這時進入到python shell的環(huán)境
5.sys與traceback
sys._current_frames()返回一個字典傅物,將每個線程的標識符映射到調用該函數時該線程中當前活動的最頂層堆棧幀夯辖。
這對于調試死鎖是最有用的:這個函數不需要死鎖線程的協(xié)作,只要這些線程的調用堆棧保持死鎖董饰,它們就會被凍結蒿褂。對于非死鎖線程返回的幀在調用代碼檢查幀時可能與該線程的當前活動沒有關系圆米。
traceback.extract_stack(stack)提取棧代碼,以及相關的文件路徑和行號等
def stacktraces(exclude=()):
code = []
current_frames = [(key, value) for key, value in sys._current_frames().items() if key not in exclude]
for threadId, stack in current_frames:
code.append("\n# ThreadID: %s" % threadId)
for filename, lineno, name, line in traceback.extract_stack(stack):
code.append('File: "%s", line %d, in %s' % (filename, lineno, name))
if line:
code.append(" %s" % (line.strip()))
print threadId
print code
可執(zhí)行stacktraces打印tornado線程棧代碼
6.tornado log_stack
對5中打印的日志進行分析啄栓,確定是由于項目代碼在打印日志的時候娄帖,tornado進程接到到了打印block log的信號,由于python的logging日志模塊是通過thread lock保證線程安全的谴供,在項目代碼acquire了tread lock之后但是還未釋放時块茁,block log又嘗試去acquire thread lock,該調用是阻塞調用桂肌,由此產生了死鎖数焊。由此也可知在linux平臺python的thread lock是通過fcntl系統(tǒng)調用實現的。
后續(xù)
知道了問題產生的根本原因崎场,那么這個問題也就解決了一大半了佩耳。上述的問題該如何解決呢?可以留個言探討一下谭跨!
追加
之前用到的pyrasite-shell需要注入到python進程中并且還需要執(zhí)行代碼非常不友好干厚,在后續(xù)的工作中發(fā)現了另一個工具:pystack-debugger,安裝之后使用命令pystack pid即可打印出當時的堆棧信息螃宙,類似于java的jstack蛮瞄,對于排查python進程死鎖問題有非常好的效果。