The last post shipped a gated mu-plugin that turns on SAVEQUERIES for one debugging session and writes anything over a threshold to a flat log file. It ended with a loose end: "wrap a few WP-CLI commands around reading and clearing that log file, and you have a reusable tool." That sentence has been sitting there long enough. Here’s the tool.
TL;DR: Three WP-CLI subcommands — status, clear, report — wrap the flat-file slow-query log from the last post into a reusable tool. A --context filter turns it from a curiosity into a real triage tool: point it at a URL pattern after a crawl and every matching slow query surfaces on its own, sorted worst-first.
Why a Flat File First, Not a Database Table?
Worth addressing directly, because it looks like the obvious shortcut: why not just insert into a custom table instead of appending to a file? Two reasons. First, a debugging session is by definition happening on a site that’s already suspected of being slow — the last thing it needs is a new set of INSERT queries competing with everything else for database time, especially since the tool exists to make that problem visible, not add to it. Second, a file survives a database rollback, a wp db reset during the same debugging session, or a multisite context switch, none of which should be able to wipe out the evidence you were in the middle of collecting.
What Are the Commands?
Three subcommands cover the whole workflow: turn profiling on, read the results, clear them for a fresh run.
<?php
/**
* Registers `wp profiler status|clear|report`. Reads the same
* /tmp/slow-query-profiler.log the gated mu-plugin writes to —
* see the previous post for that half of the tool.
*/
class Slow_Query_Profiler_Command {
private const LOG_PATH = '/tmp/slow-query-profiler.log';
/**
* Show whether the profiler is currently capturing, and how many
* entries are waiting in the log.
*/
public function status( $args, $assoc_args ) {
$enabled = defined( 'SLOW_QUERY_PROFILER_ENABLED' ) && SLOW_QUERY_PROFILER_ENABLED;
WP_CLI::log( sprintf( 'Profiler: %s', $enabled ? 'enabled' : 'disabled' ) );
if ( ! file_exists( self::LOG_PATH ) ) {
WP_CLI::log( 'Log file: none yet' );
return;
}
$lines = count( file( self::LOG_PATH ) );
WP_CLI::log( sprintf( 'Log file: %s (%d entries)', self::LOG_PATH, $lines ) );
}
/**
* Wipe the log to start a clean capture window.
*/
public function clear( $args, $assoc_args ) {
if ( file_exists( self::LOG_PATH ) ) {
unlink( self::LOG_PATH );
}
WP_CLI::success( 'Profiler log cleared.' );
}
/**
* Print captured slow queries, worst first.
*
* [--limit=<n>]
* : How many rows to show. Default 20.
*
* [--threshold=<seconds>]
* : Only show entries at or above this duration. Default 0 (show everything captured).
*
* [--context=<substring>]
* : Only show entries whose context (URL or wp-cli command) contains this string.
*/
public function report( $args, $assoc_args ) {
if ( ! file_exists( self::LOG_PATH ) ) {
WP_CLI::warning( 'No log file yet. Run a request with the profiler enabled first.' );
return;
}
$limit = (int) ( $assoc_args['limit'] ?? 20 );
$threshold = (float) ( $assoc_args['threshold'] ?? 0 );
$context = $assoc_args['context'] ?? null;
$rows = [];
foreach ( file( self::LOG_PATH ) as $line ) {
[ $duration, $ctx, $sql ] = explode( "\t", trim( $line ), 3 );
$duration = (float) $duration;
if ( $duration < $threshold ) {
continue;
}
if ( $context && false === strpos( $ctx, $context ) ) {
continue;
}
$rows[] = [ 'duration' => $duration, 'context' => $ctx, 'sql' => $sql ];
}
usort( $rows, fn( $a, $b ) => $b['duration'] <=> $a['duration'] );
$rows = array_slice( $rows, 0, $limit );
if ( empty( $rows ) ) {
WP_CLI::log( 'No entries match.' );
return;
}
WP_CLI\Utils\format_items( 'table', $rows, [ 'duration', 'context', 'sql' ] );
}
}
WP_CLI::add_command( 'profiler', 'Slow_Query_Profiler_Command' );
How Do You Use It?
$ wp profiler clear
Success: Profiler log cleared.
$ wp eval 'define("SLOW_QUERY_PROFILER_ENABLED", true);' # or flip the constant and crawl a few pages
$ wp profiler status
Profiler: enabled
Log file: /tmp/slow-query-profiler.log (14 entries)
$ wp profiler report --limit=5 --threshold=0.1
+----------+------------------------+------------------------------------------+
| duration | context | sql |
+----------+------------------------+------------------------------------------+
| 9.4213 | /sitemap_index.xml | SELECT DISTINCT post_modified_gmt ... |
| 0.3120 | /category/local-news/ | SELECT SQL_CALC_FOUND_ROWS ... |
| 0.1841 | wp-cli | SELECT option_value FROM wp_options ... |
...
--context is the part that turns this from a curiosity into a triage tool: point it at --context=/sitemap after a full crawl and every slow sitemap-related query surfaces on its own, sorted worst-first, without scrolling past everything else the crawl also touched.
What Doesn’t This Replace?
This is still the same tool as the last post, just easier to operate — it inherits the same blind spots. It only sees what actually ran during the capture window, so a rarely-hit code path still needs a deliberate crawl to trigger it, not a passive wait. And an output cache sitting in front of the page under test can make a second hit look instant regardless of whether the underlying query changed at all; wp profiler report reads what $wpdb actually executed, which is the one place that layer can’t hide from.
What’s the Generalizable Lesson Here?
- A debugging tool that gets used more than once is worth the twenty minutes it takes to wrap in a CLI command — the friction of "go find the log file and grep it by hand" is exactly the friction that makes people skip profiling on the second and third occasion.
- Prefer a flat file over a database table for anything capturing evidence about a database that might itself be misbehaving during the same session.
- A
--contextfilter is what turns a firehose log into something you’d actually reach for during a crawl. Sort and filter at read time, not write time — keep the write path as cheap as possible. - Wrapping an existing debugging script in three small subcommands is usually a better move than reaching for a dedicated profiling plugin: no new dependency, no new attack surface, and it already knows exactly what your last investigation needed.