2

CPU 使用率が 100% になり、決して終了しない Apache プロセスがときどきあります。これが 8 回 (8 CPU) 発生すると、サーバーは使用できなくなります。サーバーステータスによると、「ハング」したプロセスはかなり複雑なカスタム Perl プログラムですが、Perl 内のエラー ログに警告を出力すると、プロセスが常に完了して戻ることが示されますが、明らかに戻った後に、ループか何かに入ります。プロセスで strace を実行すると、大量の mmap2/munmap 行が表示されます。

mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4329472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d7000
mremap(0xb3d7c000, 4329472, 4333568, MREMAP_MAYMOVE) = 0xb3d7c000
munmap(0xb42d7000, 4329472)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000
munmap(0xb42d6000, 4333568)             = 0
mmap2(NULL, 4333568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb42d6000

それが何を意味するのかわかりません。これは無期限に行われます。それが何をしているかのより高いレベルのビューを取得する方法はありますか? 誰もこれに似たものを見たことがありますか？

また、通常はかなりランダムな偶然ですが、Perl プログラムを終了する前に rflush() を発行すると、ほぼ常に発生します。

mod_perl/2.0.7、perl/5.12.4、apache/2.2.24 を使用しています。これは、いくつかのマイナー バージョンでも発生していました。アップグレードしましたが、何も改善されませんでした。DBI、DBD:ODBC も使用しています。

私の最善の推測は、ある種の競合/競合状態ですが、「warn」出力でコードをトレースすると、Perl 自体にそのような問題がないことが示されます。また、Perl コードは、トリップしないタイムアウト アラーム シグナルで評価を使用するため、Perl コードで問題になる可能性はないようです。

どんなアイデアでも大歓迎です。

4

1 に答える 1

0

私はそれを解決したと思います。なぜ rflush() がそれを悪化させたのか、また strace 結果のより高いレベルのビューを見つけられなかったのかはまだわかりませんが、これがそれを行っていた理由です:

ある時点で、次のコードを「エラー」サブルーチンに追加しました。このサブルーチンは、プログラムが内部エラーを検出するたびに呼び出されます。

my $caller = "";
my $x = 1;
while (caller($x) && $x < 10)
{
        my $subroutine = (caller($x))[3];
        $subroutine =~ s/^.*::([^:]+?)$/$1/gis;
        my $line = (caller($x))[2];
        $caller = qq~->$subroutine(line $line)~.$caller if $subroutine;
}
$caller = "main".$caller;

これは、エラーが発生したサブルーチンを出力するだけです。たとえば、プログラム本体で、サブルーチン「sub1」が 1234 行目から呼び出され、そこから「sub2」が 2345 行目から呼び出され、 3456 行目の「sub2」でエラーが発生すると、「error」サブルーチンは「main(1234 行)->sub1(2345 行)->sub2(3456 行)」でエラーが発生したことを通知します。これは明らかにデバッグにとって重要です。残念ながら、「エラー」サブルーチン自体のデバッグには役立ちません!

「while」ループでは、$x < 10 であることを確認します (10 レベルのサブルーチン呼び出しがあってはなりません)。これは、暴走反復を防ぐためのものです。残念ながら、変数 $x を実際にインクリメントする行がありません。これが意味することは、$x は常に = 1 であるため、$x < 10 を無期限にチェックし続けるということです。これに関するトリッキーな部分は、「エラー」サブルーチンがシグナル トラップ ハンドラから呼び出され、明らかにメイン プログラムからフォークされることです。そのため、プログラムの本体が終了したように見える間に、「エラー」サブルーチンがこの無限ループで実行される可能性があります。そのため、何が起こっているかを直線的に「印刷」または「警告」することができず、大きな混乱を招いていました。これにより、この無限ループが、タイムアウトのあるメインの「eval」の外で実行されるようになりました。そのため、タイムアウトによってループが停止することはありませんでした。プログラムは最後の行と出力まで完了しましたが、シグナル ハンドラのこの無限ループにより、プログラムを処理していたプロセスが CPU を 100% 消費し続けました。

解決策は、「$x++」という 4 文字だけです。while ループ内にそれを追加すると、無限の反復が防止され、実際にはシグナル ハンドラーからのデバッグ情報が出力されます。

于 2013-04-22T21:41:57.687 に答える