问题表现: 数据库不定时重启
怀疑:
1,mysql 占用服务器内存过多, 导致操作系统kill掉了占用内存最大mysql程序,以保证服务器的稳定运行。
2,mysql 写入瞬时写入过多,导致io不正常,从而被系统重启。
3,数据库被人为重启
4,数据库被计划任务重启
问题排查:
1,查看mysql-error.log,发现一切正常,mysql能够正常的写入 重启日志。 从而能够排除数据库 core的可能性。
2,从/var/log/messages发现类似日志
Feb 2 01:27:01 ip-172-30-0-106 kernel: [21129733.556112] audit: type=1400 audit(1517506021.319:806): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6041 comm="apparmor_parser"Feb 2 01:27:01 ip-172-30-0-106 kernel: [21129733.808389] audit: type=1400 audit(1517506021.571:807): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6078 comm="apparmor_parser"Feb 2 14:51:52 ip-172-30-0-106 sz[3618]: [root] mysql-bin.010762/ZMODEM: got ZSKIPFeb 2 14:51:52 ip-172-30-0-106 sz[3618]: [root] mysql-bin.010762/ZMODEM: 335 Bytes, 192 BPS
从而怀疑是否是apparmor重启了数据库,或者是apparmor没有配置好相关权限,导致数据库读取/ 写入不了东西,从而重启了数据库.. 开放权限以后,几天后还是被自动重启,所以问题还是没有被找到。
3, 从 journalctl 命令中查找系统的所有日志信息发现如下: 系统日志
Feb 02 01:26:17 ip-172-30-0-106 systemd[1]: Starting Daily apt activities...Feb 02 01:26:30 ip-172-30-0-106 systemd[1]: Reloading.Feb 02 01:26:30 ip-172-30-0-106 systemd[1]: snapd.refresh.timer: Adding 3h 12min 20.171706s random time.Feb 02 01:26:30 ip-172-30-0-106 systemd[1]: Started ACPI event daemon.Feb 02 01:26:30 ip-172-30-0-106 systemd[1]: Stopping MySQL Community Server...Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: Stopped MySQL Community Server.Feb 02 01:27:01 ip-172-30-0-106 audit[6041]: AVC apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6041 comm="apparmor_parser"Feb 02 01:27:01 ip-172-30-0-106 kernel: audit: type=1400 audit(1517506021.319:806): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6041 comm="apparmor_parser"Feb 02 01:27:01 ip-172-30-0-106 CRON[6060]: pam_unix(cron:session): session opened for user root by (uid=0)Feb 02 01:27:01 ip-172-30-0-106 CRON[6061]: (root) CMD (/usr/bin/tsar --cron > /dev/null 2>&1)Feb 02 01:27:01 ip-172-30-0-106 CRON[6060]: pam_unix(cron:session): session closed for user rootFeb 02 01:27:01 ip-172-30-0-106 audit[6078]: AVC apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6078 comm="apparmor_parser"Feb 02 01:27:01 ip-172-30-0-106 kernel: audit: type=1400 audit(1517506021.571:807): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/sbin/mysqld" pid=6078 comm="apparmor_parser"Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: Reloading.Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: snapd.refresh.timer: Adding 46min 21.323606s random time.Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: Started ACPI event daemon.Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: Reloading.Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: snapd.refresh.timer: Adding 4h 51min 8.862102s random time.Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: Started ACPI event daemon.Feb 02 01:27:01 ip-172-30-0-106 systemd[1]: Starting MySQL Community Server...Feb 02 01:27:06 ip-172-30-0-106 systemd[1]: Started MySQL Community Server.Feb 02 01:27:06 ip-172-30-0-106 systemd[1]: Reloading.Feb 02 01:27:06 ip-172-30-0-106 systemd[1]: snapd.refresh.timer: Adding 4h 32.769528s random time.Feb 02 01:27:06 ip-172-30-0-106 systemd[1]: Started ACPI event daemon.Feb 02 01:27:06 ip-172-30-0-106 systemd[1]: Stopping MySQL Community Server...Feb 02 01:27:10 ip-172-30-0-106 systemd[1]: Stopped MySQL Community Server.Feb 02 01:27:14 ip-172-30-0-106 systemd[1]: Reloading.Feb 02 01:27:14 ip-172-30-0-106 systemd[1]: snapd.refresh.timer: Adding 3h 43min 30.596261s random time.Feb 02 01:27:14 ip-172-30-0-106 systemd[1]: Started ACPI event daemon.Feb 02 01:27:14 ip-172-30-0-106 systemd[1]: Starting MySQL Community Server...Feb 02 01:27:17 ip-172-30-0-106 systemd[1]: Started MySQL Community Server.Feb 02 01:27:21 ip-172-30-0-106 systemd[1]: Started Daily apt activities.Feb 02 01:27:21 ip-172-30-0-106 systemd[1]: apt-daily.timer: Adding 5h 3min 16.296108s random time.Feb 02 01:27:21 ip-172-30-0-106 systemd[1]: apt-daily.timer: Adding 3h 1min 23.389954s random time.
Feb 02 01:26:17 ip-172-30-0-106 systemd[1]: Starting Daily apt activities...
发现每次数据库重启之前都有一个这个。
从而怀疑是系统的某些日常检查,日常更新有影响到
通过命令:
yinni99@ip-172-30-0-106:/var/log/apt$ cat /etc/apt/apt.conf.d/10periodic
APT::Periodic::Update-Package-Lists “1”;
APT::Periodic::Download-Upgradeable-Packages “0”;
APT::Periodic::AutocleanInterval “0”;
确定系统没有开启自动更新。。。
问题又回到了原点!!! %>_<%
4,不放弃,感觉问题就在刚刚日志里面,从日志里面可以看到apt activities这几个关键字,百度。发现一堆罗嗦。 怀疑是 apt 自动更新底层依赖库,导致数据库重启,去/var/log/apt/ 查看日志发现
看着文件更新时间,感觉离真相越来越近,分别查看history.log 与 term.log 内容如下:
history.log
Start-Date: 2018-02-02 01:26:29Commandline: /usr/bin/unattended-upgradeUpgrade: curl:amd64 (7.47.0-1ubuntu2.5, 7.47.0-1ubuntu2.6), libcurl3-gnutls:amd64 (7.47.0-1ubuntu2.5, 7.47.0-1ubuntu2.6)Error: Sub-process /usr/bin/dpkg returned an error code (1)End-Date: 2018-02-02 01:27:17
term.log
Log started: 2018-02-02 01:26:29(Reading database ... 400278 files and directories currently installed.)Preparing to unpack .../curl_7.47.0-1ubuntu2.6_amd64.deb ...Unpacking curl (7.47.0-1ubuntu2.6) over (7.47.0-1ubuntu2.5) ...Preparing to unpack .../libcurl3-gnutls_7.47.0-1ubuntu2.6_amd64.deb ...Unpacking libcurl3-gnutls:amd64 (7.47.0-1ubuntu2.6) over (7.47.0-1ubuntu2.5) ...Processing triggers for man-db (2.7.5-1) ...Processing triggers for libc-bin (2.23-0ubuntu10) ...Setting up mysql-server-5.7 (5.7.21-0ubuntu0.16.04.1) ...mysql_upgrade: Got error: 1045: Access denied for user 'debian-sys-maint'@'localhost' (using password: YES) while connecting to the MySQL serverUpgrade process encountered error and will not continue.mysql_upgrade failed with exit status 11dpkg: error processing package mysql-server-5.7 (--configure): subprocess installed post-installation script returned error exit status 1dpkg: dependency problems prevent configuration of mysql-server: mysql-server depends on mysql-server-5.7; however: Package mysql-server-5.7 is not configured yet.dpkg: error processing package mysql-server (--configure): dependency problems - leaving unconfiguredSetting up libcurl3-gnutls:amd64 (7.47.0-1ubuntu2.6) ...Setting up curl (7.47.0-1ubuntu2.6) ...Processing triggers for libc-bin (2.23-0ubuntu10) ...Errors were encountered while processing: mysql-server-5.7 mysql-serverLog ended: 2018-02-02 01:27:17
问题已然确定,是apt的更新,导致数据库重启,查找相关资料:
http://wiki.ubuntu.org.cn/Ubu…:AutomaticSecurityUpdates/zh
https://help.ubuntu.com/commu…
(it’s an interactive dialog) which will create /etc/apt/apt.conf.d/20auto-upgrades with the following contents:
打开 /etc/apt/apt.conf.d/20auto-upgrades
修改 APT::Periodic::Unattended-Upgrade "1"
;选项为0.
so:最终结果 系统安全更新,影响到mysql