php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #78106 Path resolution fails if opcache disabled during request
Submitted: 2019-06-04 17:53 UTC Modified: 2019-06-17 13:36 UTC
Votes:4
Avg. Score:5.0 ± 0.0
Reproduced:2 of 2 (100.0%)
Same Version:1 (50.0%)
Same OS:0 (0.0%)
From: mbiebl at messageconcept dot com Assigned: dmitry (profile)
Status: Closed Package: opcache
PHP Version: 7.2.19 OS: Windows Server 2016 / IIS 10
Private report: No CVE-ID: None
 [2019-06-04 17:53 UTC] mbiebl at messageconcept dot com
Description:
------------
I have a php application (which I unfortunately can't share) which uses phpfastcache 7.* from https://www.phpfastcache.com/ (via composer)

After the update from 7.2.18 to 7.2.19, the application is broken an I get the following error in the php log:

[04-Jun-2019 17:43:55 UTC] PHP Fatal error:  Uncaught Error: Class 'Phpfastcache\Config\Config' not found in C:\src\localhost\server.php:104
Stack trace:
#0 {main}
  thrown in C:\src\localhost\server.php on line 104

The class exists at vendor/phpfastcache/phpfastcache/lib/Phpfastcache/Config/Config.php and downgrading back to 7.2.18 makes the application work again flawlessly.


Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2019-06-04 18:04 UTC] krakjoe@php.net
-Status: Open +Status: Feedback
 [2019-06-04 18:04 UTC] krakjoe@php.net
Thank you for this bug report. To properly diagnose the problem, we
need a short but complete example script to be able to reproduce
this bug ourselves. 

A proper reproducing script starts with <?php and ends with ?>,
is max. 10-20 lines long and does not require any external 
resources such as databases, etc. If the script requires a 
database to demonstrate the issue, please make sure it creates 
all necessary tables, stored procedures etc.

Please avoid embedding huge scripts into the report.


 [2019-06-04 18:08 UTC] mbiebl at messageconcept dot com
-Status: Feedback +Status: Open
 [2019-06-04 18:08 UTC] mbiebl at messageconcept dot com
Unfortunately I don't have a short reproducer script aside from the application itself
 [2019-06-04 18:14 UTC] requinix@php.net
-Status: Open +Status: Feedback
 [2019-06-04 18:14 UTC] requinix@php.net
I don't see anything in the 7.2.19 changelog that looks relevant, and it's going to be hard to reproduce and test without being able to see it happening...

How much debugging have you done? Is the autoloader running? Can it locate the class/file? What happens if you require() the file manually?
Does the 7.2.19 setup exactly match the 7.2.18 setup? What else is changing besides the version of PHP?
 [2019-06-04 18:14 UTC] requinix@php.net
-Package: Reproducible crash +Package: *General Issues
 [2019-06-04 18:54 UTC] mbiebl at messageconcept dot com
The setup is identical between 7.2.18 and 7.2.19. The application is unchanged, php.ini is the same.

The PHP version I'm using is the Windows x86 NTS build.
IIS uses PHP via FCGI.

The application is a CardDAV server built on top of sabre/dav.
I tried to create a minimal test case which simply does
```
<?php
require_once 'vendor/autoload.php';
$config = new \Phpfastcache\Config\Config();
```
but this works just fine and doesn't trigger the fatal error, so I'm a bit stuck at providing a minimal test case. 
What I can do offer to do, is to try test builds. Unfortunately I don't have the toolchain to build those windows binaries myself, but if you can provide such binaries, we could do a git bisect run this way.

Other then that, I'd be glad to provide you with more information or try any debugging steps. Just let me know.
 [2019-06-04 19:34 UTC] mbiebl at messageconcept dot com
-Status: Feedback +Status: Open
 [2019-06-04 19:34 UTC] mbiebl at messageconcept dot com
As one more data point: 7.3.6 does not seem to be affected
 [2019-06-04 21:21 UTC] cmb@php.net
-Status: Open +Status: Feedback -Assigned To: +Assigned To: cmb
 [2019-06-04 21:21 UTC] cmb@php.net
Does this happen with and without Opcache being enabled?
 [2019-06-04 21:40 UTC] mbiebl at messageconcept dot com
-Status: Feedback +Status: Assigned
 [2019-06-04 21:40 UTC] mbiebl at messageconcept dot com
After removing
```
zend_extension=php_opcache.dll
opcache.enable_cli=1
opcache.enable=1
```
from php.ini the problem seems to be gone. So it does indeed look like the problem is related to opcache.
 [2019-06-04 21:59 UTC] cmb@php.net
-Package: *General Issues +Package: opcache -Assigned To: cmb +Assigned To: pollita
 [2019-06-04 21:59 UTC] cmb@php.net
Thanks!

Bug #78103 (and maybe bug #78101) also reports an Opcache related
regression in PHP 7.2.19 (but not PHP 7.3.6), which *might* be
related.

Sara, could you please have a look at this?
 [2019-06-05 07:08 UTC] sjon@php.net
the only difference between 7.2.18 and 7.2.19 in ext/opcache is https://github.com/php/php-src/commit/5c4d125d4c2976236e2ecddd1d8c6e7b113ec482#diff-c71a95c83b8c6641638e6732d2264b55 - maybe it makes sense to create a windows build that excludes that commit to see if it still happens?
 [2019-06-05 09:48 UTC] mbiebl at messageconcept dot com
I can offer to test such a build with that commit excluded (win, x86, NTS)
 [2019-06-05 13:38 UTC] mbiebl at messageconcept dot com
7.3.6 seems to include that opcache commit as well https://github.com/php/php-src/commit/53c1b485741f31a17b24f4db2b39afeb9f4c8aba but is not affected afaics.
 [2019-06-05 14:52 UTC] martijn at squeezely dot tech
We're having the same issue with symfony on Ubuntu 18.04.2 after upgrading from 7.2.18 to 7.2.19

PHP 7.2.19-1+ubuntu18.04.1+deb.sury.org+1 (fpm-fcgi) (built: May 31 2019 11:17:15)
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.2.0, Copyright (c) 1998-2018 Zend Technologies
    with Zend OPcache v7.2.19-1+ubuntu18.04.1+deb.sury.org+1, Copyright (c) 1999-2018, by Zend Technologies

It does not directly relate to Phpfastcache but can be any random class/file in the framework
 [2019-06-05 15:14 UTC] nikic@php.net
Fully list of commits in 7.2.19: https://github.com/php/php-src/compare/PHP-7.2.18...PHP-7.2.19

Very short, the already referenced https://github.com/php/php-src/commit/5c4d125d4c2976236e2ecddd1d8c6e7b113ec482 is the only one that looks at all relevant.

There was a later fix to this area that did not make it into 7.2: https://github.com/php/php-src/commit/fa6a4483e63d87608a839d04c6e1b9eed9a0430f

The thing is, these changes should only affect opcache restarts, not normal operation.
 [2019-06-05 15:18 UTC] nikic@php.net
-Assigned To: pollita +Assigned To: dmitry
 [2019-06-05 15:18 UTC] nikic@php.net
@dmitry: Any ideas what could cause this?
 [2019-06-05 16:24 UTC] cmb@php.net
@mbiebl, maybe you could test a recent snapshot[1]?  (There have
been some failing builds, but ra3e6b50 should be good now.)

[1] <https://windows.php.net/downloads/snaps/php-7.2>
 [2019-06-05 16:42 UTC] mbiebl at messageconcept dot com
@cmb: I tried with php-7.2-nts-windows-vc15-x86-ra3e6b50.zip, problem is still reproducible
 [2019-06-05 16:55 UTC] mbiebl at messageconcept dot com
I also tried php-7.2-nts-windows-vc15-x86-rad63bd1.zip, which seems to be the last successful build before https://github.com/php/php-src/commit/5c4d125d4c2976236e2ecddd1d8c6e7b113ec482#diff-c71a95c83b8c6641638e6732d2264b55

No problems with this version, which would confirm that this commit is indeed the culprit
 [2019-06-06 02:28 UTC] ani2life at gmail dot com
I'm having a similar problem.

PHP-FPM 7.3.6 + Apache 2.4.38 + Ubuntu 18.04

If enable opcache and use require_once, it will Failed opening file.
But disable opcache or use require or PHP 7.3.5, it will OK.
 [2019-06-06 09:34 UTC] mbiebl at messageconcept dot com
I have to add that this fatal error is not 100% reproducible here in the sense that I don't get it on every request. If I switch logging from debug to production mode it feels like it takes longer until I hit this error. This smells like a race condition.
 [2019-06-06 09:39 UTC] mbiebl at messageconcept dot com
Once I get this failure, the php process seems to be in a broken state and I then get it on every request. Only thing that helps is then to kill the php process (via iisreset) and let it be respawned. Then it will work again for a while until I hit the problem again at which point only a iisreset help.
 [2019-06-06 10:02 UTC] mbiebl at messageconcept dot com
One more observation: The problem only seems to happen if I have at least 2 php-cgi.exe processes. If I have two or more clients access the server at the same time, the failure is triggered immediately. With a single client and only one php-cgi.exe process running, it seems like the failure is not triggered.
 [2019-06-11 12:20 UTC] nikic@php.net
We're having a hard time reproducing this issue. Could you please provide your opcache ini configuration(s)? I'd also be interested if the people who see this on Debian/Ubuntu are using FPM.
 [2019-06-11 13:08 UTC] michel at weimerskirch dot net
I was lead to this issue from here: https://github.com/php/php-src/pull/4161

Our setup on the affected machines is PHP 7.2.19 or 7.3.6 with opcache enabled.

Deactivating opcache or going back to 7.2.18 or 7.3.5 also "solve" the problem for us, just like for the user "ani2life".

As to the ini configuration, we tried a few combinations, but even with everything set to default the error sometimes appears.

Yes, we run FPM on Ubuntu.
 [2019-06-11 13:26 UTC] dmitry@php.net
May be this patch can help https://gist.github.com/dstogov/b13163408e0edf337b99b4e634cba38f

But it's really hard to guess, without a way to reproduce the problem.
 [2019-06-11 13:28 UTC] nikic@php.net
Thanks for the information!

If this issue only occurs sporadically, is there any correlation with opcache restarts? That is, does the error occur around the same time that an opcache restart even occurs?
 [2019-06-11 19:59 UTC] mbiebl at messageconcept dot com
How can I find out if there was an opcache restart? Is there a way to get a more verbose debug log from the opcache module?
 [2019-06-11 20:24 UTC] nikic@php.net
@mbiebl at messageconcept dot com: Assuming you already have opcache.error_log configured, if you set opcache.log_verbosity_level=4 it will capture all log messages. Maybe a lower level is enough to log non-user restarts, but I'm not sure.
 [2019-06-12 15:18 UTC] mbiebl at messageconcept dot com
I've changed my php.ini to enable debug logging for opcache like this:
```
zend_extension=php_opcache.dll
opcache.enable_cli=1
opcache.enable=1
opcache.error_log="C:\Windows\temp\php_opcache.log"
opcache.log_verbosity_level=4
```
Unfortunately, this didn't produce any useful log messages.
I only get messages like this:
```
Wed Jun 12 17:11:38 2019 (4748): Message Cached script 'C:\src\server\localhost\vendor\psr\log\Psr\Log\LoggerInterface.php'
Wed Jun 12 17:11:38 2019 (4748): Message Added key 'C:\src\server\localhost\vendor\composer/../psr/log/Psr/Log\LoggerInterface.php'
```
Also, this is only for one php process (4748), while I have multiple processes.
 [2019-06-13 08:35 UTC] martijn at squeezely dot tech
We managed to find a way to reproduce. We use nginx + php-fpm 7.2.19 with the patch supplied from dmitry@php.net

Step to reproduce

Create the following files:

test.php
----------
<?php

    ini_set('opcache.enable', 0);
    require_once 'include.php';

    echo 'done';

----------

test2.php
----------
<?php

require_once 'include.php';

echo 'done';

----------

include.php
----------
<?php

echo 'included';
----------


1. Request test.php
2. Request test2.php
3. Request test.php

Final test.php request will break. 
We also tried this with require instead of require_once but this did NOT break.


Hope this helps you fix this bug. If we need to retest with a certain patch in place let me know.
 [2019-06-13 08:43 UTC] nikic@php.net
-Status: Assigned +Status: Verified
 [2019-06-13 08:43 UTC] nikic@php.net
@martijn at squeezely dot tech: Thanks a lot! I can confirm that this reproduces the issue for me.
 [2019-06-13 10:49 UTC] nikic@php.net
-Summary: PHP Fatal error: Uncaught Error: Class 'Phpfastcache\Config\Config' not found +Summary: Path resolution fails if opcache disabled during request
 [2019-06-13 10:49 UTC] nikic@php.net
Testcase added in https://github.com/php/php-src/commit/f8a68fd9350ac97d33d1773453c4e9d47a97b33f, with a bit of run-tests plumbing.
 [2019-06-13 10:54 UTC] nikic@php.net
Automatic comment on behalf of nikita.ppv@gmail.com
Revision: http://git.php.net/?p=php-src.git;a=commit;h=f1a81380554070d7f4b0c6dcd1202364ebf3d252
Log: Fixed bug #78106
 [2019-06-13 10:54 UTC] nikic@php.net
-Status: Verified +Status: Closed
 [2019-06-13 10:57 UTC] nikic@php.net
The issue should be fixed by https://github.com/php/php-src/commit/f1a81380554070d7f4b0c6dcd1202364ebf3d252. It would be great if you can confirm that this also fixes your original issue.
 [2019-06-13 11:02 UTC] mbiebl at messageconcept dot com
Just curious: In my case, there is no explicit `ini_set('opcache.enable', 0);` anywhere in the code so I wonder if this really fixes my original issue. Are there other mechanisms which implicitly disable opcache during runtime?
Anyway, I'm happy to test it once a (daily) build is available with this commit.
 [2019-06-13 11:20 UTC] mbiebl at messageconcept dot com
Since I can only reproduce that issue with 7.2.19, I would need a daily build from the 7.2 branch with that fix included.
 [2019-06-13 13:33 UTC] cmb@php.net
Seems the snapshot builder hung; now the rf1a8138 builds are in
progress.
 [2019-06-13 14:15 UTC] mbiebl at messageconcept dot com
I tried f1a81380554070d7f4b0c6dcd1202364ebf3d252 from the PHP-7.2 branch. Unfortunately the problem is not fixed here and I get the exact same error as with 7.2.19.
 [2019-06-13 14:21 UTC] nikic@php.net
-Status: Closed +Status: Re-Opened
 [2019-06-13 14:21 UTC] nikic@php.net
Reopening as original issue not fixed.
 [2019-06-13 14:22 UTC] mbiebl at messageconcept dot com
I've setup a build env in the mean time, so I'm happy to test any patches you throw at my direction.
 [2019-06-13 19:41 UTC] mbiebl at messageconcept dot com
Since I had setup a build env, I did run "git bisect" and can confirm that 5c4d125d4c is indeed the first faulty commit.
For testing purposes I also checked out the PHP-7.2.19 branch and reverted that particular commit and everything was working again.
 [2019-06-14 09:53 UTC] cmb@php.net
@mbiebl, did you try the patch suggested by dmitry[1]?

[1] <https://gist.github.com/dstogov/b13163408e0edf337b99b4e634cba38f>
 [2019-06-14 10:34 UTC] mbiebl at messageconcept dot com
I had missed 
[1] <https://gist.github.com/dstogov/b13163408e0edf337b99b4e634cba38f>

First tests with this patch look promising. No exceptions so far.

Will testt the other patches later (as time permits)
 [2019-06-14 18:06 UTC] cmb@php.net
Thanks @mbiebl!  You can also try
<https://windows.php.net/downloads/snaps/php-7.2/r28808ca/>.
 [2019-06-17 13:25 UTC] mbiebl at messageconcept dot com
I now also tested a current PHP-7.2 branch (03db04c3aba03fd55c94c9d834a6c151e351cfc5) with the two backports from @dmitry. 
Everything is looking fine now and you can mark the issue as resolved as far as I am concerned.

Thanks a lot everyone for the excellent support!
 [2019-06-17 13:36 UTC] nikic@php.net
-Status: Re-Opened +Status: Closed
 [2019-06-17 13:36 UTC] nikic@php.net
Thanks for the confirmation! I'll ask the RMs to cherry-pick these fixes into the upcoming PHP 7.2 and 7.3 releases.
 [2019-06-18 05:49 UTC] remi@php.net
Automatic comment on behalf of nikita.ppv@gmail.com
Revision: http://git.php.net/?p=php-src.git;a=commit;h=42c7d5106b03e0a07cfa6f40ed2d883575d6fcc3
Log: Fixed bug #78106
 [2019-06-18 07:13 UTC] cmb@php.net
Automatic comment on behalf of nikita.ppv@gmail.com
Revision: http://git.php.net/?p=php-src.git;a=commit;h=a2058937bc5d01b3fda0726348279b6e7296e586
Log: Fixed bug #78106
 
PHP Copyright © 2001-2019 The PHP Group
All rights reserved.
Last updated: Fri Oct 18 06:01:27 2019 UTC