php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #57708 Wrong script executed (sapi_get_stat returns 0 inode)
Submitted: 2007-06-18 13:54 UTC Modified: 2009-05-05 14:48 UTC
Votes:2
Avg. Score:4.0 ± 1.0
Reproduced:2 of 2 (100.0%)
Same Version:1 (50.0%)
Same OS:1 (50.0%)
From: david at dfoerster dot de Assigned:
Status: No Feedback Package: APC (PECL)
PHP Version: 5.2.0 OS: Linux
Private report: No CVE-ID: None
View Add Comment Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
You can add a comment by following this link or if you reported this bug, you can edit this bug over here.
Block user comment
Status: Assign to:
Package:
Bug Type:
Summary:
From: david at dfoerster dot de
New email:
PHP Version: OS:

 

 [2007-06-18 13:54 UTC] david at dfoerster dot de
Description:
------------
I tried using APC on a site providing counters, guestbooks 
and similar services. When reloading a guestbook script 
very often, once in while a javascript code belonging to a 
counter would be returned alltough the logs clearly 
indicate that the guestbook script was executed.

I'll gladly provide any further information or try 
suggested fixes.

The affected system is a virtual linux server and the site 
makes heavy use of Apache's mod_rewrite (allthough the 
problem persists when using the script's URLs directly and 
no rewriting takes place). Just in case that helps.

Reproduce code:
---------------
Enter the URL of a script in the browser and reload the page very often.




Expected result:
----------------
The output of that script.

Actual result:
--------------
Sometimes the output of another script is shown.

(I cannot reproduce the problem on my local machine. It 
might only be triggered under heavy load.)

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2007-06-18 15:01 UTC] shire@php.net
This can sometimes happen when file inodes get switched and timestamps get backdated.  Are you using CVS, SVN, Rsync, or any other tool to update your source code that could be backdating the modified time of files?  If so try to use a different method that doesn't backdate the modified time, or enable the apc.stat_ctime option.
 [2007-06-18 15:01 UTC] shire@php.net
This can sometimes happen when file inodes get switched and timestamps get backdated.  Are you using CVS, SVN, Rsync, or any other tool to update your source code that could be backdating the modified time of files?  If so try to use a different method that doesn't backdate the modified time, or enable the apc.stat_ctime option.
 [2007-06-18 18:13 UTC] david at dfoerster dot de
Adding the apc.stat_ctime option didn't change anything. I 
can trigger that problem right after restarting apache 
without any of the scripts getting changed on the 
filesystem at all.
 [2007-06-18 19:30 UTC] shire@php.net
Can you post your apc ini settings, and your configuration options?  What version of APC are you using?

Are you using any symlinked paths or apc.stat=0?  If it's possible to trim this down to a *very* small reproduction it might help us debug. 

I don't think I've heard of this happening where the files were not being changed in some way ofter being cached.  If you run a apc_clear_cache() via an apache request does it fix the problem?
 [2007-06-20 11:20 UTC] david at dfoerster dot de
I narrowed this down to stat() sometimes returning 0 for 
the inode. I also tried disabling the sapi_get_stat call.

This seems to be a problem with the filesystem on the 
virtual server. Thanks for your effort!
 [2007-06-22 10:39 UTC] david at dfoerster dot de
I was only partly right in my previous comment. The 
sapi_get_stat call does indeed return 0 for the inode of 
every file. Disabling that call however fixes the problem.
 [2007-06-22 11:19 UTC] rasmus@php.net
Which web server are you using, and how are you running PHP? As in which SAPI are you using?
 [2007-06-22 11:31 UTC] david at dfoerster dot de
I'm running PHP as a module under Apache 2.0.54. (OS is 
Debian Sarge)
 [2007-06-22 11:36 UTC] rasmus@php.net
Hrm..  Suspicious.  Which PHP version, and from your phpinfo() page, what does it say for "Server API" near the top there?
 [2007-06-22 11:51 UTC] david at dfoerster dot de
PHP Version 5.2.0. Complete version string 
is "5.2.0-8+etch4~bpo.1".

Server Api is "Apache 2.0 Handler"

PHP API   20041225 
PHP Extension   20060613 
Zend Extension   220060519
 [2007-06-22 12:09 UTC] rasmus@php.net
This is the function in the Apache2 handler sapi that is getting called:

static struct stat*
php_apache_sapi_get_stat(TSRMLS_D)
{
    php_struct *ctx = SG(server_context);

    ctx->finfo.st_uid = ctx->r->finfo.user;
    ctx->finfo.st_gid = ctx->r->finfo.group;
    ctx->finfo.st_dev = ctx->r->finfo.device;
    ctx->finfo.st_ino = ctx->r->finfo.inode;
#if defined(NETWARE) && defined(CLIB_STAT_PATCH)
    ctx->finfo.st_atime.tv_sec = apr_time_sec(ctx->r->finfo.atime);
    ctx->finfo.st_mtime.tv_sec = apr_time_sec(ctx->r->finfo.mtime);
    ctx->finfo.st_ctime.tv_sec = apr_time_sec(ctx->r->finfo.ctime);
#else
    ctx->finfo.st_atime = apr_time_sec(ctx->r->finfo.atime);
    ctx->finfo.st_mtime = apr_time_sec(ctx->r->finfo.mtime);
    ctx->finfo.st_ctime = apr_time_sec(ctx->r->finfo.ctime);
#endif

    ctx->finfo.st_size = ctx->r->finfo.size;
    ctx->finfo.st_nlink = ctx->r->finfo.nlink;

    return &ctx->finfo;
}

Since you aren't on Netware it is the:

ctx->finfo.st_mtime = apr_time_sec(ctx->r->finfo.mtime);

line we are interested in.  So somehow this is 0?  Any chance you get set a gdb breakpoint on that to check out whether ctx->r->finfo.mtime is 0 going in?  If that is the case, we need to trace down into Apache2 to see why the current request context is not getting populated like it should.
 [2007-06-22 13:33 UTC] david at dfoerster dot de
I didn't have any success with the debugger. Is there any 
way to get the desired information without recompiling 
Apache and PHP with debug information? (Don't want to do 
that on the production machine.)

Some output added to the APC code shows that both st_ino 
and st_ctime fields are 0 and the other ones contain 
sensitive values.
 [2007-07-21 16:55 UTC] php-apc at projectjj dot com
I have hit upon similar behavior as well on a fresh machine, but it did not occur on the old machine I migrated away from. Site uses a lot of include/require and have many thousand small files (site is from before I knew how to use databases properly).

Seems the first file of a certain base name to be loaded will result in that file's data being passed along to other requests for files of the same name, despite them being in other folders.

Old working Fedora Core 3 (kernel 2.6.12-1.1381_FC3):
Apache 2.0.54
PHP 5.2.0
APC 3.0.12p2

New broken Fedora 7 (kernel 2.6.21-1.3228.fc7):
Apache 2.2.4 (with mpm_itk)
PHP 5.2.3
APC 3.0.14

Config is:
apc.num_files_hint = 6000
apc.ttl = 600
apc.gc_ttl = 600
apc.shm_size = 96
apc.shm_segments = 1
apc.include_once_override = 0
apc.write_lock = 1
apc.localcache = 1
apc.localcache.size = 4000

Tried using APC 3.0.12p2 with the new machine, but no such luck. No cigar with latest APC from cvs either.
apc.stat_ctime likewise has no effect.

Added some debug code to catch stat values, and none of the logged ones were 0.

Log code:
FILE *_cf = fopen("/tmp/php-debug.log", "ab");
fprintf(_cf, "R:%u %u %u S:%u %u %u\n", ctx->r->finfo.atime, ctx->r->finfo.mtime, ctx->r->finfo.ctime, ctx->finfo.st_atime, ctx->finfo.st_mtime, ctx->finfo.st_ctime);
fflush(_cf);
fclose(_cf);

Log output snippet:
R:963085184 275871 4007653184 S:270996 1695543040 275885
R:979085184 275871 3486408832 S:274933 1696543040 275885
R:220117888 275872 4007653184 S:270996 1715543040 275885
R:2428052480 275870 3947692160 S:264790 1779543040 275885
R:3243052480 275870 3013364992 S:274473 1778543040 275885
R:3253052480 275870 629533760 S:252065 1784543040 275885

Since I still enjoy the SHM facility of APC, I've resorted to turning off apc.cache_by_default for the affected site for now.
 [2007-07-22 07:35 UTC] gopalv82 at yahoo dot com
You are logging everything except the important value - st_ino.

The inode value is what is screwing up, from the previous comments. Rasmus said mtime, but I don't know why ??
 [2007-07-22 10:19 UTC] php-apc at projectjj dot com
I did indeed forget st_ino. Early morning debugging at its finest.

Added st_ino to output and it is never 0. Also added a corresponding output in apc_cache.c's key generation, and output looks fine.

I guess I have a different problem after all...
 [2009-03-24 14:34 UTC] shire@php.net
Does anyone still have a reproducible case for this bug that we can look at?
 [2009-05-05 14:48 UTC] shire@php.net
No feedback was provided. The bug is being suspended because
we assume that you are no longer experiencing the problem.
If this is not the case and you are able to provide the
information that was requested earlier, please do so and
change the status of the bug back to "Open". Thank you.


 
PHP Copyright © 2001-2021 The PHP Group
All rights reserved.
Last updated: Fri Dec 03 17:03:34 2021 UTC