Very slow file serving

Discussion in 'Installation/Configuration' started by Rashef, Apr 30, 2014.

  1. Rashef

    Rashef New Member

    Dear all,

    I am experiencing a weird issue with a setup including 2 server:
    1. Primary ISPconfig running Apache + PHP
    2. Slave ISPconfig running MySQL
    both Debian Wheezy and installed on 2 Windows Azure VM. While the first has 3 public endpoints (ports 21, 80, 8080) the second has none (SSH is available only through VPN) and they reach each other using the virtual private IP.

    Apparently the problem - happening with a WordPress website - is related to the response time of Apache so that even if the most of the page is loaded it could take up to 2 minutes to complete the loading. Using the network tool integrated in Chrome, I noticed three different scenarios
    1. pauses in the loading: after some files are loaded pretty quickly there are seconds of nothing, like nothing is happening, white spaces in the network output of Chrome, an then a new bunch of file loaded, then another pause...
    2. very slow downloads: some JS or CSS files (from 30 to 200 KB) just take minutes (the "receiving time) to be completely loaded
    3. long waiting time: this time requests are initiated in sequence, without "empty" pauses, but the "waiting time" is very long before the browse starts receiving; this scenario as well as the previous are more frequent with JS and CSS.

    Some extra info:
    1. I didn't notice any network related issue, FTP uploads/downloads are very smooth
    2. Some WordPress scripts that should manipulate files (such as a plugin that regenerates thumbnails) have random timeouts

    /var/log/apache2/error.log:
    Code:
    [Wed Apr 30 06:33:19 2014] [notice] caught SIGTERM, shutting down
    [Wed Apr 30 06:33:23 2014] [warn] RSA server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
    [Wed Apr 30 06:33:23 2014] [notice] suEXEC mechanism enabled (wrapper: /usr/lib/apache2/suexec)
    [Wed Apr 30 06:33:23 2014] [notice] Digest: generating secret for digest authentication ...
    [Wed Apr 30 06:33:23 2014] [notice] Digest: done
    [Wed Apr 30 06:33:23 2014] [notice] FastCGI: process manager initialized (pid 1671)
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/apache2/conf.d/ming.ini on line 1 in Unknown on line 0
    [Wed Apr 30 06:33:23 2014] [error] python_init: Python version mismatch, expected '2.7.2+', found '2.7.3'.
    [Wed Apr 30 06:33:23 2014] [error] python_init: Python executable found '/usr/bin/python'.
    [Wed Apr 30 06:33:23 2014] [error] python_init: Python path being used '/usr/lib/python2.7/:/usr/lib/python2.7/plat-linux2:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload'.
    [Wed Apr 30 06:33:23 2014] [notice] mod_python: Creating 8 session mutexes based on 150 max processes and 0 max threads.
    [Wed Apr 30 06:33:23 2014] [notice] mod_python: using mutex_directory /tmp
    [Wed Apr 30 06:33:23 2014] [warn] RSA server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
    [Wed Apr 30 06:33:23 2014] [notice] Apache/2.2.22 (Debian) DAV/2 mod_fastcgi/mod_fastcgi-SNAP-0910052141 mod_fcgid/2.3.6 PHP/5.4.4-14+deb7u9 mod_python/3.3.1 Python/2.7.3 mod_ruby/1.2.6 Ruby/1.8.7(2012-02-08) mod_ssl/2.2.22 OpenSSL/1.0.1e configured -- resuming normal operations
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    [Wed Apr 30 06:35:03 2014] [notice] caught SIGTERM, shutting down
    [Wed Apr 30 06:35:04 2014] [warn] RSA server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
    [Wed Apr 30 06:35:04 2014] [notice] suEXEC mechanism enabled (wrapper: /usr/lib/apache2/suexec)
    [Wed Apr 30 06:35:04 2014] [notice] Digest: generating secret for digest authentication ...
    [Wed Apr 30 06:35:04 2014] [notice] Digest: done
    [Wed Apr 30 06:35:04 2014] [notice] FastCGI: process manager initialized (pid 1811)
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/apache2/conf.d/ming.ini on line 1 in Unknown on line 0
    [Wed Apr 30 06:35:04 2014] [error] python_init: Python version mismatch, expected '2.7.2+', found '2.7.3'.
    [Wed Apr 30 06:35:04 2014] [error] python_init: Python executable found '/usr/bin/python'.
    [Wed Apr 30 06:35:04 2014] [error] python_init: Python path being used '/usr/lib/python2.7/:/usr/lib/python2.7/plat-linux2:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload'.
    [Wed Apr 30 06:35:04 2014] [notice] mod_python: Creating 8 session mutexes based on 150 max processes and 0 max threads.
    [Wed Apr 30 06:35:04 2014] [notice] mod_python: using mutex_directory /tmp
    [Wed Apr 30 06:35:04 2014] [warn] RSA server certificate is a CA certificate (BasicConstraints: CA == TRUE !?)
    [Wed Apr 30 06:35:04 2014] [notice] Apache/2.2.22 (Debian) DAV/2 mod_fastcgi/mod_fastcgi-SNAP-0910052141 mod_fcgid/2.3.6 PHP/5.4.4-14+deb7u9 mod_python/3.3.1 Python/2.7.3 mod_ruby/1.2.6 Ruby/1.8.7(2012-02-08) mod_ssl/2.2.22 OpenSSL/1.0.1e configured -- resuming normal operations
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    PHP Deprecated:  Comments starting with '#' are deprecated in /etc/php5/cgi/conf.d/ming.ini on line 1 in Unknown on line 0
    
    Specific website's error log:
    Code:
    [Tue Apr 29 19:49:34 2014] [warn] [client xxx.yyy.www.zzz] (70007)The timeout specified has expired: mod_fcgid: can't get data from http client, referer: http://www.domain.com/article-1
    [Tue Apr 29 20:38:19 2014] [warn] [client aaa.bbb.ccc.ddd] mod_fcgid: stderr: PHP Fatal error:  Maximum execution time of 30 seconds exceeded in /var/www/clients/client1/web3/web/wp-includes/class-wp-image-editor-gd.php on line 180, referer: http://www.domain.com/wp-admin/tools.php?page=ajax-thumbnail-rebuild
    I restarted MySQL and after 12 hours I get:
    Code:
    mysql> SHOW GLOBAL STATUS LIKE 'aborted_connects';
    +------------------+-------+
    | Variable_name    | Value |
    +------------------+-------+
    | Aborted_connects | 411   |
    +------------------+-------+
    1 row in set (0.01 sec)
    
    This is the /etc/hosts of the main ISPconfig (web.domain.com):
    Code:
    127.0.0.1       localhost.localdomain   localhost
    <private_ip_of_DB>        db.domain.com     db
    <public_ip>      web.domain.com
    ::1             localhost ip6-localhost ip6-loopback
    fe00::0         ip6-localnet
    ff00::0         ip6-mcastprefix
    ff02::1         ip6-allnodes
    ff02::2         ip6-allrouters
    and the /etc/hosts of the db (db.domain.com):
    Code:
    127.0.0.1       localhost.localdomain   localhost
    <private_ip_of_web>        web.domain.com     web
    <public_ip>      db.domain.com
    ::1             localhost ip6-localhost ip6-loopback
    fe00::0         ip6-localnet
    ff00::0         ip6-mcastprefix
    ff02::1         ip6-allnodes
    ff02::2         ip6-allrouters
    
    Anything else I could check?
     
    Last edited: Apr 30, 2014
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    Check the load with "top" command and the io load with "iotop".
     
  3. Rashef

    Rashef New Member

    I am trying to focus my analysis on one very simple page (the WordPress login page), to understand whether the issue is related to Apache or the connection to the DB.

    If I directly call the login page (http://www.domain.com/wp-login.php), the loading time is "decent" (around 2 seconds, not decent at all but considering the average...). If I am redirected to the login page because I am trying and accessing the dashboard (e.g. http://www.domain.com/wp-admin/) this is likely to happen:
    [​IMG]

    I ran the tests keeping top open: on both servers the load is almost zero while loading the pages.

    Main ISPconfig (with Apache+PHP):
    Code:
    top - 07:21:12 up 4 days, 10:58,  1 user,  load average: 0.20, 0.25, 0.31
    Tasks: 118 total,   1 running, 117 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,  0.0 st
    KiB Mem:   1728036 total,  1407356 used,   320680 free,    30684 buffers
    KiB Swap:        0 total,        0 used,        0 free,   640568 cached
    
    Slave ISPconfig (DB):
    Code:
    top - 07:21:56 up 9 days, 17:15,  1 user,  load average: 0.07, 0.06, 0.07
    Tasks:  70 total,   1 running,  69 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,  0.0 st
    KiB Mem:   1728036 total,   814740 used,   913296 free,   141756 buffers
    KiB Swap:        0 total,        0 used,        0 free,   437204 cached
    
     
  4. Rashef

    Rashef New Member

    While testing I created a New Relic free account to monitor the server and this is what I got after a few minutes:

    [​IMG]

    I think this clarifies that the DB is not the problem... what could slow down the PHP that much? I tried with default PHP but also with additional PHP versions (5.3.27, 5.4.21, 5.5.10) without any significant improvement...

    This is driving me crazy... :(
     

Share This Page