Submitted by Bridge Fibre on Thu, 08/03/2017 - 06:51
Our server running Wedmin/virtualmin has Wordpress and a Mysql db running but twice this week the site has crashed and turned out mysql was stopped. On starting it again all was fine again and in the logs for both days it began '0 [Note] Giving 0 client threads a chance to die gracefully' I've attached the full logs of those two days but unsure as to what is causing Mysql to shutdown as it doesn't appear to be crashing.
Files:
Status:
Active
Comments
Submitted by andreychek on Thu, 08/03/2017 - 09:03 Comment #1
Howdy -- it's possible that you're running into a resource issue there.
What is the output of these commands:
free -mdmesg | tail -30
ps auxw | grep mysql
Submitted by Bridge Fibre on Fri, 08/04/2017 - 07:05 Comment #2
HI,
Thanks for the response, please find results below:
master@ghost35:~$ free -m total used free shared buff/cache available Mem: 7983 1233 5124 112 1625 6315 Swap: 8191 0 8191
master@ghost35:~$ dmesg | tail -30 [ 10.172126] Floppy drive(s): fd0 is 1.44M [ 10.686711] ppdev: user-space parallel port driver [ 11.343510] Adding 8388604k swap on /dev/mapper/ghost35--vg-swap_1. Priority:-1 extents:1 across:8388604k FS [ 11.803235] EXT4-fs (sda1): mounting ext2 file system using the ext4 subsystem [ 11.805699] EXT4-fs (sda1): mounted filesystem without journal. Opts: (null) [ 12.518792] audit: type=1400 audit(1501226164.188:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/lxc-start" pid=990 comm="apparmor_parser" [ 12.529949] audit: type=1400 audit(1501226164.200:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default" pid=987 comm="apparmor_parser" [ 12.529963] audit: type=1400 audit(1501226164.200:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-cgns" pid=987 comm="apparmor_parser" [ 12.529971] audit: type=1400 audit(1501226164.200:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-with-mounting" pid=987 comm="apparmor_parser" [ 12.529978] audit: type=1400 audit(1501226164.200:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-with-nesting" pid=987 comm="apparmor_parser" [ 12.552694] audit: type=1400 audit(1501226164.224:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=992 comm="apparmor_parser" [ 12.552714] audit: type=1400 audit(1501226164.224:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=992 comm="apparmor_parser" [ 12.577201] audit: type=1400 audit(1501226164.248:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/lxd/lxd-bridge-proxy" pid=991 comm="apparmor_parser" [ 12.582015] audit: type=1400 audit(1501226164.252:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/freshclam" pid=989 comm="apparmor_parser" [ 12.583560] audit: type=1400 audit(1501226164.252:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/sbin/dhclient" pid=988 comm="apparmor_parser" [ 12.940499] vmxnet3 0000:03:00.0 ens160: intr type 3, mode 0, 5 vectors allocated [ 12.943505] vmxnet3 0000:03:00.0 ens160: NIC Link is Up 10000 Mbps [ 13.087176] cgroup: new mount options do not match the existing superblock, will be ignored [ 13.192237] floppy0: no floppy controllers found [ 14.358546] NET: Registered protocol family 40 [ 18.576457] ip_tables: (C) 2000-2006 Netfilter Core Team [295796.965889] audit_printk_skb: 30 callbacks suppressed [295796.965895] audit: type=1400 audit(1501521948.012:22): apparmor="DENIED" operation="open" profile="/usr/bin/freshclam" name="/proc/20473/status" pid=20473 comm="freshclam" requested_mask="r" denied_mask="r" fsuid=113 ouid=0 [369441.579955] audit: type=1400 audit(1501595592.458:23): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=7346 comm="apparmor_parser" [369441.676362] audit: type=1400 audit(1501595592.554:24): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/7364/status" pid=7364 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 [369441.676418] audit: type=1400 audit(1501595592.554:25): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=7364 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 [369441.676500] audit: type=1400 audit(1501595592.554:26): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/7364/status" pid=7364 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 [370910.457467] audit: type=1400 audit(1501597061.334:27): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/9240/status" pid=9240 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=111 [370910.457531] audit: type=1400 audit(1501597061.334:28): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/sys/devices/system/node/" pid=9240 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=0 [370910.457598] audit: type=1400 audit(1501597061.334:29): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/proc/9240/status" pid=9240 comm="mysqld" requested_mask="r" denied_mask="r" fsuid=111 ouid=111
master@ghost35:~$ ps auxw | grep mysql mysql 9240 0.0 2.0 1316816 166480 ? Ssl Aug01 2:35 /usr/sbin/mysqld master 27571 0.0 0.0 14228 1020 pts/0 S+ 13:04 0:00 grep --color=auto mysql
Submitted by andreychek on Fri, 08/04/2017 - 09:16 Comment #3
Hmm, I didn't see what I was thinking I might see there (references to running out of memory).
Which may just mean the issue is elsewhere... but did you by chance reboot since the last time that problem happened?
Also, you said you included the full logs, but I just wanted to be certain -- there aren't additional log messages in addition to what you shared above (ie, logs just prior to the incident).
The only other thing, if none of the above seems to be leading anywhere, is that you did have a few unusual apparmor messages.
I've never seen that cause an issue with MySQL before, but it might be worth looking into whether it's somehow interfering. In fact we could always temporarily disable it just to see if that helps. Let us know if you'd like to go that route.
Oh, and what MySQL version are you using there, is that the standard one that comes with Ubuntu 16.04?
Submitted by metal696heart on Mon, 08/07/2017 - 00:37 Comment #4
The best bet is apache with a default MaxClients 100 value and this leads to a memory issue. Lower the MaxClients to a fraction based on what your RAM amount is. Monitor your RAM / SWAP .
Submitted by Bridge Fibre on Mon, 08/07/2017 - 08:04 Comment #5
Hi metal696heart,
Thanks for that, I can't find a MaxClient option in the apache2.conf, only MaxKeepAliveRequests, am I looking in the right place? The total RAM is 8GB, what would you recommend lowering it too?
Submitted by Bridge Fibre on Mon, 08/07/2017 - 08:08 Comment #6
Hi andreychek,
My mysql version is 14.14 distrib 5.7.19. The error logs were empty except for the days the mysql stopped. We have another server running virtual min also which is set up the same and this morning we had the same issue with it, showing the same issues in the logs. What is it you mentioned disabling to test?
Submitted by metal696heart on Mon, 08/07/2017 - 10:12 Comment #7
MaxRequestWorkers was called MaxClients before version 2.3.13. The old name is still supported. From documentation.. You should read and understand this, as scaling it depends on more factors. For example if you use mod_php instead of fcgi, you should take php ram at execution into account and setting memory limit accordingly. Use some traffic and server monitoring service. This might get handy in other situations too.
Also, you will find the setting at /etc/apache2/mods-available/mpm_prefork.conf or whatever mpm module you use.
Submitted by andreychek on Mon, 08/07/2017 - 11:33 Comment #8
Usually when we see resource issues, such as running out of memory, there are warning signs that the Linux kernel had to kill processes due to low RAM. You'll see "OOM" errors when running "dmesg",
Now, it's definitely worth making sure that the MaxClients setting is right for your server. You'd want to check how much RAM an Apache process uses, how much RAM a PHP process uses -- and then use that information to determine how many can safely run at one time on your server.
Apache sometimes defaults to allowing too many to run at once.
That said, 8GB is definitely a generous amount of RAM.
The other thing was some unusual apparmor errors, that are indicating some actions being denied.
Apparmor typically works very well, without interfering with day to day things like this. But since MySQL is dying off and we don't quite know why -- looking into that in addition to the RAM wouldn't be a bad idea.
Try running "service apparmor stop" to do that.
Submitted by Bridge Fibre on Thu, 08/02/2018 - 03:21 Comment #9