-
Notifications
You must be signed in to change notification settings - Fork 9
error codes
アプリケーションでエラーが発生した場合、Herokuは常にHTTPステータスコードが503の標準的なエラーページを表示させます。しかしながら、裏に潜むエラーをデバッグ出来るよう、Herokuはカスタムエラーの情報をログへ追記します。エラーの種類毎にエラーコードが存在し、HTTPのエラーはH、ランタイムのエラーはR、ログに関するエラーはLから始まります。
クラッシュしたwebプロセス、またはwebプロセス起動時タイムアウトは、このエラーを返します。
2010-10-06T21:51:04-07:00 heroku[web.1]: State changed from down to starting
2010-10-06T21:51:07-07:00 app[web.1]: Starting process with command: `thin -p 22020 -e production -R /home/heroku_rack/heroku.ru start`
2010-10-06T21:51:09-07:00 app[web.1]: >> Using rails adapter
2010-10-06T21:51:09-07:00 app[web.1]: Missing the Rails 2.3.5 gem. Please `gem install -v=2.3.5 rails`, update your RAILS_GEM_VERSION setting in config/environment.rb for the Rails version you do have installed, or comment out RAILS_GEM_VERSION to use the latest version installed.
2010-10-06T21:51:10-07:00 heroku[web.1]: Process exited
2010-10-06T21:51:12-07:00 heroku[router]: Error H10 (App crashed) -> GET myapp.heroku.com/ web=web.1 queue=0 wait=0ms service=0ms bytes=0
2010-10-06T21:51:12-07:00 heroku[nginx]: GET / HTTP/1.1 | 75.36.147.245 | 8132 | http | 503
未処理のHTTPリクエストがたくさんあることを示しています。dynoを増やすことが一般的な解決方法となります。
2010-10-06T21:51:07-07:00 heroku[router]: Error H11 (Backlog too deep) -> GET myapp.heroku.com/ web=web.1 queue=51 wait=0ms service=0ms bytes=0
2010-10-06T21:51:07-07:00 heroku[nginx]: GET / HTTP/1.1 | 75.36.147.245 | 8132 | http | 503
HTTPリクエストが、完了するのに30秒以上掛かっています。下記の例では、Railsのアプリケーションがページをレンダーするのに37秒要しています。Railsがリクエストのサイクルを完了させるより前に、HTTPルーターが503のエラーを返しています。ですが、Railsのプロセスは流れ続けているので、ルーターがエラーメッセージを返した後で、正常終了のメッセージが表示されています。
2010-10-06T21:51:07-07:00 app[web.2]: Processing PostController#list (for 75.36.147.245 at 2010-10-06 21:51:07) [GET]
2010-10-06T21:51:08-07:00 app[web.2]: Rendering template within layouts/application
2010-10-06T21:51:19-07:00 app[web.2]: Rendering post/list
2010-10-06T21:51:37-07:00 heroku[router]: Error H12 (Request timeout) -> GET myapp.heroku.com/ web=web.2 queue=0 wait=0ms service=0ms bytes=0
2010-10-06T21:51:37-07:00 heroku[nginx]: GET / HTTP/1.1 | 75.36.147.245 | 8132 | http | 503
2010-10-06T21:51:42-07:00 app[web.2]: Completed in 37400ms (View: 27, DB: 21) | 200 OK [http://myapp.heroku.com/]
このエラーは、他のエラーよりも発生する機会がレアなエッジケースです。Gemに何かしらの機能不全があるケースと、webプロセスがコネクションを受け入れるものの、何も書き込みを行わずにソケットをクローズさせるようなケースが存在します。
2010-10-06T21:51:37-07:00 heroku[router]: Error H13 (Connection closed without response) -> GET myapp.heroku.com/ web=web.2 queue=0 wait=0ms service=173ms bytes=0
2010-10-06T21:51:37-07:00 heroku[nginx]: GET / HTTP/1.1 | 75.36.147.245 | 8132 | http | 503
これは、ほとんどの場合、webプロセスをゼロdynoまで落としてしまった結果によります。このエラーを回避するには、webプロセスを1、または、それ以上のdynoへ増やすことです。:
$ heroku ps:scale web=1
heroku psコマンドを使い、webプロセスの状態を確認して下さい。
Idle connectionのエラーは、リクエストが アクティブでは無い状態が55秒間続き、終了された時に、ログに書かれます。
CdearのHTTP routing stack上にあるアプリケーションは、herokuapp.comのドメインを使用しています。Cedar上のアプリケーションへのリクエストが、過去にHerokuが使用していたheroku.comドメインであった場合、herokuapp.comの正しいアドレスへリダイレクトされ、アプリケーションのログへリダイレクトのメッセージが書き込まれます。
このエラーメッセージは、routing meshが不正なHTTPレスポンスをdynoから検出した場合に、ログに書き込まれます。
バックエンドがHTTPレスポンスを返すより前に、クライアントのソケット、またはバックエンド（アプリケーションのwebプロセス）のソケットがクローズされています。ログの中のsockフィールドに、どちらのソケットがクローズしたかによりclient、またはbackendの値が出力されます。
routing meshが、ソケットをwebプロセスへオープンしようと試みたものの、５秒経過してしまうと、コネクションタイムアウトのエラーを受信します。これは、たいていアプリケーションが処理出来る度を越えてしまっており、新たなコネクションをタイムリーに取得することに失敗している兆候となります。もし、複数のdynoを使用しているのであれば、routing meshは、H19のエラーをログに書き込み、標準のエラーページを返すより前に複数のdynoへリトライしようとします。
2010-10-06T21:51:07-07:00 heroku[router]: Error H19 (Backend connection timeout) -> GET myapp.heroku.com/ dyno=web.1 queue= wait= service= status=503 bytes=
ルーターは、"up"状態に達するまでプロセスが開始されるのを待つ一方、75秒間、リクエストをキューに追加して行きます。もし75秒後、webプロセスが"up"状態に達しなければ、ルータはH20のエラーをログに書き込み、標準のエラーページをを返します。
2010-10-06T21:51:07-07:00 heroku[router]: Error H20 (App boot timeout) -> GET myapp.heroku.com/ dyno= queue= wait=75000ms service= status=503 bytes=
これはエラーではありませんが、完全性を保つために、エラーコードを返します。ログの出力フォーマットは同じですが、"Error"という単語が含まれていないことに気がついて下さい。
2010-10-06T21:51:07-07:00 heroku[router]: H80 (Maintenance mode) -> GET myapp.heroku.com/ web=none queue=0 wait=0ms service=0ms bytes=0
2010-10-06T21:51:07-07:00 heroku[nginx]: GET / HTTP/1.1 | 75.36.147.245 | 8132 | http | 503
これは、Herokuのプラットフォームにおける内部エラーを示しています。修正を求められるその他のエラーとは反し、特別なアクションは要求されません。再度、すぐにトライしてみて下さい。または、ステータスサイトを確認して下さい。
2010-10-06T21:51:07-07:00 heroku[router]: Error H99 (Platform error) -> GET myapp.heroku.com/ web=none queue=0 wait=0ms service=0ms bytes=0
2010-10-06T21:51:07-07:00 heroku[nginx]: GET / HTTP/1.1 | 75.36.147.245 | 8132 | http | 503
webプロセスが、代入された$PORTへバインドするのに60秒より長く時間を要しています。このエラーは、しばしばデーターベースのような外部のリソースへ接続出来なかったことが原因で発生します。
2011-05-03T17:31:38+00:00 heroku[web.1]: State changed from created to starting
2011-05-03T17:31:40+00:00 heroku[web.1]: Starting process with command: `thin -p 22020 -e production -R /home/heroku_rack/heroku.ru start`
2011-05-03T17:32:40+00:00 heroku[web.1]: Error R10 (Boot timeout) -> Web process failed to bind to $PORT within 60 seconds of launch
2011-05-03T17:32:40+00:00 heroku[web.1]: Stopping process with SIGKILL
2011-05-03T17:32:40+00:00 heroku[web.1]: Process exited
2011-05-03T17:32:41+00:00 heroku[web.1]: State changed from starting to crashed
プロセスが、不正なTCPソケットのバインドで動作しています。このエラーは、代入された$PORT以外のポートへバインドされたことにより、しばしば発生するエラーです。0.0.0.0、または*以外のインターフェースへバインドされたことによっても発生します。
2011-05-03T17:38:16+00:00 heroku[web.1]: Starting process with command: `bundle exec ruby web.rb -e production`
2011-05-03T17:38:18+00:00 app[web.1]: == Sinatra/1.2.3 has taken the stage on 4567 for production with backup from Thin
2011-05-03T17:38:18+00:00 app[web.1]: >> Thin web server
2011-05-03T17:38:18+00:00 app[web.1]: >> Maximum connections set to 1024
2011-05-03T17:38:18+00:00 app[web.1]: >> Listening on 0.0.0.0:4567, CTRL+C to stop
2011-05-03T17:38:18+00:00 heroku[web.1]: Error R11 (Bad bind) -> Process bound to port 4567, should be 43411 (see environment variable PORT)
2011-05-03T17:38:18+00:00 heroku[web.1]: Stopping process with SIGKILL
2011-05-03T17:38:18+00:00 heroku[web.1]: Process exited
2011-05-03T17:38:20+00:00 heroku[web.1]: State changed from starting to crashed
停止信号を出すSIGTERMが送信されている10秒の間で、プロセスが終了に失敗しています。プロセスを強制終了するために、SIGKILLが送信されています。
2011-05-03T17:40:10+00:00 app[worker.1]: Working
2011-05-03T17:40:11+00:00 heroku[worker.1]: Stopping process with SIGTERM
2011-05-03T17:40:11+00:00 app[worker.1]: Ignoring SIGTERM
2011-05-03T17:40:14+00:00 app[worker.1]: Working
2011-05-03T17:40:18+00:00 app[worker.1]: Working
2011-05-03T17:40:21+00:00 heroku[worker.1]: Error R12 (Exit timeout) -> Process failed to exit within 10 seconds of SIGTERM
2011-05-03T17:40:21+00:00 heroku[worker.1]: Stopping process with SIGKILL
2011-05-03T17:40:21+00:00 heroku[worker.1]: Process exited
heroku runで起動するプロセスが、呼び出し側のクライアントへ接続（アタッチ）に失敗しています。
2011-06-29T02:13:29+00:00 app[run.3]: Awaiting client
2011-06-29T02:13:30+00:00 heroku[run.3]: State changed from starting to up
2011-06-29T02:13:59+00:00 app[run.3]: Error R13 (Attach error) -> Failed to attach to process
2011-06-29T02:13:59+00:00 heroku[run.3]: Process exited
プロセスが、割り当てられた512MBを越えるメモリー量を要求しています。このエラーが発生した場合、実行し続けるために、プロセスはスワッップ領域へページングされます。このことは、プロセスのパフォーマンスを低下させる原因ともなります。
2011-05-03T17:40:10+00:00 app[worker.1]: Working
2011-05-03T17:40:10+00:00 heroku[worker.1]: Process running mem=528MB(103.3%)
2011-05-03T17:40:11+00:00 heroku[worker.1]: Error R14 (Memory quota exceeded)
2011-05-03T17:41:52+00:00 app[worker.1]: Working
プロセスが、割り当てられた512MBを大幅に越えるメモリー量を必要としていて、かつ、大幅にスワップ領域を消費しています。もし、このエラーが発生した場合、プロセスがプラットフォームにより強制終了されます。
2011-05-03T17:40:10+00:00 app[worker.1]: Working
2011-05-03T17:40:10+00:00 heroku[worker.1]: Process running mem=2565MB(501.0%)
2011-05-03T17:40:11+00:00 heroku[worker.1]: Error R15 (Memory quota vastly exceeded)
2011-05-03T17:40:11+00:00 heroku[worker.1]: Stopping process with SIGKILL
2011-05-03T17:40:12+00:00 heroku[worker.1]: Process exited
外部との接続がクローズされ、SIGHUPが送信された後にも関わらず、アタッチされたプロセスが実行され続けています。いくつかのアプリケーションでは、意図的にこの動作を行いたいでしょうが、大抵の場合、これは間違いで起きています。
2011-05-03T17:32:03+00:00 heroku[run.1]: Awaiting client
2011-05-03T17:32:03+00:00 heroku[run.1]: Starting process with command `bash`
2011-05-03T17:40:11+00:00 heroku[run.1]: Client connection closed. Sending SIGHUP to all processes
2011-05-03T17:40:16+00:00 heroku[run.1]: Client connection closed. Sending SIGHUP to all processes
2011-05-03T17:40:21+00:00 heroku[run.1]: Client connection closed. Sending SIGHUP to all processes
2011-05-03T17:40:26+00:00 heroku[run.1]: Error R16 (Detached) -> An attached process is not responding to SIGHUP after its external connection was closed.
Logplexのドレインが、アプリケーションによって生成されるログの量について行けておらず、出力先にログを送れていません。Logplexは、いくつかのメッセージを破棄するよう強制されている状態です。アプリケーションによって生成されるログの量を減らすよう調査する必要があります。（例えば、複数行に出力されるログを、より小さな単一行のログへ圧縮する等）または、生成されるログの量に追いついて行ける別のドレイン（排出）先を使う必要があります。
2011-05-03T17:40:10+00:00 heroku[logplex]: L10 (Drain buffer overflow) -> This drain dropped 1101 messages since 2011-05-03T17:35:00+00:00
Herokuのログ --アプリケーション、またはログのチャンネルが生成するログの量にテイル（追跡）のセッションがついて行けていません。Logplexが追いつこうと、いくつかのログを破棄している状態です。このエラーを回避するには、より高速なインターネット接続（ログを全て受信出来るレートまで増やして下さい）でコマンドを実行する必要があります。または、ログの量（ログが生成される割合を減らして下さい）を減らすようアプリケーションを改修する必要があります。
2011-05-03T17:40:10+00:00 heroku[logplex]: L11 (Tail buffer overflow) -> This tail session dropped 1101 messages since 2011-05-03T17:35:00+00:00