[Linux] どのプロセスが暴走しているか突き止める - pidstat編

時折りサーバ内で暴力的なI/Oが発生してまして、その度にMackerelからのアラートで人力再起動させられる生活に疲れたので原因を究明することにしました。

もうこうなってしまうとTerminalからログインすることも出来ず、AWSのWebコンソールから再起動をしています。調査方法は色々あると思うのですが今回は数分で設定できるpidstatを仕掛けることにしました。

取り戻せ平穏な日常。

プロセスの監視
pidstatの使い方
参考ページ

プロセスの監視

pidstatは秒数を引数として与えると、その時間の間にどのプロセスがどの程度リソースを利用したか統計情報を表示してくれるコマンドです。これをバックグラウンド動かし続け監視を行います。

pidstatのインストール

pidstatはsysstatに含まれていますので、まずはこいつをインストールします。

$ sudo yum install sysstat

入りましたね。

$ pidstat -V
sysstat バージョン 9.0.4
(C) Sebastien Godard (sysstat <at> orange.fr)

pidstatをバックグラウンドで実行

適当なディレクトリを作成するか、/var/logあたりにログを記録します。disownコマンドは指定したジョブをバックグラウンドで動作させる物です。

以下のコマンドで180秒毎にCPU使用率に関する統計情報を記録してくれます。バックグラウンドで動作させていますのでTerminalは閉じてしまって大丈夫です。

$ mkdir log
$ pidstat -u 180 > ./log/pidstat.log & disown $!

実際には以下のような内容が記録されます。

$ tail -f log/pidstat.log 
Linux 4.14.88-72.73.amzn1.x86_64 (ip-172-xxx-xxx-xxx)   2019年03月26日     _x86_64_    (1 CPU)

01時13分22秒       PID    %usr %system  %guest    %CPU   CPU  Command
01時16分22秒         7    0.00    0.01    0.00    0.01     0  ksoftirqd/0
01時16分22秒         8    0.01    0.00    0.00    0.01     0  rcu_sched
01時16分22秒      2330    0.01    0.00    0.00    0.01     0  rngd
01時16分22秒      2528    0.00    0.01    0.00    0.01     0  memcached
01時16分22秒      2562    0.01    0.00    0.00    0.01     0  ntpd
01時16分22秒      3362    0.01    0.01    0.00    0.01     0  mackerel-agent
01時16分22秒      3507    0.01    0.00    0.00    0.01     0  bash

実行を停止する

killで殺します。

$ ps 
  PID TTY          TIME CMD
 3507 pts/0    00:00:00 bash
 6226 pts/0    00:00:00 pidstat
16092 pts/0    00:00:00 ps

$ kill 6226

pidstatの使い方

ディスクI/Oを計測

-dオプションを利用します。

$ pidstat -d 60
Linux 4.14.88-72.73.amzn1.x86_64 (ip-172-xxx-xxx-xxx)   2019年03月26日     _x86_64_    (1 CPU)

02時31分19秒       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command
02時32分19秒      6226      0.00      0.07      0.00  foobar

指定したコマンドのみ計測

大文字の-Cに続けてコマンドの文字列を指定します。

$ pidstat -C httpd 30
Linux 4.14.88-72.73.amzn1.x86_64 (ip-172-xxx-xxx-xxx)   2019年03月26日     _x86_64_    (1 CPU)

02時37分06秒       PID    %usr %system  %guest    %CPU   CPU  Command
02時37分36秒     15483    0.10    0.07    0.00    0.17     0  httpd
02時37分36秒     15520    0.20    0.00    0.00    0.20     0  httpd
02時37分36秒     15526    1.14    0.17    0.00    1.30     0  httpd
02時37分36秒     15540    0.17    0.00    0.00    0.17     0  httpd

指定したプロセスのみ計測

-pオプションにプロセスIDを指定します。カンマ(,)で区切ると複数の指定が可能です。

$ pidstat -p 6633,7251 30
Linux 4.14.88-72.73.amzn1.x86_64 (ip-172-26-11-162)     2019年03月26日     _x86_64_    (1 CPU)

02時43分55秒       PID    %usr %system  %guest    %CPU   CPU  Command
02時44分25秒      6633    0.00    0.00    0.00    0.00     0  mysqld_safe
02時44分25秒      7251    0.33    0.07    0.00    0.40     0  mysqld

コマンドを引数付きで表示

-lオプションを付加します。

$ pidstat -u 30 -l
Linux 4.14.88-72.73.amzn1.x86_64 (ip-172-26-11-162)     2019年03月26日     _x86_64_    (1 CPU)

02時46分41秒       PID    %usr %system  %guest    %CPU   CPU  Command
02時47分11秒        22    0.00    0.03    0.00    0.03     0  kworker/0:1
02時47分11秒      2562    0.03    0.00    0.00    0.03     0  ntpd -u ntp:ntp -p /var/run/ntpd.pid -g 
02時47分11秒      3362    0.00    0.03    0.00    0.03     0  /usr/bin/mackerel-agent --pidfile=/var/run/mackerel-agent.pid --root=/var/lib/mackerel-agent -child 
02時47分11秒      7251    0.07    0.03    0.00    0.10     0  /usr/libexec/mysql57/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql57/plugin --user=mysql --log-e
02時47分11秒     15527    0.03    0.00    0.00    0.03     0  /usr/sbin/httpd 
02時47分11秒     15784    0.20    0.00    0.00    0.20     0  /usr/sbin/httpd 
02時47分11秒     15809    0.20    0.00    0.00    0.20     0  /usr/sbin/httpd 
02時47分11秒     15852    0.03    0.00    0.00    0.03     0  /usr/sbin/httpd 
02時47分11秒     15901    0.00    0.03    0.00    0.03     0  pidstat -u 30 -l