phpopcache

PHP including the wrong file (twice)

I have two sites on the same Apache installation

Server version: Apache/2.4.41 (Ubuntu)
Server built:   2022-03-16T16:52:53

which are very similar. I have boiled down the problem to these three files:

<?php
    echo "I am One<br>";
    require_once('/var/www/one/htdocs/config.php');
    okay();

<?php
    echo "This is Config One<br>";
    require_once('/var/www/one/htdocs/functions.php');

<?php
    echo "This is Functions One<br>";
    function okay() {
        echo "Aaaand we are GO!<hr/>";
    }
    // Other 100K of templates and boilerplate. This might be relevant.

Test Site Two is identical, with Two instead of One.

The error is only occasional and difficult to reproduce. It manifests with the following apparently impossible error:

Fatal error: cannot redeclare okay() (previously declared in 
/var/www/two/htdocs/functions.php:3 in /var/www/one/htdocs/functions.php on line 3

Now, I fully agree that I can't declare okay() twice. Fact is that while in site One, I never included anything from site Two.

Problem happens in "streaks"

From the logs (there is no full correlation with traffic on the sites; high traffic is required for the bug to manifest, but it's not enough, I got several high traffic periods where nothing happened), there is no immediately apparent rhyme or reason:

Bug# Date Hour 2 Mar 16 14 9 Mar 17 11 2 Mar 18 09 1 Mar 22 10 24 Mar 22 11 1 Mar 22 18 Medium traffic, and yet problems - but only one 3 Mar 22 20
Mar 23: high traffic, no problems 4 Mar 24 10 11 Mar 24 12 High traffic at 14:00, problem appear at 15:00 22 Mar 24 15 Server restarted at 15:40... 5 Mar 24 16 ...problems reappear at 16:07 5 Mar 25 10 5 Mar 25 11 2 Mar 25 18 2 Mar 25 19 21 Mar 29 11

There's a preference for the 11:00 time frame for the bug to occur, but there's no obvious traffic or request pattern that stands out that's not, say, in the 13:00 time frame, when nothing ever happened.

Nothing ever happened on the weekend, but also nothing ever happened on a Monday. You'd think the bug needed some time to "mature" after a traffic lull, but that too cannot be (it happened after less than half an hour from Apache full restart, with a traffic level comparable to a Saturday).

I don't think it is an opcache problem.

This kind of error is a common gotcha with opcache module, because it caches names and not the full paths, so if a "functions" file gets in the cache, the next one to include a different "functions" file sorts of gets it in the neck.

But I don't believe this is the reason, because:

OK, this is officially crazy.

Following @JensV's clever suggestion, I added a function_exists() test in config.php, before including the functions.php file. This actually caught out a different incarnation of the same bug, which I had missed.

if (function_exists('okay')) {
    dump $_SERVER, get_included_files() and a lot of other things
    to a bagonghi.txt file
}
// Okay, the function is not defined. Define it.
require_once('/var/www/one/htdocs/functions.php');

The same functions.php file (i.e., the one in site one) turned out to sometime result already included, before the require_once happened. But even better, this is the output of get_included_files():

Array
(
    [0] => /var/www/one/index.php
    [1] => /var/www/one/config.php
)

...the function okay() is defined, but the only file that defines it has not yet been included.

So, this looks very much like a bug in the PHP (module, at the very least), except that I'm usually chary of calling out "bug" in something that lots of people ought to have noticed before I did.

I am using Apache module for now, and I'm reasonably confident that switching to FPM would remove the issue (at the very least, I can run one and two under different pools).

But I'm at my wits' end to understand what is actually going on here.

Solution

  • it was, of course, a module.

    Just not opcache alone. It turns out that the machine had (mistakenly) still active several PHP debugging/development modules, among these, runkit7. I had not checked it when adding opcache for staging and profiling, and this carelessness quite properly came back to bit me on the tail.

    Incompatibilities between the two modules are known.