ビジーなプロセスのデバッグ

時々、php start.php statusコマンドでbusy状態のプロセスが表示されることがあります。これは対応するプロセスが処理中であることを示します。通常、処理が完了するとプロセスはidle状態に戻りますが、継続してbusy状態が続く場合は、プロセス内の処理がブロックされているか無限ループに陥っている可能性があります。以下の方法を使用して問題を特定できます。

strace+lsofコマンドを使用した特定

1. busyプロセスのpidをstatusから見つける
php start.php statusを実行した後、次のように表示されます。

図の中でbusyのプロセスのpid1172511748です。

2. straceでプロセスをトレース
プロセスの中から1つのpidを選択します(この例では11725)、そしてstrace -ttp 11725を実行して以下が表示されます。

プロセスがpoll([{fd=16、events=....というシステムコールを繰り返し呼び出していることがわかります。これはfdが16のディスクリプタが読み取り可能なイベントを待っており、つまりこのディスクリプタからデータを返すのを待っています。

システムコールが表示されない場合は、現在の端末を保持したまま、新しい端末を開いてkill -SIGALRM 11725(プロセスにアラームシグナルを送信)を実行し、straceの端末に応答があるか、あるいは特定のシステムコールでブロックされているかを確認します。それでもシステムコールが表示されない場合は、プログラムがおそらくビジネス・デッドロックにあることを意味し、次の項目2の解決策を参照してください。

プログラムがepoll_waitまたはselectのシステムコールでブロックされている場合は正常です。これはプロセスがidle状態であることを示します。

3. lsofでプロセスのディスクリプタを確認
lsof -nPp 11725を実行すると、以下が表示されます。

ディスクリプタ16に対応するのは16uレコード(最後の行)で、fd = 16に対するディスクリプタはtcp接続で、リモートアドレスは101.37.136.135:80であり、つまりプロセスはhttpリソースにアクセスしていることがわかります。そして、poll([{fd=16, events=....がhttpサーバーからのデータを待ち続けていることを説明しているので、プロセスがbusy状態にある理由がわかります。

解決策:
プロセスがどこでブロックされているかがわかったら、解決方法は簡単です。例えば、上記の場合はビジネスがcurlを呼び出しており、対応するURLが長時間データを返さないため、プロセスがずっと待機しています。この時はURLのプロバイダーに接続して、遅れる原因を特定し、同時にcurl呼び出し時にタイムアウトパラメータを付け加えて、たとえば2秒でデータを返さなければタイムアウトするようにして、長時間のブロックが避けられるようにします(その場合プロセスにはおおよそ2秒のビジー状態が発生する可能性があります)。

プロセスが長時間busyになる他の原因

プロセスがbusy状態になるのは、プロセスがブロックされるか、以下の原因がある場合があります。

1. ビジネスに致命的なエラーが発生し、プロセスが繰り返し終了する
現象: このような場合は、システムの負荷が比較的高く、statusの中のload averageが1以上であることがわかります。プロセスのexit_countの数字が非常に高く、増加し続けることがわかります。
解決策: デバッグモード(php start.php start-dを付けずに実行)でWorkermanを実行して、ビジネスのエラーを確認し、エラーを解決します。

2. コード内で無限ループが発生している
現象: topコマンドでビジーなプロセスがCPUを大量に使用していることがわかります。strace -ttp pidコマンドでシステムコール情報が表示されません。
解決策: 鳥哥の文を参考にして、gdbとPHPのソースコードを使用して位置を特定します。手順の概要は以下のようになります:

  1. php -vでバージョンを確認
  2. 対応するPHPバージョンのソースコードをダウンロード
  3. gdb --pid=busyプロセスのpidを実行
  4. source phpソースコードのパス/.gdbinitを実行
  5. zbacktraceを実行して呼び出しスタックを印刷する
    最後のステップで、現在のPHPコードの呼び出しスタックを表示し、つまりPHPコードの無限ループの位置が分かります。
    注意:zbacktraceで呼び出しスタックが表示されない場合は、PHPのコンパイル時に-gフラグが指定されていない可能性があります。その場合はPHPを再コンパイルして、Workermanを再起動して位置を特定します。

3. タイマーが無限に追加される
ビジネスコードが無限にタイマーを追加し続け、削除を行わないため、プロセス内でタイマーがますます多くなり、最終的にプロセスが無限に実行されてしまうことがあります。例えば以下のコード:

$worker = new Worker;
$worker->onConnect = function($con){
    Timer::add(10, function(){});
};
Worker::runAll();

このコードはクライアントが接続したら、タイマーを追加しますが、ビジネスコード全体にはタイマーを削除するロジックが含まれていないため、時間が経つにつれてプロセス内のタイマーが続々と増加し、最終的にプロセスが無限にタイマーを実行してしまうことになります。
正しいコードは次のようになります:

$worker = new Worker;
$worker->onConnect = function($con){
    $con->timer_id = Timer::add(10, function(){});
};
$worker->onClose = function($con){
    Timer::del($con->timer_id);
};
Worker::runAll();