잘못된 결과를 반환하는 PHP-FPM 느린 로그

Question

문제

RHEL 8의 Apache 2.4에서 PHP-FPM 7.4.30을 실행하고 있는데 PHP의 느린 로그가 제대로 작동하지 않습니다. 장기 실행 스크립트에 대한 유효한 정보는 반환되지 않습니다.

느린 로그를 활성화하면(예: request_slowlog_timeout10초 이상 높은 값을 사용하더라도) 오래 실행되지 않는 스크립트를 포함하여 많은 항목이 로그에 표시됩니다. 목록은 무작위로 나타나며 그 안에 있는 다양한 스크립트와 함수에 대한 역추적을 표시합니다. 뚜렷한 패턴이 없습니다. 반환된 정보가 유효하지 않은 것으로 확신합니다. 이러한 스크립트는 요청과 Apache에 결과 반환 사이에 그리 오랜 시간이 걸리지 않습니다.

무슨 일이 일어나야 하는가

PHP 문서에 따르면 느린 로그는 해당 스크립트 이후 특정 시간 이상 실행된 스크립트에만 플래그를 지정해야 합니다.요구서버에 만들어졌습니다. 즉, 요청과 스크립트 실행 완료 사이의 시간을 측정해야 합니다. 그러나 느린 로그를 활성화하면 이런 일이 발생하지 않습니다.

무슨 일이 일어나고 있는 것 같나요?

내 이론은 느린 로그가 런타임을 측정하지 않는다는 것입니다.개별 요청이는 Apache에서 왔지만 그 당시에는자식 프로세스가 실행 중입니다.. 하위 프로세스는 꽤 오랜 시간 동안 실행될 수 있으므로 느린 로그에 대해 오랫동안 실행되는 스크립트처럼 보일 수 있습니다. 느린 로그에서 하위 프로세스가 1시간 이상 실행된 것을 확인하면 request_slowlog_timeout현재 실행 중인 스크립트(해당 시간에 실행 중인 모든 스크립트일 수 있음)의 역추적을 출력합니다.

내 질문

1. PHP-FPM이 느린 로그에 이와 같은 잘못된 항목을 표시하는 이유는 무엇입니까? 요청의 시작을 감지할 수 없나요?
2. 의도한 것(단일 요청의 실행 시간)만 기록하도록 느린 로그를 어떻게 구성합니까?

이 문제에 대한 다른 보고서는 찾지 못했지만 프로덕션 서버와 사용자가 한 명뿐인 테스트 서버에서 느린 로그를 활성화할 때마다 보고서를 생성할 수 있습니다.

통찰력이나 도움을 주셔서 대단히 감사합니다.

Answer 1

우연히 답을 찾았나요?

나는 같은 문제가 있으며 그것을 알아 내려고 몇 시간을 보냈습니다. php-fpm 오류 로그에 다음과 같은 항목이 있다는 것은 더욱 혼란스럽습니다.

경고: [풀 www] 하위 7559가 시작 후 166.818268초 후에 신호 15(SIGTERM)에서 종료되었습니다.

또는

[2023년 6월 19일 16:24:56] 경고: [풀 www] 하위 7646, 스크립트 ''(요청: " ") 실행 시간이 초과되었습니다(66.168368초). 종료 중

그러나 request_terminate_timeout에 도달하기 전에는 동일한 PID가 느린 로그에서 발견되지 않습니다. 논리는 종료되기 전에 66초 이상 실행된 요청이 10초 후에 느린 로그에 기록되도록 지시하는 것 같습니다.

나는 어리둥절하다