系統的なエラー調査
はじめに
前回の記事 の中で、問題が発生した場合はエラーメッセージを読むことが大事だというお話をしました。ただし、「このファイルのこの行の変数が未定義やで!」などと丁寧に原因まで教えてくれることはまれで、「何言ってんだこいつ!?」と思わずモニターを叩きつけたくなるようなメッセージを吐かれることもよくあります。このようなケースは外部のライブラリやフレームワーク自体がエラーを出力する場合に特に多いです。今回は、あるメンティーさんとの面白い実例を題材に、そういったなんだかよく分からないエラーに出くわした場合に、怒りでモニターを壊すことなく、どのように原因を探っていくかというお話をしたいと思います。
データベースマイグレーションができません!
あるメンティーさんより、AWS環境でLaravelのマイグレーション時にエラーが発生し、かれこれ数日悩んでいるのでサポートして欲しいという相談を受けました。WebサーバはEC2インスタンス(以下、Webサーバ)、データベースはRDSで構築した典型的なシステム構成です。
具体的な事象としては、Webサーバ上でLaravelのマイグレーションコマンド実行に失敗し、以下のエラーメッセージが出力されるということでした。※以下、ホスト名などは適当に変更しています。
SQLSTATE[HY000] [1045] Access denied for user 'some_user'@'*.*.*.*' (using password: YES) (SQL: select * from information_schema.tables where table_schema = some_schema and table_name = migrations and table_type = 'BASE TABLE')
In Connector.php line 70:
SQLSTATE[HY000] [1045] Access denied for user 'some_user'@'*.*.*.*' (using password: YES)
上記のエラーメッセージはAccess deinedなんて書かれてるので、データベースの接続に失敗してるんだなぐらいは読み取れますが、具体的にどこがおかしいかまでは分からないですね。メンティーさんが悩むのも分かります。
原因の仮説
エラーや問題が発生した場合は、無計画にコードを書き換えたり設定を変更したりするのではなく、まずは原因の仮説を立てることが重要です。今回のケースでは、以下の2つの要因が考えられるでしょう。
- ネットワーク関係の設定が間違っている
- データベースの設定が間違っている
このメンティーさんによると、Webサーバ上から以下のようにmysql
コマンドを発行すると、データベース(RDS)に接続できるということでした。
mysql -h xxxx -u some_user -p
この結果から、ネットワーク関係の設定に問題はなく(問題ないというのは、このエラー事象には関係しないということ)、おそらくデータベースの設定周りがおかしいということが推測できます。ここまでは、メンティーさんも検討されていましたが、そこから先に進めない状況でした。
原因の調査
データベース設定の確認
まずはデータベースの設定情報をチェックします。Laravelではデータベースの接続情報などの各環境に依存する情報は、.env
という設定ファイルに記述します。今回のケースではデータベース周りの設定は以下のようになっています。特におかしなところはなさそうです。
DB_CONNECTION=mysql
DB_HOST=xxxx
DB_PORT=3306
DB_DATABASE=some_schema
DB_USERNAME=some_user
DB_PASSWORD=X2Usaria!da#4r
メンティーさんに確認してても、確実にこの設定ファイルの内容は正しいということです。ホスト名、ポート、データベース名、ユーザ名、パスワードすべて厳密にチェックしてもらいましたが、間違いないと・・・
次の仮説と検証
設定ファイルの内容が正しいと仮定した場合、その設定内容が何らかの原因でLaravelに正常にロードされていないのではないかと論理的に推測できます。これ発生する要因として次の2つを新たな仮説とします。
- 設定情報がキャッシュされているために変更が反映されていない。
- 設定情報に特殊な記号が使われて適切にエスケープ処理されていない
前者の仮説を検証するために、Laravelの設定情報のキャッシュクリアコマンドを実行した後に、再度マイグレーションを実行してますがエラー。この仮説は除外します。
次に後者の仮説を検証しましょう。gpsoftさんのこの記事にあるように、もし特殊記号が利用されている場合はきちんとエスケープ処理しないといけません。
原因の判明
もう一度設定ファイルの内容をじっくりチェックします・・・ここで、あっと気づきます。この気付きを確かめるために、以下のコマンドでLaravelが実際にロードするデータベースのパスワードを確認してみます。
php artisan tinker
Psy Shell v0.9.12 (PHP 7.4.3 — cli) by Justin Hileman
>>> config('database.connections.mysql.password')
=> "X2Usaria!da"
ビンゴ!! .env
ファイルに設定したパスワード文字列 X2Usaria!da#4r とLaravelが読み取っているパスワード文字列 X2Usaria!da が異なるものになっています。そうです、#
記号以降がコメントとして認識されていたのでした。
対応
上記原因の対応としては、新たに#
を使わないパスワードに変更するか、以下のように設定値をシングルクォーテーションで囲むことで回避することが出来ます。
DB_PASSWORD='X2Usaria!da#4r'
メンティさんには前者のパスワードを変更するという対応をしていただきました。
まとめ
今回のケースであれば、データベースの設定値を見た瞬間に、#
記号が使われてる!と一発で気づくべきかもしれませんが、人間は見落としや思い込みをするものですからそんなにうまくはいかないものです。
問題が発生した場合は、やみくもにエラーの調査をしてはいけません。原因の仮説を立て、その仮説を1つ1つ論理的に検証していく・・・、このサイクルを繰り返すことにより、そういった見落としや思い込みに左右されることなく、結果として早く真の原因にたどり着くことができるでしょう。