AWSのMySQLがよく落ちるのを解決 「Failed to start MariaDB」「InnoDB: Cannot allocate memory for the buffer pool」
朝4時45分に警報。このサイトを格納しているAWSのMariaDBが落ちたらしい。サイトに接続すると、WordPressの無愛想な「データベース接続エラー」が表示されている。
まずはMariaDBの状態を確認してみる。
[dacelo@space ~]$ sudo service mysqld status
Redirecting to /bin/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: failed (Result: exit-code) since 土 2018-06-23 04:17:45 JST; 6h ago
Docs: man:mysqld(8)
https://mariadb.com/kb/en/library/systemd/
Process: 4109 ExecStartPost=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
Process: 11314 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
Process: 11227 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: 11225 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
Main PID: 11314 (code=exited, status=1/FAILURE)
Status: “MariaDB server is down”6月 23 04:17:44 fuji systemd[1]: mariadb.service holdoff time over, scheduling restart.
6月 23 04:17:44 fuji systemd[1]: Starting MariaDB 10.1.33 database server…
6月 23 04:17:45 fuji mysqld[11314]: 2018-06-23 4:17:45 140417893861632 [Note] /usr/sbin/mysqld (mysqld 10.1.33-Ma…14 …
6月 23 04:17:45 fuji systemd[1]: mariadb.service: main process exited, code=exited, status=1/FAILURE
6月 23 04:17:45 fuji systemd[1]: Failed to start MariaDB 10.1.33 database server.
6月 23 04:17:45 fuji systemd[1]: Unit mariadb.service entered failed state.
6月 23 04:17:45 fuji systemd[1]: mariadb.service failed.
Hint: Some lines were ellipsized, use -l to show in full.
Redirecting to /bin/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: failed (Result: exit-code) since 土 2018-06-23 04:17:45 JST; 6h ago
Docs: man:mysqld(8)
https://mariadb.com/kb/en/library/systemd/
Process: 4109 ExecStartPost=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
Process: 11314 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
Process: 11227 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: 11225 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
Main PID: 11314 (code=exited, status=1/FAILURE)
Status: “MariaDB server is down”6月 23 04:17:44 fuji systemd[1]: mariadb.service holdoff time over, scheduling restart.
6月 23 04:17:44 fuji systemd[1]: Starting MariaDB 10.1.33 database server…
6月 23 04:17:45 fuji mysqld[11314]: 2018-06-23 4:17:45 140417893861632 [Note] /usr/sbin/mysqld (mysqld 10.1.33-Ma…14 …
6月 23 04:17:45 fuji systemd[1]: mariadb.service: main process exited, code=exited, status=1/FAILURE
6月 23 04:17:45 fuji systemd[1]: Failed to start MariaDB 10.1.33 database server.
6月 23 04:17:45 fuji systemd[1]: Unit mariadb.service entered failed state.
6月 23 04:17:45 fuji systemd[1]: mariadb.service failed.
Hint: Some lines were ellipsized, use -l to show in full.
落ちて、リスタートに失敗したようだ。原因はなんだろう。
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.
立ち上げて完了。以上。
Comments are closed.