mysql启动失败排查

修改mysql配置文件之后，使用service mysqld restart 重启，发现停止成功但是启动失败了。

Job for mysqld.service failed because the control process exited with error code. See "systemctl status mysqld.service" and "journalctl -xe" for details.

系统提示通过 systemctl status mysqld.service 或者 journalctl -xe 命令来查看详情。我们一个一个来分析。

1、执行 systemctl status mysqld.service

[root@lee ~]# systemctl status mysqld.service
● mysqld.service - MySQL Server
Loaded: loaded (/usr/lib/systemd/system/mysqld.service; enabled; vendor preset: disabled)
Active: deactivating (final-sigterm) (Result: exit-code) since Wed 2019-05-15 08:54:07 CST; 50s ago
Docs: man:mysqld(8)
http://dev.mysql.com/doc/refman/en/using-systemd.html
Process: 32685 ExecStart=/usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid $MYSQLD_OPTS (code=exited, status=1/FAILURE)
Process: 32668 ExecStartPre=/usr/bin/mysqld_pre_systemd (code=exited, status=0/SUCCESS)
Main PID: 30830 (code=exited, status=0/SUCCESS)
CGroup: /system.slice/mysqld.service
└─32689 /usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid

May 15 08:54:57 lee systemd[1]: mysqld.service holdoff time over, scheduling restart.
May 15 08:54:57 lee systemd[1]: Starting MySQL Server...
May 15 08:54:57 lee systemd[1]: mysqld.service: control process exited, code=exited status=1

通过上面标红的错误信息我们可以看到，mysqld主进程没有启动起来，其他就没有什么详细信息了。我们接着往下看。

2、执行 journalctl -xe

May 15 09:03:17 lee systemd[1]: Unit mysqld.service entered failed state.
May 15 09:03:17 lee systemd[1]: mysqld.service failed.
May 15 09:03:17 lee systemd[1]: mysqld.service holdoff time over, scheduling restart.
May 15 09:03:17 lee systemd[1]: Starting MySQL Server...
-- Subject: Unit mysqld.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit mysqld.service has begun starting up.
May 15 09:03:17 lee mysqld[10921]: Initialization of mysqld failed: 0
May 15 09:03:17 lee systemd[1]: mysqld.service: control process exited, code=exited status=1
May 15 09:03:19 lee systemd[1]: Failed to start MySQL Server.
-- Subject: Unit mysqld.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit mysqld.service has failed.
--
-- The result is failed.

没啥有用的信息，就告诉我们启动失败了。

3、现在我们就只知道主进程执行不成功，其他信息一无所知，这可咋整。

作为一个程序员出了问题自然是想到看日志来查找原因，我们来看看mysql的启动日志。首先看下my.cnf中日志的位置，log-error=/var/log/mysqld.log，我的日志是存在这了，打开日志看个究竟。

最后面能看到这么一大坨的东西，看下日志时间相差了8小时，这是因为我没有去配置时区，当然这个不是重点。

2019-05-15T01:08:24.682793Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2019-05-15T01:08:24.682795Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2019-05-15T01:08:24.682797Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2019-05-15T01:08:24.682799Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2019-05-15T01:08:24.682800Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2019-05-15T01:08:24.682802Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2019-05-15T01:08:24.682804Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2019-05-15T01:08:24.682806Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2019-05-15T01:08:24.682807Z 0 [Note] Shutting down plugin 'InnoDB'
2019-05-15T01:08:24.684767Z 0 [Note] InnoDB: FTS optimize thread exiting.
2019-05-15T01:08:24.684867Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2019-05-15T01:08:24.684972Z 0 [Note] InnoDB: Buffer pool(s) load completed at 190515 9:08:24
2019-05-15T01:08:24.685009Z 0 [Note] InnoDB: Starting shutdown...
2019-05-15T01:08:24.785342Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2019-05-15T01:08:24.785563Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 190515 9:08:24
里面也没啥关键信息，这么多看起来贼烦，我们来过滤下。

执行 tail -n500 /var/log/mysqld.log|grep -E 'Warning|ERROR'

2019-05-15T01:12:38.934502Z 0 [ERROR] unknown variable 'binlog_fromat=mixed'
2019-05-15T01:12:38.934522Z 0 [ERROR] Aborting
2019-05-15T01:12:40.984590Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-05-15T01:12:41.188849Z 0 [ERROR] unknown variable 'binlog_fromat=mixed'
2019-05-15T01:12:41.188873Z 0 [ERROR] Aborting
2019-05-15T01:12:43.228937Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-05-15T01:12:43.431933Z 0 [ERROR] unknown variable 'binlog_fromat=mixed'
2019-05-15T01:12:43.431951Z 0 [ERROR] Aborting
到这里就很明显能看出问题了，提示未知参数，我们的英文单词拼错了。你问我怎么会敲错的，因为是信了网上亲测可用的这些帖子的邪了。这要是可用我把小牛子都给你揪下来。

4、总结

对于mysql启动报错我们可以通过如下的步骤来排查。

①：systemctl status mysqld.service 命令，通过这个我们能很快定位到出错的进程。

②：journalctl -xe 命令，作为上一步的补充能够进一步佐证我们的判断。

③：查看mysql的日志，这个是最重要的。因为绝大部分成熟的产品一定会考虑用户的使用，mysql从载入内存开始，后续的操作都会记录到日志当中。所以我们在使用mysql时出现类似问题，大概率都能从日志文件中找到问题，加以分析就能解决了。