Gunicorn timeout（上）

最近總有用戶反饋說Redash下載比較大的Excel就會出現「失敗 - 服務器出現問題」，並且每次從點了下載到出現錯誤提示時間都是差很少的。我先查看了Nginx的error日誌，顯示 upstream prematurely closed connection while sending to client，第一反應應該是超時致使的。

1. 修改Redash配置

• .env文件修改log級別爲調試 REDASH_LOG_LEVEL="DEBUG"
• .env文件加上超時配置 REDASH_BIGQUERY_HTTP_TIMEOUT=600
• Redash的啓動命令後面增長 -t 600 參數。

10分鐘應該夠用了！重啓redash進程後，進行嘗試試，很差使！好吧，也許是配置參數寫錯了，那改爲 --timeout 600 再試一下，發現還很差使！繼續。。。

2. 修改Nginx配置

• 請求超時：keepalive_timeout、client_header_timeout、client_body_timeout
• 後端服務器處理請求的時間設置：proxy_connect_timeout、proxy_read_timeout

重啓Nginx，下載仍是失敗！！！看來不是超時致使的了？！

3. 查看進程使用的資源

先執行：
top
再嘗試下載操做，發現名叫gunicorn（Redash的server是用gunicorn啓動的）的COMMANDCPU佔用CPU到了100%，而且持續必定時間後，進程消失，新的進程啓動後，CPU佔用恢復正常值。那接下來就看看此進程都執行了哪些操做。

4. 進程跟蹤

跟蹤CPU佔用超高的 gunicorn 進程：

$ strace -T -tt -e trace=all -p 進程ID

顯式進程一直在 read、write 的系統調用，最後一行輸出
+++ killed by SIGKILL +++
後，跟蹤就中止了。難道是觸發了系統的ulimit限制，而後被系統殺掉了？

5. 設置ulimit參數

設置 gunicorn 運行用戶的 ulimit，從新嘗試，沒有解決。看來也不是這個問題。。。那是被誰 kill 掉的呢？

6. 捕捉kill信號

使用 auditctl，添加捕捉規則：

$ auditctl -a exit,always -F arch=b64 -S kill -F a1=9

進行下載文件操做，等待進程被殺死以後，顯式捕捉到結果：

$ ausearch -sc kill

輸出：

time->Fri Dec  6 16:13:26 2019
type=PROCTITLE msg=audit(1575620006.444:103711): proctitle=2F6F70742F6D6F64756C65732F7265646173682D372E302E302F7265646173682F62696E2F707974686F6E322E37002F6F70742F7265646173682F7265646173682F62696E2F67756E69636F726E002D62003132372E302E302E313A35303030002D2D6E616D6500726564617368002D770034002D2D6D61782D726571756573
type=OBJ_PID msg=audit(1575620006.444:103711): opid=11646 oauid=0 ouid=1001 oses=14406 ocomm="gunicorn"
type=SYSCALL msg=audit(1575620006.444:103711): arch=c000003e syscall=62 success=yes exit=0 a0=2d7e a1=9 a2=0 a3=0 items=0 ppid=11490 pid=11494 auid=0 uid=1001 gid=1001 euid=1001 suid=1001 fsuid=1001 egid=1001 sgid=1001 fsgid=1001 tty=(none) ses=14406 comm="gunicorn" exe="/opt/modules/redash-7.0.0/redash/bin/python2.7" key=(null)

原來是被父進程搞死了。。。

7. 查看gunicorn日誌

進入supervisord控制檯，經過tail -f 打印 gunicorn進程的輸出。

[CRITICAL] WORKER TIMEOUT (pid:15577)
[INFO] Worker exiting (pid: 15577)
[INFO] Booting worker with pid: 15646

timeout...緣由就是最開始猜想的超時問題。

gunicorn 給子進程的執行時間就有30秒，若是超過這個限制就會被父進程kill。但是timeout的超時配置並不生效。。。