Skip to main content
Version: 4.1

PHP X-Ray

PHP X-Ray (/php/xray) shows where a site's PHP is actually spending its time.

It is built on what the server already records rather than on a profiler you have to install. Every PHP-FPM pool this panel writes has request_slowlog_timeout and pm.status_path set, so PHP-FPM has been dumping the call stack of every slow request to disk, and answering questions about its own workers, all along.

Two views, answering different questions:

  • Live — what every worker is doing this second, and whether the pool has run out of them. That is the answer no stack trace can give.
  • Slow — the requests that crossed the threshold and the exact function each one was inside, grouped so the same bottleneck hit many times reads as one problem rather than many.
  • What the database was doing at the same time — the slow requests above lined up against the slow database queries the DB Governor recorded for the same account.
  • How much of each slow request was spent waiting — per request, and only when an administrator has switched it on for the site. See below.

What the database block can and cannot tell you​

A pair means one thing: a query belonging to this account was running while that request was running. It is evidence, not proof. The record is per account, so a query from another of the account's requests, or from one of its cron jobs, can fall inside the same window, and an overlap cannot say which of the two was waiting for the other. So the page says "at the same time", never "because of", and when nothing overlaps it says it found nothing rather than offering the nearest query instead.

With per-request wait timing on for the site, each pair gains one more sentence: whether that request really was blocked, for how long, and whether the longest query in the window is of the same size as the waiting. That is a stronger statement than an overlap, and it is still not "because of" — see below for exactly how far it goes.

The window is the stretch a request is known to have been running. PHP-FPM writes its record at the moment a request crosses request_slowlog_timeout, so a record stamped 22:23:33 with a 15-second threshold vouches for 22:23:18–22:23:33. The request may well have started earlier — measured on a live server, FPM's own check lagged its threshold by four seconds — so a query that ran only in a request's first seconds can fall outside the window and go unpaired. That is deliberate: widening the window would pair queries that never overlapped the request at all.

What the DB Governor records, and what it misses​

The governor keeps the record (hitechcloudcli dbgovernor slowqueries, one file per account) and fills it on the one-minute pass its own timer runs — the timer that hitechcloudcli dbgovernor enable installs. On a server where the DB Governor was never enabled there is no record at all: the block then says the governor has recorded nothing for this account — which is not the same statement as "the database was quiet", and is worth checking with your administrator before reading it as one.

Two sources, and the page says which one it is reading:

  • sample — what the governor caught running when it looked, once a minute. Needs no configuration, but a query that began and ended between two looks leaves no trace.

  • slow_log — every statement over the server's long_query_time, with no sampling gap. It needs the database's slow-query log on, which is a server-wide setting, so an administrator turns it on deliberately:

    hitechcloudcli dbgovernor slowqueries --enable --seconds 2

Queries the governor kills when an account is over its database share are recorded too, before they are killed.

How much of each slow request was spent waiting​

This block is off unless an administrator switches it on for the site, and it switches itself off again after the window they gave it:

hitechcloudcli fpm xray install # once per server
hitechcloudcli fpm xray on example.com --minutes 60
hitechcloudcli fpm xray status
hitechcloudcli fpm xray off example.com

With it on, the site's PHP pool runs a small shim before every request. The shim samples the request on two timers at the same period — one on the wall clock, one on CPU time — and the difference at a line of your code is time the request spent there not computing: blocked on the database, on a cache, on an HTTP call, on the disk. For a request slow enough to be worth it (over one second by default) it writes one record; for a fast one it writes nothing.

A record is matched to a slow-request log line by the worker that served it, the script, and the request's own start and end. A worker serves one request at a time, so that match is exact rather than likely — which the account-and-window join above can never be. A record with no matching log line is shown too, marked as such: a request can be slow enough to be worth a record without crossing PHP-FPM's own threshold.

What it can and cannot tell you​

It can say: this request ran 19.1 seconds, spent 18.4 of them waiting rather than computing, and 18.0 of that waiting was at line 2353 of class-wpdb.php, inside wpdb::_do_query.

It cannot say what it was waiting on. The profiler sees the innermost line of your PHP, not the socket underneath it — a $wpdb->query() line and a file_get_contents() line look identical from there. In particular it does not name the query. The statement text is not in this record and cannot be: it lives inside an internal function that is not a PHP frame at all. The database block above, with the DB Governor's record, is where the candidate statements are; putting the two together is the reader's job, and the page never does it for them.

The figures are sampled, not counted, so a wait of one or two sampling periods is noise and only a wait many times the period is a reading. That is why the shim ignores fast requests: on a slow one at the default 10ms period there are hundreds or thousands of samples and the figures are good.

What it costs​

Measured on a live server (AlmaLinux 10, PHP 8.3, a WordPress front page taking about 0.58 seconds, five runs each):

seconds
with the shim off0.63 0.54 0.58 0.59 0.59
with the shim on, 10ms period0.66 0.59 0.58 0.56 0.62

The difference is inside the spread between runs. It is still not left on forever: the window the administrator gives it expires on its own, because a diagnostic that nobody remembers to turn off is a diagnostic nobody audits.

Where it is not available​

The sampler is packaged for PHP 7.4 and 8.0 through 8.5. There is no package for PHP 8.6 yet, so a site on 8.6 cannot have this block, and fpm xray status says so per version rather than failing later.