[Catalyst] Very long request time weirdness

[Jonathan Rockway]

* On Tue, Jun 24 2008, luke saunders wrote:
> In order to get some info on how long requests were taking and where
> the bottlenecks were we put some code into MyApp::finalize which wrote
> info gained from $c->stats to the DB so we could easily check them
> later (code given below). Occasionally we get a request where total
> time ($c->stats->elapsed) is very long (more than 50 seconds) but each
> individual action executes very quickly (they usually sum to less than
> 1 second). So presumably something is happening between the end action
> and finalize which is taking ages, but what on earth could that be?

Feeding data to an end-user with a slow connection?  I assume your
frontend server would buffer that, but who knows?

Perhaps you can get the number of CPU seconds your process has used at
the beginning of the request (around prepare or execute) and then again
before writing data to the log, to see if you are CPU bound those 50
seconds.  If you are, then your problem is the app.  If you aren't, then
the problem is IO.

You might also want to log the size of the data you're returning.  If
you see no CPU usage, and the response body is huge, this further points
towards IO being a problem.

Regards,
Jonathan Rockway

-- 
print just => another => perl => hacker => if $,=$"