opcache.consistency_checks does not have expected effect

[ItsReddi]

Description

The following code:

; Check the cache checksum each N requests.
; The default value of "0" means that the checks are disabled.
opcache.consistency_checks=1000

First request:

[18-Aug-2022 05:53:13] NOTICE: fpm is running, pid 1
[18-Aug-2022 05:53:13] NOTICE: ready to handle connections
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/frontend/web/index.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/autoload.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/frontend/web/../../vendor/autoload.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/composer/autoload_real.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/composer/platform_check.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/composer/ClassLoader.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/composer/autoload_static.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/phpunit/phpunit/src/Framework/Assert/Functions.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/vendor/composer/../phpunit/phpunit/src/Framework/Assert/Functions.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/symfony/polyfill-php80/bootstrap.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/vendor/composer/../symfony/polyfill-php80/bootstrap.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/symfony/deprecation-contracts/function.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/vendor/composer/../symfony/deprecation-contracts/function.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/symfony/polyfill-mbstring/bootstrap.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/vendor/composer/../symfony/polyfill-mbstring/bootstrap.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/symfony/polyfill-mbstring/bootstrap80.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/symfony/polyfill-ctype/bootstrap.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/vendor/composer/../symfony/polyfill-ctype/bootstrap.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/symfony/polyfill-ctype/bootstrap80.php'
Thu Aug 18 05:53:19 2022 (7): Message Cached script '/var/www/html/vendor/guzzlehttp/promises/src/functions_include.php'
Thu Aug 18 05:53:19 2022 (7): Message Added key '/var/www/html/vendor/composer/../guzzlehttp/promises/src/functions_include.php'
....

Second Request allready a check was applied

hu Aug 18 05:54:42 2022 (8): Message Checksum failed for '/var/www/html/vendor/google/apiclient/src/aliases.php':  expected=0x5e298221, found=0xa0bc82a4
Thu Aug 18 05:54:42 2022 (8): Message Cached script '/var/www/html/vendor/google/apiclient/src/aliases.php'
Thu Aug 18 05:54:42 2022 (8): Message Added key '/var/www/html/vendor/composer/../google/apiclient/src/aliases.php'
Thu Aug 18 05:54:42 2022 (8): Message Checksum failed for '/var/www/html/vendor/google/apiclient/src/Model.php':  expected=0x2f90d8cb, found=0x91afda85
Thu Aug 18 05:54:42 2022 (8): Message Cached script '/var/www/html/vendor/google/apiclient/src/Model.php'
Thu Aug 18 05:54:42 2022 (8): Message Added key '/var/www/html/vendor/composer/../google/apiclient/src/Model.php'
Thu Aug 18 05:54:42 2022 (8): Message Checksum failed for '/var/www/html/vendor/google/apiclient/src/AuthHandler/Guzzle7AuthHandler.php':  expected=0xe22db6b7, found=0x2920b7ca
Thu Aug 18 05:54:42 2022 (8): Message Cached script '/var/www/html/vendor/google/apiclient/src/AuthHandler/Guzzle7AuthHandler.php'
Thu Aug 18 05:54:42 2022 (8): Message Added key '/var/www/html/vendor/composer/../google/apiclient/src/AuthHandler/Guzzle7AuthHandler.php'
Thu Aug 18 05:54:42 2022 (8): Message Checksum failed for '/var/www/html/vendor/google/apiclient/src/Task/Exception.php':  expected=0x107aa0c5, found=0x9814a2b0
Thu Aug 18 05:54:42 2022 (8): Message Cached script '/var/www/html/vendor/google/apiclient/src/Task/Exception.php'
Thu Aug 18 05:54:42 2022 (8): Message Added key '/var/www/html/vendor/composer/../google/apiclient/src/Task/Exception.php'
Thu Aug 18 05:54:42 2022 (8): Message Checksum failed for '/var/www/html/vendor/google/apiclient/src/Exception.php':  expected=0xb36f9cd0, found=0xb24c9e78
Thu Aug 18 05:54:42 2022 (8): Message Cached script '/var/www/html/vendor/google/apiclient/src/Exception.php'
Thu Aug 18 05:54:42 2022 (8): Message Added key '/var/www/html/vendor/composer/../google/apiclient/src/Exception.php'
Thu Aug 18 05:54:42 2022 (8): Message Checksum failed for '/var/www/html/vendor/google/apiclient/src/Collection.php':  expected=0x02cb39cf, found=0xead03b3a

Expected: No Consistency check applied after 1 Request. (Also the files should not be inconsistent, since they are not changed but this is another issue https://github.com/php/php-src/issues/8065)

With opcache.consistency_checks=1000 no check is applied on 2nd request

PHP Version

PHP 8.1.9

Operating System

php:8.1.9-fpm-alpine

[iluuu1994]

The code triggering the consistency check is here:

https://github.com/php/php-src/blob/aa702c54591b90ae44319492f7c80f8c0e0d864d/ext/opcache/ZendAccelerator.c#L2117-L2129

The code incrementing hits is here:

https://github.com/php/php-src/blob/aa702c54591b90ae44319492f7c80f8c0e0d864d/ext/opcache/ZendAccelerator.c#L2190-L2191

This code is only triggered if the compilation of the script succeeds. If the consistency check fails persistent_script is set to NULL and thus hits is never increased. I'm not sure if this is intentional. A simple fix would be to also track misses in zend_persistent_script and then add those together:

(persistent_script->dynamic_members.hits + persistent_script->dynamic_members.misses) % ZCG(accel_directives).consistency_checks == 0

Edit: The naming would be somewhat misleading. As the script is found but intentionally skipped due to the incorrect checksum. Maybe there's a better naming scheme.

[cmb69]

I think the terminology is alright; after all, this is about cache hits, and if the script isn't fetched from the cache (for whatever reasons), there was no hit.

Actually, this doesn't look like a bug to me, but rather the underlying php/php-src#8065 is the problem.

[ItsReddi]

I am unable to follow your explanation, why this should not be a bug.

Since the setting implies that "Check the cache checksum each N requests." and the second request seems to do a check on the checksum: "Message Checksum failed"

I do not know, but that tells me that the checksum is checked on each request? In this case i do not understand the setting.

[cmb69]

The first time a script is persistet, its hit count is zero. The first time the script is loaded from the cache, its hit count is still zero, so the consistency_checks will be executed; since these fail (for whatever reason), the hit counter stays zero (since the cached file isn't actually used, but it's rather compiled and cached again). So the next time the script is loaded from the cache, the consistency_checks will be executed again, and so on.

The actual problem is that the consistency_checks fail; that is not supposed to happen if the script hasn't been modified. If this check wouldn't fail, everything works as expected.

[cmb69]

Since the setting implies that "Check the cache checksum each N requests."

Ah, that part of the documentation is not correct, or at least misleading. As I explained above, it's not about a certain number of requests, but rather a certain number of cache hits.

[zsuraski]

I believe that the fact that the first hit is checksum-checked (if consistency checks are enabled) is actually intentional. After all, it's the first time we're utilizing the cached version of the file, and if it's DOA, we should know about it - as opposed to waiting N requests to find out.

I agree with @cmb69 that the behavior is correct, so the correct solution comprises of doing both:

1. Fixing the docs to reflect the current behavior, which is probably more desirable than the alternative.
2. Getting to the bottom of why you're getting corruption immediately in all of your files, which seems related to php/php-src#8065.

Seems like the consistency checks code is broken, and parts of the persistent_script that aren't immutable are getting factored into the checksum, which they shouldn't. Depending on what exactly is the root cause is here, it might imply a bigger issue too - it could be that not only the checksum code is broken - but that even with consistency checks disabled, there might be some sort of race condition that could result in a segfault (not very likely but impossible to rule out until we figure out the root cause).

[iluuu1994]

Given the feedback let's transfer this to the docs repository. https://github.com/php/php-src/issues/8065 was analyzed in the meantime.