😼

GCPのWordpressで"Error establishing a database connection"が発生した話

2022/02/03に公開

こんにちは。
某ベンチャー企業でエンジニアをやらせてもらっています、むらさ(@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