PHP-FPM request duration climbing: spotting stuck and outlier workers

When you pull ?full from the PHP-FPM status page during an incident and the request duration column looks alarming, verify your units first. The field is microseconds, not seconds or milliseconds, and it is the single most misread value in the FPM status surface. A worker showing 4500000 has been running for 4.5 seconds, not 4.5 million seconds. Convert before you escalate.

The second trap is interpretation. request duration has two meanings depending on worker state. For Running workers, it is the elapsed time of the current in-flight request. For Idle workers, it is the duration of the last completed request that worker handled. A pool full of idle workers showing high durations is not stuck. It served slow requests in the past and is now waiting for new work.

Once units and semantics are right, the value of this field is in distribution analysis. The aggregate active processes and listen queue counters tell you whether the pool is saturated. Per-worker request duration tells you why: a bimodal split between fast cached hits and slow rebuilds, a uniform shift suggesting a systemic backend slowdown, or a handful of outlier workers running 10x the median, which localises the problem to specific endpoints or stuck connections.

What this means

In a process-based concurrency model where each worker handles exactly one request at a time, longer durations directly reduce effective throughput. A pool of 50 workers serving requests at 50ms each handles roughly 1000 requests per second. The same pool serving 5-second requests collapses to 10 requests per second, even when CPU is nearly idle.

The request duration field is only available in ?full mode, which returns per-process detail: PID, state, start time, requests served, request duration, request method, request URI, content length, user, script, last request CPU, and last request memory. The non-full status page gives pool-level aggregates only.

For Idle workers, last request cpu and last request memory show the CPU and memory profile of the most recent completed request. For Running workers, these fields are zero because the calculation runs at request completion. This means CPU and memory correlation works on Idle workers only, but the request duration on Running workers is what tells you which in-flight requests are stuck.

flowchart TD
    A["Pull ?full status"] --> B{"Worker state?"}
    B -->|"Running / Reading / Finishing"| C["request duration = current elapsed time"]
    B -->|"Idle"| D["request duration = last completed request"]
    C --> E["High value = in-flight slow or stuck request"]
    D --> F["High value = served slow request in past, now idle"]
    E --> G["Investigate: script, last request cpu, last request memory"]
    F --> H["Not actionable unless slow log correlates"]

Common causes

Quick checks

# Fetch per-worker detail in JSON for parsing
curl -s "http://127.0.0.1/fpm-status?json&full" -o /tmp/fpm-full.json

# List Running workers sorted by request duration, converted to seconds
curl -s "http://127.0.0.1/fpm-status?json&full" | python3 -c "
import sys, json
d = json.load(sys.stdin)
running = [p for p in d['processes'] if p['state'] == 'Running']
for p in sorted(running, key=lambda x: -x['request duration'])[:20]:
    print(f\"{p['request duration']/1e6:8.3f}s pid={p['pid']} cpu={p['last request cpu']} mem={p['last request memory']} {p['request uri']}\")"

# Cross-check state distribution
curl -s "http://127.0.0.1/fpm-status?json&full" | python3 -c "
import sys, json, collections
d = json.load(sys.stdin)
c = collections.Counter(p['state'] for p in d['processes'])
for s, n in c.most_common():
    print(f'{n:4d} {s}')"

# Recent slow log entries (requires request_slowlog_timeout configured)
tail -100 /var/log/php-fpm/slow.log

# Confirm safety net timeouts are set
php-fpm -tt 2>&1 | grep -E 'request_terminate_timeout|request_slowlog_timeout|slowlog'

# Inspect what a specific long-running worker is waiting on (read-only)
PID=12345
cat /proc/$PID/wchan
cat /proc/$PID/status | grep -E 'State|VmRSS'
# strace attaches to the running process; use a short timeout, do not leave it attached
sudo timeout 2 strace -p $PID -e trace=network,read,write -f 2>&1 | head -20

How to diagnose it

1. Confirm the units. Convert every request duration value to seconds by dividing by 1,000,000 before reasoning about it. A fast endpoint showing values in the hundreds of thousands of microseconds is a sub-second request.

2. Split by worker state. Filter the ?full output by state. Treat Idle workers as historical context. Focus diagnosis on Running workers, and check for any workers stuck in intermediate states like Finishing.

3. Compute the median and look for outliers. A single worker running 10x the median is a different problem from all workers running 3x the median. Multiple workers showing durations more than 10x the pool median indicates outliers worth investigating.

4. Correlate with script. Group Running workers by their script field. If long durations cluster on one PHP file, the problem is endpoint-specific (slow query, missing index, expensive loop). If they spread across many scripts, the problem is systemic (database failover, DNS, storage).

5. Correlate with last request cpu. This field is only meaningful for Idle workers. Long duration with high CPU on a prior request means compute-bound. Long duration with low CPU means I/O-bound. A long in-flight Running request with no historical CPU data is the signature of a worker blocked on a network or filesystem syscall.

6. Correlate with last request memory. Same caveat: only populated for Idle workers. A worker whose last request consumed unusually high memory may have hit an expensive code path (report generation, large export, unbatched query).

7. Match against the slow log. The slow log captures stack traces for requests exceeding request_slowlog_timeout. Each entry shows the exact script and call stack where the worker was blocked. The slow log is more diagnostic than request duration alone because it points to the line of code, not just the script file.

8. Check for orphaned workers. If nginx has a shorter fastcgi_read_timeout than FPM’s request_terminate_timeout, nginx returns 504 to the client but the FPM worker continues processing. These phantom workers show high duration and low CPU because they are still waiting on the same slow dependency. Confirm by correlating nginx 504 timestamps with FPM worker start times.

9. Check for workers in undocumented states. The PHP manual documents Idle and Running, but operators have reported workers stuck in Finishing or other intermediate states.

Metrics and signals to monitor

Fixes

The right fix depends on which pattern the diagnosis surfaced. Restarting FPM is rarely the right first move: it clears the symptom, loses opcache warmth, and the underlying cause recurs as soon as traffic returns.

Endpoint-specific slow requests

If long durations cluster on one script and the slow log shows blocking inside a specific function, the fix is in the application or its dependencies. Check for missing database indexes, unbatched queries, synchronous calls to slow external APIs, or expensive loops. Recycling the affected workers with kill -SIGQUIT <pid> provides immediate capacity relief while you work the root cause.

SIGQUIT to a worker that is genuinely stuck on a syscall may not interrupt it. If the worker does not exit, request_terminate_timeout is the safety net.

Systemic backend slowdown

If long durations spread across all scripts and historical CPU is low, the problem is downstream. Check the database, cache, or external API the application depends on. Increasing pm.max_children buys time only if the dependency recovers quickly and memory headroom exists. If the dependency stays slow, new workers get stuck too.

Stuck workers in non-Running states

If workers are stuck in Finishing or other intermediate states indefinitely, request_terminate_timeout is the correct safety net. Set it to a value aligned with your application’s expected maximum request time (typically 30 to 60 seconds).

request_terminate_timeout kills workers mid-request. The client receives an error. It does not fix the underlying cause; it prevents stuck workers from accumulating.

nginx and FPM timeout mismatch

If diagnosis shows phantom workers (nginx already returned 504 but FPM workers are still Running), align the timeouts. FPM’s request_terminate_timeout should be shorter than nginx’s fastcgi_read_timeout, so FPM kills abandoned work before nginx gives up.

Session lock contention

If long durations correlate with AJAX endpoints and the slow log shows blocking at session_start, the fix is in the application. Call session_write_close() as early as possible, or move sessions to Redis or Memcached which have different locking semantics. File-based sessions take an exclusive lock at session_start and hold it until the request ends or session_write_close() is called.

Opcache-driven bimodal distribution

If the distribution splits between fast cached hits and slow rebuilds, check opcache. A hit rate below 99% after warmup means PHP is recompiling scripts, which adds latency and CPU cost uniformly. Verify opcache.validate_timestamps = 0 in production, check opcache.memory_consumption is large enough for the codebase, and confirm opcache.max_accelerated_files exceeds the number of PHP files.

Prevention

• Read the field in microseconds. Build the unit conversion into any tooling that parses ?full output. A wrapper script that divides by 1,000,000 before display prevents the most common misread.
• Enable the slow log on every production pool. request_slowlog_timeout defaults to 0 (disabled). Without it, high request durations are unexplained. Even 5 to 10 seconds is enough to capture blocking stack traces during incidents.
• Set request_terminate_timeout. A finite value prevents permanently stuck workers from accumulating and silently eroding pool capacity.
• Align nginx and FPM timeouts. FPM’s request_terminate_timeout should fire before nginx’s fastcgi_read_timeout to avoid phantom workers.
• Monitor distribution, not just aggregates. Track p50, p95, and p99 of per-worker request duration. The aggregate active processes counter hides bimodal distributions and outlier workers.
• Correlate with state. Alert on workers stuck in non-Running states for longer than a threshold, not on Idle workers showing historical durations.

How Netdata helps

Netdata’s PHP-FPM collector pulls the status page at per-second resolution, which matters because saturation events unfold in seconds and 10-second polling misses transient queue buildup.

• Per-second collection of active processes, idle processes, and listen queue surfaces the leading indicators of worker drain before 502s reach users.
• Anomaly detection on request duration and active process count flags shifts in distribution that aggregate thresholds miss, including bimodal patterns and outlier-driven plateaus.
• Correlation with downstream services (database query latency, Redis response time, external API latency in the same dashboard) shortens the path from “workers are slow” to “the database is slow”.
• Slow log and error log parsing surface the stack traces that explain why specific workers are stuck, alongside the metrics that show how many workers are affected.
• Per-pool dashboards keep multi-pool deployments honest. A slow leak in one pool does not get lost in aggregates across all pools.

Related guides

• PHP-FPM active processes near max_children: reading pool utilization
• How PHP-FPM actually works in production: a mental model for operators
• PHP-FPM idle processes at zero: no burst headroom left
• PHP-FPM listen queue growing: the earliest signal of saturation
• PHP-FPM “server reached pm.max_children setting (N), consider raising it”
• PHP-FPM monitoring checklist: the signals every production pool needs
• PHP-FPM monitoring maturity model: from survival to expert
• PHP-FPM sizing pm.max_children: by memory, not by CPU cores
• PHP-FPM slow request cascade: one slow dependency drains the whole pool
• PHP-FPM worker exhaustion: all workers busy and requests piling into the backlog