post: the PHP 8.5 deprecation that doubled our CPU - #486
Draft
Benoit382 wants to merge 1 commit into
Draft
Conversation
How a PHP 8.4 -> 8.5 migration stayed blocked for four months, and how it was finally traced to SplObjectStorage::detach() being deprecated in 8.5 and called once per promise resolution -- 8,591 deprecation notices per request, each paying a full Symfony ErrorHandler cycle before the record was discarded by log level. All the work, none of the output, which is why no log-based check ever saw it. Covers the two false leads along the way (an OPcache misconfiguration in the base image, and APM span data inflated by the agent's own instrumentation), the fifteen components that all measured at parity, and why excimer's self-time sampling succeeded where inclusive-time instruments could not. Written with Claude Code, which also ran the investigation.
|
This pull request is automatically being deployed by Amplify Hosting (learn more). |
Meroje
reviewed
Aug 24, 2026
|
|
||
| The numbers from the spring benchmark campaign were consistent and ugly: **−15 to −17 % RPS**, **+34 to +36 % on APM p50**, **+29 % CPU per request**. Several rounds of cells had been run — PHP 8.4 vs 8.5, New Relic on and off, `lazy: true` vs `lazy: false` on the Redis provider, JIT on and off — and the regression survived all of them. | ||
|
|
||
| One earlier finding pointed at downstream HTTP calls: a "+20–25 ms of PHP-side overhead per call" that showed up on fast internal services and vanished on slow ones like S3. It looked like a smoking gun. Keep it in mind — we will come back to it. |
Member
There was a problem hiding this comment.
it may not be a good look to have a claude-ism ("smoking gun") right in the first paragraph already
|
|
||
| Roughly **72 % of the codebase was being recompiled on every single request**, plus a `stat()` per included file from `validate_timestamps=1`. | ||
|
|
||
| The fix was upstream and already merged in our base-images repository — it had landed *one day after* the image tag pinned in the PR was built. A one-line bump. |
|
|
||
| This is where the AI's autonomy started paying off. We drive our load tests with [Gatling](https://gatling.io/), and announce each session in a shared channel so everyone knows an environment is under load and why. We opened one on a staging environment, held a constant ~50 rps on a fixed endpoint mix for the afternoon, and gave the agent permission to dispatch deployments itself. It then ran a series of cells without further input — each one a throwaway branch, deployed, warmed, measured, and superseded by the next: | ||
|
|
||
| | cell | what it isolates | |
|
|
||
| What we needed was **self time** — time attributed to the frame actually executing, not to its callers. | ||
|
|
||
| [Excimer](https://www.mediawiki.org/wiki/Excimer) does that. It samples on a CPU-time timer and attributes each sample to its leaf frame, so `wait()` becomes an ordinary frame and I/O wait is excluded by construction. Since Sury ships no `php8.x-excimer` package, we built it from source in our existing `php_builder` stage, mirroring how we already build `php-uv`. |
Member
There was a problem hiding this comment.
no one outside of use knows about the php_builder stage of our dockerfile
Suggested change
| [Excimer](https://www.mediawiki.org/wiki/Excimer) does that. It samples on a CPU-time timer and attributes each sample to its leaf frame, so `wait()` becomes an ordinary frame and I/O wait is excluded by construction. Since Sury ships no `php8.x-excimer` package, we built it from source in our existing `php_builder` stage, mirroring how we already build `php-uv`. | |
| [Excimer](https://www.mediawiki.org/wiki/Excimer) does that. It samples on a CPU-time timer and attributes each sample to its leaf frame, so `wait()` becomes an ordinary frame and I/O wait is excluded by construction. Since Sury ships no `php8.x-excimer` package, we built it from source in our Dockerfile, mirroring how we already build `php-uv`. |
|
|
||
| Everything else was at parity. That shape is the whole story: the last row is the *cause*, the rows above it are the *cost*. | ||
|
|
||
| PHP 8.5 deprecates `SplObjectStorage::detach()`. `unwatchPromise()` calls it, and it runs on **every promise resolution** — so the notice fires once per promise. On a request that fans out across our async stack, that is **8 591 deprecations per request**. |
Member
There was a problem hiding this comment.
The root cause and solution should be visible at the beginning for those evaluating whether or not to dive in a long read. (Even if saying "hey we failed at the very first step in migrating to a new php version: reading the logs" doesn't sound so good for us ^^)
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
New post: 8,591 invisible errors per request: the PHP 8.5 deprecation that doubled our CPU
The story of a PHP 8.4 → 8.5 migration that stayed blocked for four months, and how it was finally traced to
SplObjectStorage::detach()— deprecated in 8.5, called once per promise resolution by our Tornado library, so 8,591 deprecation notices per request. Each one paid a full SymfonyErrorHandlercycle (exception + backtrace walk) before the record was dropped by log level. All the work, none of the output — which is why no log-based check ever caught it.Fixed in Tornado #56 (two lines, tagged
v1.0.1). CPU per request went 458 ms → 220 ms against 202 ms on 8.4. PHP 8.5 has been in production since 12 August with verified parity.The post also covers the two false leads — an OPcache misconfiguration in our base image, and APM span data inflated by the agent's own instrumentation — the fifteen components that all measured at parity, and why excimer's self-time sampling worked where inclusive-time instruments did not.
Notes for reviewers
thumbnailin the front matter yet.withHeader()receiving an int, ~467/request) as a separate ticket. If that has been fixed since, the wording needs a tweak.