095 —PHP
Reading a php-fpm slowlog: three stack-trace shapes decoded
A field guide to php-fpm slowlogs on shared hosting: the three stack-trace shapes you'll meet, what each one is telling you, and where to point the next hour of debugging.
It's 14:02 on a Tuesday and the shared host's CPU graph has been pegged at 90% for forty minutes. The agency that owns the site can't get into the server, only into cPanel. Inside cPanel, under Errors or sometimes hidden behind a Terminal button, there's a file called php-fpm-slow.log. They open it and see a wall of timestamps, PIDs, and indented function names. They forward it to you.
This post is about that file. Specifically, the three stack-trace shapes that show up in a php-fpm slowlog and what each one is quietly telling you about where the time is going. None of this requires root, none of it requires installing a profiler. If you can read the slowlog, you can usually narrow a slow legacy site down to one of three causes in about ten minutes.
What a slowlog entry actually is
A php-fpm slowlog is not an error log. It's a sampler. When a request takes longer than request_slowlog_timeout (commonly 5s or 10s on managed hosts), php-fpm sends SIGUSR2-style introspection at the worker, walks its current PHP call stack, and writes that snapshot to the file. The request keeps running. You're seeing a single frozen moment inside a long request, not a profile.
A single entry looks roughly like this:
[10-Jun-2026 13:47:12] [pool www] pid 24819
script_filename = /home/site/public_html/index.php
[0x00007f2c1c0a8b40] mysqli_query() /home/site/public_html/wp-includes/wp-db.php:2056
[0x00007f2c1c0a8a90] query() /home/site/public_html/wp-includes/wp-db.php:1830
[0x00007f2c1c0a89e0] get_results() /home/site/public_html/wp-includes/class-wp-query.php:3145
[0x00007f2c1c0a8930] get_posts() /home/site/public_html/wp-content/plugins/related-posts/related.php:88
[0x00007f2c1c0a8880] rp_render() /home/site/public_html/wp-includes/class-wp-hook.php:308
[0x00007f2c1c0a87d0] apply_filters() /home/site/public_html/wp-includes/post-template.php:256
[0x00007f2c1c0a8720] the_content() /home/site/public_html/wp-content/themes/twentytwentyone/single.php:24
Read it top to bottom. The top frame is what PHP was doing at the instant of the sample. The bottom frame is the entry point. Everything in between is the path from one to the other. That stack of frames has a shape, and the shape is the diagnosis.
Shape one: the database tail
The first and most common shape ends, at the top, in something that talks to MySQL: mysqli_query, PDOStatement::execute, mysql_query on truly old code, mysqli_real_query, or occasionally mysqli_stmt::fetch. Below it you'll see one or two wrapper functions (in WordPress: wpdb::query, get_results, get_posts), then theme or plugin code, then the entry point.
If the top frame is a database call and the wrappers underneath are thin, the slow query is the story. The PHP code is fine. It asked MySQL for something and MySQL took eight seconds to answer.
What to do with this: don't optimise the PHP. Take the parameters from the stack (the plugin name, the function it's in) and find the SQL. In WordPress, wpdb's last_query property is your friend if you can reproduce. Otherwise enable MySQL's slow query log for an hour with long_query_time = 2. Pair the timestamps with the slowlog timestamps and you'll have the SQL within minutes.
The fix is almost never "add a cache." It's usually a missing index on wp_postmeta(meta_key, meta_value(10)), an ORDER BY rand() hidden in a related-posts plugin, or a NOT IN subquery generated by a tax filter that scans every post. You confirm with EXPLAIN:
EXPLAIN SELECT p.* FROM wp_posts p
INNER JOIN wp_postmeta m ON m.post_id = p.ID
WHERE m.meta_key = '_related_tags'
AND m.meta_value LIKE '%shoes%'
ORDER BY p.post_date DESC
LIMIT 5;
If the type column says ALL and the row count is in the millions, you've found it.
Shape two: the hook avalanche
The second shape is unmistakable once you've seen it twice. The top frame is something cheap and innocent. preg_match. strtolower. apply_filters itself. WP_Hook::apply_filters. Below it: another apply_filters. Below that: another apply_filters. The stack is twenty, thirty, fifty frames deep and most of them are the same three function names repeating.
[0x...] strtolower() /home/site/.../seo-plugin/canonical.php:412
[0x...] WP_Hook::apply_filters() /home/site/.../class-wp-hook.php:308
[0x...] apply_filters() /home/site/.../wp-includes/link-template.php:127
[0x...] get_permalink() /home/site/.../seo-plugin/sitemap.php:88
[0x...] WP_Hook::apply_filters() /home/site/.../class-wp-hook.php:308
[0x...] apply_filters() /home/site/.../wp-includes/post-template.php:256
... (continues for 40+ frames)
This is not a slow function. This is a runaway loop of cheap functions, almost always caused by a plugin that hooks the_content or get_permalink and then, inside its filter, calls get_permalink again on every post in the archive. Multiply by 200 posts per page and a couple of nested hooks and you have a request that does forty million function calls to render a category page.
What to do with this: identify the plugin from the directory in the middle of the stack and disable it on a staging copy. If the load drops, you've found it. The actual fix is usually a one-line guard at the top of the plugin's filter callback to skip work it doesn't need.
Shape three: the remote call
The third shape is the one that gets misdiagnosed most often. The top of the stack is stream_socket_client, fsockopen, curl_exec, or fread on a stream resource. Below it, wp_remote_get, WP_Http::request, or a vendored Guzzle handler. Below that, application code.
[0x...] curl_exec() /home/site/.../wp-includes/class-wp-http-curl.php:226
[0x...] WP_Http_Curl::request() /home/site/.../class-wp-http.php:430
[0x...] WP_Http::request() /home/site/.../http.php:191
[0x...] wp_remote_get() /home/site/.../plugins/social-feed/feed.php:54
[0x...] sf_render_widget() /home/site/.../class-wp-widget.php:394
The PHP isn't slow. MySQL isn't slow. The site is waiting on someone else's server. A social-feed plugin polling Instagram, a currency converter calling an FX endpoint, a license checker phoning home, an old Gravatar lookup with no timeout. The request takes eight seconds because the upstream took eight seconds, or worse, hit php's default default_socket_timeout of 60 and got close to it.
The diagnosis here is the easiest of the three: the URL is usually in the plugin file referenced in the bottom-most application frame. Open it, find the wp_remote_get call, look at what host it hits. Test that host from your laptop with curl -w "%{time_total}\n" -o /dev/null -s <url>. If it's slow for you too, the fix is a transient cache (the plugin should be storing the response in wp_options for 15 minutes, not hammering the API on every page load) and an aggressive timeout argument:
$response = wp_remote_get( $url, [
'timeout' => 3,
'redirection' => 1,
'user-agent' => 'site-name/1.0',
] );
if ( is_wp_error( $response ) ) {
return $cached_fallback;
}
Three seconds is a reasonable ceiling for a synchronous third-party call inside a page render. Anything more and the upstream owns your uptime.
What the slowlog won't tell you
Two honest limits worth saying out loud. First, the slowlog is a snapshot, not a timeline. If a request takes 9 seconds and you get one sample, you're seeing what was on the stack at one moment. A second sample of the same request might land on a different shape. When two consecutive entries in the same PID show different shapes, both are real and both need fixing.
Second, the slowlog doesn't see opcode cache misses, session_start blocking on a file lock, or APCu contention. Those usually present as shape one with no database call at the top, or shape two with a suspiciously low frame count. When the shapes don't fit, look at request_terminate_timeout and whether the host has a single file-based session backend under load.
One small thing today
If you have access to a legacy site that's been mysteriously slow, ask the host to enable request_slowlog_timeout = 5s and point it at a file you can read. Then leave it for a day. The shapes will sort themselves out and you'll come back to a file that, read carefully, has already done most of the diagnosis for you.
When we built Pier we kept running into the same shared-host situation: clients with the slowlog visible in cPanel but nothing to read it with. The way we ended up handling it was wiring the MySQL editor and the file browser into the same chat session, so you can paste a stack frame and ask "what query is this plugin running on the homepage" without leaving the app. It's the kind of small thing that pays for itself the first time a site is down at 2am.
— Questions —
Where do I find the php-fpm slowlog on a shared host?
Usually under cPanel's Metrics or Errors panel, or at a path like /home/USER/logs/php-fpm-slow.log. If you can't see it, ask the host to enable request_slowlog_timeout and point it at a readable file.
What's a sensible value for request_slowlog_timeout?
5 seconds on a healthy site, 2 seconds when you're actively hunting. Below 2s the file fills with normal traffic and stops being useful.
Does the slowlog catch fatal errors or 500s?
No. It only samples requests that are still running past the timeout. For fatals you want the php error_log; for 500s the web server access log paired with the error_log.
Can I read a slowlog without shell access?
Yes. If cPanel's File Manager can open the log path, you can read it. The format is plain text. You don't need a parser to read the three shapes.
Is one stack snapshot enough to diagnose a slow request?
Often, but not always. If two samples from the same PID disagree, both findings are real. Fix both before declaring the request healthy.