MySQL InnoDB crash post-mortem

MySQL crashed on me this morning.

With the exception of the standard MySQL included databases everything I use is InnoDB.

I attempted to restart the MySQL daemon but it failed twice.

I then restarted the entire server and MySQL started correctly and has been working well since.

The mysqld log file for the initial crash contains the following:

120927 10:21:05 mysqld_safe Number of processes running now: 0
120927 10:21:06 mysqld_safe mysqld restarted
120927 10:21:12 [Note] Plugin 'FEDERATED' is disabled.
120927 10:21:12 InnoDB: The InnoDB memory heap is disabled
120927 10:21:12 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120927 10:21:12 InnoDB: Compressed tables use zlib 1.2.3
120927 10:21:12 InnoDB: Using Linux native AIO
120927 10:21:13 InnoDB: Initializing buffer pool, size = 4.0G
InnoDB: mmap(4395630592 bytes) failed; errno 12
120927 10:21:13 InnoDB: Completed initialization of buffer pool
120927 10:21:13 InnoDB: Fatal error: cannot allocate memory for the buffer pool
120927 10:21:13 [ERROR] Plugin 'InnoDB' init function returned error.
120927 10:21:13 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
120927 10:21:13 [ERROR] Unknown/unsupported storage engine: InnoDB
120927 10:21:13 [ERROR] Aborting

120927 10:21:13 [Note] /usr/libexec/mysqld: Shutdown complete

120927 10:21:13 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

When trying to restart the daemon the mysqld log file contains:

```
120927 10:43:44 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
120927 10:43:44 [Note] Plugin 'FEDERATED' is disabled.
120927 10:43:44 InnoDB: The InnoDB memory heap is disabled
120927 10:43:44 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120927 10:43:44 InnoDB: Compressed tables use zlib 1.2.3
120927 10:43:44 InnoDB: Using Linux native AIO
120927 10:43:44 InnoDB: Initializing buffer pool, size = 4.0G
InnoDB: mmap(4395630592 bytes) failed; errno 12
120927 10:43:44 InnoDB: Completed initial

I have good news, and bad news. The good news is, your filesystem and mysql are most likely fine... but check /var/log/syslog or equivalent to see what else was happening on your system before 10:21:05.

When the first message you posted was logged, your mysql server had already died.

120927 10:21:05 mysqld_safe Number of processes running now: 0

So, assuming you didn't overlook anything in the mysql error log, I'm going to say it didn't crash and die -- it was actually killed.

When mysqld_safe (which is a wrapper, not the server itself) realized the server wasn't running, and that the server hadn't terminated gracefully, it restarted it for you...

120927 10:21:06 mysqld_safe mysqld restarted

...then the server daemon logged some normal startup messages...

120927 10:21:12 [Note] Plugin 'FEDERATED' is disabled.
120927 10:21:12 InnoDB: The InnoDB memory heap is disabled
120927 10:21:12 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120927 10:21:12 InnoDB: Compressed tables use zlib 1.2.3
120927 10:21:12 InnoDB: Using Linux native AIO

...but when mysqld asked the operating system to allocate 4GB of memory for the InnoDB buffer pool...

120927 10:21:13 InnoDB: Initializing buffer pool, size = 4.0G

...the kernel said "no."

InnoDB: mmap(4395630592 bytes) failed; errno 12

Checking the kernel source to be sure:

#define ENOMEM      12  /* Out of memory */

Yeah. So, every message below the "failed; errno 12" line should be disregarded -- they're all side-effects of this one.

But again, all of these things happened after the first crash.

My best guess is that an extreme low memory condition caused your kernel to originally kill mysqld in an attempt to stablize the system.

Naturally, whatever caused the memory shortage was gone after the reboot. The mysql server was able to allocate 4GB for the InnoDB buffer pool, and all should be good until whatever caused you to run out of memory causes it again.

First guess: apache child processes run amok.

StackExchange Database Administrators Q#25077, answer score: 34