GCPのWordpressで"Error establishing a database connection"が発生した話
こんにちは。
某ベンチャー企業でエンジニアをやらせてもらっています、むらさ(@murasa_milk)と申します。
早速本題です。
何が起こったのか
現在、個人開発がてらGCEでサーバーを立ち上げ、その中にWordpressを入れて遊んでいます。
そんなある日、いつものようにサイトにアクセスすると見慣れない文字が・・・
この画面はなに
Error Establishing a Database Connection(データベース接続の確立エラーと表示されることも)は、WordpressとMySQLが正常に接続されていない時に表示される画面です。
管理者、ユーザー関わらずこの画面が表示されます。
結論
- MySQLが落ちてるよ
- 落ちた理由はswapのメモリ不足だったよ
どのように調査したのか
どのように調べたか時系列順に並べてあります。
失敗したものも含まれているので、結論が知りたい方は(失敗)と書かれている部分を読み飛ばしてください。
1.PHPMyAdminを調査
不正アクセスされてDB内のデータが暗号化されたと思ったので、まずはPHPMyAdminでデータを確認することにしました。
すると、ここでも見慣れないエラーが発生しました。
MySQL サーバにログインできません
mysqli::real_connect(): (HY000/2002): No such file or directory
2. ソケット通信を確認 (失敗)
エラー文でググったところ、どうやらconfig.inc.php
周りが怪しそうです。
参考にさせていただいた記事
ミーミルの泥泉 さま No.366 【phpMyAdmin】No such file or directory
https://mimirswell.ggnet.co.jp/blog-366
SSH通信でサーバーに接続し、config.inc.phpを探して調査。
$ sudo find / -name config.inc.php
$ vim {pathToconfig.inc.php}
しかし、config.inc.phpは上記の記事で書かれている修正後になっていました。
3.そもそもMySQL生きてるん?
まずこれを最初に確認すべきでした。
ターミナルにて、MySQLのコマンドを叩くと・・・
$ /etc/init.d/mysqld status
● mysql.service - MySQL Community Server
Loaded: loaded (/lib/systemd/system/mysql.service; enabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Wed 2022-01-26 08:56:27 UTC; 1 weeks 0 days ago
Process: 18251 ExecStartPre=/usr/share/mysql/mysql-systemd-start pre (code=exited, status=0/SUCCESS)
Process: 18286 ExecStart=/usr/sbin/mysqld --daemonize --pid-file=/var/run/mysqld/mysqld.pid (code=exited, status=1/FAILURE)
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
やっぱりMySQL落ちてました。
4. 何故MySQLが落ちた?
エラーログを追ってみます。
$ sudo tail -n 20 /var/log/mysql/error.log
...
2022-01-26T08:56:27.082979Z 0 [ERROR] InnoDB: mmap(137428992 bytes) failed; errno 12
2022-01-26T08:56:27.082986Z 0 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
2022-01-26T08:56:27.082991Z 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2022-01-26T08:56:27.083003Z 0 [ERROR] Plugin 'InnoDB' init function returned error.
2022-01-26T08:56:27.083008Z 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2022-01-26T08:56:27.083014Z 0 [ERROR] Failed to initialize builtin plugins.
2022-01-26T08:56:27.083019Z 0 [ERROR] Aborting
Cannot allocate memory for the buffer pool
とあるので、メモリ周りが怪しいです。
GCEのログを追ってみます。
5. GCEのメモリログ(失敗)
どうやらデフォルトの状態ではCPU使用率しか見えないらしい・・・
メモリやディスクの使用率を見るにはOpsエージェントとやらを入れる必要があるみたいです。
今後のために入れておくことにします。
また、障害が発生した2022/1/26にCPU使用率が少し高くなっていますね。これが原因なのだろうか・・・?
6. メモリ不足の原因
真の原因はswapのメモリが0であることでした。
参考: AmazonAWSで、MySQL がよく落ちる? そんな時はSWAP領域をチェック!
https://qiita.com/madaran0805/items/ae0532a7436e1c684e72
コマンドでも確認してみます。
$ free
total used free shared buff/cache available
Mem: 595840 186980 103408 19468 305452 281652
Swap: 0 0 0
上記の記事を参考に、スワップ領域を作成してMySQLを再起動します。
$ free
total used free shared buff/cache available
Mem: 595840 186736 52668 19468 356436 291456
Swap: 1048572 0 1048572
$ sudo /etc/init.d/mysql start
[ ok ] Starting mysql (via systemctl): mysql.service.
Wordpressページにアクセスすると、正しく表示されました。
余談
データベース接続の確立エラーの画面を見た時、ちょうど先輩とミーティングしていました。
その時慌てて「やばいっす!私のWordpressハックされたっぽいです!」とか言ってしまった気がする。エンジニア1年目かお前は。
まずは落ち着くことが大事ですね。
Discussion