啊，個人程序爲啥卡住啦

時間 2019-11-16

標籤個人程序爲啥卡住简体版

原文原文鏈接

　　服務器程序員最怕的就是程序crash，不過有時候程序沒有crash，可是「不工做」了也是夠嚇人的。所謂「不工做」就是指程序再也不響應新的請求，處在了某種自娛自樂的狀態，英語有一個很形象但的單詞「hung」，但我不知道怎麼翻譯，姑且稱之爲「卡住」吧。本人遇到過的有兩種狀況，一種是卡在系統調用，如常見的磁盤IO或者網絡、多線程鎖；另外一種就是代碼進入了死循環。html

　　在《日誌的藝術》一文中，討論了日誌的重要性，若是日誌恰當，也能幫助咱們分許程序卡住的問題。若是狂刷重複的日誌，那麼極可能就是死循環，從日誌內容就能分析出死循環的位置，甚至是死循環的緣由。若是沒有日誌輸出了，那麼看看最後一條日誌的內容，也許就會告訴咱們即將進行IO操做，固然也多是即將進入死循環。python

　　若是日誌沒法提供充足的信息，那就得求助於其餘的手段，在Linux下當仁不讓的天然是gdb，gdb的功能很強大，陳皓大牛的用GDB調試程序系列是我見過的講解gdb最好的中文文章。CPython是用C語言實現的，天然也是能夠用gdb來調試的，只不過，默認只顯示C棧，凡人如我是沒法腦補出python棧來的，這個時候就須要使用到python－dbg與libpython了，前者幫助顯示Python源碼的符號信息，後者能讓咱們能在Python語言這個層面調試程序，好比打印Python調用棧。linux

　　本文簡答介紹在linux環境下如何利用gdb來分析卡住的程序，本文使用的Python爲Cpython2.7，操做系統爲Debian。git

　　本文地址：http://www.cnblogs.com/xybaby/p/8025435.html程序員

阻塞在IO

　　程序被卡住，極可能是程序被阻塞了，即在等待（wait）等個系統調用的結束，好比磁盤IO與網絡IO、多線程，默認的狀況下不少系統調用都是阻塞的。多線程的問題複雜一下，後面專門介紹。下面舉一個UDP Socket的例子（run_forever_block.py）：github

 1 # -*- coding: utf-8 -*-
 2 import socket
 3 
 4 def simple_server():
 5         address = ('0.0.0.0', 40000)
 6         s = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
 7         s.bind(address)
 8 
 9         while True:
10             data, addr = s.recvfrom(2048)
11             if not data:
12                 print "client has exist"
13                 break
14             print "received:", data, "from", addr
15 
16 if __name__ == '__main__':
17         simple_server()

　　這是一個簡單的UDP程序，代碼在（0.0.0.0， 40000）這個地址上等待接收數據，核心就是第10行的recvfrom函數，這就是一個阻塞（blocking）的系統調用，只有當讀到數據以後纔會返回，所以程序會卡在第10行。固然，也能夠經過fcntl設置該函數爲非阻塞（non-blocking）。服務器

　　咱們來看看阻塞的狀況，運行程序，而後經過top查看這個進程的狀態網絡

　　能夠看到這個進程的pid是26466，進程狀態爲S(Sleep)，CPU爲0.0。進程狀態和CPU都暗示咱們，當前進程正阻塞在某個系統調用。這個時候，有一個很好使的命令：strace，能夠跟蹤進程的全部系統調用，咱們來看看多線程

~$ strace -T -tt -e trace=all -p 26466
Process 26466 attached
19:21:34.746019 recvfrom(3,併發

　　能夠看到，進程卡在了recvfrom這個系統調用，對應的文件描述符（file descriptor）是3，其實經過recvfrom這個名字，大體也能定位問題。關於文件描述符，還有一個更實用的命令，lsof（list open file），能夠看到當前進程打開的全部文件，在linux下，一切皆文件，天然也就包括了socket。

lsof -p 26466
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME

...
python 26466 xxxxxxx 3u IPv4 221871586 0t0 UDP *:40000

　　從上面能夠看出這個文件描述符（3U）更詳細的信息，好比是IPV4 UDP，監聽在40000端口等等。

使用gdb調試Python程序

　　上面這個例子很是的簡單，簡單到咱們直接從系統調用就能看出問題，可是實際的狀況下可能更加複雜，即沒法經過系統調用直接定位處處問題的代碼。這個時候就可使用gdb了，關於如何用gdb來調試python程序，能夠參考了使用gdb調試Python進程這篇文章。以上面的代碼爲例，首先得作好準備條件

　　首先，參考DebuggingWithGdb，根據本身的Linux系統安裝好python-dbg，在個人平臺（Debian）上即 sudo apt-get install gdb python2.7-dbg

　　而後，下載libpython，放在本身的HOME目錄下

　　接下來就可使用gdb進行分析了：gdb -p 26466

　　在gdb的交互式環境中，使用bt命令，看到的是C棧，意義不大，咱們直接來看Python棧

(gdb) python
>import sys
>sys.path.insert(0, '/home/xxx')
>import libpython
>end

(gdb) py-bt

Traceback (most recent call first):
　　File "run_forever_block.py", line 10, in simple_server
　　　　data, addr = s.recvfrom(2048)
　　File "run_forever_block.py", line 17, in <module>
　　　　simple_server()

　　能夠看到，經過py-bt就能顯示出完整的python調用棧，能幫助咱們定位問題。還有不少py開頭的命令，具體可見libpython.py中（全部gdb.Command的子類都是一個命令），這篇文章中總結了幾個經常使用的：

py-list 　　查看當前python應用程序上下文

py-bt 　　查看當前python應用程序調用堆棧

py-bt-full 　　查看當前python應用程序調用堆棧，而且顯示每一個frame的詳細狀況

py-print 　　查看python變量

py-locals　　查看當前的scope的變量

py-up 　　查看上一個frame

py-down 　　查看下一個frame

死循環

　　死循環很使人討厭，死循環是預期以外的無限循環。最典型的預期以內的無限循環是socketserver，進程不死，服務不止。而死循環看起來很忙（CPU100%），可是沒有任何實質的做用。死循環有不一樣的粒度，最粗的粒度是兩個進程之間的相互調用，好比RPC；其次是函數級別，較爲常見的是沒有邊界條件的遞歸調用，或者在多個函數之間的相互調用；最小的粒度是在一個函數內部，某一個代碼塊（code block）的死循環，最爲常見的就是for，while語句。在Python中，函數級別是不會形成無限循環的，如代碼所示：

1 # -*- coding: utf-8 -*-
2 def func1():
3     func()
4 
5 def func():
6     func1()
7 
8 if __name__ == '__main__':
9     func()

　　運行代碼，很快就會拋出一個異常：RuntimeError: maximum recursion depth exceeded。顯然，python內部維護了一個調用棧，限制了最大的遞歸深度，默認約爲1000層，也能夠經過sys.setrecursionlimit(limit)來修改最大遞歸深度。在Python中，雖然出現這種函數級別的死循環不會致使無限循環，可是也會佔用寶貴的CPU，也是決不該該出現的。

　　而代碼塊級別的死循環，則會讓CPU轉到飛起，以下面的代碼

1 # -*- coding: utf-8 -*-
2 
3 def func():
4     while True:
5         pass
6 
7 if __name__ == '__main__':
8     func()

　　這種狀況，經過看CPU仍是很好定位的

　　從進程狀態R（run），以及100%的CPU，基本上就能肯定是死循環了，固然也不排除是CPU密集型，這個跟代碼的具體邏輯相關。這個時候，也是能夠經過gdb來看看當前調用棧的，具體的準備工做如上，這裏直接給出py-bt結果

(gdb) py-bt
Traceback (most recent call first):
　　File "run_forever.py", line 5, in func
　　File "run_forever.py", line 8, in <module>
(gdb)

　　在《無限「遞歸」的python程序》一文中，提到過使用協程greenlet能產生無限循環的效果，並且看起來很是像函數遞歸，其表現和gdb調試結果與這裏的死循環是同樣的

多線程死鎖

　　因爲Python的GIL，在咱們的項目中使用Python多線程的時候並很少。不過多線程死鎖是一個很是廣泛的問題，並且通常來講又是一個低機率的事情，復現不容易，多出如今高併發的線上環境。這裏直接使用《飄逸的python - 演示一種死鎖的產生》中的代碼，而後分析這個死鎖的多線程程序

 1 #coding=utf-8
 2 import time
 3 import threading
 4 class Account:
 5     def __init__(self, _id, balance, lock):
 6         self.id = _id
 7         self.balance = balance
 8         self.lock = lock
 9 
10     def withdraw(self, amount):
11         self.balance -= amount
12 
13     def deposit(self, amount):
14         self.balance += amount
15 
16 
17 def transfer(_from, to, amount):
18     if _from.lock.acquire():#鎖住本身的帳戶
19         _from.withdraw(amount)
20         time.sleep(1)#讓交易時間變長，2個交易線程時間上重疊，有足夠時間來產生死鎖
21         print 'wait for lock...'
22         if to.lock.acquire():#鎖住對方的帳戶
23             to.deposit(amount)
24             to.lock.release()
25         _from.lock.release()
26     print 'finish...'
27 
28 a = Account('a',1000, threading.Lock())
29 b = Account('b',1000, threading.Lock())
30 threading.Thread(target = transfer, args = (a, b, 100)).start()
31 threading.Thread(target = transfer, args = (b, a, 200)).start()

線程死鎖代碼實例

　　運行代碼，能夠看見，該進程（進程編號26143）也是出於Sleep狀態，由於本質上進程也是阻塞在了某個系統調用，所以，一樣可使用strace

p$ strace -T -tt -e trace=all -p 26143
Process 26143 attached
19:29:29.289042 futex(0x1286060, FUTEX_WAIT_PRIVATE, 0, NULL

　　能夠看見，進程阻塞在futex這個系統調用，參數的意義能夠參見manpage。

　　gdb也很是適用於調試多線程程序，對於多線程，有幾個很使用的命名

　　info thread：　　列出全部的線程，以及所在線程
　　thread x：　　切換到第X號線程
　　thread apply all bt：　　打印全部線程的調用棧

　　下面是簡化後的結果

(gdb) info thread
Id Target Id Frame
3 Thread 0x7fb6b2119700 (LWP 26144) "python" 0x00007fb6b38d8050 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
2 Thread 0x7fb6b1918700 (LWP 26145) "python" 0x00007fb6b38d8050 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
* 1 Thread 0x7fb6b3cf8700 (LWP 26143) "python" 0x00007fb6b38d8050 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
(gdb) thread apply all bt

Thread 3 (Thread 0x7fb6b2119700 (LWP 26144)):
#0 0x00007fb6b38d8050 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
#1 0x000000000057bd20 in PyThread_acquire_lock (waitflag=1, lock=0x126c2f0) at ../Python/thread_pthread.h:324
#2 lock_PyThread_acquire_lock.lto_priv.2551 () at ../Modules/threadmodule.c:52
...

Thread 2 (Thread 0x7fb6b1918700 (LWP 26145)):
#0 0x00007fb6b38d8050 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
#1 0x000000000057bd20 in PyThread_acquire_lock (waitflag=1, lock=0x131b3d0) at ../Python/thread_pthread.h:324
...

Thread 1 (Thread 0x7fb6b3cf8700 (LWP 26143)):
#0 0x00007fb6b38d8050 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
#1 0x000000000057bd20 in PyThread_acquire_lock (waitflag=1, lock=0x1286060) at ../Python/thread_pthread.h:324
#2 lock_PyThread_acquire_lock.lto_priv.2551 () at ../Modules/threadmodule.c:52
...