※当ブログではアフィリエイト広告を利用しています
このサイトはMixHost
で運営しているのですが、使っていてどうしても気になることがありました。
記事を書いていたりメンテナンスをしていると、かなりの頻度で「Error establishing a database connection」が発生するというもの。
数秒後にF5で更新すると直るのであまり気にしていなかったのですが、あまりに頻発するためサポートへ連絡し、解決することができたので記録として残しておきます。
同じ症状で悩んでいる方への参考になれば幸いです。
目次
とりあえずデバッグログを確認
更新すると直るのでwp-config.php に設定されているDBの接続先ホスト名やパスワードの設定は間違っていないはず。
まずはエラーが発生した時に何かログに記録されていないか確認するため、デバッグモードを有効化しました。
wp-config.phpを以下のように編集しました。1行目はファイル内の定義を書き換え、2行目以降は追記しました。
define('WP_DEBUG', true);
if (WP_DEBUG) {
define('WP_DEBUG_LOG', true);
define('WP_DEBUG_DISPLAY', false);
@ini_set('display_errors',0);
}
2行目以降を追記することで、ログが wp-content/debug.log に書き出され、ブラウザにデバッグメッセージが出力されないようになります。
外部からアクセスできるところに書き出されるため、ログを確認したらデバッグモードをoffにして削除するなり別の場所へ移動するなりするようにしましょう。
あとはひたすらエラーが出るのを待ちます。
エラーが出たら、debug.logを見てみましょう。
私の場合、エラーが出た際に以下の記録が残っていました。（一部マスキングしてます）
[17-Feb-2019 09:06:38 UTC] PHP Warning: mysqli_real_connect(): (HY000/2002): No such file or directory in /xxxxx/xxxxxx/xxxxxx/xxxxxx/wp-includes/wp-db.php on line 1531
...
wp-db.php の 1531行目は確かにDBへ接続する関数を呼び出しているのですが、DBへ接続しているだけでなぜ No such file or directory （ファイルやディレクトリが存在しない）が出るのか・・・？
調べてみたところ、DBへソケット接続する場合にソケットファイルが存在しないとこのようなエラーが出るということが分かりました。確かに、それなら納得です。
DBへ接続するためのソケットファイルの場所は以下のようにして確認できます
mysql_config --socket
/var/lib/mysql/mysql.sock
/var/lib/mysql/mysql.sock かあ・・・一応見てみたけど普通に存在するなあ・・・いや待てよ？
データベースが落ちてる？稼働状況を確認
もしかしたらこの /var/lib/mysql/mysql.sock が存在しない時間帯があるのかもしれない。そう思って以下を実行してみました。
while :; do
if [[ ! -e /var/lib/mysql/mysql.sock ]]; then
echo "$(date) mysql.sock not exist" >> mysql.sock.log;
fi; sleep 1;
done
1秒ごとに /var/lib/mysql/mysql.sock が存在するかチェックし、存在しない場合は時間とともにログに書き出すというものです。
するとなんてことでしょう。
Mon Feb 18 21:09:36 JST 2019 mysql.sock not exist
Mon Feb 18 21:09:37 JST 2019 mysql.sock not exist
Mon Feb 18 21:09:38 JST 2019 mysql.sock not exist
Mon Feb 18 21:09:39 JST 2019 mysql.sock not exist
Mon Feb 18 21:09:40 JST 2019 mysql.sock not exist
Mon Feb 18 21:09:41 JST 2019 mysql.sock not exist
Mon Feb 18 21:09:42 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:37 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:38 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:39 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:40 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:41 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:42 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:43 JST 2019 mysql.sock not exist
Mon Feb 18 21:14:44 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:38 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:39 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:40 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:41 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:42 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:43 JST 2019 mysql.sock not exist
Mon Feb 18 21:19:44 JST 2019 mysql.sock not exist
...
めちゃくちゃ無くなってるじゃん！！！！何なんこれ！！？？？
同時に以下のコマンドも実行しました。これはこのブログに毎秒アクセスして、HTTPステータスコードをログに記録するというものです。
while :; do
echo "$(date) $(curl -LI https://k8sinfo.com/ -o /dev/null -w '%{http_code}\n' -s)" >> curl.log; sleep 1;
done
ステータスコードは200が正常、500はエラーなのですが・・・
...
Mon Feb 18 21:09:33 JST 2019 200
Mon Feb 18 21:09:34 JST 2019 200
Mon Feb 18 21:09:35 JST 2019 500
Mon Feb 18 21:09:37 JST 2019 500
Mon Feb 18 21:09:38 JST 2019 500
Mon Feb 18 21:09:39 JST 2019 500
Mon Feb 18 21:09:40 JST 2019 500
Mon Feb 18 21:09:41 JST 2019 500
Mon Feb 18 21:09:42 JST 2019 200
Mon Feb 18 21:09:44 JST 2019 200
...
Mon Feb 18 21:14:34 JST 2019 200
Mon Feb 18 21:14:35 JST 2019 200
Mon Feb 18 21:14:37 JST 2019 500
Mon Feb 18 21:14:38 JST 2019 500
Mon Feb 18 21:14:39 JST 2019 500
Mon Feb 18 21:14:40 JST 2019 500
Mon Feb 18 21:14:41 JST 2019 500
Mon Feb 18 21:14:42 JST 2019 500
Mon Feb 18 21:14:43 JST 2019 500
Mon Feb 18 21:14:45 JST 2019 200
Mon Feb 18 21:14:46 JST 2019 200
...
500エラー出まくってるじゃん！！！何じゃこりゃ！！！！
この結果、/var/lib/mysql/mysql.sock が消えている時に500エラーが出ていることが分かりました。
そのため、何らかの理由でMariaDBが再起動されており、その際にアクセスできない状態になっているのでは？と推測することができました。
mixhostのcPanelからphpMyAdminを開き、「状況」メニューを開くと、稼働時間を確認することができます。
稼働時間を見ると、まあ5分程度でした。
ここまでで、なんか知らんけどDBが頻繁に再起動しているということが分かりました。
DBの管理はmixhost側の責務でありこちらでは触れることができないため、ここまでの調査結果をサポートへ連絡しました。
サポートへ連絡、そして解決へ
サポートへ連絡したのが22時ぐらい。
次の日の午後には連絡があり、「夜中にDBのメンテナンスしたから解消しているか確認しておいてほしい」という内容でした。
確かに、稼働時間を見ると執筆時点で20時間以上連続稼働しており、今まで見ていた稼働時間とは全く違います。
私の連絡を見てすぐに対応してくれたのか、元々不具合には気づいていてたまたまメンテナンスが入ったのかは定かではありませんが、とにかくスピーディーに解決してくれてよかったです。
まとめ
今の所は安定して動作しているように見えますが、1週間ほどは経過観察する予定です。
私はSEなので特に抵抗なく調査とかできてしまいますが、こういうことに慣れていない場合はサポート側が一から原因の切り分けから調査まで全て実施する必要があるため、どうしても対応に時間がかかってしまいます。
「なぜかエラーがたまに出る！何でですか？」と漠然と聞くよりも、「DBがこの時間に再起動しているように見えるので対応してほしい」と具体的に伝えた方が対応しやすいのは明白ですよね。
そういう意味では割と玄人向けのレンタルサーバーなのかもしれず、合う人と合わない人がいるかもしれません。
