Rails 3.1 + Heroku：誰かがこのHerokuのログを解読するのを助けることができますか？

Question

私のクライアントがHerokuのRailsサーバーに対して複数のJSON応答を受け取っている（私は思うが）この断続的な問題が発生しています。ここでは、問題を示すHerokuのログが...

2012-04-20T00:22:27+00:00 app[web.1]: Started POST "/games/2/call" for 76.171.181.11 at 2012-04-19 17:22:27 -0700 
2012-04-20T00:22:27+00:00 app[web.1]: Processing by GamesController#call as */* 
2012-04-20T00:22:27+00:00 app[web.1]: Parameters: {"fb_id"=>"0", "id"=>"2"} 
2012-04-20T00:22:27+00:00 app[web.1]: Completed 200 OK in 163ms (Views: 0.3ms | ActiveRecord: 93.3ms) 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4594ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 app[web.1]: cache: [POST /games/2/call] invalidate, pass 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4546ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4594ms status=200 bytes=2012 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4570ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4560ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4534ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[nginx]: 76.171.181.11 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 560 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 76.171.181.11 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 560 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 76.171.181.11 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 539 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 207.151.231.155 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 207.151.231.155 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 207.151.32.38 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_3) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.151 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 108.70.74.121 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" 

だ私はRailsとHerokuのに新たなんだので、私はかなり十分に起こっているのかを把握するために、このログを理解することはできません。 HerokuのRailsアプリケーションがクライアントからの複数のHTTPリクエストを受信して​​いるのですか、または1つのHTTPリクエストしか受信せず、複数のJSON応答を返すだけですか？

あなたの知恵のためにあまり前もってありがとう！

Answer 1

それは同時に7つのPOSTリクエストなっています：私はたまにこのような問題を持っていた

# First Request, heroku starts to process it normally 
2012-04-20T00:22:27+00:00 app[web.1]: Started POST "/games/2/call" for 76.171.181.11 at 2012-04-19 17:22:27 -0700 
2012-04-20T00:22:27+00:00 app[web.1]: Processing by GamesController#call as */* 
2012-04-20T00:22:27+00:00 app[web.1]: Parameters: {"fb_id"=>"0", "id"=>"2"} 

# First request returns OK 
2012-04-20T00:22:27+00:00 app[web.1]: Completed 200 OK in 163ms (Views: 0.3ms | ActiveRecord: 93.3ms) 

# Second request starts 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4594ms status=200 bytes=2013 

# It looks like the second request fails 
2012-04-20T00:22:27+00:00 app[web.1]: cache: [POST /games/2/call] invalidate, pass 

# Request 3-7 come in 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4546ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4594ms status=200 bytes=2012 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4570ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4560ms status=200 bytes=2013 
2012-04-20T00:22:27+00:00 heroku[router]: POST myapp.heroku.com/games/2/call dyno=web.1 queue=0 wait=0ms service=4534ms status=200 bytes=2013 

# Heroku responds to the requests... though I'm not sure what it's serving up. 
2012-04-20T00:22:27+00:00 heroku[nginx]: 76.171.181.11 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 560 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 76.171.181.11 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 560 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 76.171.181.11 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 539 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 207.151.231.155 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 207.151.231.155 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 207.151.32.38 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_3) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.151 Safari/535.19" myapp.heroku.com 
2012-04-20T00:22:27+00:00 heroku[nginx]: 108.70.74.121 - - [20/Apr/2012:00:22:27 +0000] "POST /games/2/call HTTP/1.1" 200 540 "http://myapp.heroku.com/pages/fb/webplayer_64.unity3d" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.19 (KHTML, like Gecko) Chrome/18.0.1025.162 Safari/535.19" 

を - JavascriptがDOMをそのバブルを要求し、私は一度だけ起動するようにそれらを意味し、複数回発射。これはサーバをかなり速くクラッシュさせる可能性があるので、あなたのアプリを見て、AJAX呼び出しを急速に起動させないようにしてください。

これをキャッチする簡単な方法は、ajax呼び出しの直前または直後にalert()を置き、発生回数と発生回数を確認することです。

私はそれがあなたの問題かどうか分かりませんが、私は以前にそのようなことが起こっていました。