log in
consulting hosting industries the daily tools about contact
← All posts
· 6 min read · PHP-FPM

PHP-FPM Slow Log vs. MariaDB Slow Query Log: You Need Both

Two slow logs, two completely different blind spots. Here's what each one actually catches and why running only one gives you a false sense of confidence.

Most developers know about the MariaDB slow query log. Fewer bother with PHP-FPM's slow log. And almost nobody I've talked to understands that the two instruments measure completely different things — which means relying on only one leaves you half-blind when production starts dragging.

I've been burned by this more than once. Let me save you the same afternoon.

What Each Log Actually Measures

The MariaDB slow query log captures individual SQL queries that exceed a threshold you set. It tells you that a specific SELECT took 4.2 seconds, how many rows it examined, and whether it used an index. It knows nothing about what your application was doing between queries.

The PHP-FPM slow log captures the full PHP call stack of any request that exceeds a wall-clock threshold. It tells you that a particular FPM worker was stuck for 8 seconds and shows you exactly which function was executing when the clock ran out. It knows nothing about what happened inside MariaDB.

So: MariaDB sees inside the database. PHP-FPM sees inside the PHP process. Neither sees the other's world.

A request can be slow because:

  • One SQL query is a disaster (MariaDB catches this, FPM just sees "slow request")
  • You're firing 200 queries in a loop (MariaDB might catch each one if any crosses the threshold, but they could all be individually fast — FPM catches the aggregate pain)
  • You're doing a 6-second cURL call to a third-party API (neither MariaDB nor FPM tells you why, but FPM at least shows you the stack frame pointing at Guzzle)
  • You're processing a huge CSV upload and running out of memory mid-stream, causing swapping (FPM catches the wall time; MariaDB is irrelevant)

Setting Up PHP-FPM's Slow Log

This goes in your pool config. On a typical Ubuntu/Debian server it's in /etc/php/8.2/fpm/pool.d/www.conf (adjust for your PHP version):

; Log any request taking longer than this many seconds.
; Use 0 to disable. Decimals work: 1.5
request_slowlog_timeout = 2s

; Where to write it
slowlog = /var/log/php-fpm/slow.log

; Optional: capture a backtrace from the child process
; This requires --enable-fpm-backtrace at compile time (most distro builds include it)
request_slowlog_trace_depth = 20

Restart FPM and then watch the log:

tail -f /var/log/php-fpm/slow.log

When a request breaches the threshold, you'll get something like this:

[05-Jul-2025 14:32:11]  [pool www] pid 18432
script_filename = /var/www/myapp/public/index.php
[0x00007f3d4c017d30] curl_exec() /var/www/myapp/vendor/guzzlehttp/guzzle/src/Handler/CurlHandler.php:45
[0x00007f3d4c017c80] __invoke() /var/www/myapp/vendor/guzzlehttp/guzzle/src/Handler/Proxy.php:28
[0x00007f3d4c017bc0] __invoke() /var/www/myapp/vendor/guzzlehttp/guzzle/src/PrepareBodyMiddleware.php:38
...
[0x00007f3d4c0171a0] handle() /var/www/myapp/app/Http/Controllers/LabResultsController.php:94

Right there — line 94 of LabResultsController.php, waiting on a cURL call. MariaDB's slow log would have shown you nothing, because this request might not have touched the database at all.

Setting Up the MariaDB Slow Query Log

In /etc/mysql/mariadb.conf.d/50-server.cnf (or wherever your distro puts it):

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 1
log_queries_not_using_indexes = 1
min_examined_row_limit = 100

I set long_query_time = 1 in production for most apps. For a write-heavy OLTP system I'll sometimes drop it to 0.5. log_queries_not_using_indexes is gold — I've found more problems with that flag than with the time threshold alone. The min_examined_row_limit keeps it from logging every tiny lookup on a small table that happens to skip an index.

A slow query entry looks like:

# Time: 2025-07-05T14:28:47.123456Z
# User@Host: myapp[myapp] @ localhost [127.0.0.1]
# Query_time: 3.451892  Lock_time: 0.000187 Rows_sent: 1 Rows_examined: 892341
SET timestamp=1751726927;
SELECT * FROM lab_results WHERE patient_id = 4421 AND status = 'pending' ORDER BY created_at DESC;

Rows examined: 892,341. Rows sent: 1. That's a full table scan to find one row. Add an index on (patient_id, status) and that query drops to single-digit milliseconds.

PHP-FPM would have told you the request was slow. MariaDB tells you this exact query is why.

Reading Both Logs Together

Here's how I actually correlate them in practice. They don't share a request ID, which is annoying, but timestamps are close enough to cross-reference manually during an investigation.

For day-to-day analysis I use pt-query-digest from Percona Toolkit on the MariaDB log:

pt-query-digest /var/log/mysql/slow.log --limit 10 > /tmp/digest.txt

This groups identical query patterns and ranks them by total time consumed, not just worst single execution. A query that takes 200ms but runs 5,000 times per hour is often more important than one that occasionally takes 4 seconds.

For the FPM slow log, grep and sort get you most of the way there. I'll typically count which script/controller shows up most:

grep 'script_filename' /var/log/php-fpm/slow.log | \
  sed 's/.*script_filename = //' | \
  sort | uniq -c | sort -rn | head -20

And which functions appear in the stack most often:

grep -oP '\w+\(\)' /var/log/php-fpm/slow.log | \
  sort | uniq -c | sort -rn | head -20

Crude, but effective. In an hour you can build a picture of what's actually slow.

The Gotchas

FPM slow log requires the child process to still be running. The log is captured by sending SIGUSR1 to the worker process at the threshold time. If the request completes in, say, 1.9 seconds and your threshold is 2 seconds, you get nothing. It's not a post-hoc analysis — it's a live snapshot. This means extremely fast-failing requests that are still slow by user standards can slip through.

request_slowlog_timeout measures wall clock, not CPU time. A worker blocked waiting on a slow disk read, a network call, or even a sleep() in your code will all trigger it. This is usually what you want, but don't confuse it with CPU profiling.

MariaDB's log_queries_not_using_indexes can be very noisy on a busy app. I've seen it generate gigabytes of logs overnight on apps with ORM code that issues small queries against tiny tables. The min_examined_row_limit setting is your friend here — set it to something reasonable like 500 or 1000 for a busy system.

Neither log captures queries run inside stored procedures cleanly. If you're using stored procedures heavily (I try not to, but some inherited codebases do), the slow log attribution can be misleading.

Log rotation. Both logs will grow without bound if you don't set up logrotate. I've inherited servers where the MySQL slow log was 40GB. /etc/logrotate.d/ entries for both; make sure the FPM one sends the right signal to reopen the file.

/var/log/php-fpm/slow.log {
    daily
    rotate 7
    compress
    delaycompress
    missingok
    notifempty
    postrotate
        /bin/kill -USR1 $(cat /var/run/php/php8.2-fpm.pid 2>/dev/null) 2>/dev/null || true
    endscript
}

When I'd Reach for Each

Turn on both, always, on every production server. This isn't optional instrumentation you enable when something goes wrong — by the time something's wrong, you've already missed the early evidence.

That said, here's how I triage:

  • Users report slowness, but the MariaDB slow log is clean? Go straight to the FPM log. You're probably looking at a third-party API, a filesystem operation, or an N+1 query where each individual query is fast.
  • FPM log shows PDOStatement::execute() or similar database frames at the top of every slow stack? Cross-reference with MariaDB. You now have a call-stack breadcrumb pointing you at exactly which query to dig into.
  • FPM log shows curl_exec(), file_get_contents(), or stream_socket_*? That's a network I/O problem. MariaDB won't help you here — you need to look at timeouts, retries, and whether the external service has an SLA.
  • Both logs are quiet but the site still feels slow? You're probably looking at something the slow logs don't capture at all — PHP opcache misconfiguration, a full FPM worker pool (check pm.max_children and the status endpoint), or network latency between tiers.

I worked on a Laravel app for an e-commerce client a couple years back where the checkout page was timing out intermittently. MariaDB slow log: nothing unusual. Turned on the FPM slow log and within an hour caught a stack showing curl_exec() inside a shipping rate calculation. The UPS API was returning in 8+ seconds during peak hours. A caching layer around that call fixed the problem in an afternoon. Without the FPM slow log we'd have spent days chasing the database.

The Bottom Line

Two logs, two instruments, two different views into what your stack is actually doing. The MariaDB slow log tells you what SQL is hurting you. The PHP-FPM slow log tells you what your PHP process was doing when it finally gave up.

Neither is a replacement for the other, and neither tells you the whole story alone. Run both, understand what each one sees, and you'll cut your mean-time-to-diagnose in half.

php-fpm mariadb mysql performance slow-log laravel devops server

Related

Need help shipping something like this? Get in touch.