Project

General

Profile

Actions

Bug #3726

closed

require degradation from 1.9.1

Added by funny_falcon (Yura Sokolov) over 13 years ago. Updated almost 13 years ago.

Status:
Closed
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

Actions #1

Updated by rogerdpack (Roger Pack) over 13 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

Actions #2

Updated by raggi (James Tucker) over 13 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

Actions #3

Updated by raggi (James Tucker) over 13 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

Actions #4

Updated by funny_falcon (Yura Sokolov) over 13 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

Actions #5

Updated by funny_falcon (Yura Sokolov) over 13 years ago

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

Actions #6

Updated by raggi (James Tucker) over 13 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

Actions #7

Updated by funny_falcon (Yura Sokolov) over 13 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) almost 13 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.

Actions

Also available in: Atom PDF

Like0
Like0Like0Like0Like0Like0Like0Like0Like0