本文來自《網(wǎng)易游戲運(yùn)維平臺(tái) （neteasegameops）》微信公眾號(hào)的投稿，隸屬于網(wǎng)易游戲運(yùn)維與基礎(chǔ)架構(gòu)部，運(yùn)基部專注于虛擬化、智能運(yùn)維、SAAS服務(wù)、游戲安全、大數(shù)據(jù)、網(wǎng)絡(luò)等領(lǐng)域， 服務(wù)的產(chǎn)品包括《明日之后》、《夢(mèng)幻西游》、《大話西游》、《第五人格》等數(shù)百款游戲。
前言
借著機(jī)器學(xué)習(xí)的東風(fēng)，Python近年來大熱，一舉沖入最受歡迎編程語言榜前三。同時(shí)，Python已經(jīng)在Web、運(yùn)維、科學(xué)計(jì)算、游戲等領(lǐng)域廣泛應(yīng)用，很多人使用它來構(gòu)建原型、實(shí)現(xiàn)周邊模塊、做實(shí)驗(yàn)、寫性能要求不高的業(yè)務(wù)邏輯、作為膠水語言完成系統(tǒng)串聯(lián)，亦有不少公司使用Python來開發(fā)大型應(yīng)用。
如今，拿Python寫的代碼越來越多，有代碼的地方就有bug。雖然bug free是我們的追求，但有時(shí)面對(duì)復(fù)雜需求、大型系統(tǒng)，我們不得不接受一個(gè)事實(shí)：我們可能要花一半時(shí)間寫bug，再花另一半時(shí)間把它們調(diào)試好。代碼調(diào)試占了如此高的工作比重，那么提升它的效率就是一個(gè)很有意義的話題了。
Python是一種強(qiáng)類型動(dòng)態(tài)語言，具有非常活躍的社區(qū)和海量的庫。所以，我們?cè)谑褂脗鹘y(tǒng)的代碼調(diào)試方法的同時(shí)，還多了一些額外的選擇。接下來的章節(jié)中我會(huì)介紹一些常見的調(diào)試方法和Python特有的技巧，并分享一些調(diào)試的經(jīng)驗(yàn)。
Print和logging可以在代碼運(yùn)行過程中暴露出一些變量的值、打印出關(guān)鍵信息，幫助我們觀察和跟蹤代碼的執(zhí)行過程。
作為script programmer，我們?cè)谡{(diào)試時(shí)的第一反應(yīng)是print here, print there, print everywhere. 在寫小腳本的時(shí)候這樣做完全沒問題，但當(dāng)我們開始構(gòu)建比較復(fù)雜的業(yè)務(wù)模塊的時(shí)候，print的問題就顯現(xiàn)出來了，格式隨意、缺乏時(shí)間戳等必要信息、通常只print到stdout，寫其他的流或者文件還需要額外的代碼。最關(guān)鍵的一點(diǎn)是：看起來一點(diǎn)都不專業(yè) 233。下面是一個(gè)簡單的例子：
try:
1 / 0
except ZeroDivisionError as e:
print('some text', e)
with open('some.log', 'w') as f:
print('some text', e, file=f)
Logging是比print更規(guī)范和“專業(yè)“的做法，下面羅列一些logging的好處和個(gè)人覺得比較有用的實(shí)踐：
我們可以定義好日志的規(guī)范格式，包含必要信息，并且有利于后續(xù)的日志處理和分析。如下是使用logging.Formatter格式化日志的例子：
LOG_FORMAT = '%(asctime)s %(levelname) 8s: [%(filename)s:%(lineno)d] [%(processName)s:%(process)d %(threadName)s] - %(message)s'
DATE_FORMAT = '[%Y-%m-%d %H:%M:%S]'
def get_logger(name):
logger = logging.getLogger(name)
formatter = logging.Formatter(LOG_FORMAT, DATE_FORMAT)
handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(formatter)
logger.addHandler(handler)
return logger
logger = get_logger(__name__)
logger.warning('test msg')
得到這樣的日志輸出：
[2019-01-09 13:36:26] WARNING: [test1.py:33] [MainProcess:16830 MainThread] - test msg
如果想讓日志更易處理，更有表現(xiàn)力，可以嘗試結(jié)構(gòu)化的日志，一個(gè)使用logging.Filter結(jié)構(gòu)化日志的例子：
import json
class JsonLogFilter(logging.Filter):
def filter(self, log):
if isinstance(log.msg, str):
return True
if isinstance(log.msg, (dict, list, tuple)):
log.msg = json.dumps(log.msg)
return True
return False
logger.addFilter(JsonLogFilter())
logger.warning({
'action': 'server_start',
'port': 8080,
'engine': {'name': 'tornado', 'version': '0.1.1'}
})
得到這樣的日志輸出：
[2019-01-09 13:46:01] WARNING: [test1.py:57] [MainProcess:17549 MainThread] - {'action': 'server_start', 'port': 8080, 'engine': {'name': 'tornado', 'version': '0.1.1'}}
這樣的日志可以很清晰地?cái)y帶大量信息，后續(xù)的日志解析和處理也更方便。
logging可以定義消息等級(jí)，常見的等級(jí)：
我們可以通過logger的同名成員函數(shù)來輸出不同等級(jí)的日志，設(shè)置logger或者logHandler的level，來決定什么級(jí)別的日志會(huì)被輸出：
logger.setLevel(logging.ERROR)
stdLogHandler.setLevel(logging.INFO)
這些工作會(huì)在后續(xù)的日志處理中產(chǎn)生價(jià)值，一些實(shí)踐例子：
把error和critical的日志輸出到單獨(dú)的error log文件，查問題時(shí)優(yōu)先關(guān)注它們；
把error和critical日志直接流入報(bào)警系統(tǒng)、故障自愈系統(tǒng)等，觸發(fā)對(duì)應(yīng)策略；
業(yè)務(wù)發(fā)布時(shí)關(guān)掉debug日志，在排查問題時(shí)通過外部配置、RPC等方式觸發(fā)進(jìn)程修改日志等級(jí)；
排查問題時(shí)，啟動(dòng)一個(gè)新的進(jìn)程，指定debug level的日志，輸出debug log來輔助排查；
logging模塊提供了文件、標(biāo)準(zhǔn)輸出等多種logHandler，我們也可以自定義自己的handler，讓日志輸出到不同的流。
logger也可以添加多個(gè)logHandler，并且分別定義Formatter、Level，讓日志同時(shí)以不同的方式輸出到多個(gè)流。
每個(gè)logger初始化的時(shí)候都可以指定名字，我們通常會(huì)以模塊名作為logger name，方便后續(xù)的管理和日志使用。
例如，我們同時(shí)使用了requests和kafka，但我們比較關(guān)注kafka的日志，requests只有在error的時(shí)候才值得關(guān)注，可以這樣配置：
logging.getLogger('requests').setLevel(logging.ERROR)
logging.getLogger('kafka').setLevel(logging.WARNING)
通過以上的的介紹，我們已經(jīng)可以自如地定制日志的輸出了，那么什么時(shí)候應(yīng)該輸出日志呢？日志太多會(huì)影響性能，造成不必要的干擾，難以閱讀，日志太少會(huì)讓我們對(duì)進(jìn)程的執(zhí)行情況缺乏了解。在實(shí)踐中，我們應(yīng)該在生產(chǎn)環(huán)境盡可能取得二者平衡。
這里有一些建議：
確保每一次日志輸出都是有價(jià)值、無歧義、易讀的；
Debug日志盡可能詳盡地輸出細(xì)節(jié)信息，例如關(guān)鍵函數(shù)的調(diào)用、輸入、輸出，某些關(guān)鍵分支步驟的選擇等，在生產(chǎn)環(huán)境中關(guān)閉，必要時(shí)再打開；
一些重要變量的變更、重要函數(shù)的調(diào)用應(yīng)該盡量輸出日志；
做一些周期性指標(biāo)統(tǒng)計(jì)并通過日志等方式輸出，以備監(jiān)控報(bào)警和觀察執(zhí)行情況，例如QPS、數(shù)據(jù)吞吐量、任務(wù)堆積數(shù)等；
CRUD中的Create、Update、Delete通常需要輸出Info log，用作資源操作記錄；
對(duì)一些可以發(fā)生，但大量發(fā)生代表可能有嚴(yán)重問題的代碼分支，最好輸出Warning日志，并在后續(xù)日志報(bào)警中按數(shù)量報(bào)警，例如：緩存未命中，RPC Retry等；
可自動(dòng)恢復(fù)的異常通常至少要輸出Warning日志；
不可恢復(fù)的異常視邏輯嚴(yán)重程度輸出Error或者Critical日志，并且要帶上堆棧和必要的變量信息；
微服務(wù)系統(tǒng)中，確保每條日志都帶上可追蹤的session id；
不要在頻繁調(diào)用的函數(shù)中輸出Info及以上級(jí)別的日志，如果真的需要，可以考慮周期統(tǒng)計(jì)輸出，或者采樣輸出；
無意挑起IDE和編輯器之爭，但現(xiàn)代的IDE確實(shí)提供了更便捷更強(qiáng)大的Debug功能，這些功能通常需要我們這些vim、sublime、emacs愛好者花費(fèi)額外的時(shí)間才能得到。
對(duì)廣大IDE使用者來說，最便捷的離線調(diào)試方法顯然就是IDE Debugger了，我們以PyCharm為例簡單介紹下。
PyCharm Debugger提供了一系列常見的功能：
斷點(diǎn)；
step in / out， step over等操作；
Variables窗口，查看當(dāng)前scope內(nèi)的變量，也可以自己添加Watches；
Frames窗口，可以切換線程，查看線程的Frames鏈。
Evaluate窗口，可以直接計(jì)算表達(dá)式值；
Attach到已運(yùn)行的進(jìn)程，并開啟Debugger。
仍然有大量程序員是GDB、PDB、IPDB系列Debugger的用戶，這些工具同樣能在代碼調(diào)試過程中產(chǎn)生幫助，以ipdb（Ipython pdb）為例。
我們可以直接加載ipdb，啟動(dòng)進(jìn)程：
? test python3 -m ipdb run.py
> /Users/Valens/PycharmProjects/test/run.py(1)<module>()
----> 1 import time
2 import logging
3 import random
ipdb> r
WARNING:root:handling a big value: 0.8740442611857767
> /Users/Valens/PycharmProjects/test/run.py(18)handle()
17 set_trace()
---> 18 self._last_big_value = data['value']
19 self._counter += 1
ipdb> p data
{'value': 0.8740442611857767, 'done': True}
ipdb> n
> /Users/Valens/PycharmProjects/test/run.py(19)handle()
18 self._last_big_value = data['value']
---> 19 self._counter += 1
20 return data
也可以在代碼中設(shè)置斷點(diǎn)，并在斷點(diǎn)處停下來，啟動(dòng)ipython debugger：
import time
import logging
import random
from ipdb import set_trace
class Processor(object):
def __init__(self):
self._counter = 0
self._last_big_value = float('inf')
def handle(self, data):
data['done'] = True
if data['value'] > 0.8:
logging.warning('handling a big value: %s' % data['value'])
set_trace() # 斷點(diǎn)
self._last_big_value = data['value']
self._counter += 1
return data
def feed(processor):
while True:
time.sleep(random.random())
processor.handle({
'value': random.random()
})
def main():
feed(Processor())
if __name__ == '__main__':
main()
然后執(zhí)行
? test python3 run.py
WARNING:root:handling a big value: 0.844438382990963
> /Users/Valens/PycharmProjects/test/run.py(18)handle()
17 set_trace()
---> 18 self._last_big_value = data['value']
19 self._counter += 1
ipdb> p data
{'value': 0.844438382990963, 'done': True}
GDB是老牌且功能強(qiáng)大的Debugger，在后起之秀更加易用的今天，它出場的機(jī)會(huì)不算多。但當(dāng)線上進(jìn)程Coredump時(shí)，我們的選擇并不多，這時(shí)候GDB的強(qiáng)大之處就顯現(xiàn)出來了。
使用GDB調(diào)試Python，首先需要準(zhǔn)備好必要的包：
libpython 讓GDB可以調(diào)試python代碼，包含pybt pyprint pyup pydown等一系列GDB命令的python版本；
python-dbg python debug擴(kuò)展，包括python符號(hào)文件和libpython等工具，在不同發(fā)行版的包名可能不一樣；
如果你用到了一些c擴(kuò)展的python庫，需要解與之相關(guān)的棧，可能也需要對(duì)應(yīng)的dbg包，例如 python-mysqldb-dbg
通常，如果我們知道一個(gè)python進(jìn)程會(huì)core dump，那可以選擇用python-dbg運(yùn)行它（當(dāng)然會(huì)有少量性能的trade off），等待它c(diǎn)ore dump后，再用gdb打開會(huì)獲得最全面的信息。非dbg運(yùn)行的python core dump也可以如此嘗試，但可能因?yàn)榉?hào)表缺失、版本不一致等原因損失一些信息。
我們準(zhǔn)備一個(gè)測(cè)試，還是剛才熟悉的代碼，在random數(shù)字大于0.9時(shí)觸發(fā)一段“神秘代碼“，python2.7下的經(jīng)典stack overflow bug，讓進(jìn)程因?yàn)镾eg fault而被內(nèi)核core dump掉。
import time
import logging
import random
class Processor(object):
def __init__(self):
self._counter = 0
self._last_big_value = float('inf')
def handle(self, data):
data['done'] = True
if data['value'] > 0.8:
logging.warning('handling a big value: %s' % data['value'])
self._last_big_value = data['value']
if data['value'] > 0.9:
raise_seg_fault()
self._counter += 1
return data
def raise_seg_fault():
logging.error('seg fault')
exec'()'*7**6
def feed(processor):
while True:
time.sleep(random.random())
processor.handle({
'value': random.random()
})
def main():
feed(Processor())
if __name__ == '__main__':
main()
跑起~
valens@some-host:~$ python-dbg run.py
WARNING:root:handling a big value: 0.860424864923
WARNING:root:handling a big value: 0.94984309816
ERROR:root:seg fault
Segmentation fault (core dumped)
然后用gdb打開core dump文件，指定exec為python-dbg
valens@some-host:~$ gdb python-dbg core.python-dbg.some-host.28249
GNU gdb (Debian 7.7.1+dfsg-5) 7.7.1
...
Reading symbols from python-dbg...done.
[New LWP 28249]
[Thread debugging using libthread_db enabled]
Using host libthread_db library '/lib/x86_64-linux-gnu/libthread_db.so.1'.
Core was generated by `python-dbg run.py`.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x0000000000563415 in symtable_visit_expr (st=<error reading variable: Cannot access memory at address 0x7ffdc1083fe8>, e=<error reading variable: Cannot access memory at address 0x7ffdc1083fe0>) at ../Python/symtable.c:1185
跟蹤c棧
(gdb) bt
#0 0x0000000000563415 in symtable_visit_expr (st=<error reading variable: Cannot access memory at address 0x7ffdc1083fe8>, e=<error reading variable: Cannot access memory at address 0x7ffdc1083fe0>) at ../Python/symtable.c:1185
#1 0x0000000000563bde in symtable_visit_expr (st=0x7f3fe9b00110, e=0x20f8150) at ../Python/symtable.c:1256
跟蹤py棧和變量
# 列出py棧
(gdb) py-bt
#32710 Frame 0x7f3fe9b17248, for file run.py, line 25, in raise_seg_fault ()
exec'()'*7**6
#32714 Frame 0x7f3fe9b33c60, for file run.py, line 18, in handle (self=<Processor(_counter=19, _last_big_value=<float at remote 0x1b7e620>) at remote 0x7f3fe9b0ba00>, data={'done': True, 'value': <float at remote 0x1b7e620>})
raise_seg_fault()
#32717 Frame 0x7f3fe9aef840, for file run.py, line 32, in feed (processor=<Processor(_counter=19, _last_big_value=<float at remote 0x1b7e620>) at remote 0x7f3fe9b0ba00>)
'value': random.random()
#32720 Frame 0x7f3fe9b887e0, for file run.py, line 37, in main ()
feed(Processor())
#32723 Frame 0x7f3feb29f060, for file run.py, line 41, in <module> ()
main()
# 向上回到frame: handle
(gdb) py-up
#32714 Frame 0x7f3fe9b33c60, for file run.py, line 18, in handle (self=<Processor(_counter=19, _last_big_value=<float at remote 0x1b7e620>) at remote 0x7f3fe9b0ba00>, data={'done': True, 'value': <float at remote 0x1b7e620>})
# 查看這個(gè)frame的局部變量
(gdb) py-locals
self = <Processor(_counter=19, _last_big_value=<float at remote 0x1b7e620>) at remote 0x7f3fe9b0ba00>
data = {'done': True, 'value': <float at remote 0x1b7e620>}
# 讀一下value
(gdb) p *(PyFloatObject*) 0x1b7e620
$3 = {_ob_next = 0x7f3fe9b10d30, _ob_prev = 0x7f3fe9b33c60, ob_refcnt = 2, ob_type = 0x8b7580 <PyFloat_Type>, ob_fval = 0.94984309816000645}
通過查看py棧和c棧的調(diào)用關(guān)系和變量值，大部分的問題都應(yīng)該能定位了～
線上的情況經(jīng)常是錯(cuò)綜復(fù)雜的，我們也沒辦法在寫代碼和測(cè)試階段就完全預(yù)測(cè)代碼的每一步執(zhí)行和每個(gè)分支。當(dāng)線上業(yè)務(wù)出問題通常都會(huì)有點(diǎn)難以下手。其實(shí)很多l(xiāng)inux工具都可以在這時(shí)候提供幫助。當(dāng)然，不僅限于看看cpu內(nèi)存消耗、查查網(wǎng)絡(luò)鏈接和fd那么簡單，這里以perf和strace做簡單舉例，如果大家覺得有用，可以更深入地學(xué)習(xí)具體用法。
perf是linux下一個(gè)非常好用的性能profile工具。在日常用來進(jìn)行性能優(yōu)化以外，我們也可以在用它來排查一些線上的問題，當(dāng)一個(gè)數(shù)據(jù)處理進(jìn)程消費(fèi)速度減慢，或者一個(gè)server cpu暴增時(shí)，不妨perf一下，看看進(jìn)程現(xiàn)在在干嘛，為我們排查和推斷問題原因提供依據(jù)。
舉例：
# perf 進(jìn)程 6252 10秒，采集call graph信息
perf record -g -p 6252 sleep 10
perf report --stdio
...
89.67% 3.54% python-dbg python2.7-dbg [.] call_function
|
--- call_function
|
|--99.80%-- PyEval_EvalFrameEx
| |
| |--73.81%-- fast_function
| | call_function
| | PyEval_EvalFrameEx
| | |
| | |--72.77%-- fast_function
| | | call_function
| | | PyEval_EvalFrameEx
| | | |
| | | |--54.21%-- fast_function
| | | | call_function
| | | | PyEval_EvalFrameEx
| | | | |
| | | | |--62.17%-- fast_function
| | | | | call_function
| | | | | PyEval_EvalFrameEx
| | | | | |
| | | | | |--56.99%-- fast_function
| | | | | | call_function
| | | | | | PyEval_EvalFrameEx
...
perf report --stdio -g none
# Samples: 3K of event 'cpu-clock'
# Event count (approx.): 839500000
#
# Children Self Command Shared Object Symbol
# ........ ........ .......... .................. .....................................
#
89.67% 0.00% python-dbg libc-2.19.so [.] __libc_start_main
89.67% 0.00% python-dbg python2.7-dbg [.] main
89.67% 0.00% python-dbg python2.7-dbg [.] Py_Main
89.67% 0.00% python-dbg python2.7-dbg [.] PyRun_AnyFileExFlags
89.67% 0.00% python-dbg python2.7-dbg [.] PyRun_SimpleFileExFlags
89.67% 0.00% python-dbg python2.7-dbg [.] PyRun_FileExFlags
89.67% 0.00% python-dbg python2.7-dbg [.] run_mod
89.67% 0.00% python-dbg python2.7-dbg [.] PyEval_EvalCode
89.67% 3.54% python-dbg python2.7-dbg [.] call_function
89.67% 1.28% python-dbg python2.7-dbg [.] fast_function
89.67% 0.95% python-dbg python2.7-dbg [.] PyEval_EvalCodeEx
89.67% 14.80% python-dbg python2.7-dbg [.] PyEval_EvalFrameEx
57.89% 0.09% python-dbg python2.7-dbg [.] ext_do_call
57.74% 0.33% python-dbg python2.7-dbg [.] PyObject_Call
57.65% 0.24% python-dbg python2.7-dbg [.] function_call
19.15% 0.03% python-dbg python2.7-dbg [.] do_call
18.82% 0.06% python-dbg python2.7-dbg [.] type_call
18.55% 0.21% python-dbg python2.7-dbg [.] slot_tp_init
18.20% 0.09% python-dbg python2.7-dbg [.] instancemethod_call
15.78% 1.94% python-dbg python2.7-dbg [.] PyObject_GetAttr
13.94% 0.12% python-dbg python2.7-dbg [.] PyObject_GenericGetAttr
...
有時(shí)我們會(huì)遇到進(jìn)程阻塞，這時(shí)候可以通過strace來追蹤系統(tǒng)調(diào)用看看進(jìn)程是不是卡在某處io，或者在接收巨量的網(wǎng)絡(luò)包，以及其他跟系統(tǒng)調(diào)用、信號(hào)相關(guān)的場景。
舉例：
# strace -p 1227
Process 1227 attached
select(0, NULL, NULL, NULL, {0, 524306}) = 0 (Timeout)
gettimeofday({1547026076, 550492}, NULL) = 0
write(2, 'WARNING:root:handling a big valu'..., 50) = 50
select(0, NULL, NULL, NULL, {0, 195142}) = 0 (Timeout)
深究代碼調(diào)試的本質(zhì)，是觀察代碼執(zhí)行，從中找出不合理的邏輯、未處理的邊界情況以及可優(yōu)化的地方。那么，沒有什么比直接進(jìn)入正在執(zhí)行的Python進(jìn)程并近距離觀察和把玩它的邏輯更方便的了。作為一個(gè)動(dòng)態(tài)語言，Python在Debug On-the-fly方面具有非常大的想象空間。
這里夾帶私貨地介紹一個(gè)Python Inject Debugger：pylane
pylane，網(wǎng)易游戲開源的 Python 調(diào)試工具
https://github.com/NtesEyes/pylane
pylane 通過 gdb trace python 進(jìn)程，然后在該進(jìn)程的python vm中動(dòng)態(tài)地注入一段python代碼，從而對(duì)一個(gè)運(yùn)行中的python進(jìn)程執(zhí)行一段任意的新邏輯。
作為Debugger，pylane最常用的功能是pylane shell，它對(duì)目標(biāo)進(jìn)程注入了一個(gè)新線程，并在這個(gè)線程中啟動(dòng)一個(gè)python Interpreter，然后連接到終端的IPython Console。接下來，我們就可以在這個(gè)Console中訪問目標(biāo)進(jìn)程中的所有對(duì)象。
繼續(xù)使用上文中的Processor代碼，用pylane shell attach它。
pylane shell <PID>
接下來舉幾個(gè)典型的用例。
友情提醒，在生產(chǎn)環(huán)境做任何非規(guī)范的變更都有危險(xiǎn)，請(qǐng)三思。
如果我們需要看到某個(gè)內(nèi)部變量的值，但這個(gè)變量沒有通過log等方式暴露出來，那就可以用pylane來直接查看。
pylane shell 4996
# 用內(nèi)置tools的get_insts方法獲取Processor的實(shí)例
In [2]: p = tools.get_insts('Processor')[0]
In [3]: p
Out[3]:
<__main__.Processor object at 0x7f3d45c6ad68>
# 在代碼運(yùn)行的同時(shí)觀察p的屬性變化
In [4]: p._counter
Out[4]: 252
In [5]: p._counter
Out[5]: 262
In [6]: p._last_big_value
Out[6]: 0.8872528770214453
在源文件存在的情況下，可以直接查看某個(gè)object的代碼。
In [2]: tools.print_source_code(tools.get_classes('Processor')[0])
Out[2]:
class Processor(object):
def __init__(self):
self._counter = 0
self._last_big_value = float('inf')
def handle(self, data):
data['done'] = True
if data['value'] > 0.8:
logging.warning('handling a big value: %s' % data['value'])
self._last_big_value = data['value']
self._counter += 1
return data
如果需要調(diào)用一次函數(shù)，觸發(fā)某段邏輯，也可以直接調(diào)用。
In [4]: p = tools.get_insts('Processor')[0]
In [5]: p.handle({'value': -100})
Out[5]: {'done': True, 'value': -100}
我們有時(shí)會(huì)想知道進(jìn)程目前在干什么，比如任務(wù)執(zhí)行的很慢，進(jìn)程完全阻塞了的情況。
執(zhí)行下面的方法打印所有線程的棧和變量：
In [6]: tools.print_threads()
Out[6]:
Thread: MainThread
Stack:
File '/usr/lib/python2.7/threading.py', line 1098, in _exitfunc
t.join()
File '/usr/lib/python2.7/threading.py', line 940, in join
self.__block.wait()
File '/usr/lib/python2.7/threading.py', line 340, in wait
waiter.acquire()
Locals:
{'saved_state': None, 'waiter': <thread.lock object at 0x7fc7c9d062d0>, 'self': <Condition(<thread.lock object at 0x7fc7c9d06290>, 1)>, 'timeout': None}
或者，如果我們知道線程名，可以這樣指定：
tools.print_threads(['Thread1', 'Thread2'])
objgraph 是一個(gè)非常好用的Python內(nèi)存排查工具，但它需要入侵代碼，如果線上有一個(gè)難以復(fù)現(xiàn)的內(nèi)存泄露，用pylane + objgraph可以更容易地排查：
先在跑服務(wù)的virtual env中準(zhǔn)備好objgraph包，然后打開pylane shell
In [5]: import objgraph
In [6]: objgraph.growth()
Out[6]:
[('function', 1484, 1484),
('wrapper_descriptor', 1105, 1105),
('builtin_function_or_method', 732, 732),
('method_descriptor', 590, 590),
('dict', 581, 581),
('tuple', 529, 529),
('weakref', 509, 509),
('list', 267, 267),
('getset_descriptor', 234, 234),
('member_descriptor', 229, 229)]
In [7]: objgraph.growth()
Out[7]: [('list', 268, 1)]
如果遇到某個(gè)調(diào)用比較深的函數(shù)執(zhí)行有問題，我們想知道它每次執(zhí)行了多久，輸入輸出是什么，但是之前沒有l(wèi)og出來，可以monkey patch它。
In [2]: p = tools.get_insts('Processor')[0]
In [3]: origin_func, p.handle = p.handle, tools.log_it(p.handle)
接下來可以看到新的log了
WARNING:root:handling a big value: 0.821825815755
WARNING:root:func: handle sec_cost: 0.0002 input: (({'done': True, 'value': 0.8218258157546575},), {}) output {'done': True, 'value': 0.8218258157546575}
WARNING:root:func: handle sec_cost: 0.0003 input: (({'done': True, 'value': 0.5901812673170566},), {}) output {'done': True, 'value': 0.5901812673170566}
調(diào)試完，回滾即可
In [4]: p.handle = origin_func
顯而易見，擁有一個(gè)attach console，我們能做的事情遠(yuǎn)不止此，我們可以用它來修改運(yùn)行時(shí)配置（？），開關(guān)某個(gè)功能（？？），熱更新代碼（？？？），當(dāng)然，注意安全。
重申：在生產(chǎn)環(huán)境做任何非規(guī)范的變更都有危險(xiǎn)，請(qǐng)三思。
這篇文章是按個(gè)人的一些經(jīng)驗(yàn)和見解寫就，旨在分享一些個(gè)人常用的代碼調(diào)試方式和思路。能力和精力有限，如有謬誤，歡迎指正。文章中提到了的大部分工具，都是簡單介紹，淺嘗輒止，它們的更多功能請(qǐng)參閱各個(gè)工具的文檔。
在套路和工具以外，代碼調(diào)試更多的還是依靠開發(fā)者的知識(shí)儲(chǔ)備、編碼經(jīng)驗(yàn)和想象力，當(dāng)然，偶爾也需要一點(diǎn)運(yùn)氣。持續(xù)不斷地學(xué)習(xí)，多看大神們的代碼，多寫，多總結(jié)，才能在寫代碼和調(diào)代碼的時(shí)候更加駕輕就熟，離bug free的偉大目標(biāo)更近一點(diǎn)。
Python中文社區(qū)作為一個(gè)去中心化的全球技術(shù)社區(qū)，以成為全球20萬Python中文開發(fā)者的精神部落為愿景，目前覆蓋各大主流媒體和協(xié)作平臺(tái)，與阿里、騰訊、百度、微軟、亞馬遜、開源中國、CSDN等業(yè)界知名公司和技術(shù)社區(qū)建立了廣泛的聯(lián)系，擁有來自十多個(gè)國家和地區(qū)數(shù)萬名登記會(huì)員，會(huì)員來自以公安部、工信部、清華大學(xué)、北京大學(xué)、北京郵電大學(xué)、中國人民銀行、中科院、中金、華為、BAT、谷歌、微軟等為代表的政府機(jī)關(guān)、科研單位、金融機(jī)構(gòu)以及海內(nèi)外知名公司，全平臺(tái)近20萬開發(fā)者關(guān)注。
聯(lián)系客服
