Apache 프로세스가 수행하는 작업을 추적하는 방법

Question

가끔 아파치 프로세스가 CPU 사용량의 100 %로 이동하여 종료되지 않습니다. 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도 사용하고 있습니다.

가장 좋은 추측은 일종의 경합/경쟁 조건이지만 "경고"출력을 사용하여 코드를 추적하면 Perl 자체에서 그러한 문제가 없음을 나타냅니다. Perl 코드는 절대로 절대로 작동하지 않는 시간 초과 경고 신호와 함께 evals를 사용하기 때문에 Perl 코드에서 문제가되는 것처럼 보이지 않습니다.

어떤 아이디어라도 높이 평가할 수 있습니다.

Answer 1

나는 그것을 해결했다고 생각합니다. 아직도 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 (line 1234) -> sub1 (2345 행) -> sub2 (3456 행) "입니다. 디버깅에 중요합니다. 불행히도, "오류"서브 루틴 자체를 디버깅하는 데 도움이되지 않습니다!

"while"루프에서 $ x(10 단계의 서브 루틴 호출이 있어서는 안됨)을 확인합니다. 이는 런 어웨이 반복을 방지하기위한 것입니다. 불행하게도 변수 $ x를 실제로 증가시키는 줄이 빠져 있습니다. 이것이 의미하는 바는 $ x always = 1이기 때문에 $ x <을 계속 유지할 것입니다.이 문제에 대한 까다로운 부분은 시그널 트랩 처리기에서 "error"서브 루틴이 호출되어 주 프로그램 프로그램 자체가 끝나는 것처럼 보이는 동안 "오류"서브 루틴이이 무한 루프에서 실행될 수 있습니다. 이로 인해 일어난 일에 대한 선형보기를 "인쇄"하거나 "경고"하는 것이 불가능하게되어 큰 혼란을 낳았습니다. 그것은 또한이 무한 루프가 타임 아웃을 가지고있는 나의 메인 "eval"의 외부에서 실행되도록 만들었습니다. 그래서 타임 아웃은 루프가 예상했던 것처럼 멈추지 않았습니다. 프로그램은 마지막 행과 출력으로 완료되었지만 서비스를 제공하는 프로세스는 신호 처리기의이 무한 루프로 인해 CPU의 100 %를 소비했습니다.

해결 방법은 "$ x ++"의 4 가지 문자입니다. while 루프 안에 추가하면 무한 반복을 방지하고 실제로 신호 처리기의 디버깅 정보를 출력 할 수 있습니다.