pidof の -S / --separtor オプション で複数プロセスに strace する

procps の ML を眺めていたら便利そうな新機能がマージされていた

gitlab.com

$ ./pidof -h

Usage:
 lt-pidof [options] [program [...]]

Options:
 -s, --single-shot         return one PID only
 -c, --check-root          omit processes with different root
 -x                        also find shells running the named scripts
 -o, --omit-pid <PID,...>  omit processes with PID
 -S, --separator SEP       use SEP as separator put between PIDs 👈
 -h, --help     display this help and exit
 -V, --version  output version information and exit

For more details see pidof(1).

誰に便利って、頻繁に strace 使う人向け (コミットの説明にもまんま例が書いてある)

I frequency use pidof command with strace system call tracer.
strace can trace MULTIPLE processes specified with "-p $PID"
arguments like:

      strace -p 1 -p 1030 -p 3043

Sometimes I want to do as following

      strace -p $(pidof httpd)

However, above command line doesn't work because -p option
is needed for specifying a pid. pidof uses a whitespace as
a separator. For passing the output to strace, the separator
should be replaced with ' -p '.

This maybe not a special to my use case.

This commit introduces -S option that allows a user to specify a
separator the one wants.

    $ ./pidof bash
    ./pidof bash
    24624 18790 12786 11898 11546 10766 7654 5095
    $ ./pidof -S ',' bash
    ./pidof -S ',' bash
    24624,18790,12786,11898,11546,10766,7654,5095
    $ ./pidof -S '-p ' bash
    ./pidof -S '-p ' bash
    24624-p 18790-p 12786-p 11898-p 11546-p 10766-p 7654-p 5095
    $ ./pidof -S ' -p ' bash
    ./pidof -S ' -p ' bash
    24624 -p 18790 -p 12786 -p 11898 -p 11546 -p 10766 -p 7654 -p 5095
    $ strace -p $(./pidof -S ' -p ' bash)
    strace -p $(./pidof -S ' -p ' bash)
    strace: Process 24624 attached
    strace: Process 18790 attached
    strace: Process 12786 attached
    ...

Signed-off-by: Masatake YAMATO <yamato@redhat.com>
 parent c9be22a8 master

こんな感じで strace で複数プロセスに一度でアタッチできる! あーべんり〜 わかる〜

[vagrant@localhost procps]$ sudo strace -p $(./pidof nginx -S ' -p ')
strace: Process 9621 attached
strace: Process 9620 attached
strace: Process 9619 attached
[pid  9619] rt_sigsuspend([], 8 <unfinished ...> 👈
[pid  9620] epoll_wait(9,  <unfinished ...> 👈
[pid  9621] epoll_wait(11,  👈

複数のコマンドを組み合わせて同様のことを実現するテクニックはあるのだが、 シンプルな手段があれば越したことはない

procps-ng: sysctl の Segmentation Fault を報告 、の続き

続

hiboma.hatenadiary.jp

上記のエントリにも書いたのだが、2ヶ月ほど前に procps-ng にバグレポートを投げていたのにようやく反応をもらえて、速攻で fix された

gitlab.com

gitlab.com

なかなかのんびりしているプロジェクトなのだな。また何か見つけたら貢献していこう

(追記)

私が issue を立てる前に、バグを作ってしまった作者自信から修正パッチが ML に投稿されていたとのこと。が、見過ごされていたらしい 😭

running sysctl as non-privileged user causes segmentaion fault (#76) · Issues · procps-ng / procps · GitLab

www.freelists.org

刈場坂峠〜白石峠 🚲

12/30 (金)、2017年 最後の自転車

走行距離 97km、獲得標高 1415m

2017年を平穏にしめくくろう ... という気持ちとは裏腹に、気温0度の峠からダウンヒル中にパンクしたり、昼食が足りなくてハンガーノックになりかけたり、落石で通行止めの峠でルート変更を余儀なくされたり、トラブルだらけだった

続きを読む

procps-ng: sysctl の Segmentation Fault を報告

procps-ng の master の sysctl を使っていたら Segmentation Fault を起こしたので issue をオープンしといた

gitlab.com

問題のあるコミット

以下のような感じ

diff --git a/sysctl.c b/sysctl.c
index 29f31af..be05722 100644
--- a/sysctl.c
+++ b/sysctl.c
@@ -158,6 +158,8 @@ static char *StripLeadingAndTrailingSpaces(char *oneline)
 /*
  * Read a sysctl setting
  */
+#define IOBUFSIZ    (128<<10)
+static char *iobuf;
 static int ReadSetting(const char *restrict const name)
 {
    int rc = 0;
@@ -220,6 +222,9 @@ static int ReadSetting(const char *restrict const name)
 
    fp = fopen(tmpname, "r");
 
+   if (iobuf)
(fp, iobuf, _IOFBF, IOBUFSIZ);
+
    if (!fp) {
        switch (errno) {
        case ENOENT:
@@ -430,6 +435,9 @@ static int WriteSetting(const char *setting)
 
    fp = fopen(tmpname, "w");
 
+   if (iobuf)
+       setvbuf(fp, iobuf, _IOFBF, IOBUFSIZ);
+
    if (!fp) {
        switch (errno) {
        case ENOENT:
@@ -793,6 +801,8 @@ int main(int argc, char *argv[])
    argc -= optind;
    argv += optind;
 
+   iobuf = (char*)malloc(IOBUFSIZ);    /* Allow to fail */
+
    if (DisplayAllOpt)
        return DisplayAll(PROC_PATH);

非特権ユーザで sysctl を実行すると、権限が足りない場合に fopen(3) が EACCESS で失敗して NULL を返すのだが、エラーを確認せずに setvbuf(3) しちゃって ぬるぽ で ガッ SIGSEGV するのだった

$ /usr/local/sbin/sysctl net.ipv4.tcp_fastopen_key
Segmentation fault (core dumped)

$ /usr/local/sbin/sysctl -w vm.overcommit_ratio=0
Segmentation fault (core dumped)

本来は以下のような挙動をとるはず

$ /usr/local/sbin/sysctl net.ipv4.tcp_fastopen_key
sysctl: permission denied on key 'net.ipv4.tcp_fastopen_key'

$ /usr/local/sbin/sysctl -w vm.overcommit_ratio=0
sysctl: permission denied on key 'vm.overcommit_ratio'

感想

  • まだ master ブランチに入ってるだけでリリースされてないので、ささっと直してくれるだろう
  • わりと「うっかり」したバグだよなぁ
  • 何も反応なかったらパッチを送ってみよ

strace の -k オプションでスタックトレースを出す

strace で -k を指定すると システムコール呼び出しのスタックトレースを採取できるのを知った。v4.9 から使える experimental 扱いのオプション

       -k          Print  the execution stack trace of the traced processes after each system call (experimental).  This option is available only if strace is built with libunwind.

以下のような出力を得られる

$ strace -k ls
execve("/usr/local/bin/ls", ["ls"], 0x7ffcf3bcdd58 /* 26 vars */) = 0
 > /usr/lib64/libc-2.17.so(execve+0x7) [0xbf557]
 > /usr/local/bin/strace(exec_or_die+0x127) [0x2bd7]
 > /usr/local/bin/strace(startup_child+0x3c6) [0x24df6]
 > /usr/local/bin/strace(init+0x6c0) [0x25540]
 > /usr/local/bin/strace(main+0x16) [0x2c26]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/strace(_start+0x29) [0x379a]
brk(NULL)                               = 0x1281000
 > /usr/lib64/ld-2.17.so(__brk+0xc) [0x1826c]
 > /usr/lib64/ld-2.17.so(_dl_sysdep_start+0x148) [0x17448]
 > /usr/lib64/ld-2.17.so(_dl_start+0x381) [0x1bc1]
 > /usr/lib64/ld-2.17.so(check_one_fd.part.0+0x7d) [0x1178]
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f93c8f7a000
 > /usr/lib64/ld-2.17.so(__mmap+0x3a) [0x18f5a]
 > /usr/lib64/ld-2.17.so(__libc_memalign+0x84) [0x17db4]
 > /usr/lib64/ld-2.17.so(_dl_init_paths+0x91) [0x7ea1]
 > /usr/lib64/ld-2.17.so(dl_main+0x154b) [0x342b]
 > /usr/lib64/ld-2.17.so(_dl_sysdep_start+0x238) [0x17538]
 > /usr/lib64/ld-2.17.so(_dl_start+0x381) [0x1bc1]
 > /usr/lib64/ld-2.17.so(check_one_fd.part.0+0x7d) [0x1178]
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
 > /usr/lib64/ld-2.17.so(access+0x7) [0x18e57]
 > /usr/lib64/ld-2.17.so(dl_main+0x1700) [0x35e0]
 > /usr/lib64/ld-2.17.so(_dl_sysdep_start+0x238) [0x17538]
 > /usr/lib64/ld-2.17.so(_dl_start+0x381) [0x1bc1]
 > /usr/lib64/ld-2.17.so(check_one_fd.part.0+0x7d) [0x1178]

...

やったー

CentOS7

CentOS7.4 の strace-4.12-4.el7 ではサポートされていない機能だ。ざんねーん

$ rpm -qf /usr/bin/strace 
strace-4.12-4.el7.x86_64

$ /usr/bin/strace -k ps
/usr/bin/strace: invalid option -- 'k'
Try '/usr/bin/strace -h' for more information.

ちなみに Ubuntu Xenial もだめだー。とほほー

ビルドする

strace を git clone してきて、libunwind, libunwind-devel をインストールしておけば ./configure が勝手に検知して有効にしてくれた

ユースケース

障害や不具合の調査では、strace でシステムコールを読んで原因を絞り込んでいくことがある。そして問題のあるシステムコールを見つけることができたとしても、アプリケーションのどのコードから呼び出されいるかを突き止めるので手間がかかったりする

一つの方法として、GDB でシステムコールに breakpoint を仕掛けてバックトレースをとると解決できるが、production で使うには GDB で停止するオーバーヘッドが問題になりそうだったり (注: 計測してみたら問題ないかも。感覚の話ですいません 😳 ) 、複数のシステムコールをまとめて追いかけたい際には不便 ... という問題を解決してくれそうなオプション

システムコールから逆引きで呼び出し元のシンボルとファイル名が一覧できるので、ただ単にソースコードリーディング用のツールとしても有用そう

実行例

ps コマンドの write(2) だけに絞り込んでスタックトレースを出す

$ strace -ewrite -k ps --quick-pid 1 
write(1, "  PID TTY          TIME CMD\n", 28  PID TTY          TIME CMD
) = 28
 > /usr/lib64/libc-2.17.so(__write_nocancel+0x7) [0xe9840]
 > /usr/lib64/libc-2.17.so(_IO_file_write+0x43) [0x75fb3]
 > /usr/lib64/libc-2.17.so(_IO_do_write+0x7c) [0x7741c]
 > /usr/lib64/libc-2.17.so(_IO_file_xsputn+0xb1) [0x76651]
 > /usr/lib64/libc-2.17.so(fwrite+0xed) [0x6c03d]
 > /usr/local/bin/ps(show_one_proc+0x3d6) [0x7146]
 > /usr/local/bin/ps(main+0x8ab) [0x2b2b]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/ps(_start+0x29) [0x2ca5]
write(1, "    1 ?        00:00:19 systemd\n", 32    1 ?        00:00:19 systemd
) = 32
 > /usr/lib64/libc-2.17.so(__write_nocancel+0x7) [0xe9840]
 > /usr/lib64/libc-2.17.so(_IO_file_write+0x43) [0x75fb3]
 > /usr/lib64/libc-2.17.so(_IO_do_write+0x7c) [0x7741c]
 > /usr/lib64/libc-2.17.so(_IO_file_xsputn+0xb1) [0x76651]
 > /usr/lib64/libc-2.17.so(fwrite+0xed) [0x6c03d]
 > /usr/local/bin/ps(main+0x8ab) [0x2b2b]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/ps(_start+0x29) [0x2ca5]
+++ exited with 0 +++

よいかんじだ

その他の使用例

例えば -P を組み合わせるて 特定のファイルを扱うシステムコールとトレースを観察する

id コマンドと /etc/passwd をトレースすると、libc の getpwuid(3) 呼び出しと中間に libnss_files が入っているのが分かる。ライブラリ関数や .so ライブラリの関係を把握できる。

$ strace -k -P /etc/passwd -y id
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 3</etc/passwd>
 > /usr/lib64/libc-2.17.so(__open_nocancel+0x7) [0xe95a0]
 > /usr/lib64/libc-2.17.so(_IO_file_fopen+0x4c4) [0x77314]
 > /usr/lib64/libc-2.17.so(__fopen_internal+0x74) [0x6b5e4]
 > /usr/lib64/libnss_files-2.17.so(_nss_files_getpwuid_r+0x113) [0x60a3]
 > /usr/lib64/libc-2.17.so(getpwuid_r+0x15e) [0xbe52e]
 > /usr/lib64/libc-2.17.so(getpwuid+0x76) [0xbdc66]
 > /usr/local/bin/id(main+0x677) [0x20e7]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/id(_start+0x29) [0x2478]
fstat(3</etc/passwd>, {st_mode=S_IFREG|0644, st_size=1564, ...}) = 0
 > /usr/lib64/libc-2.17.so(__fxstat64+0x14) [0xe9154]
 > /usr/lib64/libc-2.17.so(_IO_file_doallocate+0x25) [0x6a9d5]
 > /usr/lib64/libc-2.17.so(_IO_doallocbuf+0x35) [0x784e5]
 > /usr/lib64/libc-2.17.so(_IO_file_underflow+0x1a4) [0x77654]
 > /usr/lib64/libc-2.17.so(_IO_default_uflow+0xe) [0x7856e]
 > /usr/lib64/libc-2.17.so(_IO_getline_info+0xa4) [0x6c514]
 > /usr/lib64/libc-2.17.so(fgets_unlocked+0x3d) [0x7569d]
 > /usr/lib64/libnss_files-2.17.so(internal_getent+0x8f) [0x5b0f]
 > /usr/lib64/libnss_files-2.17.so(_nss_files_getpwuid_r+0x81) [0x6011]
 > /usr/lib64/libc-2.17.so(getpwuid_r+0x15e) [0xbe52e]
 > /usr/lib64/libc-2.17.so(getpwuid+0x76) [0xbdc66]
 > /usr/local/bin/id(main+0x677) [0x20e7]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/id(_start+0x29) [0x2478]
read(3</etc/passwd>, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1564
 > /usr/lib64/libc-2.17.so(__read_nocancel+0x7) [0xe97e0]
 > /usr/lib64/libc-2.17.so(_IO_file_read+0x17) [0x76597]
 > /usr/lib64/libc-2.17.so(_IO_file_underflow+0x130) [0x775e0]
 > /usr/lib64/libc-2.17.so(_IO_default_uflow+0xe) [0x7856e]
 > /usr/lib64/libc-2.17.so(_IO_getline_info+0xa4) [0x6c514]
 > /usr/lib64/libc-2.17.so(fgets_unlocked+0x3d) [0x7569d]
 > /usr/lib64/libnss_files-2.17.so(internal_getent+0x8f) [0x5b0f]
 > /usr/lib64/libnss_files-2.17.so(_nss_files_getpwuid_r+0x81) [0x6011]
 > /usr/lib64/libc-2.17.so(getpwuid_r+0x15e) [0xbe52e]
 > /usr/lib64/libc-2.17.so(getpwuid+0x76) [0xbdc66]
 > /usr/local/bin/id(main+0x677) [0x20e7]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/id(_start+0x29) [0x2478]
close(3</etc/passwd>)                   = 0
 > /usr/lib64/libc-2.17.so(__close_nocancel+0x7) [0xe9e90]
 > /usr/lib64/libc-2.17.so(_IO_file_close_it+0x120) [0x76cc0]
 > /usr/lib64/libc-2.17.so(fclose+0x180) [0x6ac40]
 > /usr/lib64/libnss_files-2.17.so(_nss_files_getpwuid_r+0xe9) [0x6079]
 > /usr/lib64/libc-2.17.so(getpwuid_r+0x15e) [0xbe52e]
 > /usr/lib64/libc-2.17.so(getpwuid+0x76) [0xbdc66]
 > /usr/local/bin/id(main+0x677) [0x20e7]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/local/bin/id(_start+0x29) [0x2478]
uid=1000(vagrant) gid=1000(vagrant) groups=1000(vagrant)
+++ exited with 0 +++

その他の使用例(2)

nginx が 静的コンテンツを返すシステムコールとスタックトレースを眺める。イベント駆動なコードはなかなか把握するのが辛いけど、どのフェーズでどのようなシステムコールが呼び出されるかを把握すると、追いかけやすくなる ... かな?

accept4(6<TCP:[782776]>, {sa_family=AF_INET, sin_port=htons(61829), sin_addr=inet_addr("192.168.33.1")}, [110->16], SOCK_NONBLOCK) = 3<TCP:[789563]>
 > /usr/lib64/libc-2.17.so(accept4+0x17) [0xf9787]
 > /usr/sbin/nginx(ngx_event_accept+0xef) [0x40aef]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
epoll_ctl(17<anon_inode:[eventpoll]>, EPOLL_CTL_ADD, 3<TCP:[789563]>, {EPOLLIN|EPOLLRDHUP|EPOLLET, {u32=729518769, u64=139758965330609}}) = 0
 > /usr/lib64/libc-2.17.so(epoll_ctl+0xa) [0xf88ca]
 > /usr/sbin/nginx(ngx_os_specific_status+0x29b) [0x49eab]
 > /usr/sbin/nginx(ngx_handle_read_event+0xa0) [0x40390]
 > /usr/sbin/nginx(ngx_http_init_connection+0x31b) [0x5f2ab]
 > /usr/sbin/nginx(ngx_event_accept+0x473) [0x40e73]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
recvfrom(3<TCP:[789563]>, "GET / HTTP/1.1\r\nHost: 192.168.33.10\r\nUser-Agent: curl/7.52.1\r\nAccept: */*\r\n\r\n", 1024, 0, NULL, NULL) = 77
 > /usr/lib64/libpthread-2.17.so(recv+0x1d) [0xea3d]
 > /usr/sbin/nginx(ngx_unix_recv+0x62) [0x44dc2]
 > /usr/sbin/nginx(ngx_http_process_request+0xb7d) [0x62d2d]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
stat("/usr/share/nginx/html/index.html", {st_mode=S_IFREG|0644, st_size=3700, ...}) = 0
 > /usr/lib64/libc-2.17.so(__xstat64+0x15) [0xe9105]
 > /usr/sbin/nginx(ngx_resolve_addr+0x37a5) [0x3ca75]
 > /usr/sbin/nginx(ngx_open_cached_file+0x336) [0x3d3d6]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x4967) [0x9c5f7]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
open("/usr/share/nginx/html/index.html", O_RDONLY|O_NONBLOCK) = 4</usr/share/nginx/html/index.html>
 > /usr/lib64/libpthread-2.17.so(__open_nocancel+0x7) [0xee90]
 > /usr/sbin/nginx(ngx_resolve_addr+0x3428) [0x3c6f8]
 > /usr/sbin/nginx(ngx_resolve_addr+0x38fa) [0x3cbca]
 > /usr/sbin/nginx(ngx_open_cached_file+0x1d0) [0x3d270]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x7e7) [0x98477]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_internal_redirect+0x129) [0x5c7b9]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x4d28) [0x9c9b8]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
fstat(4</usr/share/nginx/html/index.html>, {st_mode=S_IFREG|0644, st_size=3700, ...}) = 0
 > /usr/lib64/libc-2.17.so(__fxstat64+0x14) [0xe9154]
 > /usr/sbin/nginx(ngx_resolve_addr+0x3914) [0x3cbe4]
 > /usr/sbin/nginx(ngx_open_cached_file+0x1d0) [0x3d270]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x7e7) [0x98477]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_internal_redirect+0x129) [0x5c7b9]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x4d28) [0x9c9b8]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
setsockopt(3<TCP:[789563]>, SOL_TCP, TCP_CORK, [1], 4) = 0
 > /usr/lib64/libc-2.17.so(setsockopt+0xa) [0xf946a]
 > /usr/sbin/nginx(ngx_tcp_nopush+0x36) [0x44cd6]
 > /usr/sbin/nginx(ngx_linux_sendfile_chain+0x40d) [0x4b58d]
 > /usr/sbin/nginx(ngx_http_write_filter+0x4f0) [0x7f090]
 > /usr/sbin/nginx(ngx_http_write_filter+0x1786) [0x80326]
 > /usr/sbin/nginx(ngx_http_write_filter+0x53cc) [0x83f6c]
 > /usr/sbin/nginx(ngx_http_write_filter+0x86ec) [0x8728c]
 > /usr/sbin/nginx(ngx_http_write_filter+0xbbea) [0x8a78a]
 > /usr/lib64/nginx/modules/ngx_http_xslt_filter_module.so(_init+0x158c) [0x2d2c]
 > /usr/lib64/nginx/modules/ngx_http_image_filter_module.so(_init+0x1b88) [0x3148]
 > /usr/sbin/nginx(ngx_http_write_filter+0xdedf) [0x8ca7f]
 > /usr/sbin/nginx(ngx_http_write_filter+0xe72c) [0x8d2cc]
 > /usr/sbin/nginx(ngx_output_chain+0x8f8) [0x25de8]
 > /usr/sbin/nginx(ngx_http_write_filter+0x1095e) [0x8f4fe]
 > /usr/sbin/nginx(ngx_http_write_filter+0x110fe) [0x8fc9e]
 > /usr/sbin/nginx(ngx_http_output_filter+0x2a) [0x5b53a]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0xb8e) [0x9881e]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_internal_redirect+0x129) [0x5c7b9]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x4d28) [0x9c9b8]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
writev(3<TCP:[789563]>, [{iov_base="HTTP/1.1 200 OK\r\nServer: nginx/1.10.2\r\nDate: Wed, 08 Nov 2017 05:33:40 GMT\r\nContent-Type: text/html\r\nContent-Length: 3700\r\nLast-Modified: Mon, 18 Sep 2017 09:18:55 GMT\r\nConnection:"..., iov_len=239}], 1) = 239
 > /usr/lib64/libc-2.17.so(writev+0x17) [0xef1e7]
 > /usr/sbin/nginx(ngx_writev+0x19) [0x45529]
 > /usr/sbin/nginx(ngx_linux_sendfile_chain+0x182) [0x4b302]
 > /usr/sbin/nginx(ngx_http_write_filter+0x4f0) [0x7f090]
 > /usr/sbin/nginx(ngx_http_write_filter+0x1786) [0x80326]
 > /usr/sbin/nginx(ngx_http_write_filter+0x53cc) [0x83f6c]
 > /usr/sbin/nginx(ngx_http_write_filter+0x86ec) [0x8728c]
 > /usr/sbin/nginx(ngx_http_write_filter+0xbbea) [0x8a78a]
 > /usr/lib64/nginx/modules/ngx_http_xslt_filter_module.so(_init+0x158c) [0x2d2c]
 > /usr/lib64/nginx/modules/ngx_http_image_filter_module.so(_init+0x1b88) [0x3148]
 > /usr/sbin/nginx(ngx_http_write_filter+0xdedf) [0x8ca7f]
 > /usr/sbin/nginx(ngx_http_write_filter+0xe72c) [0x8d2cc]
 > /usr/sbin/nginx(ngx_output_chain+0x8f8) [0x25de8]
 > /usr/sbin/nginx(ngx_http_write_filter+0x1095e) [0x8f4fe]
 > /usr/sbin/nginx(ngx_http_write_filter+0x110fe) [0x8fc9e]
 > /usr/sbin/nginx(ngx_http_output_filter+0x2a) [0x5b53a]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0xb8e) [0x9881e]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_internal_redirect+0x129) [0x5c7b9]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x4d28) [0x9c9b8]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
sendfile(3<TCP:[789563]>, 4</usr/share/nginx/html/index.html>, [0] => [3700], 3700) = 3700
 > /usr/lib64/libc-2.17.so(sendfile+0xa) [0xedd6a]
 > /usr/sbin/nginx(ngx_linux_sendfile_chain+0x28d) [0x4b40d]
 > /usr/sbin/nginx(ngx_http_write_filter+0x4f0) [0x7f090]
 > /usr/sbin/nginx(ngx_http_write_filter+0x1786) [0x80326]
 > /usr/sbin/nginx(ngx_http_write_filter+0x53cc) [0x83f6c]
 > /usr/sbin/nginx(ngx_http_write_filter+0x86ec) [0x8728c]
 > /usr/sbin/nginx(ngx_http_write_filter+0xbbea) [0x8a78a]
 > /usr/lib64/nginx/modules/ngx_http_xslt_filter_module.so(_init+0x158c) [0x2d2c]
 > /usr/lib64/nginx/modules/ngx_http_image_filter_module.so(_init+0x1b88) [0x3148]
 > /usr/sbin/nginx(ngx_http_write_filter+0xdedf) [0x8ca7f]
 > /usr/sbin/nginx(ngx_http_write_filter+0xe72c) [0x8d2cc]
 > /usr/sbin/nginx(ngx_output_chain+0x8f8) [0x25de8]
 > /usr/sbin/nginx(ngx_http_write_filter+0x1095e) [0x8f4fe]
 > /usr/sbin/nginx(ngx_http_write_filter+0x110fe) [0x8fc9e]
 > /usr/sbin/nginx(ngx_http_output_filter+0x2a) [0x5b53a]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0xb8e) [0x9881e]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_internal_redirect+0x129) [0x5c7b9]
 > /usr/sbin/nginx(ngx_http_v2_huff_encode+0x4d28) [0x9c9b8]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0x7a) [0x5ba1a]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
write(16</var/log/nginx/access.log>, "192.168.33.1 - - [08/Nov/2017:05:33:40 +0000] \"GET / HTTP/1.1\" 200 3700 \"-\" \"curl/7.52.1\" \"-\"\n", 94) = 94
 > /usr/lib64/libpthread-2.17.so(__write_nocancel+0x7) [0xe690]
 > /usr/sbin/nginx(ngx_http_parse_chunked+0x20f4) [0x685a4]
 > /usr/sbin/nginx(ngx_http_parse_chunked+0x28aa) [0x68d5a]
 > /usr/sbin/nginx(ngx_http_filter_finalize_request+0x110) [0x5e030]
 > /usr/sbin/nginx(ngx_http_free_request+0xbc) [0x5fccc]
 > /usr/sbin/nginx(ngx_http_block_reading+0x313) [0x608f3]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0xcb) [0x5ba6b]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
close(4</usr/share/nginx/html/index.html>) = 0
 > /usr/lib64/libpthread-2.17.so(__close_nocancel+0x7) [0xe750]
 > /usr/sbin/nginx(ngx_pool_cleanup_file+0x19) [0x23199]
 > /usr/sbin/nginx(ngx_destroy_pool+0x1e) [0x232ae]
 > /usr/sbin/nginx(ngx_http_free_request+0x121) [0x5fd31]
 > /usr/sbin/nginx(ngx_http_block_reading+0x313) [0x608f3]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0xcb) [0x5ba6b]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
setsockopt(3<TCP:[789563]>, SOL_TCP, TCP_CORK, [0], 4) = 0
 > /usr/lib64/libc-2.17.so(setsockopt+0xa) [0xf946a]
 > /usr/sbin/nginx(ngx_tcp_push+0x36) [0x44d36]
 > /usr/sbin/nginx(ngx_http_block_reading+0xac1) [0x610a1]
 > /usr/sbin/nginx(ngx_http_core_content_phase+0xcb) [0x5ba6b]
 > /usr/sbin/nginx(ngx_http_core_run_phases+0x25) [0x55ce5]
 > /usr/sbin/nginx(ngx_http_process_request+0xae) [0x6225e]
 > /usr/sbin/nginx(ngx_http_process_request+0xa8c) [0x62c3c]
 > /usr/sbin/nginx(ngx_os_specific_status+0xb61) [0x4a771]
 > /usr/sbin/nginx(ngx_process_events_and_timers+0x6a) [0x401da]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
recvfrom(3<TCP:[789563]>, "", 1024, 0, NULL, NULL) = 0
 > /usr/lib64/libpthread-2.17.so(recv+0x1d) [0xea3d]
 > /usr/sbin/nginx(ngx_unix_recv+0x62) [0x44dc2]
 > /usr/sbin/nginx(ngx_http_process_request+0x14fa) [0x636aa]
 > /usr/sbin/nginx(ngx_event_process_posted+0x53) [0x40783]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]
close(3<TCP:[789563]>)                  = 0
 > /usr/lib64/libpthread-2.17.so(__close_nocancel+0x7) [0xe750]
 > /usr/sbin/nginx(ngx_close_connection+0x130) [0x30800]
 > /usr/sbin/nginx(ngx_http_close_connection+0x50) [0x5ea30]
 > /usr/sbin/nginx(ngx_event_process_posted+0x53) [0x40783]
 > /usr/sbin/nginx(ngx_dlerror+0x9e5) [0x47da5]
 > /usr/sbin/nginx(ngx_spawn_process+0x18a) [0x4670a]
 > /usr/sbin/nginx(ngx_dlerror+0xca0) [0x48060]
 > /usr/sbin/nginx(ngx_master_process_cycle+0x46d) [0x491bd]
 > /usr/sbin/nginx(main+0x899) [0x20889]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x21c05]
 > /usr/sbin/nginx(_start+0x29) [0x20c1e]

ソケットプログラミングのお勉強になる

感想

  • ソースコードリーディングがはかどる
  • 障害や不具合解決でもはかどりそう。事例ができたら紹介したい
  • だがしかし、experimental なのでディストリビューションではサポートされない可能性が高いため、ビルドが面倒だ

脇道の話: コミットの歴史

strace-plus として fork されていたコードが本家に還元されたという経緯があるらしい

github.com

Based on the code that was originally taken from strace-plus of Philip J. Guo. とのこと

だがしかし strace-plus は既に閉じてしまったプロジェクトだ https://code.google.com/archive/p/strace-plus/

Disclaimer: As of Jan 2012, this project is unsupported. Features from strace-plus have been merged into the official strace as the -k option, starting from version 4.9."