はじめに
Herokuでアプリを運用している際に、突然エラーが表示されたという経験はありませんか？このエラーの原因を解析したいが、優秀なDevOpsチームもいるわけでもないので、何をすれば良いか分からないという方々には、Scout APMが役に立ちます。ここでは、Herokuでよく見かける２つのエラーをScoutを使って、今までより早く、効率的にその問題の解析を行い、エラーコードを見つける方法を説明していきます。
Herokuのエラーログについて
まず始めに、Herokuを使用している方に起こりやすい典型的なエラーと、それをデバッグするために、どうScoutを使用していくかを説明していきます。Herokuを頻繁に使用しているユーザーは何度も目にしたことがあるかもしれませんが、Herokuにてエラーが起こった際は、アプリケーションエラーページにおいて、HTTP503のコードと共に、”このサービスはご利用いただけません”と表示されます。
残念ながら、この情報は開発者がデバッグするためには、ほとんど役に立ちません。しかし、Herokuのダッシュボード上のActivityタブにおいて、またはHerokuのCLIアプリケーションを使ってログを深掘りしていくと、その詳細が見えてきます。
$ heroku logs --tail
HerokuはH、R、Lという３つのアルファベットを使い、それぞれHはHTTPに関するエラー、RはRuntimeに関するエラー、LはLoggingシステムに関するエラーを表しています。またHerokuで使用されている、その他のエラー表記はこちらで確認出来ます。例として、下のスクリーンショットに表示されているエラーはH12のエラーということなります。
Scoutでエラーコードから解決策を導き出す
ここまで、ログをチェックし、どのようなタイプのエラーなのかを判別する方法を説明しました。ただ、エラーコードが分かったからというて、Herokuが公開している文書を参考にエラーを修正出来るかと言われたら、そうではありません。このようなエラーコードを見て何のエラーが起こっているかが分かったとしても、なぜ起こってしまったのかということまでは判別できないからです。ここで、それを説明してくれるのがScoutのようなアプリケーションパフォーマンスモニタリング（APM）です。Scout APMは、エラーコードがどこでなぜ起こったのかという情報まで提供してくれます。幸運なことに、Herokuのログシステムは、いつ、何のエラーが発生したかまでは教えてくれますので、典型的な２つのエラーを例として、そのエラーが起こったとき、一体どこでなぜ起こったのかをScout APMを使用して、精査してみましょう。
H12：リクエストタイムアウト
Herokuではリクエストの完了までに３０秒以上かかったとき、このH12エラーが表示されます。このようなエラーは明らかに普通の反応時間の遅れとは異なるため、ScoutのOverviewページにおいて、大きなスパイクとして表示されます。これが調査開始の合図です。
あなたがもしこのようなスパイクをScoutのチャートに表示されいてるのを発見したら、その周りをドラッグしてボックスとして囲います。すると、スパイクの中で起こっていたエンドポイントの簡単なリストが表示されます。その中で、要因と思われるエンドポイントを選択し、そのエンドポイントの中でエラーが発生した時間のトレースを見つけ出します。
この時点で、対象となるトレースを特定することができ、どこで時間やメモリーが消費されてたかがレイヤーごとにブレイクダウンされた情報から分かります。例えば、多くの時間がある一つのモデルに対するデータベースのクエリで消費されているとしたら、そのバックトレースと実際に実行されたクエリを見ることができます。
下記のような例では、多くの時間がコントローラーによって使用されていることがわかります。事実、このプロセスで４０秒以上かかっています。よって、これがH12のエラーコードがHerokuによって表示された原因と判別出来るわけです。
さらに、上記ような例においては、コントローラータイムを細かく分割してくれるAutoInstrumentsを使用することで、より詳細なデバックを可能にしてくれます。以上の作業を経て、コントローラーやバックトレースの中で問題のあるコードがどこに存在するかを確認することが出来ました。ここで、エディットアクション見ると、#edit 22において1 call のsleep (40) のせいで、このアプリが４０秒もプロセスに時間がかかってしまったと判明できるわけです。もちろん、このコードはこの説明をする目的で使用されましたが、Scoutを使うことで、これだけの情報を掴むことが出来ることをお分かりいただけたかと思います。
次は
Scout APMを使った、エラーコードR14/R15の解析について見ていきたいと思います。
14日間無料トライアルを実施中ですので、この機会に是非ご利用ください！