Project

General

Profile

Bug #3726

require degradation from 1.9.1

Added by funny_falcon (Yura Sokolov) almost 9 years ago. Updated about 8 years ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Target version:
ruby -v:
ruby 1.9.2p0 (2010-08-18 revision 29036) [x86_64-linux]
Backport:
[ruby-core:31798]

Description

=begin
I have two simultaneous installation of ruby 1.9.1 and ruby 1.9.2.
There are installed gems ( pg in particular ).

Having file 5.rb containing

require 'pg'

i have following results:

For ruby 1.9.1:

# time /opt/ruby1.9.1/bin/ruby1.9 5.rb

real 0m0.086s
user 0m0.056s
sys 0m0.008s

# time /opt/ruby1.9.1/bin/ruby1.9 -r profile 5.rb
% cumulative self self total
time seconds seconds calls ms/call ms/call name
100.00 0.03 0.03 2 15.00 25.00 Kernel.require
0.00 0.03 0.00 131 0.00 0.00 Module#method_added
0.00 0.03 0.00 3 0.00 0.00 Class#inherited
0.00 0.03 0.00 1 0.00 0.00 String#=~
0.00 0.03 0.00 13 0.00 0.00 BasicObject#singleton_method_added
0.00 0.03 0.00 4 0.00 0.00 IO#set_encoding
0.00 0.03 0.00 1 0.00 30.00 #toplevel

real 0m0.116s
user 0m0.076s
sys 0m0.020s

For ruby 1.9.2:

# time /opt/ruby1.9.2/bin/ruby1.9 5.rb

real 0m0.449s
user 0m0.296s
sys 0m0.048s

# time /opt/ruby1.9.2/bin/ruby1.9 -r profile 5.rb
% cumulative self self total
time seconds seconds calls ms/call ms/call name
27.74 0.43 0.43 28 15.36 60.36 Kernel.gem_original_require
5.16 0.51 0.08 3963 0.02 0.02 Hash#default
5.16 0.59 0.08 45 1.78 7.33 Array#each
4.52 0.66 0.07 287 0.24 0.42 String#gsub
3.23 0.71 0.05 897 0.06 0.06 Module#===
3.23 0.76 0.05 11 4.55 45.45 Gem::SourceIndex#load_specification
3.23 0.81 0.05 371 0.13 0.24 Kernel.dup
3.23 0.86 0.05 265 0.19 0.68 RbConfig.expand
2.58 0.90 0.04 126 0.32 10.63 Class#new
2.58 0.94 0.04 374 0.11 0.11 Kernel.initialize_dup
2.58 0.98 0.04 605 0.07 0.07 Kernel.===
1.94 1.01 0.03 585 0.05 0.05 Hash#[]=
1.94 1.04 0.03 31 0.97 4.19 Gem::Requirement#initialize
1.94 1.07 0.03 11 2.73 2.73 IO#read
1.94 1.10 0.03 31 0.97 3.23 Array#map!
1.29 1.12 0.02 531 0.04 0.04 Module#method_added
1.29 1.14 0.02 27 0.74 85.93 Kernel.require
1.29 1.16 0.02 363 0.06 0.06 Kernel.instance_variable_set
1.29 1.18 0.02 59 0.34 0.34 String#scan
1.29 1.20 0.02 64 0.31 0.63 Array#map
1.29 1.22 0.02 21 0.95 1.43 Gem::Specification#attribute
1.29 1.24 0.02 59 0.34 1.53 Gem::Version#initialize
1.29 1.26 0.02 29 0.69 1.03 Array#select
0.65 1.27 0.01 308 0.03 0.03 String#==
0.65 1.28 0.01 159 0.06 0.06 String#to_i
0.65 1.29 0.01 3 3.33 186.67 Mutex#synchronize
0.65 1.30 0.01 26 0.38 0.38 Dir#[]
0.65 1.31 0.01 59 0.17 0.34 Gem::Version#correct?
0.65 1.32 0.01 1 10.00 10.00 Gem.ruby_engine
0.65 1.33 0.01 71 0.14 0.14 String#=~
0.65 1.34 0.01 2 5.00 5.00 Dir#glob
0.65 1.35 0.01 40 0.25 0.25 Module#attr_accessor
0.65 1.36 0.01 176 0.06 0.06 Regexp#=~
0.65 1.37 0.01 9 1.11 1.11 Module#include
0.65 1.38 0.01 8 1.25 1.25 Time#local
0.65 1.39 0.01 100 0.10 0.10 Symbol#to_s
0.65 1.40 0.01 8 1.25 1.25 Comparable.>=
0.65 1.41 0.01 11 0.91 40.91 Kernel.eval
0.65 1.42 0.01 47 0.21 0.21 Kernel.object_id
0.65 1.43 0.01 18 0.56 1.67 Gem::GemPathSearcher#matching_files
0.65 1.44 0.01 1 10.00 10.00 Gem::SourceIndex#search
0.65 1.45 0.01 143 0.07 0.07 Hash#[]
0.65 1.46 0.01 163 0.06 0.06 BasicObject#singleton_method_added
0.00 1.46 0.00 3 0.00 0.00 Gem::Specification#original_name
0.00 1.46 0.00 1 0.00 150.00 Hash#each_value
0.00 1.46 0.00 1 0.00 0.00 Hash#merge!
0.00 1.46 0.00 1 0.00 0.00 Mutex#initialize
.......................................................
0.00 1.46 0.00 1 0.00 0.00 Gem.load_path_insert_index
0.00 1.46 0.00 1 0.00 0.00 Array#insert
0.00 1.46 0.00 1 0.00 10.00 Gem.activate
0.00 1.55 0.00 1 0.00 1550.00 #toplevel

real 0m2.215s
user 0m1.656s
sys 0m0.096s
=end

History

#1

Updated by rogerdpack (Roger Pack) almost 9 years ago

=begin
This is probably because it no longer uses gem_prelude "as much" in 1.9.2
If this is the case and you want the old speed back you could use the faster_rubygems gem.
=end

#2

Updated by raggi (James Tucker) almost 9 years ago

=begin
This isn't degradation, it's actually correct behaviour. RubyGems can be (and will be) optimised over time, but the old performance was reliant on very incorrect semantics that are not acceptable for production use.

=end

#3

Updated by raggi (James Tucker) almost 9 years ago

=begin
It is also worth noting that this is actually measuring the load time for rubygems itself.

A more accurate representation of the speed of require would come from first loading rubygems explicitly.

require 'rubygems'

Profile { require 'pg' }

Even this has some issues, as the source_index is loaded for the first gem load, and then not required to be loaded each time, so a yet more accurate approach might be something like:

require 'rubygems'
require 'hoe'

Profile { require 'pg' }

As said before, optimisations in this area need to be done in rubygems (and are in progress).

=end

#4

Updated by funny_falcon (Yura Sokolov) almost 9 years ago

=begin

It is also worth noting that this is actually measuring the load time for rubygems itself.

I understand it.

I have shell scripts running by schedule, and some cgi scripts, and they runs much slower under 1.9.2 than under 1.9.1 because of this changed behavior.
=end

#5

Updated by funny_falcon (Yura Sokolov) almost 9 years ago

=begin
Well, faster-rubygems seems to do the job. Thank you, Roger.
=end

#6

Updated by raggi (James Tucker) almost 9 years ago

=begin

On 22 Aug 2010, at 03:25, Yura Sokolov wrote:

Issue #3726 has been updated by Yura Sokolov.

It is also worth noting that this is actually measuring the load time for rubygems itself.

I understood it.

I have shell scripts running by schedule, and some cgi scripts, and they runs much slower under 1.9.2 than under 1.9.1 because of this changed behaviour.

I sympathise with your requirements, however, your requirements do not discount the fact that the prior performance was reliant on a bug.

=end

#7

Updated by funny_falcon (Yura Sokolov) almost 9 years ago

=begin
Some bugs are called "features" ;-D
Anyway, faster-rubygems do the job. Perhaps, some ideas from it could be incorparated into the rubygems?
=end

Updated by naruse (Yui NARUSE) about 8 years ago

  • Status changed from Open to Closed

On 1.9.3, require gets faster than 1.9.2.
So I close this as duplicated.

Also available in: Atom PDF