Hello All,
I have a performance problem with an Apache/PHP5 Configuration under heavy load the website becomes too slow.
Using strace I found what appears to me a strange behavior.
The strange behavior I want point out is related to a sequence of tentative httpd does in order to read an file.
In this particular case apache httpd servers tries 8 times before reach and read the file (if you want I can send the complete strace output)
More strange all these tentative seems to be correctly completed because of success (0) return code for each line.
For every file should be served by apache httpd, apache httpd tries to lstat all directory in path more times:
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs", {st_mode=S_IFDIR|0755, st_size=2048, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
FIRST TENTATIVE
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs", {st_mode=S_IFDIR|0755, st_size=2048, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
SECOND
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
access("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", R_OK) = 0
THIRD
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs", {st_mode=S_IFDIR|0755, st_size=2048, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
FOURTH
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs", {st_mode=S_IFDIR|0755, st_size=2048, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
FIFTH
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs", {st_mode=S_IFDIR|0755, st_size=2048, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
SIXTH
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
SEVENTH (blocked in the middle of path scan)
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/myspaces/myspaces08", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP", {st_mode=S_IFDIR|0755, st_size=13312, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al", {st_mode=S_IFDIR|0755, st_size=80, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps", {st_mode=S_IFDIR|0750, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs", {st_mode=S_IFDIR|0755, st_size=2048, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages", {st_mode=S_IFDIR|0777, st_size=1024, ...}) = 0
lstat("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
EIGHT AND FINALLY READ THE FILE
open("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", O_RDONLY) = 416
fstat(416, {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
open("/usr/local/myspaces/myspaces08/NSP/wa/al/wall/webspace/siteapps/21451/htdocs/wp-content/languages/zh_CN.php", O_RDONLY) = 417
fstat(417, {st_mode=S_IFREG|0777, st_size=1312, ...}) = 0
mmap(NULL, 1312, PROT_READ, MAP_SHARED, 417, 0) = 0x2b4a96443000
munmap(0x2b4a96443000, 1312) = 0
close(417) = 0
read(416, "<?php\r\n// Make the admin interfa"..., 8192) = 1312
read(416, "", 8192) = 0
read(416, "", 8192) = 0
close(416) = 0
Could anybody explain me why I have this behavior?
I'm not sure it is attributable to a misconfiguration of php, because I see it happen also with different types of files (i.e. css, gif, jpg...)
# httpd -V
Server version: Apache/2.2.11 (Unix)
Server built: Jan 8 2009 09:27:22
Server's Module Magic Number: 20051115:21
Server loaded: APR 1.2.7, APR-Util 1.2.7
Compiled using: APR 1.2.7, APR-Util 1.2.7
Architecture: 64-bit
Server MPM: Prefork
threaded: no
forked: yes (variable process count)
Server compiled with....
-D APACHE_MPM_DIR="server/mpm/prefork"
-D APR_HAS_SENDFILE
-D APR_HAS_MMAP
-D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
-D APR_USE_SYSVSEM_SERIALIZE
-D APR_USE_PTHREAD_SERIALIZE
-D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
-D APR_HAS_OTHER_CHILD
-D AP_HAVE_RELIABLE_PIPED_LOGS
-D DYNAMIC_MODULE_LIMIT=128
-D HTTPD_ROOT="/etc/httpd"
-D SUEXEC_BIN="/usr/sbin/suexec"
-D DEFAULT_PIDLOG="logs/httpd.pid"
-D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
-D DEFAULT_LOCKFILE="logs/accept.lock"
-D DEFAULT_ERRORLOG="logs/error_log"
-D AP_TYPES_CONFIG_FILE="conf/mime.types"
-D SERVER_CONFIG_FILE="conf/httpd.conf"
# cat /proc/version
Linux version 2.6.18-028stab062.3 (root@rhel5-64-build) (gcc version 4.1.2
20070626 (Red Hat 4.1.2-14)) #1 SMP Thu Mar 26 14:46:38 MSK 2009
# /usr/libexec/php5-cgi/bin/php -v
PHP 5.2.9 (cli) (built: Sep 14 2009 16:52:55)
Copyright (c) 1997-2009 The PHP Group
Zend Engine v2.2.0, Copyright (c) 1998-2009 Zend Technologies
with the ionCube PHP Loader v3.1.33, Copyright (c) 2002-2007, by ionCube Ltd.
</pre>
Any help is very appreciated,
Vincenzo
