From: ben at indietorrent dot org Operating system: Windows 7 x64 PHP version: 5.4.8 Package: Scripting Engine problem Bug Type: Bug Bug description:Intermittent warning and fatal error on require() statement
Description: ------------ I observe erratic behavior relating to require() statements. The files that are being required are static (they are not created or destroyed during script execution), so there should be no reason that they are required successfully the vast majority of the time, but fail to be required some small percentage of the time. It bears mention that I am also wrapping the calls to require() in calls to file_exists(). It seems that while file_exists() always returns true (the require() statements are always executed), the calls to require() fail intermittently with "PHP Warning: Unknown: failed to open stream: No such file or directory" and then "PHP Fatal error: Unknown: Failed opening required". The symptoms of this issue are very similar to those described in https://bugs.php.net/bug.php?id=49012 ("Spurious fatal error on require() statement"), but I don't know whether the root cause is the same or not. I have confirmed that this problem occurs on several different computers, no two of which have the exact same OS or *AMP stack component versions. For this reason, I do not believe this issue to be due to failing hardware, a corrupt operating system, or similar. I should note also that in PHP 5.2 and 5.3, the offending line number was always zero (0). Unless line number zero has some special meaning in PHP, this seems like a bug in itself. In any case, in PHP 5.4.8, the line number is non-zero *usually* (but not always), and seems to be accurate. (I have not tested with any PHP version before 5.2 or between 5.3 and 5.4.8.) I have not installed any third-party extensions and am using a pristine 5.4.8 installation. PHP is running via Apache's mod_php module. php.ini is relatively untouched; the only changes I made were to enable some of the modules that are disabled by default (I can list them if it's relevant). Unfortunately, I am unable to reproduce this issue at will, because it occurs completely sporadically. That said, the problem occurs quite frequently, so, if a developer is able to provide specific debugging instructions, it should be easy enough for me to capture the relevant information. By "quite frequently", I mean every couple of minutes during normal browsing. Also, I have used Firefox's handy "Reload Tab Every..." context menu feature to reload an affected page every 1 second for 10 minutes straight and the issue occurred only twice. This seems to indicate that the issue does not necessarily occur some percentage of the time (+/- variance), but rather, it occurs when more complex conditions are met. For whatever reason, the issue occurs most frequently when I make several concurrent requests to the affected URLs/files, and I navigate to various URLs before each page has loaded fully. Strangely enough, if I let the auto-refresh test run long enough (this run, it took more than 30 minutes of refreshing every second), the specific error messages change (the location of the failed require statements change), but their nature is always the same: failed require() statements due to variations of "file not found". Also, the issue seems most likely to occur when the Web-server (Apache in this case) has been sitting idle for some period of time (e.g., 10 or more minutes). Oftentimes, if I have been away from the computer and refresh an affected page when I return, the issue occurs. Could this behavior point to memory managment or caching? The code-base that causes this issue is shared across several different production websites, all of which run on various GNU/Linux distributions. With Ubuntu 10.04 + Apache 2.2.14 + mod_php + PHP 5.3.2, I do not observe the issue at all. On another identically-configured server, the only difference being Fast-CGI (fcgid) instead of mod_php, I do observe the issue, but its manifestation is slightly different than on Windows with mod_php. (I'm happy to provide details regarding the differences.) I find it particularly strange that the messages and specific points of failure change over time. The first log entry (made only a few seconds after Apache was started) makes no sense; there is no file mentioned, and the line number is zero: -------------------- [29-Oct-2012 15:30:29 America/New_York] PHP Warning: Unknown: failed to open stream: No such file or directory in Unknown on line 0 -------------------- At least the related fatal error mentions a file: -------------------- [29-Oct-2012 15:30:29 America/New_York] PHP Fatal error: Unknown: Failed opening required 'C:/Users/Ben/Documents/Apache/project/public/auxiliary/css.php' (include_path='.;C:\Program Files\php\includes;C:\Program Files\php\PEAR\pear') in Unknown on line 0 -------------------- The next time the warning/fatal occurs, we have a file AND a line number: -------------------- [29-Oct-2012 15:31:19 America/New_York] PHP Warning: require(../include/global.inc.php): failed to open stream: No such file or directory in C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk\public\auxiliary\css.php on line 5 [29-Oct-2012 15:31:19 America/New_York] PHP Fatal error: require(): Failed opening required '../include/global.inc.php' (include_path='.;C:\Program Files\php\includes;C:\Program Files\php\PEAR\pear') in C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk\public\auxiliary\css.php on line 5 -------------------- I mean... what, does PHP need to "warm-up"? This warning/fatal sequence carries-on for some minutes, and then the error (provided this is indeed the same root-cause) morphs slightly: -------------------- [29-Oct-2012 15:34:07 America/New_York] PHP Fatal error: Uncaught exception 'SmartyException' with message 'Unable to load template file 'C:/Users/Ben/Documents/Apache/project/protected/templates\css/global.css'' in C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk\protected\common\libs\php-classes\external\Smarty-3.1.11\libs\sysplugins\smarty_internal_templatebase.php:127 Stack trace: #0 C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk\protected\common\libs\php-classes\external\Smarty-3.1.11\libs\sysplugins\smarty_internal_templatebase.php(374): Smarty_Internal_TemplateBase->fetch('C:/Users/Ben/Do...', NULL, NULL, NULL, true) #1 C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk\public\auxiliary\css.php(75): Smarty_Internal_TemplateBase->display('C:/Users/Ben/Do...') #2 {main} thrown in C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk\protected\common\libs\php-classes\external\Smarty-3.1.11\libs\sysplugins\smarty_internal_templatebase.php on line 127 -------------------- After this point, the errors don't change again. I have discussed this issue at length on the Smarty forums ( http://www.smarty.net/forums/viewtopic.php?t=23591 ) and the Smarty authors pointed-out that Smarty throws the above exception when a call to filemtime($templateSourceFile) returns FALSE (Smarty does not bother to read the file's contents when filemtime() returns FALSE). So, we have erroneous failures when require() is called, coupled with erroneous failures when filemtime() is called. The path from the above log excerpts, "C:/Users/Ben/Documents/Apache/project", is an NFTS junction point that resolves to "C:\Users\Ben\Documents\Projects\project Testing\project-svn\trunk". I'm not sure that this is relevant, because the errors occur regardless of which path I use in the calls to require(), but it deserves mention in light of https://bugs.php.net/bug.php?id=39484 ("intermittent include failure under symlinked virtual hosts"). -- Edit bug report at https://bugs.php.net/bug.php?id=63413&edit=1 -- Try a snapshot (PHP 5.4): https://bugs.php.net/fix.php?id=63413&r=trysnapshot54 Try a snapshot (PHP 5.3): https://bugs.php.net/fix.php?id=63413&r=trysnapshot53 Try a snapshot (trunk): https://bugs.php.net/fix.php?id=63413&r=trysnapshottrunk Fixed in SVN: https://bugs.php.net/fix.php?id=63413&r=fixed Fixed in release: https://bugs.php.net/fix.php?id=63413&r=alreadyfixed Need backtrace: https://bugs.php.net/fix.php?id=63413&r=needtrace Need Reproduce Script: https://bugs.php.net/fix.php?id=63413&r=needscript Try newer version: https://bugs.php.net/fix.php?id=63413&r=oldversion Not developer issue: https://bugs.php.net/fix.php?id=63413&r=support Expected behavior: https://bugs.php.net/fix.php?id=63413&r=notwrong Not enough info: https://bugs.php.net/fix.php?id=63413&r=notenoughinfo Submitted twice: https://bugs.php.net/fix.php?id=63413&r=submittedtwice register_globals: https://bugs.php.net/fix.php?id=63413&r=globals PHP 4 support discontinued: https://bugs.php.net/fix.php?id=63413&r=php4 Daylight Savings: https://bugs.php.net/fix.php?id=63413&r=dst IIS Stability: https://bugs.php.net/fix.php?id=63413&r=isapi Install GNU Sed: https://bugs.php.net/fix.php?id=63413&r=gnused Floating point limitations: https://bugs.php.net/fix.php?id=63413&r=float No Zend Extensions: https://bugs.php.net/fix.php?id=63413&r=nozend MySQL Configuration Error: https://bugs.php.net/fix.php?id=63413&r=mysqlcfg
