AWSのMySQLがよく落ちるのを解決 「Failed to start MariaDB」「InnoDB: Cannot allocate memory for the buffer pool」

朝4時45分に警報。このサイトを格納しているAWSのMariaDBが落ちたらしい。サイトに接続すると、WordPressの無愛想な「データベース接続エラー」が表示されている。

まずはMariaDBの状態を確認してみる。

落ちて、リスタートに失敗したようだ。原因はなんだろう。

MySQLのログを見てみる

[dacelo@space ~]$ sudo cat /var/log/mysql/mysqld.log
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: The InnoDB memory heap is disabled
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: Compressed tables use zlib 1.2.7
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: Using Linux native AIO
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: Using SSE crc32 instructions
2018-06-23 4:17:45 140417893861632 [Note] InnoDB: Initializing buffer pool, size = 384.0M
InnoDB: mmap(421724160 bytes) failed; errno 12
2018-06-23 4:17:45 140417893861632 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
2018-06-23 4:17:45 140417893861632 [ERROR] Plugin 'InnoDB' init function returned error.
2018-06-23 4:17:45 140417893861632 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2018-06-23 4:17:45 140417893861632 [Note] Plugin 'FEEDBACK' is disabled.
2018-06-23 4:17:45 140417893861632 [ERROR] Unknown/unsupported storage engine: InnoDB
2018-06-23 4:17:45 140417893861632 [ERROR] Aborting

最初に気になるのは
「The InnoDB memory heap is disabled」
というメッセージ。
でもこれはInnoDBが実装しているメモリーマネージャではなく、OSのメモリ割り当てを使うようになっていることをNoteとしてコメントしているものなので、特に気にする必要はない。
その後[ERROR]として真っ先に出てくるのは「InnoDB: Cannot allocate memory for the buffer pool」。ああ、メモリ不足ですな。

メモリの状態を確認

[dacelo@space ~]$ free
total used free shared buff/cache available
Mem: 1013892 110336 681004 41864 222552 703460
Swap: 0 0 0

[dacelo@space ~]$ curl http://169.254.169.254/latest/meta-data/instance-type
t2.micro

t2.microだとメモリーはもともと1GBしかないので、Swapがないと厳しいようだ。

Swapの設定

[dacelo@space ~]$ df -h
ファイルシス サイズ 使用 残り 使用% マウント位置
/dev/xvda1 30G 4.1G 26G 14% /
devtmpfs 473M 0 473M 0% /dev
tmpfs 496M 0 496M 0% /dev/shm
tmpfs 496M 38M 458M 8% /run
tmpfs 496M 0 496M 0% /sys/fs/cgroup
tmpfs 100M 0 100M 0% /run/user/1003

とりあえずメモリと同量のSwapを用意しよう。

[dacelo@space ~]$ sudo dd if=/dev/zero of=/swapfile bs=1M count=1024
1024+0 レコード入力
1024+0 レコード出力
1073741824 バイト (1.1 GB) コピーされました、 12.0896 秒、 88.8 MB/秒

[dacelo@space ~]$ sudo mkswap /swapfile
スワップ空間バージョン1を設定します、サイズ = 1048572 KiB
ラベルはありません, UUID=81d454d7-31db-4e93-bdc6-7e82ac2d0551

[dacelo@space ~]$ sudo swapon /swapfile
swapon: /swapfile: 安全でない権限 0644 を持ちます。 0600 がお勧めです。

あ、そうですか。

[dacelo@space ~]$ sudo chmod 600 /swapfile

[dacelo@space ~]$ free -m
total used free shared buff/cache available
Mem: 990 108 76 40 804 678
Swap: 1023 0 1023
[dacelo@space ~]$ free
total used free shared buff/cache available
Mem: 1013892 111412 78436 41868 824044 694376
Swap: 1048572 0 1048572

Swap設定完了。これでもうそうそう落ちることはないだろう。

[dacelo@space ~]$ sudo service mysqld start
Redirecting to /bin/systemctl start mysqld.service
[dacelo@space ~]$ sudo systemctl status mysqld.service
● mariadb.service - MariaDB 10.1.33 database server
Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; vendor preset: disabled)
Drop-In: /etc/systemd/system/mariadb.service.d
└─migrated-from-my.cnf-settings.conf
Active: active (running) since 土 2018-06-23 11:05:54 JST; 11s ago
Docs: man:mysqld(8)
https://mariadb.com/kb/en/library/systemd/
Process: 17574 ExecStartPost=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
Process: 17458 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= || VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ] && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
Process: 17456 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
Main PID: 17545 (mysqld)
Status: "Taking your SQL requests now..."
CGroup: /system.slice/mariadb.service
└─17545 /usr/sbin/mysqld6月 23 11:05:52 fuji systemd[1]: Starting MariaDB 10.1.33 database server...
6月 23 11:05:53 fuji mysqld[17545]: 2018-06-23 11:05:53 140671148730624 [Note] /usr/sbin/mysqld (mysqld 10.1.33-Ma...45 ...
6月 23 11:05:54 fuji systemd[1]: Started MariaDB 10.1.33 database server.
Hint: Some lines were ellipsized, use -l to show in full.

立ち上げて完了。以上。