Request completed in 96902ms!!!???

23 views
Skip to first unread message

marsbomber

unread,
Oct 5, 2011, 1:56:19 AM10/5/11
to Ruby or Rails Oceania
Hi guys,

I'm having a really weird issue here. My app is super slow on 1
particular request. Completed in 96902ms (View: 90, DB: 24). Where
could Rails spend all the time on? Thanks, Jim

Pat Allan

unread,
Oct 5, 2011, 2:02:48 AM10/5/11
to rails-...@googlegroups.com
Hi Jim

You may want to provide us with a little more detail - what is that request doing? Is it making use of any external services? Is there anything out of the ordinary in the controller?

--
Pat

> --
> You received this message because you are subscribed to the Google Groups "Ruby or Rails Oceania" group.
> To post to this group, send email to rails-...@googlegroups.com.
> To unsubscribe from this group, send email to rails-oceani...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/rails-oceania?hl=en.
>

Michael Pearson

unread,
Oct 5, 2011, 2:07:21 AM10/5/11
to rails-...@googlegroups.com
My approach to this is somewhat dodgy, but it's a good way to start getting a feel for what's gone wrong before getting into 'real' profiling.

At the top of the method in your controller add:

start = Time.now

And then at points in your controller:

$stderr.puts "TIME1 #{Time.now - start}"

increment TIME1 to TIMEn on each instance.

Then run the slow request, check your logs, and refine.

--
Michael Pearson
The Bon Scotts; http://www.thebonscotts.com

Fred Wu

unread,
Oct 5, 2011, 7:38:03 AM10/5/11
to rails-...@googlegroups.com
What does the console/log say? If no external services is involved, there might be some dodgy logic that loops, etc, etc...

Installing the newrelic gem (and use its local monitor) might help with some performance debugging.

Aleksey Gureiev

unread,
Oct 5, 2011, 7:38:49 AM10/5/11
to rails-...@googlegroups.com
Some ideas for potential time sinks that I've met:

* Calling external services
* Blocking (waiting for some resource)
* Garbage collection

The first two can be addressed by sending the job into background process, but I would still see what takes so long.
The last one is the result of pushing too much in memory and you may want to review what's that. Sometimes, you just need the list of object IDs, not whole objects, so why fetching everything.

- A

suranyami

unread,
Oct 5, 2011, 7:27:46 AM10/5/11
to Ruby or Rails Oceania
You need to provide code in order for anyone to really answer your
question.

But taking a completely wild stab at it, I'm going to guess you're
doing something like loading a list of objects from a database,
without any indexes, and accessing attributes of related tables, each
of which will probably generate a query per record, and you're
probably loading all of the items without paginating.

That'd be one way to generate really slow responses... :-)

Places to start:

1. Log files. Are there thousands of queries being generated for the
one page? If so, try reading up on the "N + 1 problem", eager loading
and "include", join and other operations. (http://
guides.rubyonrails.org/active_record_querying.html)

2. SQL explain queries: learn how to use them.

3. Indexes: read about what they are, and how they can make your
database queries several orders of magnitude faster.

4. Try using something like https://github.com/dsboulder/query_reviewer
or https://github.com/jeberly/query-analyzer to get a more fine-
grained analysis of what's taking the time.

5. Lastly: learn how to supply the right amount of information to
allow others to answer your questions. Try looking on http://stackoverflow.com
for existing answers to your problem. If there isn't something
specific, read their submission suggestions, then post something there
or here. Saying "I've got a problem, it's too slow, why?" is not
helpful. Supply code snippets and/or relevant log files.

Hope this helps.

marsbomber

unread,
Oct 5, 2011, 7:20:48 PM10/5/11
to Ruby or Rails Oceania
Thanks guys for the suggestions! It appears to be a file corruption
issue caused by git I believe. All I did was re-checking out master,
the problem fixed itself ... Something goes into the trickery book :D

On Oct 5, 10:27 pm, suranyami <d...@suranyami.com> wrote:
> You need to provide code in order for anyone to really answer your
> question.
>
> But taking a completely wild stab at it, I'm going to guess you're
> doing something like loading a list of objects from a database,
> without any indexes, and accessing attributes of related tables, each
> of which will probably generate a query per record, and you're
> probably loading all of the items without paginating.
>
> That'd be one way to generate really slow responses... :-)
>
> Places to start:
>
> 1. Log files. Are there thousands of queries being generated for the
> one page? If so, try reading up on the "N + 1 problem", eager loading
> and "include", join and other operations. (http://
> guides.rubyonrails.org/active_record_querying.html)
>
> 2. SQL explain queries: learn how to use them.
>
> 3. Indexes: read about what they are, and how they can make your
> database queries several orders of magnitude faster.
>
> 4. Try using something likehttps://github.com/dsboulder/query_reviewer
> orhttps://github.com/jeberly/query-analyzerto get a more fine-
> grained analysis of what's taking the time.
>
> 5. Lastly: learn how to supply the right amount of information to
> allow others to answer your questions. Try looking onhttp://stackoverflow.com

Tim Uckun

unread,
Oct 5, 2011, 7:19:56 PM10/5/11
to rails-...@googlegroups.com
One other thing to watch out for is to_yaml. Unless you are using a
yaml library that uses the native libs this call can cause huge
problem with large data structures. One place where there might be
hidden to_yaml calls are serialized fields. Use a profiler they are
very handy.

Ben Hoskings

unread,
Oct 6, 2011, 1:41:50 AM10/6/11
to rails-...@googlegroups.com
It definitely wasn't git :)

git can certainly fix corruption, in that it can check out a fresh copy of the files stored in the repo. It won't cause corruption, though -- in fact, a fundamental part of git's design is guaranteeing the content it stores is intact (or exploding when it isn't), even from an questionable location (whether it be a dodgy disk, or an untrusted server).

That's why when kernel.org was hacked last month, the repos stored there (the linux kernel, and git itself) didn't have to be treated as suspect.

The upshot is that if you can successfully `git checkout <REF>`, then your content is known-good (i.e. what came out is exactly what went in).

- Ben

Leonard

unread,
Oct 10, 2011, 2:20:46 AM10/10/11
to rails-...@googlegroups.com
Without knowing exactly what is in your git repo this seems extremely unlikely that git both caused and fixed the issue(I'm imagining that having a flat file database which was in source control might cause app slowness, but this is hardly git's fault). It's great that your app is now working properly, but I suspect that the slowness was caused by something else entirely.

I'd echo some of the suggestions but might go a step further and say that slowness is almost certainly because of your database and more specifically the queries you're making on it. As to why a git checkout "solved" the issue: Are you running some sort of deployment script when you checkout your repo? Does this build your database in any way?

If you're using a proper database (like Postgres) you can enable slow query logging (see http://wiki.postgresql.org/wiki/Logging_Difficult_Queries) which you can use to identify slow queries and then do further manual analysis. This analysis will often reveal that you're doing something silly in your queries, or that you've not got proper indexing on your database schema.
Reply all
Reply to author
Forward
0 new messages