Extremely slow start up with ruby 1.9.1 vs 1.8.7

I created a fresh new rails app, no gems, no nothing. Completely
unmodified. Doing anything that initializes rails takes 2 - 3 times
longer in ruby 1.9.1 than it does in 1.8.7. Obviously with a fresh rails
app, this is only 2 - 3 seconds extra. But with a decent sized app, this
can take up to 25 seconds for rails to initialize, vs the 12 seconds in
1.8.7.

I’ve been racking my brain on this all day. I don’t know where to begin.
Any ideas what might be causing the problem or a way to profile the code
and figure out what is taking so long?

The reason its an issue for me, heroku times out before my app has a
chance to start, displaying an error message that the app times out.

Any help is appreciated. Thanks.

Ben, did you ever figure out anything here? I’m experiencing the same
problem with 1.9.2: rails w/1.9 slower than w/1.8 · GitHub

On 27 December 2010 22:08, Micah G. [email protected] wrote:

Ben, did you ever figure out anything here? I’m experiencing the same
problem with 1.9.2: rails w/1.9 slower than w/1.8 · GitHub

I am seeing a similar issue with startup between Rails 3 with 1.9.2
and Rails 2 with 1.8.7, though I have not investigated whether it is
ruby or rails that is the issue. For example if I do rake db:migrate
with nothing to do it takes 7 seconds on the former but only 2 on the
latter. I see the same effect starting tests and so on. It is a bit
of a pain. I am using rvm and bundler in both cases.

Colin

On 28 December 2010 09:16, Colin L. [email protected] wrote:

of a pain. I am using rvm and bundler in both cases.
I have done some further tests and confirmed that it is Ruby 1.9.2
that is causing the problem. I am comparing a Rails 3 app with ruby
1.9.2p0 (2010-08-18 revision 29036) [i686-linux] against ruby 1.8.7
(2010-08-16 patchlevel 302) [i686-linux]. With a small app, as
mentioned above, an empty rake db:migrate takes 7 seconds rather than
2 and Rake test takes 40 seconds on 1.9.2 versus 11 on 1.8.7. This is
on Ubuntu 10.04.

Any suggestions anyone?

Colin

On 28 December 2010 11:24, Colin L. [email protected] wrote:

latter. I see the same effect starting tests and so on. It is a bit
of a pain. I am using rvm and bundler in both cases.

I have done some further tests and confirmed that it is Ruby 1.9.2
that is causing the problem. I am comparing a Rails 3 app with ruby
1.9.2p0 (2010-08-18 revision 29036) [i686-linux] against ruby 1.8.7
(2010-08-16 patchlevel 302) [i686-linux]. With a small app, as
mentioned above, an empty rake db:migrate takes 7 seconds rather than
2 and Rake test takes 40 seconds on 1.9.2 versus 11 on 1.8.7. This is
on Ubuntu 10.04.

I have now tried this with ruby 1.9.2 p136 and it has not helped.
When I look at the processor utilisation I see that rake is consuming
all my available processor for most of the time. Can anyone confirm
that they are using 1.9.2 with rails 3 (preferably on Ubuntu or
similar) without seeing the slowdown that I have experienced.
Alternatively can anyone suggest where I go from here (apart from
buying a more powerful PC).

Colin

On 29 December 2010 20:47, cpr [email protected] wrote:

Just FYI, I can confirm that I’m seeing the same numbers you are
(following your gist).

Running Ubuntu 10.4 on Virtual Box on Win 7 x64 on a MacBook Pro i7.

Can I just check that you are confirming that you see a significant
slow down between Ruby 1.8.7 and 1.9.2?

Colin

On Wed, Dec 29, 2010 at 2:04 AM, Colin L. [email protected]
wrote:

with nothing to do it takes 7 seconds on the former but only 2 on the

Colin, do you have a sample application? Next, it really depends
on your overall system and Rails app configuration. For example,
if you don’t have enough RAM, your system move data from memory
to the disk and vice-versa. This is a huge performance hit. Can you
provide more information?

-Conrad

On 29 December 2010 23:18, Conrad T. [email protected] wrote:


Colin, do you have a sample application? Next, it really depends
on your overall system and Rails app configuration. For example,
if you don’t have enough RAM, your system move data from memory
to the disk and vice-versa. This is a huge performance hit. Can you
provide more information?

I have 1GByte RAM and while running the test it shows less than half
used and the disk is not rattling. The processor shows 100%
utilisation whilst the test is running, with rake being the process
using most of it.

I have tried making a new rails 3.0.3 app
rails new testruby
then using rvm to switch between 1.8.7 p302 and 1.9.2 p136

On each ruby I ran
time rake db:migrate
a couple of times to let the disk cache settle out then for 1.8.7 I got
real 0m2.111s
user 0m1.804s
sys 0m0.220s

and on 1.9.2
real 0m4.098s
user 0m3.512s
sys 0m0.424s

I also tried rake test and got, on 1.8.7
real 0m3.615s
user 0m3.104s
sys 0m0.316s

and on 1.9.2
real 0m6.487s
user 0m5.320s
sys 0m0.684s

It seems as if 1.9.2 takes about twice as long for some reason.

Colin

On a bare app I get the same numbers as you show in your gist (about a
2x factor for sys and real times).

On my relatively new app’s specs I get these:

Using ~/.rvm/gems/ruby-1.9.2-p136 with gemset rails3

% time rake spec
real 1m3.337s
user 0m41.383s
sys 0m3.760s

Using ~/.rvm/gems/ruby-1.8.7-p330 with gemset rails3

% time rake spec
real 0m21.948s
user 0m12.721s
sys 0m2.248s

I ran each rvm 5 times and they’re very consistent. The CPU is at 45%,
I have 2G ram and the app footprint in test is much smaller than that
(~500M).

Interesting that the ratios between the sys times and the real times
are not tracking relative to the bare app. The real time going to 3x
is nasty.

I think I’ll do a ruby-prof next.

-cpr

On Thu, Dec 30, 2010 at 7:59 AM, Colin L. [email protected]
wrote:

utilisation whilst the test is running, with rake being the process
user 0m1.804s
sys 0m0.316s

Colin, do you have a test case that I can run locally? Or can you
tell me the specifics? Next, I’m not sure that 1 GB RAM is sufficient
because other resources outside the actual application uses the RAM.
For example, on my slower machine, iMac, with 4 GB Ram, the RAM
utilization for some common applications are as follows:

Safari 5 ~554.0 MB
Textmate ~96.1 MB
Terminal ~14.0 MB
Chrome ~199.6 MB
Firefox ~128.2 MB
and so on

Note: The above doesn’t include any of the OS specific processes but
you can see that this adds up. Also, most modern OS will reserve RAM
for its use that cannot be used by the end user. Just something to keep
in mind.

Lastly, in regards to running spec, I tend to use Ruby Spork gem because
anytime you do ‘rake spec’, the Rails framework needs to be loaded
before
the application specific code can be executed. This is also true when
running
‘rake db:migrate’

Good luck,

-Conrad

Hi Colin and all,

I had exactly the same here: 1GB RAM, Ubuntu, RVM with Ruby1.9 and
Rails - and it’s terribly slow comparing with the elder Ruby and Rails
combo. Did you figured out anything?

Also how did you speed up your server running? I already use Thin
locally, and found it"s faster then Webrick, but still have to wait a
lot after loading. Any trick?

Thanks,
Zoli

On 2 January 2011 01:57, gezope [email protected] wrote:

Hi Colin and all,

I had exactly the same here: 1GB RAM, Ubuntu, RVM with Ruby1.9 and
Rails - and it’s terribly slow comparing with the elder Ruby and Rails
combo. Did you figured out anything?

Also how did you speed up your server running? I already use Thin
locally, and found it"s faster then Webrick, but still have to wait a
lot after loading. Any trick?

I use mongrel. The server startup time is not really an issue for me
in development as starting the server is not something that happens
repeatedly. I don’t know whether the response time once the server is
up and running is significantly different between 1.9.2 and 1.8.7, I
had not noticed an obvious difference. It is the test cycle time
particularly that is a pain. I use autotest and when I make a change
I have to wait while the tests get underway, which is tedious.

Colin

Using ruby-prof I captured the CPU time of the startup of my 3.0.3
Rails app (https://gist.github.com/762764):

ruby-1.8.7-p330 (Total CPU: 8.573606)

%self total self wait child calls name
20.99 8.50 1.80 0.00 8.49 1898 Kernel#require
10.16 0.87 0.87 0.00 0.00 17128 Module#constants
6.71 0.82 0.58 0.00 0.25 3691 Array#select
6.22 8.00 0.53 0.00 7.95 58841 Array#each
4.16 1.85 0.36 0.00 1.66 14214 Array#map

ruby-1.9.2-p136 (Total CPU 16.794391)

%self total self wait child calls name
39.93 16.47 6.71 0.00 16.46 1904 Kernel#require
3.85 2.51 0.65 0.00 2.23 14252 Array#map
3.61 0.61 0.61 0.00 0.00 594435 Symbol#to_s
3.23 15.68 0.54 0.00 15.59 41201 Array#each
2.38 0.40 0.40 0.00 0.00 2855 Module#constants

Looks like require is 1/2 speed and that evaluating array blocks(?)
has slowed down considerably. I saw chatter about require being an
issue in 1.9.1 but the issue was closed.

Doesn’t seem to be a Rails issue as much as a Ruby issue.

I have the same issue wrt using autotest. My tests take 3x the time to
run with 1.9.2.

-cpr

Update:

On Jan 2, 9:18pm, paul h [email protected] wrote:

using most of it.
sys 0m0.220s
sys 0m0.424s
following:

real 0m3.615s
user 0m3.104s
sys 0m0.316s

Finished in 0.289591 seconds

real 0m4.363s
user 0m3.390s
sys 0m0.540s

and on 1.9.2
real 0m6.487s
user 0m5.320s
sys 0m0.684s

Finished in 0.578807 seconds

real 0m7.211s
user 0m5.810s
sys 0m0.940s

On 2 January 2011 21:18, paul h [email protected] wrote:

on your overall system and Rails app configuration. For example,
rails new testruby
user 0m2.100s
sys 0m0.150s
So you are getting 1.9.2 faster than 1.8.7 for db:migrate?

On Jan 2, 9:52pm, Colin L. [email protected] wrote:

On 29 December 2010 23:18, Conrad T. [email protected] wrote:
utilisation whilst the test is running, with rake being the process
user 0m1.804s

real 0m0.922s
user 0m0.730s
sys 0m0.150s

So you are getting 1.9.2 faster than 1.8.7 for db:migrate?
Yep I was…

however:

I now get (1.9.2p136):

real 4.239s
user 3.600s
sys 0.460s

I’ve just checked back over the shell output, and I missed an error
message earlier on (I hadn’t run bundle install), so those test
results (1.9.2) should be ignored - apologies to all for that. (In my
defence I’m just recovering from major ‘man-flu’, first day up and
about today, and rvm is a new install today :))

Hi Colin,

I have duplicated your tests using rvm on Ubuntu 10.04, with AMD64,
and 3GB RAM, results are below:

On Dec 30 2010, 3:59pm, Colin L. [email protected] wrote:

used and the disk is not rattling. The processor shows 100%
real 0m2.111s
user 0m1.804s
sys 0m0.220s

real 0m2.520s
user 0m2.100s
sys 0m0.340s

and on 1.9.2
real 0m4.098s
user 0m3.512s
sys 0m0.424s

real 0m0.922s
user 0m0.730s
sys 0m0.150s

I also tried rake test and got, on 1.8.7

I ran rake test and got no output, rake test:benchmark gave the
following:

real 0m3.615s
user 0m3.104s
sys 0m0.316s

Finished in 0.289591 seconds

and on 1.9.2
real 0m6.487s
user 0m5.320s
sys 0m0.684s

Finished in 0.578807 seconds

It seems as if 1.9.2 takes about twice as long for some reason.

Colin

Paul

Seems pretty consistent. Is anyone NOT seeing these results? It’s
starting to look like this is the reality of Rails on 1.9.2. Is this
simply a known Rails performance regression from 1.8 to 1.9? If so, it
removes a great deal of my desire to upgrade. Perhaps we should take
this to rails-core.

On 8 January 2011 20:55, Micah G. [email protected] wrote:

Seems pretty consistent. Is anyone NOT seeing these results? It’s
starting to look like this is the reality of Rails on 1.9.2. Is this
simply a known Rails performance regression from 1.8 to 1.9? If so, it
removes a great deal of my desire to upgrade. Perhaps we should take
this to rails-core.

Done.

http://permalink.gmane.org/gmane.comp.lang.ruby.rails.core/14754

Colin

I am also getting the slow startup of rake, which impacts development
using autotest.

I’m running 1.9.2 on a Mac, and it seems to be taking a lot longer
than I ever remember it taking.

I didn’t yet run benchmarks, seems like they would be very similar to
what you guys were seeing.

  • Anthony