PHP-FPM Slow Log: When Request Duration Lies

We run PHP 8.1 with PHP-FPM and Nginx on AWS, handling about 500 req/s across 12 FPM pools. Last month, the slow log flagged a batch of requests taking 5-8 seconds, but our application logs showed sub-second execution. Something was off.

I enabled the FPM slow log with request_slowlog_timeout = 2s and slowlog = /var/log/php-fpm/slow.log. The log entries pointed to fpm_get_status in the backtrace, which seemed odd. Digging deeper, I found that these slow requests were all hitting the status endpoint /status?full.

Our monitoring agent polled /status?full every 10 seconds. When the pool is under load, fpm_get_status iterates over all worker processes and their request details. With 50 workers per pool, that iteration can take seconds, especially if some workers are busy. The slow log captured the status request itself as slow, not the actual user requests.

To confirm, I ran a quick test: curl -w "%{time_total}\n" http://localhost/status?full while the pool was busy. It consistently took over 3 seconds. The fix was to use the simpler /status endpoint (without ?full) and increase the polling interval to 30 seconds. Also, I moved the status endpoint to a separate pool with fewer workers to isolate the overhead.

; Before
pm.status_path = /status
; After
pm.status_path = /status
; Monitoring now hits /status (no ?full)

Why does this happen? fpm_get_status with full collects per-request data from all workers, which requires locking and can block if workers are busy. The cost scales with the number of workers and their activity. The non-full endpoint only returns aggregate stats, which is much cheaper.

But this approach fails when you actually need per-request details for debugging. In that case, use ?full sparingly, perhaps only on a separate pool with a single worker. Also, the slow log itself adds overhead: each request timed out triggers a backtrace dump, which can be expensive if many requests are slow. Set request_slowlog_timeout wisely (we use 2s, but 5s might be safer for high-traffic pools).

Another gotcha: the slow log only captures the PHP backtrace at the moment of timeout, not the full request lifecycle. If the delay is in I/O (e.g., database or external HTTP), the backtrace might point to the blocking call, but not the cause. We once had a slow log pointing to PDOStatement::execute due to a missing index, but the actual query was fine under normal load; the delay was from lock contention during peak hours.

So, before you trust the slow log, check what’s actually slow. Are you logging the status endpoint? Are you using ?full? What’s your worker count? I’d like to hear how others balance monitoring granularity with overhead.