How to Trace a Slow PHP Request to the Actual SQL Query

A PHP-FPM slow log shows where a request was paused, but it usually does not show the SQL query that caused the delay. To diagnose the real problem, correlate PHP-FPM request data with the database slow-query log.

Why it happens

A stack trace that ends near a database call is a useful clue, not a complete diagnosis. It tells you which PHP code path was active. It does not prove whether the cause was an inefficient query, a lock wait, database overload, or slow work elsewhere.

Use two logs together

1. Record the request in PHP-FPM. Include the request URI, worker PID, duration, memory use, and timestamp in the pool access log.

2. Keep the PHP-FPM slow log enabled. A short threshold and a deeper trace can reveal the plugin, theme, or application function active during the delay.

3. Temporarily enable the database slow-query log. Use a cautious threshold, such as one second, and keep the capture window short.

4. Reproduce one slow request. Match the PHP and database records by time, database, request path, and query text.

5. Inspect the captured query. Use EXPLAIN for a slow SELECT, or investigate the blocking transaction when the process list shows a lock wait.

Useful PHP-FPM settings

slowlog = /path/to/php-fpm-slow.log
request_slowlog_timeout = 3s
request_slowlog_trace_depth = 50

access.log = /path/to/php-fpm-access.log
access.format = "%t pid=%p method=%m uri=%r%Q%q status=%s duration_ms=%{milliseconds}d memory_mb=%{megabytes}M"

Validate the PHP-FPM configuration before reloading the service. Access-log entries may appear only after a request finishes.

Capture slow database queries briefly

SET GLOBAL log_output = 'FILE';
SET GLOBAL long_query_time = 1;
SET GLOBAL slow_query_log = ON;

Save the original database settings first and restore them after the test. Slow-query logs can grow quickly and may contain application data.

Common mistakes

• Cause: Treating a PHP stack frame as proof of a bad query. Fix: Capture the SQL and its timing before changing code or indexes.

• Cause: Trying to match a PHP worker PID to a database connection ID. Fix: Correlate by timestamp, database, request path, and query text; the identifiers are unrelated.

• Cause: Waiting only for the slow-query log. Fix: Use SHOW FULL PROCESSLIST while the request is still slow to catch active queries and lock waits.

• Cause: Leaving detailed logging enabled indefinitely. Fix: Capture for a few minutes, restore the previous settings, and remove sensitive log data when finished.

Account for database sessions and overlapping traffic

A global slow-query threshold normally becomes the default for new database sessions; existing pooled connections may keep their previous session value. Verify the setting in the connection used for the reproduction. Timestamps alone become ambiguous under load, so use a short isolated capture or application tracing to connect the request to its query.

The reliable path is request, stack, SQL, then query plan. Next, capture one slow request and compare its PHP-FPM access entry with the matching database slow-query record.

Reference: MariaDB slow query log.