String corruption on deployments with php-fpm 8.1.6

[nono-gdv]

Description

Hello,

We experience seemingly random in-memory corruption of code when deploying new versions of our PHP app on php-fpm 8.1.6 on Linux. Here is a sample error message:

include(/space/www/api2019/data/releases/20220607140425/vendor/la�R�F): Failed to open stream: No such file or directory

This example happens in the class loader from composer. The beginning of the file name is correct, the end is obviously not.

Another example (another release on another server):

Call to undefined function Symfony\Component\HttpFoundation\implode()

This bug is not easily reproducible, it happens in random-looking places in the code, sometimes but not always, on some servers but not others (we have 10 app servers, the bug appears on one server at a time, very rarely two, not on every release but more than half of them).

When it happens, it looks like there is only one corrupted chunk of data; depending on the affected data, it may only cause a few real errors or basically prevent the code from working on the server at all. It generates errors for a few minutes. Restarting the fpm daemon fixes it; reloading it or running opcache_reset() does not.

We will try to reproduce it on a staging server; at the moment I can only say it appears under load and not under light testing.

It may or may not be related to #8731 (same app, same servers, seemingly fixed by downgrading to 8.0.19).

I know this report is not really helpful, but I'm at a loss how to make it more useful.

Downgrading to PHP 8.0.19 seems to fix the issue.

PHP Version

PHP 8.1.6 (cli) (built: May 17 2022 16:49:19) (NTS)

Operating System

Debian 10

[willemstuursma]

Hello @nono-gdv,

I just wanted to drop by and add that at Mollie, we are experiencing the exact same issue. But we use apache2 with mod_php. We only have this problem during apache restarts (sudo service apache2 restart).

To me, it looks like the interned strings cache is read while it is being written to.

ErrorException
include(/data/www/mo���D): Failed to open stream: No such file or directory

or

ErrorException
During class fetch: Uncaught ErrorException: include(/data/www/mollie.com/rele��
B): Failed to open stream: No such file or directory in /data/www/mollie.com/releases/[redacted]/vendor/composer/ClassLoader.php:571

Note that the cut off is a different places.

Our error reporting uses JSON as a transport so I am unable to provide the exact bytes following the valid characters.

We've tried increasing the interned strings buffer but to no avail.

[lcobucci]

Adding more context to what @willemstuursma reported (I work at the same company)...

We enabled verbose opcache logging and observed a flood of Interned string buffer overflow messages around the time of deployments. Setting the interned string buffer size to 64Mb (it was 32Mb) didn't change anything.

To make things more interesting, the tools we have in place to monitor opcache show a lot of free memory on that buffer (not even 50% is used).

@cmb69 @iluuu1994 is there anything we could provide to help on finding the root cause?

[iluuu1994]

@lcobucci See:
#9259
https://www.php.net/manual/en/opcache.configuration.php#ini.opcache.interned-strings-buffer

The amount of memory used to store interned strings, in megabytes.

Is it possible you're setting the INI value to 32M instead of 32?

Error handling / logging was improved in #9260 but only for PHP 8.2.

[lcobucci]

We're setting it to 64 atm, which is correctly picked up by Datadog tooling.

[cmb69]

Do you have a sufficiently large opcache.memory_consumption?

[lcobucci]

I believe so (it's set to 256).

[willemstuursma]

Hi @cmb69 we have upgraded from PHP 8.1.9 to 8.1.10 and the problem went away.

[ssigwart]

Unforunately, I don't have definitive way to replicate this, but I'm seeing this issue on PHP 8.1.27.

I've noticed it twice in the past week, but seeing what happen, I think it's very likely it has happened before.

1. In the first instance, we have a custom autoloader that adds .php to a class name. On one of many web servers, just after we deployed and called opcache_reset() to flush the cache, the file cache got corrupted and started adding .pgp instead. Calling opcache_reset() resolved the issue.
2. In the second instance, we had a class constant that ended in "S". However, on one web server, opcache didn't include the "S" in the constant. I confirmed that the file on disk included the "S", but new ReflectionClass(MyClass::class))->getConstants() had it without the "S".

The opcache stats show memory_usage.free_memory = 88 and interned_strings_usage.free_memory = 0, so I plan to raise the memory amounts, but it seems like some type of memory corruption bug in PHP that when it is low, incorrect file contents are being cached.

[ssigwart]

I'm not sure if it makes a difference, but we use symlinks for our directories. On deployment, we change /var/www/oursite, which is a symlink to point to a new directory.

[ssigwart]

I just noticed the same issue as I mentioned above in #8739 (comment) (bullet 2). The same class had the issue of the last letter of the constant being removed, though it was a different constant. This time, it was a constant with name ACCOUNT_ALL that opcache had as ACCOUNT_AL.

This is on PHP 8.1.29. However, I already raised memory since last time and the stats from opcache_get_status show that there was plenty of memory.

Array
(
    [opcache_enabled] => 1
    [cache_full] =>
    [restart_pending] =>
    [restart_in_progress] =>
    [memory_usage] => Array
        (
            [used_memory] => 161684560
            [free_memory] => 375186352
            [wasted_memory] => 0
            [current_wasted_percentage] => 0
        )

    [interned_strings_usage] => Array
        (
            [buffer_size] => 33554432
            [used_memory] => 25416576
            [free_memory] => 8137856
            [number_of_strings] => 228762
        )

    [opcache_statistics] => Array
        (
            [num_cached_scripts] => 3996
            [num_cached_keys] => 7673
            [max_cached_keys] => 16229
            [hits] => 1713543
            [start_time] => 1717695939
            [last_restart_time] => 1719851218
            [oom_restarts] => 0
            [hash_restarts] => 0
            [manual_restarts] => 131
            [misses] => 4627
            [blacklist_misses] => 0
            [blacklist_miss_ratio] => 0
            [opcache_hit_rate] => 99.730701851388
        )
)

[nielsdos]

Referring the bullet points from #8739 (comment)
As for 1., I found the same issue with opcache_reset causing all sorts of strange crashes and bugs, I would recommend avoiding that function in high traffic. Reference: #14471
Does bullet point 2. involve opcache_reset too?

[ssigwart]

Thanks, @nielsdos. Both involve using opcache_reset. Our setup is that we have two directories and a symlink to one of them. When we do a deployment, we change the symlink so changes are atomic. It's something like the following:

# Assume web root is as `/var/www/site/` and is a symlink to `/var/www/site_a`.
cd /var/www
rsync -a --delete /code/to/deploy/ site_b/
ln -s site_b ~/site_new
chown -h apache:apache ~/site_new
sudo mv -Tf ~/site_new /var/www/site

After we've done that, we run php -r 'opcache_reset();' to clear the CLI opcache and then curl -q -k https://127.0.0.1/path/to/clear/opcache.php to clear the Apache opcache.

From what I've seen, it's the Apache version of opcache that gets corrupted.

What's the alternative to opcache_reset? For Apache, I assume restarting apache, right? I'm not sure about the CLI. Unfortunately, it has been 8 years since we added the calls to opcache_reset, so I can't remember for sure, but I think we needed to clear it because the symlinks would have issues and result in slowness and/or invalid cached data after a deployment.

[nielsdos]

I'll try to look into the opcache_reset issue tomorrow, but can't make any promises.

What's the alternative to opcache_reset? For Apache, I assume restarting apache, right?

Yes indeed, until the opcache_reset bug you experience is fixed this would be the way to go I think.

I'm not sure about the CLI.

I don't think you can easily force a reset here.