こんにちは。Kaneyasuです。
先日、すごい広島 IT初心者の会 [77]にお邪魔してきました。本記事はその時にさせてもらったLTについて述べたものです。
スライドはこちらです。
IT初心者の方も来られるということで何が伝えたいと思って、そうだ！エラーの調べ方とかどうだろうか！？
と、思って書いたところ、思ったより職人芸っぽい話になって、現場でもこれ初心者向けか！？というお言葉をいただいた問題作です（汗）
従って、結局需要の有無がよくわからなかったのですが、せっかく書いたのでもうちょっと語らせてくださいというのが本記事です（笑）
スライドではフォローしきれなかったポイントを書かせていただきます。
エラー調査とは、少しずつ範囲を狭めること
エラー調査の際には、「ここまではエラーが起きていない」「ここからはまだわからない」といったように、範囲を狭めていく作業を繰り返します。この手法は二分探索法に似ています。
具体的にはフロント、バックエンド、データベース、それぞれのログを見て、入力値・出力値やエラーの有無を確認していきます。エラーのない部分は除外して怪しいところを狭めていきます。そのためには、一時的にソースを改変したりすることもあります。
そんなことをしなくてもスタックトレースなどで一発で特定できることもありますが、一筋縄では調べられないエラーに遭遇したら、一旦落ち着いてゆっくり切り分けていくよう心がけています。その過程で得られた情報が、エラーの原因のバグ報告を作る際に役立つこともあります。
ログの出力先とログの特性を押さえておく
厄介なエラーの場合、ログを見てもぱっと見何もヒントが得られないことがあります。しかし、そんな時でも諦めるのは早いです。ログはいろんなところあります。対象のシステムがLAMPによるWEBシステムだとしたら見るべきログの候補は以下のものがあります。
- フロント側
- ブラウザの開発ツールのコンソール、ネットワークタブなど
- WEBサーバー側
- システム独自のログ
- Apacheログ：/var/log/httpd
- PHP-FPMのログ：/var/log/php-fpm
- システムログ：/var/log/message
- MySQLのログ
- エラーログ
- 一般クエリログ
普通は、ブラウザの開発コンソールとシステム独自のログにエラーが書かれています。それらにエラーが出ていない場合は、上に出ているようなログを一つ一つ見ていくとエラーの尻尾を掴める可能性が高いです。経験上、プログラムがエラーを拾いきれないメモリ不足などの問題はPHP-FPMログやシステムログに何かが出ます。
Apacheのログを挙げているのは、アクセスログによりそもそもサーバーまでリクエストが届いているか調べることができるからです。他には、レアケースですが、システムがログ周りの設定を間違えている時、Apacheのログにしかエラーが出力されないことがあります。
大概のシステムは、ログにSQLを出すようにしています。SQLエラーとかDBの不整合は、ログから発行されたSQLを調べることで原因を特定できると思いますが、たまにSQLがプレスーホルダ状態でしか出力されないケースがあります。こんな時でも、MySQLの一般クエリログなら完全なSQLが見れるということを知っておくと助かることがあります。
（一般クエリログは設定によってON/OFFできるので環境次第では見れないこともあります。）
ApacheのログやSQLに関するログは、処理が終わった後でない出ないことを覚えておくと特定がしやすくなります。特にSQLの場合、SQLがクエリに出てない＝SQLが止まってる可能性が高く、こういう時はDBでコマンドを実行すると、現在の状態が見れるのでそこから現象を掴むことができます。
例えば、MySQLならSHOW PROCESSLISTコマンドで実行中のSQLが見れます。Timeの列が非常に大きいSQLがあれば、重すぎて終わらないSQLの可能性が高いので、これをEXPLAINなどで調査することで原因を掴める可能性が高いです。
+-----+------+-----------+------+---------+------+----------------+------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-----+------+-----------+------+---------+------+----------------+------------------------------------------+
| 1 | root | localhost | NULL | Query | 0 | NULL | SHOW PROCESSLIST |
| 2 | root | localhost | mydb | Query | 120 | Sorting result | SELECT * FROM large_table ORDER BY name |
| 3 | jane | localhost | NULL | Sleep | 5 | | NULL |
| 4 | bob | localhost | mydb | Query | 1 | NULL | UPDATE mytable SET name='Alice' WHERE id=2|
+-----+------+-----------+------+---------+------+----------------+------------------------------------------+
ログが出ていないなら、出ていないでそこから何が起きてるか仮説を立てることも必要です。
適度な一時報告の大切さ
エラー調査に時間がかかる場合は、適度に一時報告をするようにしています。本音を言うと、一時報告はやりたくありません。なぜなら余計なツッコミが入って作業が中断される可能性があるからです。報告は一発で終わらせたいところですが、状況によっては他に優先するべきことがあったり、わからない／直らないならなんらかの判断が必要です。そう言った意味で、一時報告は必要になります。あとは、一時報告することで自分以外の人が違う角度で調べてくれたり、時間調整してくれたりする可能性が生まれます。（あくまで可能性です・・・）
そもそもこう言う話はされたことありますか？
本記事のお話、いかがでしょうか？
今回、本記事とLTを用意した理由は、私自身がエラー調査の仕方などを誰かから教わったことがなく、自分が見出した方法についても誰かと話したことがないからです。地味すぎる話題ではありますが、こういうことができるか否かはエンジニアとしての一つの壁に思えます。ご自分や周りの人のやり方と見比べてみてください。