Hi All, I'm having trouble with a Rails app and I can't figure out what / where the problem is.
>From the logging and testing I've done, it looks like there is a consistent 3 second delay between the time that Rails finishes rendering the view and the time that the browser actually receives the data. That delay doesn't show up on my laptop, running in Production mode, but it does show up on my server, running in Production mode. Both machines are running Ruby 1.8.7 and both are running Rails 3.0.3. I ran the test as pure as I could. I SSHed into the server and loaded the page through curl and timed the load. I also loaded directly from Rails itself, not going through the Apache proxy. I think that eliminates both the network and Apache as sources of the delay. I think the delay is somewhere in Rails itself. Here's my logs. First, the commands and date/time stamps from the prompt. [litho:~/apps/timetrack/current/log] jmartin$ date ; curl -b "cookie:val" http://127.0.0.1:10100/activity/list >/dev/null ; date ;curl -b "cookie:val" http://127.0.0.1:10100/activity/list >/dev/ null ; date Tuesday, February 1, 2011 2:28:38 PM GMT % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 4709 0 4709 0 0 1328 0 --:--:-- 0:00:03 --:--:-- 1328 Tuesday, February 1, 2011 2:28:42 PM GMT Tuesday, February 1, 2011 2:28:42 PM GMT % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 4709 0 4709 0 0 1352 0 --:--:-- 0:00:03 --:--:-- 1352 Tuesday, February 1, 2011 2:28:45 PM GMT Next, here are the entries from the Rails production.log file. Started GET "/activity/list" for 127.0.0.1 at Tue Feb 01 14:28:38 +0000 2011 Processing by ActivityController#list as */* before filter Exist fragment? views/127.0.0.1:10100/activity/list (0.1ms) Write fragment views/127.0.0.1:10100/activity/list (0.1ms) Rendered activity/_recent.html.erb (7.4ms) Rendered activity/_switch.html.erb (2.4ms) Rendered activity/list.html.erb within layouts/application (14.1ms) Completed 200 OK in 19ms (Views: 14.5ms | ActiveRecord: 108.9ms) Started GET "/activity/list" for 127.0.0.1 at Tue Feb 01 14:28:42 +0000 2011 Processing by ActivityController#list as */* before filter Exist fragment? views/127.0.0.1:10100/activity/list (0.1ms) Read fragment views/127.0.0.1:10100/activity/list (0.1ms) Rendered activity/_recent.html.erb (1.3ms) Rendered activity/_switch.html.erb (2.4ms) Rendered activity/list.html.erb within layouts/application (7.7ms) Completed 200 OK in 12ms (Views: 8.3ms | ActiveRecord: 106.9ms) It looks like the Rails app receives the request as soon as curl sends it. It process it in 12 or 19 milliseconds and then curl doesn't get the response for another 3 full seconds. What could possibly be causing the delay between the time that the view is Completed and logged and the time that curl receives the HTML data? -- You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to [email protected]. To unsubscribe from this group, send email to [email protected]. For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en.
