Hello all,

I have already notified to the mailing list a performance problem with
apache/mod_php5.

Now I have an update and I think this is probably a bug.
PHP lstat the full path more times before read the file when in apache httpd
configuration is specified *PHP_ADMIN_VALUE open_basedir *setting.

I have a simple website with only phpinfo.php page and inside we have only
"<? phpinfo() ?>".

httpd.2.2.15 fresh compiled and PHP 5.2.13.

If is specified *PHP_ADMIN_VALUE open_basedir* in Virtual host
configuration:

<Directory "/usr/local/myspace/webspace/httpdocs">
 *               PHP_ADMIN_VALUE open_basedir "/usr/local/myspace/webspace"*
</Directory>
<VirtualHost *:80>
        ServerName damorealt.xoom.it
        DocumentRoot "/usr/local/myspace/webspace/httpdocs"
    CustomLog   /var/log/httpd/damorealt/access_log   combined
    ErrorLog   /var/log/httpd/damorealt/error_log
</VirtualHost >

Calling page http://damorealt.xoom.it/phpinfo.php we can reproduce following
behavior:

25933 accept(3, {sa_family=AF_INET, sin_port=htons(47433),
sin_addr=inet_addr("212.48.14.186")}, [17179869200]) = 15
25933 getsockname(15, {sa_family=AF_INET, sin_port=htons(80),
sin_addr=inet_addr("151.99.197.198")}, [17179869200]) = 0
25933 fcntl(15, F_GETFL)                = 0x2 (flags O_RDWR)
25933 fcntl(15, F_SETFL, O_RDWR|O_NONBLOCK) = 0
25933 read(15, "GET /phpinfo.php HTTP/1.0\r\nUser-"..., 8000) = 129
25933 gettimeofday({1278695388, 52976}, NULL) = 0
25933 stat("/usr/local/myspace/webspace/httpdocs/phpinfo.php",
{st_mode=S_IFREG|0644, st_size=16, ...}) = 0
25933 open("/usr/local/myspace/.htaccess", O_RDONLY) = -1 ENOENT (No such
file or directory)
25933 open("/usr/local/myspace/webspace/.htaccess", O_RDONLY) = -1 ENOENT
(No such file or directory)
25933 open("/usr/local/myspace/webspace/httpdocs/.htaccess", O_RDONLY) = -1
ENOENT (No such file or directory)
25933 open("/usr/local/myspace/webspace/httpdocs/phpinfo.php/.htaccess",
O_RDONLY) = -1 ENOTDIR (Not a directory)
25933 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={20, 0}}, NULL) =
0
25933 rt_sigaction(SIGPROF, {0x2b80442fdd80, [PROF], SA_RESTORER|SA_RESTART,
0x3916e302d0}, {SIG_DFL, [], 0}, 8) = 0
25933 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
25933 getcwd("/"..., 4095)              = 2
25933 chdir("/usr/local/myspace/webspace/httpdocs") = 0

*water boiling point*

25933 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace", {st_mode=S_IFDIR|0755, st_size=4096, ...})
= 0
25933 lstat("/usr/local/myspace/webspace", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace/webspace/httpdocs", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace/webspace/httpdocs/phpinfo.php",
{st_mode=S_IFREG|0644, st_size=16, ...}) = 0

First check

25933 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace", {st_mode=S_IFDIR|0755, st_size=4096, ...})
= 0
25933 lstat("/usr/local/myspace/webspace", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace/webspace/httpdocs", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace/webspace/httpdocs/phpinfo.php",
{st_mode=S_IFREG|0644, st_size=16, ...}) = 0

Second check

25933 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace", {st_mode=S_IFDIR|0755, st_size=4096, ...})
= 0
25933 lstat("/usr/local/myspace/webspace", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0

Third check (incomplete)

25933 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace", {st_mode=S_IFDIR|0755, st_size=4096, ...})
= 0
25933 lstat("/usr/local/myspace/webspace", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace/webspace/httpdocs", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
25933 lstat("/usr/local/myspace/webspace/httpdocs/phpinfo.php",
{st_mode=S_IFREG|0644, st_size=16, ...}) = 0

Final check and then read the file.

25933 open("/usr/local/myspace/webspace/httpdocs/phpinfo.php", O_RDONLY) =
16
25933 fstat(16, {st_mode=S_IFREG|0644, st_size=16, ...}) = 0
25933 read(16, "<? phpinfo() ?>\n", 8192) = 16
25933 read(16, "", 8192)                = 0
25933 read(16, "", 8192)                = 0
25933 close(16)                         = 0


If *PHP_ADMIN_VALUE open_basedir "/usr/local/myspace/webspace"  is
removed*in virtual host configuration we finally have simpliest
behavior:

226235 accept(3, {sa_family=AF_INET, sin_port=htons(59366),
sin_addr=inet_addr("212.48.14.186")}, [17179869200]) = 15
26235 getsockname(15, {sa_family=AF_INET, sin_port=htons(80),
sin_addr=inet_addr("151.99.197.198")}, [17179869200]) = 0
26235 fcntl(15, F_GETFL)                = 0x2 (flags O_RDWR)
26235 fcntl(15, F_SETFL, O_RDWR|O_NONBLOCK) = 0
26235 read(15, "GET /phpinfo.php HTTP/1.0\r\nUser-"..., 8000) = 129
26235 gettimeofday({1278696735, 988799}, NULL) = 0
26235 stat("/usr/local/myspace/webspace/httpdocs/phpinfo.php",
{st_mode=S_IFREG|0644, st_size=16, ...}) = 0
26235 open("/usr/local/myspace/.htaccess", O_RDONLY) = -1 ENOENT (No such
file or directory)
26235 open("/usr/local/myspace/webspace/.htaccess", O_RDONLY) = -1 ENOENT
(No such file or directory)
26235 open("/usr/local/myspace/webspace/httpdocs/.htaccess", O_RDONLY) = -1
ENOENT (No such file or directory)
26235 open("/usr/local/myspace/webspace/httpdocs/phpinfo.php/.htaccess",
O_RDONLY) = -1 ENOTDIR (Not a directory)
26235 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={20, 0}}, NULL) =
0
26235 rt_sigaction(SIGPROF, {0x2afef587dd80, [PROF], SA_RESTORER|SA_RESTART,
0x3916e302d0}, {SIG_DFL, [], 0}, 8) = 0
26235 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
26235 getcwd("/"..., 4095)              = 2
26235 chdir("/usr/local/myspace/webspace/httpdocs") = 0

*water boiling point*

26235 time(NULL)                        = 1278696735
26235 lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
26235 lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
26235 lstat("/usr/local/myspace", {st_mode=S_IFDIR|0755, st_size=4096, ...})
= 0
26235 lstat("/usr/local/myspace/webspace", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
26235 lstat("/usr/local/myspace/webspace/httpdocs", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
26235 lstat("/usr/local/myspace/webspace/httpdocs/phpinfo.php",
{st_mode=S_IFREG|0644, st_size=16, ...}) = 0

And read the file.

26235 open("/usr/local/myspace/webspace/httpdocs/phpinfo.php", O_RDONLY) =
16
26235 fstat(16, {st_mode=S_IFREG|0644, st_size=16, ...}) = 0
26235 read(16, "<? phpinfo() ?>\n", 8192) = 16
26235 read(16, "", 8192)                = 0
26235 read(16, "", 8192)                = 0
26235 close(16)                         = 0
26235 uname({sys="Linux", node="svilpar4", ...}) = 0
26235 time(NULL)                        = 1278696735
26235 writev(15, [{"HTTP/1.1 200 OK\r\nDate: Fri, 09 J"..., 173},
{"<!DOCTYPE html PUBLIC \"-//W3C//D"..., 4109}, {"<table border=\"0\"
cellpadding=\"3"..., 4101}], 3) = 8383
26235 writev(15, [{"<tr><td class=\"e\">highlight.bg</"..., 4105},
{"sendmail_from</td><td class=\"v\">"..., 4099}], 2) = 8204
26235 time(NULL)                        = 1278696735
26235 writev(15, [{" </td></tr>\n<tr><td class=\"e\">HT"..., 4108},
{"</td><td class=\"v\">1024</td><td "..., 4098}], 2) = 8206
26235 writev(15, [{"md2 md4 md5 sha1 sha256 sha384 s"..., 4098}, {"
</td></tr>\n</table><br />\n<tabl"..., 4106}], 2) = 8204
26235 writev(15, [{"session.use_cookies</td><td clas"..., 4104}, {" </td><td
class=\"v\">enabled </td"..., 4102}], 2) = 8206
26235 chdir("/")                        = 0
26235 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) =
0
26235 writev(15, [{"\"]</td><td class=\"v\">Keep-Alive<"..., 4206}], 1) =
4206
26235 write(10, "212.48.14.186 - - [09/Jul/2010:1"..., 116) = 116
26235 shutdown(15, 1 /* send */)        = 0
26235 poll([{fd=15, events=POLLIN}], 1, 2000) = 1 ([{fd=15,
revents=POLLIN|POLLHUP}])
26235 read(15, "", 512)                 = 0
26235 close(15)                         = 0
26235 read(4, 0x7fff615ff5eb, 1)        = -1 EAGAIN (Resource temporarily
unavailable)
26235 accept(3,

Note that this behavior also happens when safemode is ON.

Can somebody explain me why PHP have such behavior?

Best regards,
Vincenzo

Reply via email to