El problema
Estoy ejecutando PHP-FPM 7.4.30 bajo Apache 2.4 en RHEL 8 y no puedo hacer que el registro lento de PHP funcione correctamente. No devolverá información válida sobre scripts de larga duración.
Cuando habilito el registro lento, incluso con un valor alto durante request_slowlog_timeout10 segundos o más, veo que aparecen muchas entradas en el registro, incluidos scripts que sé que no duran mucho tiempo. La lista aparece aleatoria y muestra rastros de una gran variedad de scripts y funciones dentro de ellos. No hay ningún patrón obvio. Estoy seguro de que la información devuelta no es válida. Estos scripts simplemente no tardan tanto entre la solicitud y la devolución de un resultado a Apache.
Qué debería pasar
Según la documentación de PHP, el registro lento debería marcar sólo aquellos scripts que se ejecutaron durante más de un cierto tiempo desde elpedidoal servidor. En otras palabras, debe medir el tiempo entre la solicitud y el momento en que el script terminó de ejecutarse. Sin embargo, esto no es lo que sucede cuando habilito el registro lento.
Lo que parece estar pasando
Mi teoría es que el slowlog no mide el tiempo de ejecución desolicitudes individualesque vienen de Apache, sino más bien de la época en que unEl proceso hijo se ha estado ejecutando.. Dado que los procesos secundarios pueden ejecutarse durante un tiempo bastante prolongado, pueden parecer scripts de ejecución prolongada para el registro lento. Cuando el registro lento ve que un proceso secundario se ha ejecutado durante más de request_slowlog_timeout, genera un seguimiento del script que se está ejecutando actualmente (que podría ser cualquier cosa que se esté ejecutando en ese momento).
Mis preguntas
- ¿Por qué PHP-FPM muestra entradas no válidas como esta en el registro lento? ¿No es capaz de detectar el inicio de una solicitud?
- ¿Cómo configuro el registro lento para registrar solo lo previsto: el tiempo de ejecución de una única solicitud?
No he encontrado ningún otro informe sobre este problema, pero puedo generarlo cada vez que habilito el registro lento en un servidor de producción, así como en un servidor de prueba con un solo usuario.
Muchas gracias por cualquier idea o ayuda.
Respuesta1
¿Por casualidad encontraste una respuesta?
Tengo el mismo problema y he pasado horas intentando resolverlo. Es aún más confuso que el registro de errores de php-fpm tenga entradas como
ADVERTENCIA: [pool www] el niño 7559 salió en la señal 15 (SIGTERM) después de 166,818268 segundos desde el inicio
O
[19 de junio de 2023 16:24:56] ADVERTENCIA: [pool www] hijo 7646, secuencia de comandos '' (solicitud: " ") se agotó el tiempo de ejecución (66,168368 segundos), finalizando
Sin embargo, ese mismo PID no se encuentra en ninguna parte del registro lento antes de que llegue a request_terminate_timeout. La lógica parece dictar que una solicitud que se ejecutó durante más de 66 segundos antes de ser terminada también se registrará en el registro lento después de 10 segundos.
estoy perplejo