Bugs item #29116, was opened at 2011-04-05 11:01
You can respond by visiting:
http://rubyforge.org/tracker/?func=detail&atid=575&aid=29116&group_id=126
Category: #gem and #require methods
Group: None
Status: Open
Resolution: None
Priority: 3
Submitted By: Sam Goldstein (samgoldstein)
Assigned to: Ryan Davis (zenspider)
Summary: Mega slowness in custom require
Initial Comment:
I recently upgraded to rubygems 1.6.5 and started experiencing a major slowdown
loading the environment for a Rails 2.3 application.
I traced the problem back to the Kernel.require (custom_require.rb) and
Gem.loaded_path?. It seems that searching $LOADED_FEATURES repeatedly is
inefficient and results in a 4x slowdown in my specific case.
I've downgraded to rubygems 1.3.5 which doesn't suffer from this problem. This
is a major hurdle to developing in ruby, as it takes me ~45 seconds to load the
environment and run one test.
Below is some console output demonstrating the problem.
/www/aboutus/app_root [master] $ time rake environment
(in /www/aboutus/app_root)
real 0m11.407s
user 0m8.787s
sys 0m2.552s
/www/aboutus/app_root [master] $ sudo gem update --system
Updating RubyGems
Updating rubygems-update
Successfully installed rubygems-update-1.7.1
Updating RubyGems to 1.7.1
Installing RubyGems 1.7.1
RubyGems 1.7.1 installed
=== 1.7.1 / 2011-03-32
* 1 bug fix:
* Fixed missing file in Manifest.txt. (Also a bug in hoe was fixed where
`rake check_manifest` showing a diff would not exit with an error.)
------------------------------------------------------------------------------
RubyGems installed the following executables:
/usr/local/bin/gem
/www/aboutus/app_root [master] $ time rake environment
(in /www/aboutus/app_root)
NOTE: SourceIndex.new(hash) is deprecated; From
/www/aboutus/app_root/config/../vendor/rails/railties/lib/rails/vendor_gem_source_index.rb:100:in
`new'.
real 0m46.707s
user 0m41.200s
sys 0m5.394s
Thanks!
----------------------------------------------------------------------
>Comment By: Ryan Davis (zenspider)
Date: 2011-05-23 16:47
Message:
Much of this slowdown occurred as a result of us fixing complex gem dependency
resolution bugs. Unfortunately, we're not in a good place to do too much to
address this issue right now. I will point out that in both old (< 1.4)
rubygems and newer, that the time is going to be proportional to the amount of
gems installed. Keeping around a bunch of old stuff you're not using will only
harm you in any version.
I did get a repro using MOST of what Sam reported. I couldn't install some gems
because I didn't have requisite libraries (eg I never use mysql, so it couldn't
build) and some of his gems are not in the main gem repo. Of his 287 gems
(WOW!) I was able to install 273 of them.
Until I tried out a rails app, EVERY timing I tried to do wound up at least 25%
faster in 1.7/1.8 over 1.3.7. Once we got to really complex graphs of
activation (read: rails), I was able to get a repro where 1.7/1.8 was slower. I
got the following times while loading a rails 2.3.4 config/environment.rb file:
repo=xxx; before 'gem clean'
number of gems: 273
1.3.7
real 0m1.492s
user 0m1.230s
sys 0m0.256s
1.7.2
real 0m3.533s
user 0m3.281s
sys 0m0.242s
1.8.2
real 0m3.998s
user 0m3.731s
sys 0m0.261s
I copied that repo and ran gem clean on it (and reinstalled rails 2.3.4 because
rails 3 wiped it out on cleanup!) and got the following MUCH better times:
repo=yyy; after 'gem clean'
number of gems: 183
1.3.7
real 0m1.288s
user 0m1.054s
sys 0m0.231s
1.7.2
real 0m1.106s
user 0m0.932s
sys 0m0.169s
1.8.2
real 0m1.365s
user 0m1.181s
sys 0m0.179s
So... that's the workaround for now. I'll do what I can to profile and
optimize, but I can't promise much for the next release, partially because we
don't have enough test coverage on this aspect of rubygems.
----------------------------------------------------------------------
Comment By: Dan Peterson (dpiddy)
Date: 2011-05-23 08:20
Message:
This is still happening in 1.8.3.
----------------------------------------------------------------------
Comment By: Dan Peterson (dpiddy)
Date: 2011-05-04 18:42
Message:
I have seen this as well for something non-Rails. Using `rvm rubygems` I saw
the slowness started with 1.6.0. Haven't had a chance to really dig into it
more yet.
----------------------------------------------------------------------
Comment By: Sam Goldstein (samgoldstein)
Date: 2011-04-05 11:07
Message:
More info on gem dependencies and installed gems.
$ rake gems
(in /www/aboutus/compostus/compost)
- [F] thrift_client ~> 0.4.3
- [I] thrift
- [I] thrift = 0.2.0.4
- [F] simple_uuid = 0.1.1
- [F] cassandra = 0.8.2
- [F] thrift_client >= 0.4.0
- [I] thrift
- [I] json
- [R] rake
- [F] simple_uuid >= 0.1.0
- [F] rack ~> 1.0.0
- [F] diff-lcs = 1.1.2
- [I] ffi ~> 0.6.0
- [R] rake >= 0.8.7
- [F] haml
- [I] libxml-ruby
- [I] hpricot >= 0.8.1
- [I] json
- [I] mysql = 2.8.1
- [F] net-ssh
- [F] ya2yaml = 0.26
- [F] ruby-openid = 2.1.6
- [F] mechanize = 1.0.0
- [I] nokogiri >= 1.2.1
- [I] nokogiri
- [F] composite_primary_keys = 2.2.2
- [R] activerecord >= 2.2.0
- [F] aws-s3 = 0.6.2
- [F] xml-simple
- [F] builder
- [F] mime-types
- [F] right_aws
- [F] right_http_connection >= 1.2.4
- [F] fastercsv = 1.5.0
- [I] levenshtein
- [F] newrelic_rpm = 2.13.4
- [F] after_commit ~> 1.0.7
- [R] activerecord
- [F] less = 1.2.21
- [F] treetop >= 1.4.2
- [F] polyglot >= 0.3.1
- [F] mutter >= 0.4.2
- [F] treetop = 1.4.8
- [F] polyglot >= 0.3.1
- [F] mime-types = 1.16
- [I] curb = 0.7.8
I = Installed
F = Frozen
R = Framework (loaded before rails starts)
$ gem list
abstract (1.0.0)
actionmailer (3.0.5, 3.0.3, 2.3.4, 2.2.2)
actionpack (3.0.5, 3.0.3, 2.3.4, 2.2.2)
activemodel (3.0.5, 3.0.3)
activerecord (3.0.5, 3.0.3, 2.3.4, 2.2.2)
activeresource (3.0.5, 3.0.3, 2.3.4, 2.2.2)
activesupport (3.0.5, 3.0.3, 2.3.11, 2.3.8, 2.3.7, 2.3.5,
2.3.4, 2.2.2)
acts_as_commentable (3.0.1, 2.0.2)
addressable (2.2.4)
after_commit (1.0.7, 1.0.5)
amatch (0.2.3)
amazon_sdb (0.6.7)
amqp (0.6.0)
ar-extensions (0.8.0)
arel (2.0.9, 2.0.8)
au_document_parser (0.5.3, 0.4.3, 0.4.2, 0.4.1, 0.4.0,
0.3.2, 0.3.1, 0.3.0, 0.2.4)
autotest-growl (0.1.7)
aws-s3 (0.6.2)
babel (0.1.4)
builder (2.1.2)
bundler (1.0.10)
capistrano (2.5.5)
capybara (0.3.0)
carmen (0.2.5)
cassandra (0.7.2, 0.6)
cgi_multipart_eof_fix (2.5.0)
cheat (1.2.1)
chronic (0.3.0, 0.2.3)
clearance (0.10.3.2, 0.8.8, 0.8.3)
compass (0.8.17)
compass-960-plugin (0.9.11)
composite_primary_keys (2.2.2)
configuration (1.1.0)
crack (0.1.4)
cucumber (0.10.2, 0.6.3, 0.6.2)
cucumber-rails (0.3.2, 0.2.4, 0.2.3)
culerity (0.2.6)
curb (0.7.8, 0.7.7.1, 0.7.1)
daemons (1.0.10)
database_cleaner (0.4.3)
diesel (0.1.4)
diff-lcs (1.1.2)
differ (0.1.1)
diffy (2.0.1)
dirb (1.0.0, 0.1.1, 0.1.0)
duration (0.1.0)
erubis (2.6.6)
eventmachine (0.12.10)
factory_girl (1.2.3)
fakefs (0.2.1)
faker (0.3.1)
faraday (0.5.7)
fastercsv (1.5.0)
fastthread (1.0.7)
ffi (0.6.3, 0.5.4, 0.5.3)
file-tail (1.0.4)
fixjour (0.1.6)
flexmock (0.8.6)
gem_plugin (0.2.3)
gemcutter (0.5.0)
geminstaller (0.5.4)
geokit (1.5.0)
getopt-declare (1.28)
gherkin (2.3.5)
git (1.2.5)
gltail (0.1.8)
gravatar (1.0)
grit (2.0.0, 1.1.1)
haml (3.0.25, 3.0.13, 2.2.19, 2.2.9)
heroku (1.9.8)
highline (1.5.1)
hoe (2.3.3)
hpricot (0.8.1)
httparty (0.5.0)
i18n (0.5.0)
icalendar (1.1.2, 1.1.0)
jeweler (1.4.0)
jm81-whois (0.5.0)
json (1.4.6, 1.2.0, 1.1.6)
json_pure (1.2.0)
launchy (0.3.3)
less (1.2.21)
levenshtein (0.2.0)
libxml-ruby (1.1.3)
log4r (1.1.9)
lorem (0.1.2)
macaddr (1.0.0)
mail (2.2.15, 1.5.2)
maruku (0.6.0)
mechanize (1.0.0, 0.9.3)
memcache-client (1.7.4)
micronaut (0.3.0)
mime-types (1.16)
mkrf (0.2.3)
mocha (0.9.8)
mongrel (1.1.5)
more (0.1.1)
multi_json (0.0.5)
multipart-post (1.1.0)
mutter (0.5.3)
mysql (2.8.1)
needle (1.3.0)
net-scp (1.0.2)
net-sftp (2.0.4, 1.1.0)
net-ssh (2.0.15, 1.1.4, 1.0.10)
net-ssh-gateway (1.0.1)
newrelic_rpm (2.14.0, 2.9.9, 2.9.8, 2.9.3)
nkallen-cache-money (0.2.5)
nokogiri (1.4.0)
open4 (1.0.1)
paperclip (2.3.1.1)
parseexcel (0.5.2)
polyglot (0.3.1, 0.3.0, 0.2.9)
rack (1.2.2, 1.2.1, 1.0.1)
rack-mount (0.6.14, 0.6.13)
rack-rewrite (1.0.2)
rack-test (0.5.7, 0.5.3)
rails (3.0.5, 3.0.3, 2.3.4, 2.2.2)
railties (3.0.5, 3.0.3)
rake (0.8.7, 0.8.3)
rcov (0.9.6)
RedCloth (4.2.2)
redis (2.1.1)
redis-namespace (0.10.0)
resque (1.13.0)
rest-client (1.4.2)
riddle (1.0.11, 1.0.8)
right_aws (1.10.0)
right_http_connection (1.2.4)
rpx_now (0.6.11)
rspec (2.5.0, 1.3.0, 1.2.9, 1.2.7)
rspec-core (2.5.1)
rspec-expectations (2.5.0)
rspec-mocks (2.5.0)
rspec-rails (2.5.0, 1.3.2, 1.2.9, 1.2.7)
ruby-aws (1.2.0)
ruby-graphviz (0.9.21)
ruby-ole (1.2.10.1)
ruby-opengl (0.60.1)
ruby-openid (2.1.6)
ruby-prof (0.9.2, 0.8.1)
rubyforge (2.0.4, 2.0.3)
rubygems-update (1.7.1, 1.6.2)
RubyInline (3.8.1)
rufus-tokyo (0.1.14)
rvm (0.0.98)
selenium-webdriver (0.0.14)
sequel (3.14.0, 3.9.0, 3.6.0)
simple_uuid (0.0.2)
sinatra (1.2.1, 1.1.2, 1.0, 0.9.5)
slave (1.2.1)
smurf (1.0.3)
snailgun (1.0.6)
spork (0.7.5)
spreadsheet (0.6.4.1)
sqlite3 (1.3.3)
sqlite3-ruby (1.3.3, 1.2.5)
stemmer (1.0.1)
syntax (1.0.0)
technicalpickles-jeweler (1.2.1)
term-ansicolor (1.0.5, 1.0.4)
Text (1.1.2)
thinking-sphinx (1.3.18, 1.3.14)
thor (0.14.6)
thoughtbot-factory_girl (1.2.2)
thrift (0.2.0.4)
thrift_client (0.3.3, 0.3.1)
tilt (1.2.2)
timetrap (1.7.4, 1.4.0, 1.3.0, 1.2.1, 1.2.0, 1.1.3, 1.1.2)
treetop (1.4.9, 1.4.8, 1.4.2)
tzinfo (0.3.26, 0.3.25, 0.3.24)
uuid (2.1.0, 2.0.1)
uuidtools (2.1.2, 2.1.1)
vegas (0.1.8)
vlad (1.3.2)
webrat (0.7.0, 0.6.0, 0.4.4)
will_paginate (2.3.11)
xhtmldiff (1.0.0)
xml-simple (1.0.14, 1.0.12)
xmpp4r (0.4)
ya2yaml (0.26)
ZenTest (4.1.4)
----------------------------------------------------------------------
Comment By: Sam Goldstein (samgoldstein)
Date: 2011-04-05 11:02
Message:
BTW the first environment load was with gem version 1.3.5
----------------------------------------------------------------------
You can respond by visiting:
http://rubyforge.org/tracker/?func=detail&atid=575&aid=29116&group_id=126
_______________________________________________
Rubygems-developers mailing list
http://rubyforge.org/projects/rubygems
Rubygems-developers@rubyforge.org
http://rubyforge.org/mailman/listinfo/rubygems-developers
