MySQL服务退出错误排查

mysql exited with error code

个人搭建的基于 Ghost CMS系统 使用了 MySQL 作为数据存储,在VPS虚拟机重启后,Ghost CMS无法使用后端MySQL。检查数据库状态:

systemctl start mysql

提示错误:

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

mysql服务状态

  • 检查服务状态输出:

    systemctl status mysql.service
    

显示:

● mysql.service - MySQL Community Server
   Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Tue 2021-08-10 15:43:35 CST; 23min ago
  Process: 16817 ExecStart=/usr/sbin/mysqld --daemonize --pid-file=/run/mysqld/mysqld.pid (code=exited, status=1/FAILURE)
  Process: 16796 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
 Main PID: 612 (code=killed, signal=KILL)

Aug 10 15:43:35 freedom systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug 10 15:43:35 freedom systemd[1]: Failed to start MySQL Community Server.
Aug 10 15:43:35 freedom systemd[1]: mysql.service: Service hold-off time over, scheduling restart.
Aug 10 15:43:35 freedom systemd[1]: mysql.service: Scheduled restart job, restart counter is at 5.
Aug 10 15:43:35 freedom systemd[1]: Stopped MySQL Community Server.
Aug 10 15:43:35 freedom systemd[1]: mysql.service: Start request repeated too quickly.
Aug 10 15:43:35 freedom systemd[1]: mysql.service: Failed with result 'exit-code'.
Aug 10 15:43:35 freedom systemd[1]: Failed to start MySQL Community Server.
  • 通过 journalctl -xe 检查可以看到:

    Aug 11 20:51:59 freedom systemd[1]: Starting MySQL Community Server...
    -- Subject: Unit mysql.service has begun start-up
    -- Defined-By: systemd
    -- Support: http://www.ubuntu.com/support
    --
    -- Unit mysql.service has begun starting up.
    Aug 11 20:52:00 freedom mysqld[26240]: Initialization of mysqld failed: 0
    Aug 11 20:52:00 freedom systemd[1]: mysql.service: Control process exited, code=exited status=1
    Aug 11 20:52:00 freedom systemd[1]: mysql.service: Failed with result 'exit-code'.
    Aug 11 20:52:00 freedom systemd[1]: Failed to start MySQL Community Server.
    
  • 检查 /var/log/mysql/error.log 日志可以看到:

    2021-08-11T12:52:00.377011Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
    2021-08-11T12:52:00.392173Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.34-0ubuntu0.18.04.1) starting as process 26242 ...
    2021-08-11T12:52:00.438647Z 0 [Note] InnoDB: PUNCH HOLE support available
    2021-08-11T12:52:00.438697Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
    2021-08-11T12:52:00.438703Z 0 [Note] InnoDB: Uses event mutexes
    2021-08-11T12:52:00.438707Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
    2021-08-11T12:52:00.438711Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
    2021-08-11T12:52:00.438723Z 0 [Note] InnoDB: Using Linux native AIO
    2021-08-11T12:52:00.440910Z 0 [Note] InnoDB: Number of pools: 1
    2021-08-11T12:52:00.445361Z 0 [Note] InnoDB: Using CPU crc32 instructions
    2021-08-11T12:52:00.454508Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
    2021-08-11T12:52:00.456527Z 0 [ERROR] InnoDB: mmap(137428992 bytes) failed; errno 12
    2021-08-11T12:52:00.456550Z 0 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
    2021-08-11T12:52:00.456560Z 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
    2021-08-11T12:52:00.456570Z 0 [ERROR] Plugin 'InnoDB' init function returned error.
    2021-08-11T12:52:00.456577Z 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
    2021-08-11T12:52:00.456584Z 0 [ERROR] Failed to initialize builtin plugins.
    2021-08-11T12:52:00.456832Z 0 [ERROR] Aborting
    
    2021-08-11T12:52:00.457348Z 0 [Note] Binlog end
    2021-08-11T12:52:00.468226Z 0 [Note] Shutting down plugin 'CSV'
    2021-08-11T12:52:00.468937Z 0 [Note] /usr/sbin/mysqld: Shutdown complete
    
    2021-08-11T12:52:01.095959Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
    

从mysql日志来看,启动时 InnoDB初始化失败,原因是不能为缓冲池分配内存( InnoDB: Cannot allocate memory for the buffer pool )

  • 观察内存使用:

    # free
                  total        used        free      shared  buff/cache   available
    Mem:         492560      290200       24268         764      178092      189576
    Swap:             0           0           0
    
  • 之前内存应该是足够使用的,部署初始时资源足够,所以我考虑重启一次系统,观察情况

重启系统之后,果然能够正常启动mysql和ghost cms,初始内存使用状况如下:

top - 21:23:56 up 8 min,  1 user,  load average: 0.00, 0.03, 0.03
Tasks:  91 total,   1 running,  53 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.0 us,  0.0 sy,  0.0 ni,100.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :   492560 total,     9136 free,   400224 used,    83200 buff/cache
KiB Swap:        0 total,        0 free,        0 used.    79584 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
  611 mysql     20   0 1164088 188936   7160 S  0.0 38.4   0:00.59 mysqld
  864 ghost     20   0  893936 104132  18964 S  0.0 21.1   0:07.43 node
  519 ghost     20   0  632608  25616   7584 S  0.0  5.2   0:01.32 ghost run
  748 proxy     20   0  155540  18752   2672 S  0.0  3.8   0:00.08 squid
  575 root      20   0  187548  10464   2564 S  0.0  2.1   0:00.13 unattended-upgr
  532 root      20   0  170736  10084   2324 S  0.0  2.0   0:00.16 networkd-dispat
  608 www-data  20   0  158748   6796   4712 S  0.0  1.4   0:00.04 nginx
  402 root      19  -1   78328   5760   5152 S  0.0  1.2   0:00.14 systemd-journal
 1040 huatai    20   0   24692   5104   3516 S  0.0  1.0   0:00.02 bash
    1 root      20   0  225020   4560   2512 S  0.0  0.9   0:02.29 systemd
  923 root      20   0  112160   4520   3488 S  0.0  0.9   0:00.01 sshd
 1054 huatai    20   0   46104   3892   3296 R  0.0  0.8   0:00.39 top

内存不足

虽然重启一次后暂时满足了暂时需求,但是发现无法对系统做进一步维护,例如无法执行 apt upgrade (出现OOM),所以最终还是采用升级VPS,将原先512M内存升级成1G,每月多支付 1.5 $。