2009年10月15日

[Apache-Users 7464]MongrelとApache間のTimeoutについて

** Apache ユーザーズメーリングリスト **
** 注意:このメールへの返信は Apache-Users へ行きます **

初めて質問させていただきます
田村と申します

以下の環境のRubyOnRailsアプリを運用しております

 Webサーバー(兼APサーバー): 
apache 2.2.10
mongrel 1.0.1
Rails 1.2.3
ruby 1.8.5(2006-12-16 patchlevel 11)
 
 ※上記の構成を1台のlinux上に配置しています
 ※3つのmongrelプロセスがAPサーバー上で起動して
  おり、apacheのmod_proxyで振り分けています

この環境で、たまにapacheのタイムアウトエラーが発生します。
その際のログですが、以下の通りです

------------------------------------------------------------------------
(1)apacheのaccess.log
xxx.xxx.xxx.xxx - - [01/Sep/2009:08:49:23 +0900] "GET /xxxxxxxxxxx/list?・・
(省略)・・・ HTTP/1.1" 502 415 300328494 xxx.xxx.zzz.zzz httpd[29177] 
"http://xxx.xxx.zzz.zzz/xxxxxxxxxx/list?clear=1" "Mozilla/4.0 (compatible;
MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET
CLR 3.0.4506.2152; .NET CLR 3.5.30729)" "-"

 →08:49:23に呼び出しがあり、502でエラーを返しています

(2)apacheのerror.log
[Tue Sep 01 08:54:23 2009] [error] [client xxx.xxx.xxx.xxx] (70007)The
timeout specified has expired: proxy: error reading status line from remote
server localhost, referer: http://xxx.xxx.zzz.zzz/xxxxxxxxxxx/list?clear=1
[Tue Sep 01 08:54:24 2009] [error] [client xxx.xxx.xxx.xxx] proxy: Error
reading from remote server returned by /xxxxxxxxxxx/list, referer:
http://xxx.xxx.zzz.zzz/xxxxxxxxxxx/list?clear=1

 →08:54:24にタイムアウトのエラーログが出力
  (apacheのProxyTimeoutの設定は5分)

(3)Railsのdevelopment.log
Processing XxxxxxController#list (for 127.0.0.1 at 2009-09-01 08:55:51)
[GET]
INFO xxxxxx_web: Session ID: 658810dd360b7f9c9c04165b8e5a5401
INFO xxxxxx_web: Parameters: {・・・・(省略)・・・・・}
WARN xxxxxx_web: Hash: {:code=>"XXXXXXX", :message=>""} DEBUG ・・・・・
・・・(省略)・・・
INFO xxxxxx_web: Completed in 4.12208 (0 reqs/sec) | Rendering: 1.65873
(40%) | DB: 3.29524 (79%) | 200 OK
http://xxx.xxx.zzz.zzz/xxxxxxxxxxx/list?・・・(省略)・・・]
WARN madison_web: Hash: {:code=>"IGED0101", :message=>""}

 →08:55:51にアプリの処理が開始して、4.12208秒後に完了

(4)Railsアプリケーションのログ
2009/09/01 08:55:51.620 開始のログ
2009/09/01 08:55:55.757 終了のログ

 →development.logの内容と一致した結果となっています

------------------------------------------------------------------------

(1)〜(4)のログを見る限りでは、apacheからmongrelに問い合わせを
行ったが、Railsのアプリが開始する前にタイムアウトしているようです。
また、apacheがクライアントに502の応答を返却した後にRailsの
アプリ処理が開始しているようです。

Mongrelはシングルスレッドでしか起動しないため、3つ以上の長時間
処理が集中するとタイムアウトするのはわかるのですが、上記の
場合は、特にアクセスは集中しておらず、同一タイミングで他に実施
されている処理はありませんでした。

何故このような現象が発生するのかが不明なのですが、
どなたかご存知の方はいらっしゃいませんでしょうか?

長文失礼いたしました。

よろしくお願いいたします。

--
入退会・変更・配送一時停止は以下へ
http://www.apache.jp/mailman/listinfo/apache-users


投稿者 xml-rpc : 2009年10月15日 17:15
役に立ちました?:
過去のフィードバック 平均:(0) 総合:(0) 投票回数:(0)
本記事へのTrackback: http://hoop.euqset.org/blog/mt-tb2006.cgi/89469
トラックバック
コメント
コメントする




画像の中に見える文字を入力してください。