試行錯誤のおと

Python で実装した Web アプリケーションを uwsgi 上で動作させて運用しているときのお役立ち Tips 的なやつ。

仕事で uwsgi を運用しているのだけど、先日 uwsgi の worker がずっと busy な状態になっているプロセスが常駐していたので調査した。 strace でプロセスの状態を追うと read() で止まっていてその前後は読めない状態だった。その時は read() で待たされていることが原因だったので read() している fd を特定して、どういったことが原因で待たされているのか調査することで解決した。

けれども、もう少しスマートに解決したいという欲求はあって、 Python の faulthandler [1]なる機能を教えてもらったので調べてみた。

faulthandler を使うと指定したシグナル (SIGSEGV, SIGFPE, SIGABRT, SIGBUS, SIGILL) を受信したときにスタックトレースを標準エラー出力に出力してプロセスを終了する。簡単な WSGI アプリケーションを書いて、環境変数から faulthandler を設定してみた。

#!/usr/bin/env python3.4
from werkzeug import run_simple


def app(environ, start_response):
    start_response('200 OK', [('Content-Type', 'text/plain; charset=utf-8')])
    yield b'Hello World!\n'

run_simple('127.0.0.1', 5000, app)

# exec
docker@3b813e88ee88:~$ python3 -V
Python 3.4.2
docker@3b813e88ee88:~$ PYTHONFAULTHANDLER=1 python3 ./wsgi.py &
[1] 39
docker@3b813e88ee88:~$  * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
docker@3b813e88ee88:~$ curl 127.0.0.1:5000
127.0.0.1 - - [05/Jul/2016 07:28:39] "GET / HTTP/1.1" 200 -
Hello World!
# send SIGSEGV
docker@3b813e88ee88:~$ kill -s SEGV $(pidof python3)
Fatal Python error: Segmentation fault

Current thread 0x00007f7b6d866700 (most recent call first):
  File "/usr/lib/python3.4/socketserver.py", line 154docker@d733ec43cf93:~$  in _eintr_retry
  File "/usr/lib/python3.4/socketserver.py", line 236 in serve_forever
  File "/home/docker/.local/lib/python3.4/site-packages/werkzeug/serving.py", line 499 in serve_forever
  File "/home/docker/.local/lib/python3.4/site-packages/werkzeug/serving.py", line 659 in inner
  File "/home/docker/.local/lib/python3.4/site-packages/werkzeug/serving.py", line 694 in run_simple
  File "./wsgi.py", line 9 in <module>

  [1]+  Segmentation fault      PYTHONFAULTHANDLER=1 python3 ./wsgi.py

標準エラー出力にスタックトレースの出力を確認できた。

あとは uwsgi を使ってアプリケーションを動かして確認するのだけど気をつけないといけないところがあって、 py-call-osafterfork [2] を有効にしないと uwsgi worker にシグナルを送信してもアプリケーションに伝達されないので注意。

# exec
# 今回 uwsgi は emperor モードで実行
# env: PYTHONFAULTHANDLER=1 を vassal の設定ファイルで指定
root@fb755eb211cb:/# uwsgi -y /etc/uwsgi/emperor.yaml
# send SIGSEGV
root@fb755eb211cb:/# ps auxf
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root       127  0.0  0.0  20256  3284 ?        Ss   08:38   0:00 /bin/bash
root       148  0.0  0.0  17496  2144 ?        R+   08:39   0:00  \_ ps auxf
root        10  0.0  0.0  20256  3264 ?        Ss   08:31   0:00 /bin/bash
root       144  0.0  0.0  48236  4664 ?        S+   08:39   0:00  \_ uwsgi -y /etc/uwsgi/emperor.yaml
root       145  0.9  0.1  66480 11172 ?        S+   08:39   0:00      \_ uWSGI master
docker     146  0.0  0.1  68692 10476 ?        S+   08:39   0:00          \_ uWSGI worker 1
docker     147  0.0  0.1  68692 10476 ?        S+   08:39   0:00          \_ uWSGI worker 2
docker       1  0.0  0.0  20252  3224 ?        Ss+  08:31   0:00 /bin/bash

# worker(cheaper) に SIGSEGV を送る
docker@fb755eb211cb:~$ kill -s SEGV 146
Fatal Python error: Segmentation fault

Current thread 0x00007fa047204780 (most recent call first):
!!! uWSGI process 146 got Segmentation Fault !!!
*** backtrace of 146 ***
uWSGI worker 1(uwsgi_backtrace+0x30) [0x4635f0]
uWSGI worker 1(uwsgi_segfault+0x21) [0x4639b1]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0) [0x7fa046de58d0]
/lib/x86_64-linux-gnu/libpthread.so.0(raise+0x2b) [0x7fa046de579b]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0) [0x7fa046de58d0]
/lib/x86_64-linux-gnu/libc.so.6(epoll_wait+0x13) [0x7fa044f8ae33]
uWSGI worker 1(event_queue_wait+0x33) [0x456ed3]
uWSGI worker 1(wsgi_req_accept+0xd2) [0x4175f2]
uWSGI worker 1(simple_loop_run+0xb6) [0x45f7a6]
uWSGI worker 1(uwsgi_ignition+0x208) [0x463c78]
uWSGI worker 1(uwsgi_worker_run+0x25d) [0x466fbd]
uWSGI worker 1(uwsgi_run+0x3ae) [0x4674de]
uWSGI worker 1(_start+0) [0x41698e]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7fa044ec3b45]
uWSGI worker 1() [0x4169b7]
*** end of backtrace ***
DAMN ! worker 1 (pid: 146) died, killed by signal 11 :( trying respawn ...
Respawned uWSGI worker 1 (new pid: 150)
...

同様にスタックトレースの出力が確認できた。標準エラー出力に出力されるため、実際の動作では damontools の multilog や systemd のサービスとして動作させることが必要。

これで、知らないコードを追いかけずにすんで便利。2 台以上の worker でトラブル起こしていたら、1 台試してみるのいいかも。出力できる文字数が 500 文字までとか制限はあるけれども、インフラ担当者が環境変数指定すればいいだけなので、設定しておいて間違いはなさそう。

使った設定とかは下記のリポジトリに置いておく (気まぐれで消すかも)。

github.com

参照

[1]: http://docs.python.jp/3/library/faulthandler.html
[2]: https://uwsgi-docs.readthedocs.io/en/latest/Options.html#py-call-osafterfork

最近、趣味で rust を書いてる。

rust で sha256 を使って符号化したいケースがあったので調べてみた。

調べていくと rust-crypto [1] なる crate が見つかった。更新頻度も高くてよさそう。

しかし、これドキュメントがない。

ドキュメントがないので、ソースコードを追って読んでみた。メモがてら記録としてサンプルコードを残しておくことにする。

Cargo.toml

[package]
name = "test"
version = "0.1.0"
authors = ["kizkoh"]

[dependencies]
rust-crypto = "0.2"

main.rs

extern crate crypto;

use crypto::sha2::Sha256;
use crypto::digest::Digest;

pub fn main() {
    let input: String = "test".to_string();
        
    let mut sha256 = Sha256::new();
    sha256.input_str(&input);

    println!("input: {}", input);
    println!("digest: {}", sha256.result_str());
}

$ cargo run                                                                                                                                         [master]
     Running `target/debug/test`
input: test
digest: 9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08
$ echo -n "test" | openssl dgst -sha256
(stdin)= 9f86d081884c7d659a2feaa0c55ad015a3bf4f1b2b0b822cd15d6c15b0f00a08

ちゃんと openssl と同じ結果になる。

[1] https://crates.io/crates/rust-crypto

試行錯誤のおと

日々の試行錯誤した結果です。失敗することが多い記録、それだけでっす！

Python の faulthandler を uwsgi で指定する

参照

rust で hash 関数を扱ってみた

Linux で radiko を再生するシェルスクリプト書いた