Has anyone noticed Rails abrubtly slows down for no reason?

I've noticed this on various pages, both in development mode (which I
do with Mongrel) and in production mode under FastCGI. I've seen it on
Mac and on Linux. It's really bizarre. I'll pull up a random page,
one that typically takes under a second to return, and it will crawl
for an obscene amount of time. For example, I just pulled up a
straightforward "edit profile page" and the mongrel output is:

<snip>

Occasionally when I kill Mongrel, I get messages about waiting for
threads, and most recently this dumped out after killing mongrel:

% cumulative self self total
time seconds seconds calls ms/call ms/call name
23.00 31.22 31.22 143 218.32 318.67 Kernel.sleep

<snip>

Uh, am I crazy or is that output from the "profile" library? Are you accidentally loading a "Profile" class and it's actually loading the ruby library (which absolutely crawls, crawls, crawls).

That's not normal output for Mongrel, so you've gotta be loading it somehow.

Zed A. Shaw wrote:

<snip>
>
> Occasionally when I kill Mongrel, I get messages about waiting for
> threads, and most recently this dumped out after killing mongrel:
>
> % cumulative self self total
> time seconds seconds calls ms/call ms/call name
> 23.00 31.22 31.22 143 218.32 318.67 Kernel.sleep
<snip>

Uh, am I crazy or is that output from the "profile" library? Are you accidentally loading a "Profile" class and it's actually loading the ruby library (which absolutely crawls, crawls, crawls).

That's not normal output for Mongrel, so you've gotta be loading it somehow.

Hi Zed - thank you for the response.

I grep'ed my code for "profiler", "benchmark", and "report" but the
only results I turned up were in my tests, not the application code.
That said, when that particluar dump happened I was running in
development mode. Is there a chance that something in the Rails stack
loads up the profiler when you're running in development mode?

I haven't seen that output under production mode, but I have seen the
kind of abrupt slowdowns that seem to linger until the ruby processes
are killed. Perhaps I linked the two (the abrupts slowdowns and that
output) incorrectly. Note also that I haven't been running Mongrel in
production mode (yet). I've been using FastCGI. So, I'd say it's
unlikely this is a Mongrel issue... which is in some ways unfortunate,
because you're among the most responsive people in the Ruby community
:).

In production mode, what I've been doing is throwing httperf at a
particular part of my app that does a db query returning @50 things,
and the view iterates them to build the page. What I often see is that
this page can take a second to run:

Completed in 1.09736 (0 reqs/sec) | Rendering: 0.99119 (90%) | DB:
0.02663 (2%) | 200 OK

But after say 10-15 requests, it can take almost 40 seconds to run:

Completed in 37.74147 (0 reqs/sec) | Rendering: 37.69804 (99%) | DB:
0.02693 (0%) | 200 OK

I understand that if my box is heavily loaded that things will take
longer - in this particular case at 3 connections per second it seeems
to spike the CPU after a few seconds. I know that makes this page a
good place to opimize or cache. The part that concerns me is when I
see the breakdown of the execution time spending nearly zero time in
the database and 37 seconds rendering the page. My database and web
server are on the same machine (right now) contending for the same
resources. The fact that the database seems to be processing things
quickly but the rendering takes a nosedive makes me wonder if something
is wrong in the app. It just doesn't smell right, as they say.

Or... is this common in Rails apps? What are other people seeing?

Tom

Tom wrote:

<snip>

I understand that if my box is heavily loaded that things will take
longer - in this particular case at 3 connections per second it seeems
to spike the CPU after a few seconds. I know that makes this page a
good place to opimize or cache. The part that concerns me is when I
see the breakdown of the execution time spending nearly zero time in
the database and 37 seconds rendering the page. My database and web
server are on the same machine (right now) contending for the same
resources. The fact that the database seems to be processing things
quickly but the rendering takes a nosedive makes me wonder if something
is wrong in the app. It just doesn't smell right, as they say.

Or... is this common in Rails apps? What are other people seeing?

I am running three different apps on Apache 1.3+FCGI+Slackware and have
not experience any problem in production, so far. It seems 3 requests/sec is
slow but I don't know what is the average. Is 10 req/sec a good measure?

During development, sometimes due to an Exception (self inflicted) WEBrick
just doesn't recover. Subsequent request just takes forever and not get any result.
CTRL+C on WEBrick had no effect. I checked the server memory usage (free)
and can see available mem reducing then in memory stuff gets swapped out. By the
time I finish killing (kill -9) WEBrick and checked free memory again the
swap-space had grew and there was more free mem available.

Just thought I'd share in case you can see any similarities.

Long
www.edgesoft.ca