After Update to SVN 4928 web pages time out constantly

[Joseph Hales]

I spoke too soon after a few moments it stopped responding but I am not seeing any new errors in the apache log this time. I will try restarting the server itself instead of just the service.

[Joseph Hales]

No the web server is still not responding and I am back to getting the same apache errors.

[Tue Oct 13 10:58:17.303264 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.303784 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.304310 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.304799 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.305287 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.305771 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.306251 2015] [:error] [pid 7864] [client 10.1.51.37:64087] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 10:58:17.661588 2015] [mpm_prefork:notice] [pid 1518] AH00169: caught SIGTERM, shutting down
[Tue Oct 13 11:00:51.298115 2015] [mpm_prefork:notice] [pid 1544] AH00163: Apache/2.4.16 (Ubuntu) OpenSSL/1.0.1f configured – resuming normal operations
[Tue Oct 13 11:00:51.348300 2015] [core:notice] [pid 1544] AH00094: Command line: ‘/usr/sbin/apache2’
[Tue Oct 13 11:01:34.564492 2015] [mpm_prefork:error] [pid 1544] AH00161: server reached MaxRequestWorkers setting, consider raising the MaxRequestWorkers setting

[Wayne Workman]

@Joseph-Hales what does the command top show ?

[Joseph Hales]

top - 11:19:05 up 18 min,  1 user,  load average: 2.83, 2.84, 2.19
Tasks: 463 total,   1 running, 462 sleeping,   0 stopped,   0 zombie
%Cpu(s): 10.1 us,  0.8 sy,  0.0 ni, 84.6 id,  4.2 wa,  0.0 hi,  0.2 si,  0.0 st
KiB Mem:  24678932 total,  2849080 used, 21829852 free,   134548 buffers
KiB Swap:  4844540 total,        0 used,  4844540 free.  1368608 cached Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 1419 mysql     20   0 8721920 193320   7612 S 139.0  0.8  24:30.19 mysqld
 2647 www-data  20   0  325384  14092   5248 S   9.6  0.1   0:03.52 apache2
 2642 www-data  20   0  325628  14776   5684 S   1.7  0.1   0:02.77 apache2
 3452 www-data  20   0  325628  14324   5228 S   1.7  0.1   0:02.56 apache2
 2653 www-data  20   0  325628  14296   5212 S   1.3  0.1   0:02.58 apache2
 2975 www-data  20   0  325376  14880   6040 S   1.3  0.1   0:03.06 apache2
 2982 www-data  20   0  325628  14308   5224 S   1.3  0.1   0:03.38 apache2
 2993 www-data  20   0  325628  14324   5236 S   1.3  0.1   0:03.42 apache2
 3002 www-data  20   0  325628  14332   5244 S   1.3  0.1   0:03.14 apache2
 3439 www-data  20   0  325628  14296   5212 S   1.3  0.1   0:03.72 apache2
 3520 www-data  20   0  324092  13088   5532 S   1.3  0.1   0:02.69 apache2
 3523 www-data  20   0  325372  14092   5252 S   1.3  0.1   0:03.21 apache2
 3524 www-data  20   0  324348  13056   5252 S   1.3  0.1   0:03.24 apache2
 3532 www-data  20   0  325628  14632   5536 S   1.3  0.1   0:03.17 apache2
 3699 www-data  20   0  325628  14316   5232 S   1.3  0.1   0:04.04 apache2
 3764 www-data  20   0  325628  14352   5268 S   1.3  0.1   0:02.65 apache2
 3459 www-data  20   0  325628  14368   5284 S   1.0  0.1   0:02.37 apache2

Mod edited to use code box.

[Wayne Workman]

@Joseph-Hales How many cores does this server have? How much RAM? What’s the core speed? Is the storage SSD or mechanical?

I’m not sure how it’s possible for MySQL to use 139% of a CPU…

[Tom Elliott]

Please update and try again, I’m trying to limit the number of sessions.

[Joseph Hales]

updating here is lscpu output

Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Byte Order: Little Endian
CPU(s): 16
On-line CPU(s) list: 0-15
Thread(s) per core: 2
Core(s) per socket: 4
Socket(s): 2
NUMA node(s): 2
Vendor ID: GenuineIntel
CPU family: 6
Model: 26
Stepping: 5
CPU MHz: 2261.117
BogoMIPS: 4521.87
Virtualization: VT-x
L1d cache: 32K
L1i cache: 32K
L2 cache: 256K
L3 cache: 8192K
NUMA node0 CPU(s): 0,2,4,6,8,10,12,14
NUMA node1 CPU(s): 1,3,5,7,9,11,13,15

[Joseph Hales]

Old errors reoccur plus some new ones.

[Tue Oct 13 11:32:00.141558 2015] [:error] [pid 3576] [client 10.110.50.40:65405] PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62
[Tue Oct 13 11:32:01.035167 2015] [:error] [pid 3579] [client 10.117.50.11:53325] PHP Fatal error:  Uncaught exception 'ReflectionException' with message 'Class EventManager does not exist' in /var/www/html/fog/lib/fog/FOGBase.class.php:64\nStack trace:\n#0 /var/www/html/fog/lib/fog/FOGBase.class.php(64): ReflectionClass->__construct('EventManager')\n#1 /var/www/html/fog/commons/init.php(196): FOGBase->getClass('EventManager')\n#2 /var/www/html/fog/commons/base.inc.php(3): require_once('/var/www/html/f...')\n#3 /var/www/html/fog/service/servicemodule-active.php(2): require_once('/var/www/html/f...')\n#4 {main}\n  thrown in /var/www/html/fog/lib/fog/FOGBase.class.php on line 64
[Tue Oct 13 11:32:01.089682 2015] [:error] [pid 3667] [client 10.1.50.220:53541] PHP Fatal error:  Uncaught exception 'ReflectionException' with message 'Class ServiceManager does not exist' in /var/www/html/fog/lib/fog/FOGBase.class.php:64\nStack trace:\n#0 /var/www/html/fog/lib/fog/FOGBase.class.php(64): ReflectionClass->__construct('ServiceManager')\n#1 /var/www/html/fog/lib/fog/FOGCore.class.php(14): FOGBase->getClass('ServiceManager')\n#2 /var/www/html/fog/lib/fog/FOGCore.class.php(217): FOGCore->getSetting('FOG_THEME')\n#3 /var/www/html/fog/commons/init.php(192): FOGCore->setSessionEnv()\n#4 /var/www/html/fog/commons/base.inc.php(3): require_once('/var/www/html/f...')\n#5 /var/www/html/fog/service/servicemodule-active.php(2): require_once('/var/www/html/f...')\n#6 {main}\n  thrown in /var/www/html/fog/lib/fog/FOGBase.class.php on line 64
[Tue Oct 13 11:32:01.230274 2015] [:error] [pid 5538] [client 10.113.50.91:50426] PHP Fatal error:  Uncaught exception 'ReflectionException' with message 'Class ServiceManager does not exist' in /var/www/html/fog/lib/fog/FOGBase.class.php:64\nStack trace:\n#0 /var/www/html/fog/lib/fog/FOGBase.class.php(64): ReflectionClass->__construct('ServiceManager')\n#1 /var/www/html/fog/lib/fog/FOGCore.class.php(14): FOGBase->getClass('ServiceManager')\n#2 /var/www/html/fog/lib/fog/FOGCore.class.php(217): FOGCore->getSetting('FOG_THEME')\n#3 /var/www/html/fog/commons/init.php(192): FOGCore->setSessionEnv()\n#4 /var/www/html/fog/commons/base.inc.php(3): require_once('/var/www/html/f...')\n#5 /var/www/html/fog/service/snapins.checkin.php(2): require_once('/var/www/html/f...')\n#6 {main}\n  thrown in /var/www/html/fog/lib/fog/FOGBase.class.php on line 64
[Tue Oct 13 11:34:49.125571 2015] [mpm_prefork:error] [pid 5892] AH00161: server reached MaxRequestWorkers setting, consider raising the MaxRequestWorkers setting```

[Joseph Hales]

had to delete some of the errors as the post kept getting marked as spam by the filter but they seem to be repeats.

[Wayne Workman]

@Joseph-Hales said:

had to delete some of the errors as the post kept getting marked as spam by the filter but they seem to be repeats.

You can get around that by uploading the logs in a .txt file.

[Joseph Hales]

Ok yet another sign FOG hates me I come back from lunch my forum session wouldn’t let me log back in kept saying forbidden until I closed the window and reopened it

[Joseph Hales]

Should I roll back to SVN 4700 and if so what check out version is that?

[Wayne Workman]

@Joseph-Hales if you go to your svn/trunk directory you can run svn info to get the revision number that you currently have checked out.

You know the only safe method of downgrading is with a snapshot, right?

[Joseph Hales]

Any other suggestions it seems like after a restart sql hits some sort of loop state and just locks up with that apache maxworkers error.

[Wayne Workman]

@Joseph-Hales If it’s possible, disable the interface on the fog server at boot time.

On CentOS 7 / RHEL 7 / Fedora 19-22 you may do this by editing /etc/sysconfig/network-scripts/<interface name> and changing the line ONBOOT="yes" to ONBOOT="no"

http://ask.xmodulo.com/configure-static-ip-address-centos7.html

Then reboot and see how MySQL behaves… does it enter into a loop-like state then?

If not, it probably really is load related - and hopefully @Tom-Elliott can figure out what the difference is between then and now.

If it still has this problem with the interface turned off, then the problem resides on the fog server somewhere and is not load related.

[Tom Elliott]

I’ve completely rewritten session handling in the hopes that this would be fixed. I suspect that what’s happening is the sessions are being started and started many times. So after initial startup all the connections are in use for the new start up.

[Joseph Hales]

I have increased MaxConnections and MaxRequestWorkers both to 1000 installed SVN 4956 and restarted the server with the exact same results now on the attached apache error log I notice it gets to the MaxRequestWorkers suggestion and then stops untill I restart the server. This behavior also appears in my earlier posts I just didn’t note it.
Apache.log.txt

[Joseph Hales]

With the new settings I am occasionally able to get web interface pages to load 1 time out of 10 with several minutes to load each page but it doesn’t appear that Apache is logging anything anymore after it crashes on the max workers suggestion.

[Joseph Hales]

Fog ping hosts seems to be my next resource hog after mysql is this normal?

TOP 10 MEM (ps auxww --sort=-rss|head -n10)
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
mysql     1419  143  0.9 8723248 235708 ?      Ssl  10:14 252:42 /usr/sbin/mysqld
root      1956 32.5  0.5 312728 129040 ?       S    10:14  57:12 /usr/bin/php -q /opt/fog/service/FOGPingHosts/FOGPingHosts
root      2027  0.0  0.1  90772 25100 ?        Ss   10:14   0:00 /usr/bin/perl /usr/share/webmin/miniserv.pl /etc/webmin/miniserv.conf
root      2174  0.0  0.1 800960 24888 ?        Ssl  10:14   0:01 /opt/simpana/Base/cvd
sealion   1471  0.3  0.0 809564 22208 ?        Sl   10:14   0:38 python /usr/local/sealion-agent/etc/init.d/../../bin/sealion.py start
www-data  2695  0.3  0.0 328436 20700 ?        S    10:15   0:36 /usr/sbin/apache2 -k start
www-data  2359  0.2  0.0 329392 20344 ?        S    10:14   0:28 /usr/sbin/apache2 -k start
www-data  2702  0.2  0.0 402536 18924 ?        S    10:15   0:30 /usr/sbin/apache2 -k start
www-data  2299  0.2  0.0 475844 18440 ?        S    10:14   0:30 /usr/sbin/apache2 -k start

Mod edited to use code box.

[Joseph Hales]

Here is what a fog client sees when the server Apache log is spamming the following.

fog.log

[Wed Oct 14 14:38:20.061493 2015] [:error] [pid 2706] [client 10.109.49.82:50064] PHP Warning:  mysqli::query(): Couldn't fetch mysqli in /var/www/html/fog/lib/db/MySQL.class.php on line 62