Bug #79729 [Asn]: Strings missing last character (Apache + OPcache)

Edit report at https://bugs.php.net/bug.php?id=79729&edit=1 ID: 79729 User updated by: ca at lsp dot net Reported by: ca at lsp dot net Summary: Strings missing last character (Apache + OPcache) Status: Assigned Type: Bug Package: opcache Operating System: Windows Server 2016 Standard PHP Version: 7.3.19 Assigned To: cmb Block user comment: N Private report: N New Comment: Meanwhile, I opened bug 79735 for the "Call to undefined method" error. After some consideration though, the root cause could be the same. This is the *complete* log entry for the current issue in the PHP error log: ``` [24-Jun-2020 06:53:14 UTC] PHP Fatal error: Uncaught --> Smarty: Plugin 'cut_hea' not callable <-- thrown in C:\***\vendor\smarty\smarty\libs\sysplugins\smarty_internal_method_registerplugin.php on line 50 ``` The short stacktrace suggests that this error occurred in an exception_handler or similar, and maybe OPcache isn't working properly in that context? Previous Comments: ------------------------------------------------------------------------ [2020-06-25 10:30:13] ca at lsp dot net @cmb Thank you for the docs update, I have set those values now. Today I observed the following (possibly related) exceptions in the same instance, all in the context of web requests: ``` 10:14:02 CEST Error: Uncaught Error: Call to undefined method ***\MyDB::searchByCol() 10:20:10 CEST Error: Uncaught Error: Call to undefined method ***\MyDB::searchByCol() 10:23:33 CEST Error: Uncaught Error: Call to undefined method ***\MyDB::searchByCol() 11:03:03 CEST Error: Uncaught Error: Call to undefined method ***\MyDB::searchByCol() ``` (Note: The method MyDB::searchByCol() *does* exist.) The same issue occurred 3x on June 12, two days after we enabled OPcache (and one day after the upgrade to 7.3.19). Unfortunately I had obviously not restarted the Apache server after making the latest config changes, so the OPcache log verbosity was not sufficient for the web server requests (and possibly the file_cache value was not yet effective either), so I will have to wait and see if it occurs again. One thing I should mention though is that we run multiple branches simultaneously on that test server: - C:/app = test app for branch "develop" - C:/app-review/12345-foo = review app for branch "12345-foo" So could these issues be related to the fact that there are multiple MyDB.php files? I wonder if I have to enable opcache.revalidate_path to prevent the wrong file from being loaded by OPcache? ------------------------------------------------------------------------ [2020-06-24 14:48:37] cmb@php.net I've just amended the recommended settings section in the docs[1]; will take a while until it is rolled out to the server. I don't think there is any valuable data you could provide, if the problem occurs again. Of course, in that case, check the logs, and maybe it's useful to set opcache.log_verbosity_level to 3 or 4 in advance. [1] <http://svn.php.net/viewvc?view=revision&revision=350081> ------------------------------------------------------------------------ [2020-06-24 13:14:34] ca at lsp dot net > To actually enable the file_cache_fallback, you also need to set opcache.file_cache to an already existing (...) directory. Thanks for the clarification. I would have expected the "Recommended php.ini settings" [1] to mention this though. Is it worth creating a separate bug for this documentation improvement? As regards the truncated strings, is there any valuable data I could collect when the issue appears again, before trying opcache.optimization_level=0? [1] https://www.php.net/manual/de/opcache.installation.php#opcache.installation.recommended ------------------------------------------------------------------------ [2020-06-24 12:43:29] cmb@php.net > opcache.file_cache => no value => no value To actually enable the file_cache_fallback, you also need to set opcache.file_cache to an already existing (and writeable, and preferably empty) directory. ------------------------------------------------------------------------ [2020-06-24 12:40:25] ca at lsp dot net > we recommend to never disable opcache.file_cache_fallback (which it is in your case) I'm a bit confused, because opcache.file_cache_fallback is actually *not* disabled in our case (see OPcache configuration above). I just verified this (both via php -i and a phpinfo() script accessed via Apache, in case these may differ, which they don't seem to). Here's the relevant section from the current output of php -i (coincidentally just after a deployment calling opcache_reset(), hence 0 hits/misses): ``` Zend OPcache Opcode Caching => Up and Running Optimization => Enabled SHM Cache => Enabled File Cache => Disabled Startup => OK Shared memory model => win32 Cache hits => 0 Cache misses => 0 Used memory => 8770936 Free memory => 125446792 Wasted memory => 0 Interned Strings Used memory => 342472 Interned Strings Free memory => 5948536 Cached scripts => 0 Cached keys => 0 Max keys => 7963 OOM restarts => 0 Hash keys restarts => 0 Manual restarts => 0 Directive => Local Value => Master Value opcache.blacklist_filename => no value => no value opcache.consistency_checks => 0 => 0 opcache.dups_fix => Off => Off opcache.enable => On => On opcache.enable_cli => On => On opcache.enable_file_override => Off => Off opcache.error_log => C:\***\opcache_error.log => C:\***\opcache_error.log opcache.file_cache => no value => no value opcache.file_cache_consistency_checks => On => On opcache.file_cache_fallback => On => On opcache.file_cache_only => Off => Off opcache.file_update_protection => 2 => 2 opcache.force_restart_timeout => 180 => 180 opcache.interned_strings_buffer => 8 => 8 opcache.log_verbosity_level => 1 => 1 opcache.max_accelerated_files => 4000 => 4000 opcache.max_file_size => 0 => 0 opcache.max_wasted_percentage => 5 => 5 opcache.memory_consumption => 128 => 128 opcache.mmap_base => no value => no value opcache.opt_debug_level => 0 => 0 opcache.optimization_level => 0x7FFEBFFF => 0x7FFEBFFF opcache.preferred_memory_model => no value => no value opcache.protect_memory => Off => Off opcache.restrict_api => no value => no value opcache.revalidate_freq => 60 => 60 opcache.revalidate_path => Off => Off opcache.save_comments => On => On opcache.use_cwd => On => On opcache.validate_permission => Off => Off opcache.validate_timestamps => On => On ``` PS: The only change I made since the issue ocurred was to set opcache.error_log (and to use rsync --checksum in deployment rather than rsync --times to avoid OPcache possibly being confused by timestamps not reflecting the deployment timestamp). ------------------------------------------------------------------------ The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at https://bugs.php.net/bug.php?id=79729 -- Edit this bug report at https://bugs.php.net/bug.php?id=79729&edit=1