背景
在装机实施时,BIOS忘记调整时间,导致服务器时间与CST不符合;待发现问题时,MySQL环境已经在运行,所以只能通过操作系统进行更改;但是更改完成后,MySQL进行重启时发生了问题。以下为问题复现和解决过程
测试环境
MySQL 5.7.24 CentOS 7.4
root@localhost : (none) 12:00:54> show variables like '%time_zone';
+------------------+--------+
| Variable_name | Value |
+------------------+--------+
| system_time_zone | CST |
| time_zone | +08:00 |
+------------------+--------+
2 rows in set (0.01 sec)
root@localhost : (none) 12:00:56> show variables like 'log_time%';
+----------------+--------+
| Variable_name | Value |
+----------------+--------+
| log_timestamps | SYSTEM |
+----------------+--------+
1 row in set (0.00 sec)
root@localhost : (none) 02:20:54> show variables like '%fast_shutdown';
+----------------------+-------+
| Variable_name | Value |
+----------------------+-------+
| innodb_fast_shutdown | 2 |
+----------------------+-------+
1 row in set (0.00 sec)
测试过程
[root@localhost ~]# date
Tue Dec 4 11:06:55 CST 2018
[root@localhost ~]# ps -ef|grep mysql
mysql 5113 1 4 11:06 ? 00:00:00 /usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid
root 5160 1403 0 11:06 pts/0 00:00:00 grep --color=auto mysql
###主机向前修改时间
[root@localhost ~]# date -s 10:00
Tue Dec 4 10:00:00 CST 2018
[root@localhost ~]# date
Tue Dec 4 10:00:01 CST 2018
###停止MySQL
[root@localhost ~]# service mysqld stop
Redirecting to /bin/systemctl stop mysqld.service
###查看错误日志,时间由11:00到10:00,出现了hang
[root@localhost ~]# tail -f /var/log/mysql/error.log
2018-12-04T11:06:52.731556+08:00 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2018-12-04T11:06:52.731564+08:00 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
...
2018-12-04T10:00:07.198925+08:00 0 [Note] InnoDB: FTS optimize thread exiting.
2018-12-04T10:00:07.199255+08:00 0 [Note] InnoDB: Starting shutdown...
2018-12-04T10:01:15.036504+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-04T10:02:22.191904+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-04T10:03:32.160278+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
解决1
###手动kill掉
[root@localhost ~]# ps -ef|grep mysqld
mysql 5234 1 0 12:00 ? 00:00:00 /usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid
root 5300 1886 0 12:04 pts/1 00:00:00 grep --color=auto mysqld
[root@localhost ~]# kill -9 5234 1
解决2
###手动修改时间(大于error.log最大的time)
[root@localhost ~]# date -s 12:00
Tue Dec 4 12:00:00 CST 2018
###查看error日志,正常关闭
[root@localhost ~]# tail -f /var/log/mysql/error.log
2018-12-04T10:00:07.198780+08:00 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2018-12-04T10:00:07.198783+08:00 0 [Note] Shutting down plugin 'INNODB_TRX'
2018-12-04T10:00:07.198786+08:00 0 [Note] Shutting down plugin 'InnoDB'
2018-12-04T10:00:07.198925+08:00 0 [Note] InnoDB: FTS optimize thread exiting.
2018-12-04T10:00:07.199255+08:00 0 [Note] InnoDB: Starting shutdown...
2018-12-04T10:01:15.036504+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-04T10:02:22.191904+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-04T10:03:32.160278+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-04T12:00:00.032698+08:00 0 [Note] InnoDB: MySQL has requested a very fast shutdown without flushing the InnoDB buffer pool to data files. At the next mysqld startup InnoDB will do a crash recovery!
2018-12-04T12:00:00.847336+08:00 0 [Note] InnoDB: Shutdown completed; log sequence number 0
2018-12-04T12:00:00.849656+08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2018-12-04T12:00:00.849693+08:00 0 [Note] Shutting down plugin 'MEMORY'
2018-12-04T12:00:00.849701+08:00 0 [Note] Shutting down plugin 'CSV'
2018-12-04T12:00:00.849706+08:00 0 [Note] Shutting down plugin 'sha256_password'
2018-12-04T12:00:00.849708+08:00 0 [Note] Shutting down plugin 'mysql_native_password'
2018-12-04T12:00:00.849808+08:00 0 [Note] Shutting down plugin 'binlog'
2018-12-04T12:00:00.850080+08:00 0 [Note] /usr/sbin/mysqld: Shutdown complete
原因
MySQL所在的服务器的时间更改,MySQL的缓存的时间戳依据的是主机的时间;在我们手动向前修改时间,会出现MySQL退出时要求清空比生成时间“还早”的缓存而导致了锁死。
验证
[root@yuelei1 etc]# date;date -s 14:07
Fri Dec 14 14:09:39 CST 2018
Fri Dec 14 14:07:00 CST 2018
[root@yuelei1 etc]# date;service mysqld stop
Fri Dec 14 14:07:02 CST 2018
Redirecting to /bin/systemctl stop mysqld.service
[root@yuelei1 ~]# tail -f /var/log/mysql/error.log
...
2018-12-14T14:07:03.272305+08:00 0 [Note] Shutting down plugin 'INNODB_TRX'
2018-12-14T14:07:03.272552+08:00 0 [Note] Shutting down plugin 'InnoDB'
2018-12-14T14:07:03.273119+08:00 0 [Note] InnoDB: FTS optimize thread exiting.
2018-12-14T14:07:03.273566+08:00 0 [Note] InnoDB: Starting shutdown...
2018-12-14T14:08:10.771410+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-14T14:09:18.510532+08:00 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2018-12-14T14:09:40.432857+08:00 0 [Note] InnoDB: MySQL has requested a very fast shutdown without flushing the InnoDB buffer pool to data files. At the next mysqld startup InnoDB will do a crash recovery!
2018-12-14T14:09:40.982834+08:00 0 [Note] InnoDB: Shutdown completed; log sequence number 0
2018-12-14T14:09:40.986140+08:00 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2018-12-14T14:09:40.986185+08:00 0 [Note] Shutting down plugin 'MEMORY'
2018-12-14T14:09:40.986196+08:00 0 [Note] Shutting down plugin 'CSV'
2018-12-14T14:09:40.986200+08:00 0 [Note] Shutting down plugin 'sha256_password'
2018-12-14T14:09:40.986203+08:00 0 [Note] Shutting down plugin 'mysql_native_password'
2018-12-14T14:09:40.986303+08:00 0 [Note] Shutting down plugin 'binlog'
2018-12-14T14:09:40.986775+08:00 0 [Note] /usr/sbin/mysqld: Shutdown complete
总结
1、在向前修改主机时间,MySQL停止时会出现hang,可能出现的大问题是数据入库时间会错乱
2、修改数据库的服务器时间,上线的系统是严禁修改的