Skip to content
  • Aaron Patterson's avatar
    41020311
    Reduce system calls by activating the `did_you_mean` gem. · 41020311
    Aaron Patterson authored
    Activating the gem puts the gem on the load path, where simply requiring
    the file will search every gem that's installed until it can find a gem
    that contains the `did_you_mean` file.
    
    Calling RubyGems' `require` will search each installed gem until it can
    find one that contains the file it should require.  This means that the
    more gems you have installed, the longer it can take to require that
    gem.
    
    To see this in action, lets compare the number of `stat` calls for a
    "bare require" vs the number of `stat` calls for a require that follows
    a gem activation by using these two programs:
    
    ```
    [aaron@TC rubygems (master)]$ cat req_dym.rb
    begin
      require 'did_you_mean'
    rescue LoadError
    end
    [aaron@TC rubygems (master)]$ cat gem_dym.rb
    begin
      gem 'did_you_mean'
      require 'did_you_mean'
    rescue Gem::LoadError, LoadError
    end
    ```
    
    The first program just requires the `did_you_mean` gem, where the second
    one activates the gem, then requires it.  We can count the number of
    `stat` calls using `dtrace`:
    
    ```
    [aaron@TC rubygems (master)]$ ruby -v
    ruby 2.3.0p0 (2015-12-25 revision 53290) [x86_64-darwin15]
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean req_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
         283
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean gem_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
          13
    ```
    
    The "bare require" version does over 10x the number of stat calls
    compared to the "gem, then require" version.  Of course the number for
    the first one depends on the number of gems you have installed that sort
    before the `did_you_mean` gem.
    
    Lets also look at trunk Ruby:
    
    ```
    [aaron@TC rubygems (master)]$ ruby -v
    ruby 2.4.0dev (2016-02-25 trunk 53940) [x86_64-darwin15]
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean req_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
        2325
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean gem_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
         685
    ```
    
    This change will reduce the number of `stat` calls on trunk Ruby too,
    but since this installation doesn't have the `did_you_mean` gem,
    RubyGems is still reading every gem spec file so that it can raise a
    `Gem::LoadError` exception with a nice error message.  If we can modify
    RubyGems a little, it may be possible to drop the number of stat calls
    even on a Ruby installation that doesn't have the `did_you_mean` gem.
    
    git-svn-id: svn+ssh://ci.ruby-lang.org/ruby/trunk@53941 b2dd03c8-39d4-4d8f-98ff-823fe69b080e
    41020311
    Reduce system calls by activating the `did_you_mean` gem.
    Aaron Patterson authored
    Activating the gem puts the gem on the load path, where simply requiring
    the file will search every gem that's installed until it can find a gem
    that contains the `did_you_mean` file.
    
    Calling RubyGems' `require` will search each installed gem until it can
    find one that contains the file it should require.  This means that the
    more gems you have installed, the longer it can take to require that
    gem.
    
    To see this in action, lets compare the number of `stat` calls for a
    "bare require" vs the number of `stat` calls for a require that follows
    a gem activation by using these two programs:
    
    ```
    [aaron@TC rubygems (master)]$ cat req_dym.rb
    begin
      require 'did_you_mean'
    rescue LoadError
    end
    [aaron@TC rubygems (master)]$ cat gem_dym.rb
    begin
      gem 'did_you_mean'
      require 'did_you_mean'
    rescue Gem::LoadError, LoadError
    end
    ```
    
    The first program just requires the `did_you_mean` gem, where the second
    one activates the gem, then requires it.  We can count the number of
    `stat` calls using `dtrace`:
    
    ```
    [aaron@TC rubygems (master)]$ ruby -v
    ruby 2.3.0p0 (2015-12-25 revision 53290) [x86_64-darwin15]
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean req_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
         283
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean gem_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
          13
    ```
    
    The "bare require" version does over 10x the number of stat calls
    compared to the "gem, then require" version.  Of course the number for
    the first one depends on the number of gems you have installed that sort
    before the `did_you_mean` gem.
    
    Lets also look at trunk Ruby:
    
    ```
    [aaron@TC rubygems (master)]$ ruby -v
    ruby 2.4.0dev (2016-02-25 trunk 53940) [x86_64-darwin15]
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean req_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
        2325
    [aaron@TC rubygems (master)]$ sudo dtrace -q -n 'syscall::stat*:entry { printf("%s\n", copyinstr(arg0)); }' -c`rbenv which ruby`" --disable-did_you_mean gem_dym.rb" | wc -l
    
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
    dtrace: error on enabled probe ID 3 (ID 826: syscall::stat64:entry): invalid user access in action #1 at DIF offset 24
         685
    ```
    
    This change will reduce the number of `stat` calls on trunk Ruby too,
    but since this installation doesn't have the `did_you_mean` gem,
    RubyGems is still reading every gem spec file so that it can raise a
    `Gem::LoadError` exception with a nice error message.  If we can modify
    RubyGems a little, it may be possible to drop the number of stat calls
    even on a Ruby installation that doesn't have the `did_you_mean` gem.
    
    git-svn-id: svn+ssh://ci.ruby-lang.org/ruby/trunk@53941 b2dd03c8-39d4-4d8f-98ff-823fe69b080e
Loading