Diagnosing Slow Page Loads

Hey Gang,

I am having some issues on my Linode 160 regarding slow page loads. I am trying to pinpoint why this is occurring. Specifically, I am having issues with SquirrelMail, gallery and Joomla/Mambo sites. I am seeing about 10 seconds for a squirrelmail login on average and 5-15 second login on Joomla sites.

Anyway. I have 3 squirrelmail 2 joomla sites and 5 gallery sites. Very low load (less than 250 visits per day).

I am planning on rolling out a Joomla site for my apartment building (100 families) so that may add more load later on. I am trying to plan for the future and I have considered moving to a dedicated server if this is load related.

What is the best way for me to isolate why I am seeing login delays and general HTTP performance lags?

Below are some details of what I am running today:

Linode 160
Host51
Debain Stable
Kernel 2.6.12.3
Apache 2.0.54
MySQL 4.0.24
Courier IMAP
Postfix 2.1.5

VMSTAT

procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
 0  0  58544   8312   4088  18196   32   16    65    34  148    30  1  0 95  3

FREE

             total       used       free     shared    buffers     cached
Mem:        155548     145568       9980          0       4516      20832
-/+ buffers/cache:     120220      35328
Swap:       103416      58608      44808

TOP

metrowebworks:~# top
top - 10:54:46 up 2 days,  3:18,  1 user,  load average: 0.58, 0.50, 0.30
Tasks:  71 total,   1 running,  70 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.4% us,  0.0% sy,  0.0% ni, 99.6% id,  0.0% wa,  0.0% hi,  0.0% si
Mem:    155548k total,   147716k used,     7832k free,     4140k buffers
Swap:   103416k total,    58532k used,    44884k free,    18248k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                         
20966 root      16   0  2124 1072  852 R  0.3  0.7   0:00.02 top                                                                             
    1 root      16   0  1576  436  412 S  0.0  0.3   0:00.31 init                                                                            
    2 root      34  19     0    0    0 S  0.0  0.0   0:00.13 ksoftirqd/0                                                                     
    3 root      10  -5     0    0    0 S  0.0  0.0   0:00.09 events/0                                                                        
    4 root      20  -5     0    0    0 S  0.0  0.0   0:00.00 khelper                                                                         
    5 root      10  -5     0    0    0 S  0.0  0.0   0:00.00 kthread                                                                         
    6 root      10  -5     0    0    0 S  0.0  0.0   0:01.31 kblockd/0                                                                       
   62 root      20  -5     0    0    0 S  0.0  0.0   0:00.00 aio/0                                                                           
   61 root      15   0     0    0    0 S  0.0  0.0   0:18.54 kswapd0                                                                         
   63 root      25   0     0    0    0 S  0.0  0.0   0:00.00 jfsIO                                                                           
   64 root      25   0     0    0    0 S  0.0  0.0   0:00.00 jfsCommit                                                                       
   65 root      25   0     0    0    0 S  0.0  0.0   0:00.00 jfsSync                                                                         
   66 root      20  -5     0    0    0 S  0.0  0.0   0:00.00 xfslogd/0                                                                       
   67 root      20  -5     0    0    0 S  0.0  0.0   0:00.00 xfsdatad/0                                                                      
   68 root      15   0     0    0    0 S  0.0  0.0   0:00.70 xfsbufd                                                                         
  613 root      11  -5     0    0    0 S  0.0  0.0   0:00.00 kcryptd/0                                                                       
  707 root      15   0     0    0    0 S  0.0  0.0   0:02.42 kjournald                                                                       
  805 root      15   0     0    0    0 S  0.0  0.0   0:00.26 kjournald                                                                       
 2247 root      16   0  3800  496  496 S  0.0  0.3   0:00.35 sshd                                                                            
 2267 root      15   0  1612  532  460 S  0.0  0.3   0:01.30 syslogd                                                                         
 2270 root      16   0  1572  408  380 S  0.0  0.3   0:00.04 klogd                                                                           
 2275 root      16   0  1748  376  376 S  0.0  0.2   0:00.00 courierlogger                                                                   
 2276 root      16   0  1860  408  388 S  0.0  0.3   0:00.00 authdaemond.pla                                                                 
 2278 root      16   0  2048  548  492 S  0.0  0.4   0:00.32 authdaemond.pla                                                                 
 2279 root      16   0  2048  552  496 S  0.0  0.4   0:00.30 authdaemond.pla                                                                 
 2280 root      16   0  2048  544  496 S  0.0  0.3   0:00.39 authdaemond.pla                                                                 
 2281 root      16   0  2048  540  488 S  0.0  0.3   0:00.32 authdaemond.pla                                                                 
 2282 root      16   0  2048  548  492 S  0.0  0.4   0:00.34 authdaemond.pla                                                                 
 2287 root      15   0  1844  440  412 S  0.0  0.3   0:00.23 couriertcpd                                                                     
 2290 root      15   0  1748  452  396 S  0.0  0.3   0:00.21 courierlogger                                                                   
 2295 root      16   0  1844  436  408 S  0.0  0.3   0:00.01 couriertcpd                                                                     
 2300 root      15   0  1744  448  396 S  0.0  0.3   0:00.04 courierlogger                                                                   
 2304 root      16   0  1604  408  408 S  0.0  0.3   0:00.01 inetd                                                            

MY.CNF

#
# The MySQL database server configuration file.
#
# You can copy this to one of:
# - "/etc/mysql/my.cnf" to set global options,
# - "/var/lib/mysql/my.cnf" to set server-specific options or
# - "~/.my.cnf" to set user-specific options.
#
# One can use all long options that the program supports.
# Run program with --help to get a list of available options and with
# --print-defaults to see which it would actually understand and use.
#
# For explanations see
# http://dev.mysql.com/doc/mysql/en/server-system-variables.html

# This will be passed to all mysql clients
# It has been reported that passwords should be enclosed with ticks/quotes
# escpecially if they contain "#" chars...
# Remember to edit /etc/mysql/debian.cnf when changing the socket location.
[client]
port            = 3306
socket          = /var/run/mysqld/mysqld.sock

# Here is entries for some specific programs
# The following values assume you have at least 32M ram

# This was formally known as [safe_mysqld]. Both versions are currently parsed.
[mysqld_safe]
socket          = /var/run/mysqld/mysqld.sock
nice            = 0

[mysqld]
#
# * Basic Settings
#
user            = mysql
pid-file        = /var/run/mysqld/mysqld.pid
socket          = /var/run/mysqld/mysqld.sock
port            = 3306
basedir         = /usr
datadir         = /var/lib/mysql
tmpdir          = /tmp
language        = /usr/share/mysql/english
skip-external-locking
#
# Instead of skip-networking the default is now to listen only on
# localhost which is more compatible and is not less secure.
bind-address            = 127.0.0.1
#
# * Fine Tuning
#
key_buffer              = 128K
max_allowed_packet      = 1M
thread_stack            = 64K
table_cache             = 4
sort_buffer             = 64K
net_buffer_length       = 2K

skip-locking

#
# * Query Cache Configuration
#
query_cache_limit       = 1048576
query_cache_size        = 16777216
query_cache_type        = 1
#
# * Logging and Replication
#
# Both location gets rotated by the cronjob.
# Be aware that this log type is a performance killer.
#log            = /var/log/mysql.log
#log            = /var/log/mysql/mysql.log
#
# Error logging goes to syslog. This is a Debian improvement :)
#
# Here you can see queries with especially long duration
#log-slow-queries       = /var/log/mysql/mysql-slow.log
#
# The following can be used as easy to replay backup logs or for replication.
#server-id              = 1
# log-bin                 = /var/log/mysql/mysql-bin.log
# See /etc/mysql/debian-log-rotate.conf for the number of files kept.
max_binlog_size         = 104857600
#binlog-do-db           = include_database_name
#binlog-ignore-db       = include_database_name
#
# * BerkeleyDB
#
# The use of BerkeleyDB is now discouraged and support for it will probably
# cease in the next versions.
skip-bdb
#
# * InnoDB
skip-innodb
#
# InnoDB is enabled by default with a 10MB datafile in /var/lib/mysql/.
# Read the manual for more InnoDB related options. There are many!
#
# * Security Feature
#
# Read the manual, too, if you want chroot!
# chroot = /var/lib/mysql/
#
# If you want to enable SSL support (recommended) read the manual or my
# HOWTO in /usr/share/doc/mysql-server/SSL-MINI-HOWTO.txt.gz
# ssl-ca=/etc/mysql/cacert.pem
# ssl-cert=/etc/mysql/server-cert.pem
# ssl-key=/etc/mysql/server-key.pem

[mysqldump]
quick
quote-names
max_allowed_packet      = 8M
# sort_buffer           = 8M
[mysql]
#no-auto-rehash # faster start of mysql but no tab completition

[isamchk]
key_buffer              = 8M
sort_buffer             = 8M

APACHE.CONF

##
## Server-Pool Size Regulation (MPM specific)
## 

# prefork MPM
# StartServers ......... number of server processes to start
# MinSpareServers ...... minimum number of server processes which are kept spare
# MaxSpareServers ...... maximum number of server processes which are kept spare
# MaxClients ........... maximum number of server processes allowed to start
# MaxRequestsPerChild .. maximum number of requests a server process serves
 <ifmodule prefork.c="">StartServers         5
MinSpareServers      2
MaxSpareServers     10
MaxClients          10
MaxRequestsPerChild  0</ifmodule> 

# pthread MPM
# StartServers ......... initial  number of server processes to start
# MaxClients ........... maximum  number of server processes allowed to start
# MinSpareThreads ...... minimum  number of worker threads which are kept spare
# MaxSpareThreads ...... maximum  number of worker threads which are kept spare
# ThreadsPerChild ...... constant number of worker threads in each server process
# MaxRequestsPerChild .. maximum  number of requests a server process serves
 <ifmodule worker.c="">StartServers         2
MaxClients         20 
MinSpareThreads     25
MaxSpareThreads     75
ThreadsPerChild     25
MaxRequestsPerChild  0</ifmodule> 

# perchild MPM
# NumServers ........... constant number of server processes
# StartThreads ......... initial  number of worker threads in each server process
# MinSpareThreads ...... minimum  number of worker threads which are kept spare
# MaxSpareThreads ...... maximum  number of worker threads which are kept spare
# MaxThreadsPerChild ... maximum  number of worker threads in each server process
# MaxRequestsPerChild .. maximum  number of connections per server process (then it dies)
 <ifmodule perchild.c="">NumServers           5
StartThreads         5
MinSpareThreads      5
MaxSpareThreads     10
MaxThreadsPerChild  20
MaxRequestsPerChild  0
AcceptMutex fcntl</ifmodule> 

12 Replies

Your swap activity is a bit high so though the amount in swap isn't terribly large, you are actively using it which makes things worse, vmstat output for a longer period (say 10 seconds) would help.

You don't specify which Apache server pool managment method you are using but if you are only getting 250 hits per day, they are all a bit on the high side.

As for the top output, try sorting by memory usage, will be much more informative.

I am using Here is VMSTAT for 10 Seconds ( i launched an SSL login of squirrelmail at the beginning)

metrowebworks:~# vmstat 1 10
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
 0  0  54016  13740   3944  17840   32   16    65    34  148    30  1  0 95  3
 1  0  54004  13356   3948  17864  140    0   156    77  263   198 37 13 47  3
 1  0  54004  13100   3964  17900    0    0    32   285  243   205 48 39 14  0
 0  0  54004  13280   3964  17904    0    0     0     0  113    28  1  0 99  0
 0  0  54004  13280   3964  17904    0    0     0     0  102     7  0  0 100  0
 0  0  54004  13280   3964  17904    0    0     0     0  103     7  0  0 100  0
 0  0  54004  13280   3972  17904    0    0     0   198  157    19  0  0 100  0
 0  0  54004  13280   3980  17904    0    0     0    17  119    17  0  0 100  0
 0  0  54004  13320   3980  17904    0    0     0     0  102     7  0  0 100  0
 0  0  54004  13320   3980  17904    0    0     0     0  102     9  0  0 100  0

MRTG

http://www.metrowebworks.com/mrtg

Top Sorted by Memory Utilization

top - 11:49:10 up 2 days,  4:12,  1 user,  load average: 0.03, 0.13, 0.15
Tasks:  63 total,   1 running,  62 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0% us,  0.0% sy,  0.0% ni, 100.0% id,  0.0% wa,  0.0% hi,  0.0% si
Mem:    155548k total,   148600k used,     6948k free,     5048k buffers
Swap:   103416k total,    53548k used,    49868k free,    21120k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                         
 4888 www-data  16   0 35932  16m 3312 S  0.0 10.5   2:02.15 apache2                                                                         
 3418 www-data  15   0 35828  15m 3340 S  0.0 10.2   2:01.80 apache2                                                                         
 2855 www-data  15   0 34972  15m 3280 S  0.0 10.2   1:55.01 apache2                                                                         
 2856 www-data  16   0 35812  14m 3316 S  0.0  9.6   1:59.98 apache2                                                                         
 4822 www-data  15   0 36124  13m 3324 S  0.0  9.1   2:03.00 apache2                                                                         
 4889 www-data  15   0 35020  13m 3256 S  0.0  8.6   1:54.23 apache2                                                                         
 3301 www-data  15   0 34856  13m 3236 S  0.0  8.6   2:00.76 apache2                                                                         
 2857 www-data  15   0 35952  12m 3232 S  0.0  8.4   1:57.27 apache2                                                                         
 2859 www-data  15   0 35220  10m 3264 S  0.0  7.0   2:14.39 apache2                                                                         
 2858 www-data  15   0 35844  10m 3428 S  0.0  6.9   2:03.30 apache2                                                                         
 2356 mysql     16   0 25892 5192 1692 S  0.0  3.3   0:00.23 mysqld                                                                          
 2358 mysql     16   0 25892 5192 1692 S  0.0  3.3   0:00.55 mysqld                                                                          
 2359 mysql     15   0 25892 5192 1692 S  0.0  3.3   0:02.45 mysqld                                                                          
 2725 root      16   0  8752 2456 1568 S  0.0  1.6   0:00.49 miniserv.pl                                                                     
21068 root      15   0  2676 1472 1136 S  0.0  0.9   0:00.01 bash                                                                            
20816 postfix   16   0  3036 1128  964 S  0.0  0.7   0:00.01 pickup                                                                          
21898 root      16   0  2124 1068  852 R  0.0  0.7   0:00.07 top                                                                             
 2355 root      24   0  2572  892  892 S  0.0  0.6   0:00.00 mysqld_safe                                                                     
 2319 root      24   0  2572  888  888 S  0.0  0.6   0:00.02 mysqld_safe                                                                     
 2497 postfix   16   0  3068  812  696 S  0.0  0.5   0:00.44 qmgr                                                                            
 2656 root      16   0 23532  692  660 S  0.0  0.4   0:00.67 apache2                                                                         
 2512 root      16   0  6988  676  676 S  0.0  0.4   0:00.01 saslauthd                                                                       
 2511 root      16   0  6988  644  644 S  0.0  0.4   0:00.03 saslauthd                                                                       
 2493 root      16   0  3032  604  536 S  0.0  0.4   0:00.95 master                                                                          
 2507 root      16   0  6988  584  584 S  0.0  0.4   0:00.00 saslauthd                                                                       
 2517 root      16   0  6988  584  584 S  0.0  0.4   0:00.01 saslauthd                                                                       
 2516 root      16   0  6988  572  572 S  0.0  0.4   0:00.00 saslauthd                                                                       
 2279 root      15   0  2048  552  496 S  0.0  0.4   0:00.33 authdaemond.pla                                                                 
 2280 root      15   0  2048  552  496 S  0.0  0.4   0:00.41 authdaemond.pla                                                                 
 2530 root      16   0  1816  552  476 S  0.0  0.4   0:00.77 cron                                                                            
 2278 root      15   0  2048  548  492 S  0.0  0.4   0:00.33 authdaemond.pla                                                                 
 2282 root      15   0  2048  548  492 S  0.0  0.4   0:00.36 authdaemond.pla                                                                 
 2281 root      15   0  2048  544  488 S  0.0  0.3   0:00.34 authdaemond.pla  

I am not sure how to figure out if I am using worker or thread. Where is this designated?

metrowebworks:/etc/apache2/mods-enabled# /usr/sbin/apache2 -V
Server version: Apache/2.0.54
Server built:   Sep  5 2005 11:15:09
Server's Module Magic Number: 20020903:9
Architecture:   32-bit
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 HTTPD_ROOT=""
 -D SUEXEC_BIN="/usr/lib/apache2/suexec2"
 -D DEFAULT_PIDLOG="/var/run/httpd.pid"
 -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
 -D DEFAULT_LOCKFILE="/var/run/accept.lock"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D AP_TYPES_CONFIG_FILE="/etc/apache2/mime.types"
 -D SERVER_CONFIG_FILE="/etc/apache2/apache2.conf"
metrowebworks:/etc/apache2/mods-enabled# ll
total 0
lrwxrwxrwx  1 root root 36 Jun  7 22:55 cgi.load -> /etc/apache2/mods-available/cgi.load
lrwxrwxrwx  1 root root 37 Jun  7 22:56 perl.conf -> /etc/apache2/mods-available/perl.conf
lrwxrwxrwx  1 root root 37 Jun  7 22:56 perl.load -> /etc/apache2/mods-available/perl.load
lrwxrwxrwx  1 root root 37 Jun  7 22:55 php4.conf -> /etc/apache2/mods-available/php4.conf
lrwxrwxrwx  1 root root 37 Jun  7 22:55 php4.load -> /etc/apache2/mods-available/php4.load
lrwxrwxrwx  1 root root 40 Jun  7 22:58 rewrite.load -> /etc/apache2/mods-available/rewrite.load
lrwxrwxrwx  1 root root 36 Jun  7 22:58 ssl.conf -> /etc/apache2/mods-available/ssl.conf
lrwxrwxrwx  1 root root 36 Jun  7 22:58 ssl.load -> /etc/apache2/mods-available/ssl.load
lrwxrwxrwx  1 root root 39 Jun  7 22:58 suexec.load -> /etc/apache2/mods-available/suexec.load
lrwxrwxrwx  1 root root 40 Jun  7 22:54 userdir.conf -> /etc/apache2/mods-available/userdir.conf
lrwxrwxrwx  1 root root 40 Jun  7 22:54 userdir.load -> /etc/apache2/mods-available/userdir.load

Thanks mike!

Here is a more accurate representation of web access from my AWstats summary page in Webmin:

This is for October 2005 so far. Each row represents a website.

![](" />

Anyone care to comment? Mikegrb?

Thanks!!

Ron

I find that these page load delays are worse if Apache has been idle for some time. I think that the delay is caused by parts of Apache having to be swapped back into physical memory. When there is no web traffic, Apache does very little, whereas, even if there is no mail being sent or received, Postfix is always active, spawning processes to check queues and so forth. The kernel sees this and swaps parts of Apache out because it is idle and there are other, busier processes that may need the memory.

Here is vmstat reporting every five seconds while I call up a web page - Apache has been idle for over thirty minutes:````
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
0 0 88976 8620 7536 13516 2 1 5 14 6 14 0 1 98 0
0 0 88976 8572 7580 13516 0 0 0 14 105 12 0 1 99 0
0 0 88976 8436 7716 13516 0 0 0 52 114 13 5 10 85 0
0 0 88976 8412 7740 13516 0 0 0 8 103 10 0 0 100 0
0 0 88976 8412 7740 13516 0 0 0 10 103 8 0 0 100 0
0 0 88976 8412 7740 13516 0 0 0 0 101 8 0 0 100 0
1 0 88976 7644 7796 13548 136 0 150 7 139 26 1 0 99 0
0 0 88976 3564 7872 15252 458 0 801 14 308 75 0 0 100 0
0 0 88976 3540 7892 15252 0 0 0 6 103 11 0 0 100 0
0 0 88976 3492 7936 15256 0 0 0 14 105 15 0 0 100 0

Here is ps reporting before and after I called up a web page (different occasion, but again, Apache had been idle for half an hour:````
fremont usr # ps -C apache2 -o pid,sz,rss,vsz
  PID    SZ   RSS    VSZ
 1352  6265  1208  25060
29062  6089   452  24356
29063  7618  1468  30472
29064  7502  3884  30008
29065  7490  2504  29960
32642  7453  4096  29812
31899  7464  1560  29856
fremont usr # ps -C apache2 -o pid,sz,rss,vsz
  PID    SZ   RSS    VSZ
 1352  6265  1208  25060
29062  6089   452  24356
29063  7618  3544  30472
29064  7502  3884  30008
29065  7490  2504  29960
32642  7453  4096  29812
31899  7464  1604  29856

You can see that process 29063 did the work, because its resident set size has gone up from 1468 to 3544 kB as stuff was swapped back in.

Maybe the solution is to adjust some of the kernel vmm parameters? Is there a vm subsystem guru in the house?

Or just run a big Linode so you never use swap.

Yeah, I was going to recommend chacking your swap usage. I think others are right about apache swapping. Is there anything you can sacrifice to reduce your memory needs? My linode 120 stays fast and responsive, but almost never touches swap… but I'm not running much more than qmail + apache + named.

You might also want to play with different swappiness values (you can echo a number of 0 to 100 into /proc/sys/vm/swappiness to tune it).

@NecroBones:

You might also want to play with different swappiness values (you can echo a number of 0 to 100 into /proc/sys/vm/swappiness to tune it).

I have it set to 60. Without knowing what this does, I'm not sure what i should set it to.

Also, would it require a reboot to become live?

The swappiness setting takes effect immediately. Note that with a low enough setting, the kernel may decide that there is an out-of-memory condition even when there is swap available to free up pages.

Also, set MaxRequestsPerChild in your apache configuration to something like 20 or 25. This will cause apache to clean up unused child processes fairly regularly, and each time an apache child process is terminated the swap pages that are backing that process's unmapped memory are freed, along with any unmapped memory that might actually be resident. I have mine set to 15, personally, but my site is very low traffic. Also, if you can tighten up MaxSpareServers, too, that will help.

if you're running PHP you're most likely using the prefork mpm since PHP is not thread-safe.

@OverlordQ:

if you're running PHP you're most likely using the prefork mpm since PHP is not thread-safe.
@ronpoz:

Server compiled with....
 -D APACHE_MPM_DIR="server/mpm/prefork"


He is.

@inkblot:

Also, set MaxRequestsPerChild in your apache configuration to something like 20 or 25. This will cause apache to clean up unused child processes fairly regularly, and each time an apache child process is terminated the swap pages that are backing that process's unmapped memory are freed, along with any unmapped memory that might actually be resident. I have mine set to 15, personally, but my site is very low traffic. Also, if you can tighten up MaxSpareServers, too, that will help.

Well I took your suggestions and it looks like sites are running much faster. Even the memory usage is down:

http://metrowebworks.com/mrtg/mem.html

Thanks a lot for your help!

Thanks for the posting info, free'd up about 10M of mem on my node.

Anyway we can get things like this stickied, or possibly added to a Tip and Tricks section?

Reply

Please enter an answer
Tips:

You can mention users to notify them: @username

You can use Markdown to format your question. For more examples see the Markdown Cheatsheet.

> I’m a blockquote.

I’m a blockquote.

[I'm a link] (https://www.google.com)

I'm a link

**I am bold** I am bold

*I am italicized* I am italicized

Community Code of Conduct