WSGIアプリケーションの事後検証デバッグ

# 概要

apache2 + mod_wsgi で動作しているアプリケーションが応答なしになった場合にコアダンプを取得し、事後検証デバッグ(postmotem debugging)で問題箇所を特定する手順を説明します。説明に使う環境は Ubuntu 16.04, python2.7 です。

# コアダンプの取得

まず対象のプロセスのPIDを特定します。例えば busy loop にはまっている例だと、top コマンドで CPU 使用率が高まっているプロセスを探します。

```
top - 11:16:13 up  4:15,  2 users,  load average: 1.14, 0.81, 1.28
Tasks: 214 total,   1 running, 213 sleeping,   0 stopped,   0 zombie
%Cpu(s): 48.5 us,  2.6 sy,  0.3 ni, 47.9 id,  0.4 wa,  0.0 hi,  0.4 si,  0.0 st
KiB Mem :  4046124 total,   389952 free,  2063300 used,  1592872 buff/cache
KiB Swap:  4191228 total,  4068572 free,   122656 used.  1589852 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
12175 www-data  20   0  442352  10736   5680 S 100.0  0.3   1:26.03 apache2
```

gcore コマンド(gdb パッケージに含まれています)で対象プロセスの PID を指定してコアダンプを生成します。

```
$ sudo gcore 12175
[New LWP 12206]
[New LWP 12207]
...略...
[New LWP 12231]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
0x00007f6c9e5e051d in read () at ../sysdeps/unix/syscall-template.S:84
84	../sysdeps/unix/syscall-template.S: No such file or directory.
warning: target file /proc/12175/cmdline contained unexpected null characters
Saved corefile core.12175
```

調査用のコアダンプが確保できたので、apache を restart するなどして問題の起きているプロセスを再起動しても大丈夫です。

# コアダンプを開く

file コマンドで実行ファイルのパスを確認します

```
$ file core.12175
core.12175: ELF 64-bit LSB core file x86-64, version 1 (SYSV), SVR4-style, from '/usr/sbin/apache2'
```

gdb に実行ファイルとコアファイルを指定して起動します。

```
$ gdb /usr/sbin/apache2 core.12175
GNU gdb (Ubuntu 7.11.1-0ubuntu1~16.5) 7.11.1
...略...
Core was generated by `/usr/sbin/apache2'.
#0  0x00007f6c9e5e051d in read () at ../sysdeps/unix/syscall-template.S:84
84	../sysdeps/unix/syscall-template.S: No such file or directory.
[Current thread is 1 (Thread 0x7f6c9f0ba780 (LWP 12175))]
```

# 対象スレッドの選択

gdb 上で info threads で問題のスレッドを探します。例では Python で busy loop にはまっているものを使っているので、 pthread_cond_wait のスレッドは無視して、Pythonのコードを実行中のスレッドに注目します。

```
(gdb) info threads
  Id   Target Id         Frame
* 1    Thread 0x7f6c9f0ba780 (LWP 12175) 0x00007f6c9e5e051d in read ()
    at ../sysdeps/unix/syscall-template.S:84
...略...
  7    Thread 0x7f6c927fc700 (LWP 12211) pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
  8    Thread 0x7f6c91ffb700 (LWP 12212) 0x00007f6c9ac0d516 in PyEval_EvalFrameEx () from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
...略...
```

対象のスレッドを選択してバックトレースを表示してみます。

```
(gdb) thread 8
[Switching to thread 8 (Thread 0x7f6c91ffb700 (LWP 12212))]
#0  0x00007f6c9ac0d516 in PyEval_EvalFrameEx ()
   from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
(gdb) bt
#0  0x00007f6c9ac0d516 in PyEval_EvalFrameEx ()
   from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
#1  0x00007f6c9ad4505c in PyEval_EvalCodeEx ()
   from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
#2  0x00007f6c9ac9b370 in ?? ()
   from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
#3  0x00007f6c9ac6e273 in PyObject_Call ()
   from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
#4  0x00007f6c9ad44487 in PyEval_CallObjectWithKeywords ()
   from /usr/lib/x86_64-linux-gnu/libpython2.7.so.1.0
#5  0x00007f6c9b106432 in ?? () from /usr/lib/apache2/modules/mod_wsgi.so
#6  0x000055b4f2e7bc80 in ap_run_handler ()
#7  0x000055b4f2e7c206 in ap_invoke_handler ()
#8  0x000055b4f2e936a2 in ap_process_async_request ()
#9  0x000055b4f2e8f9f0 in ?? ()
#10 0x000055b4f2e85bf0 in ap_run_process_connection ()
#11 0x00007f6c9b937765 in ?? () from /usr/lib/apache2/modules/mod_mpm_event.so
#12 0x00007f6c9e5d76ba in start_thread (arg=0x7f6c91ffb700)
    at pthread_create.c:333
#13 0x00007f6c9e30d41d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
```

Pythonレベルのバックトレースが見えないとよくわからないので次に進みます。

## 余談: Python以外で詰まっている場合

今回はPythonの処理で詰まっている例でしたが、もしCのライブラリの処理で詰まっている場合は、 [Debug Symbol Packages - Ubuntu Wiki](https://wiki.ubuntu.com/Debug%20Symbol%20Packages) に添って対象ライブラリの *-dbgsym.ddeb を取得、インストールの上でバックトレースを表示すればソースのどこを処理しているか確認できます。

# Python のバックトレースを見る

[DebuggingWithGdb - Python Wiki](https://wiki.python.org/moin/DebuggingWithGdb) に書かれているように、 libpython のシンボルとデバッガ拡張があれば Python レベルでのバックトレースを見れます。Ubuntu であれば python2.7-dbg パッケージにそれらが含まれています。

```
$ sudo apt install python2.7-dbg
```

とした上で再度コアダンプを開くと、 py-bt (Pythonのバックトレースを表示する), py-list (Pythonのソースを表示する)が使えるようになります。

```
$ gdb /usr/sbin/apache2 core.12175
...
(gdb) thread 8
[Switching to thread 8 (Thread 0x7f6c91ffb700 (LWP 12212))]
#0  PyEval_EvalFrameEx (f=<optimized out>, throwflag=<optimized out>)
    at ../Python/ceval.c:2341
2341	../Python/ceval.c: No such file or directory.
(gdb) py-bt
Traceback (most recent call first):
  File "/var/www/html/hello.wsgi", line 2, in application
    while True:
(gdb) py-list
   1    def application(environ, start_response):
  >2        while True:
   3            pass
```

確かに busy loop にはまっているのが確認できました。

## 余談: 他ホストで取ったダンプを見る場合

コアダンプを生成したホストと事後検証に使うホストが異なる場合、ライブラリのバージョンが揃っていれば特に困らないですが、そうでない場合はちょっと準備が必要です：

* 当該ホストの `/usr/lib` を取得して、`適当な場所/usr/lib` に展開
* file コマンドで libpython2.7.so.1.0 の BuildID を確認
* BuildID が同じシンボルファイル (strip 前のライブラリ) を `/usr/lib/debug/.build-id/BuildIDの先頭2文字/BuildIDの残り.debug` として配置
* gdb で `set sysroot 適当な場所` としてルートディレクトリを変更

# まとめ

* コアダンプを確保しておけば事後検証デバッグで問題の調査ができる
* Ubuntu ではライブラリのシンボルも配布されているので活用しよう