Ancient History

It’s been a long time since I’ve blogged here. No matter! The day has come. Whilst we’re reminiscing though, let me remind you of a really old post: Calling on the GC after Rubygems.

The actual source of the problem was never truly resolved. The problem is that RubyGems has to load it’s source_index. That was made lazy, which meant that the problem was pushed further into the stack, but not actually solved. We all know MRIs GC is weak, and indeed, these kinds of issues come to hurt with memory fragmentation. It may come as no surprise that this gets worse if you have a lot of gems installed. Fact is, that’s a gut feeling though. The first article I posted really shows the pain of why. Since the more recent changes to RubyGems, some modifications are required to actually show the same effect, specifically, you have to rewrite that snippet like so:

_{see comments on the gist for some more details}

This has been a nitpick for me for a long time. I actually want to do a lot better, but I was poking around in the RubyGems source earlier today, for other reasons, and found that GemPathSearcher uses Dir#[]. This was an amazing revelation. I’ve read it before, but never paid attention to the ramifications. RubyGems doesn’t use the spec.files manifest at runtime. This is probably for the best, after all, ruby already stat(2)’s the crap out of your system. I immediately started a branch and hacked up the patch that I committed today.

Wheres my win?

Well this patch, and a quick bit of optimization:

_{(you may need to run that with sudo if you use system installed RubyGems)}

You end up with significantly less ram spam!

Results

Before RubyGems 1.6:

    #       strings_no_gems.log:            2214 bytes, change:      100%
    #    strings_gems_no_gc.log:         5173464 bytes, change:   233670%
    #          strings_gems.log:         4795559 bytes, change:       92%

After RubyGems 1.6:

    #       strings_no_gems.log:            2214 bytes, change:      100%
    #    strings_gems_no_gc.log:         1663044 bytes, change:    75114%
    #          strings_gems.log:         1368931 bytes, change:       82%

Yes, that’s about a 4mb saving!

Ok, I have 570 gems installed. So shoot me. I don’t believe in symptom solvers (for this problem) (gemsets, etc).

Conclusions

Some of you might think that’s not a lot, but 4mb of strings that get duplicated (once for the AST, once for the string object itself) is actually quite a lot of GC churn, and it’s all in the early pages. Due to fragmentation issues somewhat poorly covered elsewhere, what this means is, you’d basically never get that ram back. The point is, even for those of you with less gems installed, you will receive noticeable savings in boot times, and your apps will actually use less ram overall (probably more than the initial saving itself). On some platforms such as JRuby there may be other gains that are also important. Users of gems that package documentation files inside (tut tut rspec and rails plugins!) will also see big benefits.

When coupled with other work that I didn’t blog about a while ago, that you’re probably already running, this means RubyGems load times should no longer be significant anywhere. In fact, once I get the upcoming Rack releases out (pre launched a couple of weeks ago for Rails 2.x), and Rails releases with this patch, then we can deprecate require ‘thread’ from RubyGems too. All told, this will bring RubyGems to about the same speed (same order of magnitude) as the horribly broken gem_prelude.rb hack in Ruby 1.9. Hopefully we’ll be shot of that thing soon!

Finally, in other news, I recommend that you checkout the other recent happenings in RubyGems. There’s big changes coming, and more improvements on the horizon.

Cheers!

So you got this:


Error loading RubyGems plugin ".rvm/gems/ruby-head/gems/gemcutter-0.5.0/lib/rubygems_plugin.rb": cannot load such file -- rubygems/commands/migrate (LoadError)


You need to remove that version of gemcutter. The problem is, it probably won’t uninstall cleanly because the plugin is causing rubygems loading to fail… I need to patch RubyGems to help with this issue, indeed, we’ve got all kinds of new plans for plugins in the future. Anyway, on to a solution:


a=(`ruby -e 'require "rubygems" rescue nil; puts Gem.path.first'`/gems/gemcutter-0.5.0) && rm -rf $a


This is a bash script, and I use rm -rf so check yourself first, or at least, don’t blame me if you’re lazy. It should work fine on most common setups.

You can use a similar trick with other gems, although I recommend using gem uninstall first. Alas in this case it is not possible.

Also, once you’ve fixed this problem, you really want to do a gem update –system.

And a year goes by, not unlike this tumbleweed…

Attribution: roll with it by Johnny Action

Ever noticed how tumbleweed doesn’t really tumble, but more sits stagnant, much like this blahg has been?

Wordpress is up and running again (it was a wget -m mirror for most of the last year). Prepare for more signal. Using geshi for code blocks for the time being.

So there’s BlankSlate, and today tmm1 was doing something where he was delegating to Array, but wanted to actually have Array in the ancestor chain (for Class#===), so I came up with this:

def BS(superclass = nil, name = :BlankSlate)
  klass = eval(%w[
    class #{name} #{" < #{superclass}" if superclass}
    end
    #{name}
  ])
  klass.class_eval {
    instance_methods.each { |m| undef_method m unless m =~ /^__/ }
  }
  klass
end

And then he came up with the anti-eval solution:

class BlankSlate
  instance_methods.each { |m| undef_method m unless m =~ /^__/ }
end
 
def BlankSlate superclass = nil
  if superclass
    @blank_slates ||= {}
    @blank_slates[superclass] ||= Class.new(superclass) do
      instance_methods.each { |m| undef_method m unless m =~ /^__/ }
    end
  else
    BlankSlate
  end
end

refactors to:

class BlankSlate
  instance_methods.each { |m| undef_method m unless m =~ /^__/ }
end
 
def BlankSlate superclass = BlankSlate
  @blank_slates ||= Hash.new do |h,k|
    h[k] = Class.new(superclass) do
      instance_methods.each { |m| undef_method m unless m =~ /^__/ }
    end
  end
  @blank_slates[superclass]
end

But watch out!!!:

a = StrokeDB::LazyMappingArray.new([1,2,3]) # => [1, 2, 3]
Array === a # => true
Array.new(a) # => []
[a].flatten # => []
 
# The last two are 'incorrect' behaviour (probably work on rubinius,
# mind you, so did the delegation approach).

Anyway, you get the idea, mix and match, (feedback?), whatever. Enjoy.

I know, I’m shouting, but there’s stuff to shout about!

I’ve hated ri for being so slow for so long. The new one is out!

I really recommend installing rdoc 2 and firing up ri for the first time. Now only the ‘first time’ takes a long time

It’s joyous, just under a second I can really put up with. Thanks to Eric, and I believe Ryan (as I seem to remember him mentioning his ri patch quite some time ago).

Here’s some stuff from the #ruby-lang mailinglist, with my replies inlined. It’s here because this kind of discussion often doesn’t go far on a mailinglist, but the response may have some validity to some people.

There really isn’t a secret list of “idioms” or rules that will save you from writing slow software. You really have to profile, and more than that, you need to focus on the right stuff, at the right time. I once found this hard to swallow, but I understand it, and it makes perfect sense. Being free of it, I now write better software, in a much shorter time frame. Oh and it’s easier to maintain too.

On 17 Mar 2008, at 18:08, Paul Brannan wrote:

On Tue, Mar 18, 2008 at 02:17:22AM +0900, Gerardo Santana G?mez Garrido wrote:
On Mon, Mar 17, 2008 at 12:42 PM, Marc Heiler wrote:
Anyone of you has a few hints on how to speed up ruby code?
(Note – not writing it, but running it )

I only have a few hints, like 5… would love to extend it.

When generating text output, using StringIO is faster than using puts

This doesn’t make sense. One can easily call #puts on a StringIO
object.

Do you have a concrete example/benchmark that demonstrates the
difference?

Paul

This is a prime example of platform differences, hell, right up to the tool stack you’re running.

Generic ‘optimizations’ or hints in areas like this are not worth their salt. It’ll be different in one console / terminal / operating system to the next.

Moreover, a much better solution is to rebuffer the data, and specifically to coalesce it, in many cases (not all). This is not something that a generic “#freeze” “optimization” will give you. It’s a design decision, the overhead for which can be discovered by profiling if you spend some time thinking about what the numbers mean, and paying attention to how long you really think things should take. It doesn’t take long to realize that $stdout.puts is slow on a lot, but not *all* platforms. The simplest test is redirect to file, which on some setups, is *significantly* faster than terminal output (one is to memory, one is to disk, and yet…. go figure).

On 17 Mar 2008, at 15:06, Paul Brannan wrote:

On Mon, Mar 17, 2008 at 11:20:59PM +0900, Avdi Grimm wrote:
On Mon, Mar 17, 2008 at 9:22 AM, Ilan Berci coder68 @yahoo.com wrote:
There is only 1 hint:

PROFILE IT!!!

+1

is +10 allowed?

I learned this lesson, and it is a serious lesson to learn.

There was a time when I had a feeling of perfection, where I wanted the code to be entirely as computationally optimal as possible all the time. The truth is, the stack underneath contains so much indirection and complexity, this is almost impossible to really attain, and indeed to do so, one has to profile anyway. The thing that solved this for me was including a notion of the development process, time, and simplicity into my notion of perfection.

> All discussions of performance tuning are meaningless without profiling numbers.

Profiling only tells you where performance bottlenecks are. It does
nothing for letting you know how to fix those bottlenecks. That’s where
benchmarks come into play.

Sure, but that’s algorithm and even state dependent. Maybe you can get 10% by adding a GC.start after loading a pile of data (this would be very app specific).

Benchmarks can lie (if poorly written, and it’s all too easy to write bad benchmarks), for example, on win32, it is possible to construct a benchmark under which the conditions will cause the ternary operator to appear faster than if else. Obviously, this is not *really* the case, moreover, it’s completely irrelevant unless you’re app is entirely bound by boolean logic operations. It’s also extremely difficult to use a profiling or benchmarking tool against, in pure ruby. Oh, and I’d put good money on it not having the same results on different versions or different interpreters.

There are limits to how low you can measure performance and a large portion of the discussed list falls into that category. It also seems to fall in to the category of stuff that is:

• interpreter specific
• implementation dependent (meaning you could kill yourself if you migrate versions even)
• only going to gain you 0.001% or something equally irrelevant.

If you really want to continue on that list, you’ll want to include stuff like the following (which I don’t really agree with as good ideas to spread across the board):

• implicit return if faster
• implicit block break values are faster
• inject is ‘super slow’
• splats are slow
• sprintf is slow

These all show up in micro-benchmarks for sure. They don’t necessarily (in fact, “very often”) show up as real sources of poor performance in production code, unless you have very small units (in which case, good for you ). Poor performance in common application code tends to come from complexity most often. In some areas (heavier I/O code is maybe the most common?) you may need to add complexity, but it’s often possible to provide a drop-in piece of indirection (off the top of my head: cache, coalesce, un-block, drop threaded complexity, buffer, *increase buffer sizes*, and so on).

There was someone talking about ERB#new. That’s ERB.new… and for performance, Erubis is often faster, so there’s no real need to do much profiling there, as someone’s done it for you, as one other example of design change leading the real win.

Design change is really what has a significant effect on performance, in most all cases. Very few ‘generic’ things like concat vs. + for strings (which is pretty clear when profiling) really give you meaningful gains, although it does happen (this was a ~10,000 page pdf being generated iirc):

Here’s something I used to replace ‘builder’ for something that needed more speed:

X = Object.new
def X.[](name, att = nil, inner = nil)
	inner ? att ? "< #{name}#{att}>#{inner}" : "< #{name}>#{inner}" : att ? "< #{name}#{att} />" : "< #{name}/>"
end

Clearly the api is not the same, and it doesn’t do nearly the same stuff. It’s an extreme example. However, it smashes over everything else for performance (when combined with concat, not +, clearly), so we no longer have to care. Maintenance is not proving any kind of problem either, as we don’t use it everywhere. We use this *only* where we need to, which in our case was a very long XML generation (in excess of 20mb with very high node count).

The example has the following different profiles, which I would strongly argue simply could not be obtained by sticking with a lib with builders features (that is, this isn’t builders fault, nor is the above a replacement for builder. It’s one-time build and use code for a few cases where it’s needed):

Total Time: 4.452756

  %total   %self     total      self      wait     child            calls   Name
--------------------------------------------------------------------------------
 100.00%   0.00%      4.45      0.00      0.00      4.45                0     Global#[No method] (prof_vs_frozen.rb:55}  prof_vs_frozen.rb:55
                      4.45      2.01      0.00      2.44              1/1     Integer#times
--------------------------------------------------------------------------------
                      4.45      2.01      0.00      2.44              1/1     Global#[No method]
 100.00%  45.16%      4.45      2.01      0.00      2.44                1     Integer#times (ruby_runtime:0}  ruby_runtime:0
                      2.01      2.01      0.00      0.00    200000/200000     <Object::Object>#[]
                      0.22      0.22      0.00      0.00    100000/100000     Array#<<
                      0.22      0.22      0.00      0.00    100000/100000     String#==
--------------------------------------------------------------------------------
                      2.01      2.01      0.00      0.00    200000/200000     Integer#times
  45.05%  45.05%      2.01      2.01      0.00      0.00           200000     <Object::Object>#[] (prof_vs_frozen.rb:44}  prof_vs_frozen.rb:44
--------------------------------------------------------------------------------
                      0.22      0.22      0.00      0.00    100000/100000     Integer#times
   4.92%   4.92%      0.22      0.22      0.00      0.00           100000     String#== (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.22      0.22      0.00      0.00    100000/100000     Integer#times
   4.87%   4.87%      0.22      0.22      0.00      0.00           100000     Array#<< (ruby_runtime:0}  ruby_runtime:0

Thread ID: 214780
Total Time: 116.686341

  %total   %self     total      self      wait     child            calls   Name
--------------------------------------------------------------------------------
 100.00%   0.00%    116.69      0.00      0.00    116.69                0     Global#[No method] (prof_vs_frozen.rb:85}  prof_vs_frozen.rb:85
                    116.69      0.64      0.00    116.04              1/1     Integer#times
--------------------------------------------------------------------------------
                    116.69      0.64      0.00    116.04              1/1     Global#[No method]
 100.00%   0.55%    116.69      0.64      0.00    116.04                1     Integer#times (ruby_runtime:0}  ruby_runtime:0
                    116.04      6.50      0.00    109.55    100000/100000     Builder::XmlBase#method_missing
--------------------------------------------------------------------------------
                    116.04      6.50      0.00    109.55    100000/100000     Integer#times
  99.45%   5.57%    116.04      6.50      0.00    109.55           100000     Builder::XmlBase#method_missing (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:37}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:37
                      0.22      0.22      0.00      0.00    100000/200000     Kernel#kind_of?
                      2.12      1.70      0.00      0.42    200000/400000     Builder::XmlBase#_newline
                     39.69      2.32      0.00     37.37    100000/200000     Builder::XmlMarkup#_start_tag
                      2.16      1.66      0.00      0.49    100000/600000     Array#each
                     61.31      1.56      0.00     59.75    100000/100000     Builder::XmlBase#_nested_structures
                      0.22      0.22      0.00      0.00    100000/200000     NilClass#nil?
                      1.48      0.97      0.00      0.51    100000/200000     Builder::XmlMarkup#_end_tag
                      2.13      1.71      0.00      0.42    200000/400000     Builder::XmlBase#_indent
                      0.22      0.22      0.00      0.00    100000/200000     Array#first
--------------------------------------------------------------------------------
                     39.69      2.32      0.00     37.37    100000/200000     Builder::XmlBase#method_missing
                     39.77      2.30      0.00     37.47    100000/200000     Builder::XmlBase#method_missing-1
  68.10%   3.96%     79.46      4.62      0.00     74.84           200000     Builder::XmlMarkup#_start_tag (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:286}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:286
                      0.56      0.56      0.00      0.00    200000/600000     Symbol#to_s
                      0.93      0.93      0.00      0.00    400000/800000     String#< <
                     73.35      3.39      0.00     69.96    200000/200000     Builder::XmlMarkup#_insert_attributes
--------------------------------------------------------------------------------
                     73.35      3.39      0.00     69.96    200000/200000     Builder::XmlMarkup#_start_tag
  62.86%   2.91%     73.35      3.39      0.00     69.96           200000     Builder::XmlMarkup#_insert_attributes (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:299}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:299
                      0.42      0.42      0.00      0.00    200000/600000     Array#each
                      0.44      0.44      0.00      0.00    200000/200000     Kernel#nil?
                     69.10      3.75      0.00     65.35    200000/200000     Hash#each
--------------------------------------------------------------------------------
                     69.10      3.75      0.00     65.35    200000/200000     Builder::XmlMarkup#_insert_attributes
  59.22%   3.21%     69.10      3.75      0.00     65.35           200000     Hash#each (ruby_runtime:0}  ruby_runtime:0
                     62.90      3.13      0.00     59.76    200000/200000     Builder::XmlMarkup#_attr_value
                      0.54      0.54      0.00      0.00    200000/600000     Symbol#to_s
                      0.49      0.49      0.00      0.00    200000/800000     String#<<
                      1.43      1.01      0.00      0.42    200000/200000     Enumerable#member?
--------------------------------------------------------------------------------
                     62.90      3.13      0.00     59.76    200000/200000     Hash#each
  53.90%   2.68%     62.90      3.13      0.00     59.76           200000     Builder::XmlMarkup#_attr_value (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:310}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:310
                      0.44      0.44      0.00      0.00    200000/400000     Module#===
                     58.89      1.83      0.00     57.07    200000/200000     Builder::XmlBase#_escape_quote
                      0.43      0.43      0.00      0.00    200000/200000     String#to_s
--------------------------------------------------------------------------------
                     61.31      1.56      0.00     59.75    100000/100000     Builder::XmlBase#method_missing
  52.55%   1.34%     61.31      1.56      0.00     59.75           100000     Builder::XmlBase#_nested_structures (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:132}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:132
                      0.21      0.21      0.00      0.00    100000/200000     Fixnum#-
                     59.33      0.97      0.00     58.36    100000/100000     Proc#call
                      0.21      0.21      0.00      0.00    100000/200000     Fixnum#+
--------------------------------------------------------------------------------
                     59.33      0.97      0.00     58.36    100000/100000     Builder::XmlBase#_nested_structures
  50.84%   0.83%     59.33      0.97      0.00     58.36           100000     Proc#call (ruby_runtime:0}  ruby_runtime:0
                     58.36      6.57      0.00     51.79    100000/100000     Builder::XmlBase#method_missing-1
--------------------------------------------------------------------------------
                     58.89      1.83      0.00     57.07    200000/200000     Builder::XmlMarkup#_attr_value
  50.47%   1.57%     58.89      1.83      0.00     57.07           200000     Builder::XmlBase#_escape_quote (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:118}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:118
                      0.65      0.65      0.00      0.00    200000/200000     String#gsub
                     56.41      1.30      0.00     55.12    200000/200000     Builder::XmlBase#_escape
--------------------------------------------------------------------------------
                     58.36      6.57      0.00     51.79    100000/100000     Proc#call
  50.02%   5.63%     58.36      6.57      0.00     51.79           100000     Builder::XmlBase#method_missing-1 (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:37}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:37
                      0.22      0.22      0.00      0.00    100000/200000     Kernel#kind_of?
                      2.12      1.70      0.00      0.42    200000/400000     Builder::XmlBase#_newline
                     39.77      2.30      0.00     37.47    100000/200000     Builder::XmlMarkup#_start_tag
                      2.18      1.69      0.00      0.49    100000/600000     Array#each
                      3.43      1.56      0.00      1.87    100000/100000     Builder::XmlBase#_nested_structures-1
                      0.22      0.22      0.00      0.00    100000/200000     NilClass#nil?
                      1.49      0.98      0.00      0.51    100000/200000     Builder::XmlMarkup#_end_tag
                      2.13      1.71      0.00      0.42    200000/400000     Builder::XmlBase#_indent
                      0.22      0.22      0.00      0.00    100000/200000     Array#first
--------------------------------------------------------------------------------
                     56.41      1.30      0.00     55.12    200000/200000     Builder::XmlBase#_escape_quote
  48.35%   1.11%     56.41      1.30      0.00     55.12           200000     Builder::XmlBase#_escape (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:114}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:114
                     55.12      2.26      0.00     52.85    200000/200000     String#to_xs
--------------------------------------------------------------------------------
                     55.12      2.26      0.00     52.85    200000/200000     Builder::XmlBase#_escape
  47.24%   1.94%     55.12      2.26      0.00     52.85           200000     String#to_xs (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xchar.rb:110}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xchar.rb:110
                      0.59      0.59      0.00      0.00    200000/200000     Array#join
                     51.68      3.45      0.00     48.23    200000/200000     Array#map
                      0.59      0.59      0.00      0.00    200000/200000     String#unpack
--------------------------------------------------------------------------------
                     51.68      3.45      0.00     48.23    200000/200000     String#to_xs
  44.29%   2.96%     51.68      3.45      0.00     48.23           200000     Array#map (ruby_runtime:0}  ruby_runtime:0
                     48.23     19.46      0.00     28.77    600000/600000     Fixnum#xchr
--------------------------------------------------------------------------------
                     48.23     19.46      0.00     28.77    600000/600000     Array#map
  41.33%  16.68%     48.23     19.46      0.00     28.77           600000     Fixnum#xchr (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xchar.rb:93}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xchar.rb:93
                     11.46      7.74      0.00      3.72  1800000/1800000     Kernel#===
                      1.26      1.26      0.00      0.00    600000/600000     Fixnum#<
                      1.56      1.56      0.00      0.00    600000/600000     Integer#chr
                      7.86      5.28      0.00      2.58  1200000/1200000     Hash#[]
                      6.63      4.10      0.00      2.53    600000/600000     Range#===
--------------------------------------------------------------------------------
                     11.46      7.74      0.00      3.72  1800000/1800000     Fixnum#xchr
   9.82%   6.63%     11.46      7.74      0.00      3.72          1800000     Kernel#=== (ruby_runtime:0}  ruby_runtime:0
                      3.72      3.72      0.00      0.00  1800000/2600000     Fixnum#==
--------------------------------------------------------------------------------
                      7.86      5.28      0.00      2.58  1200000/1200000     Fixnum#xchr
   6.73%   4.53%      7.86      5.28      0.00      2.58          1200000     Hash#[] (ruby_runtime:0}  ruby_runtime:0
                      2.58      2.58      0.00      0.00  1200000/1200000     Hash#default
--------------------------------------------------------------------------------
                      6.63      4.10      0.00      2.53    600000/600000     Fixnum#xchr
   5.69%   3.52%      6.63      4.10      0.00      2.53           600000     Range#=== (ruby_runtime:0}  ruby_runtime:0
                      2.53      2.53      0.00      0.00  1200000/1200000     Fixnum#<=>
--------------------------------------------------------------------------------
                      3.72      3.72      0.00      0.00  1800000/2600000     Kernel#===
                      0.84      0.84      0.00      0.00   400000/2600000     Builder::XmlBase#_newline
                      0.84      0.84      0.00      0.00   400000/2600000     Builder::XmlBase#_indent
   4.63%   4.63%      5.40      5.40      0.00      0.00          2600000     Fixnum#== (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.42      0.42      0.00      0.00    200000/600000     Enumerable#member?
                      2.16      1.66      0.00      0.49    100000/600000     Builder::XmlBase#method_missing
                      2.18      1.69      0.00      0.49    100000/600000     Builder::XmlBase#method_missing-1
                      0.42      0.42      0.00      0.00    200000/600000     Builder::XmlMarkup#_insert_attributes
   4.44%   3.59%      5.18      4.19      0.00      0.99           600000     Array#each (ruby_runtime:0}  ruby_runtime:0
                      0.42      0.42      0.00      0.00    200000/400000     Module#===
                      0.56      0.56      0.00      0.00    200000/200000     Hash#merge!
--------------------------------------------------------------------------------
                      2.13      1.71      0.00      0.42    200000/400000     Builder::XmlBase#method_missing
                      2.13      1.71      0.00      0.42    200000/400000     Builder::XmlBase#method_missing-1
   3.65%   2.93%      4.26      3.42      0.00      0.84           400000     Builder::XmlBase#_indent (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:127}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:127
                      0.84      0.84      0.00      0.00   400000/2600000     Fixnum#==
--------------------------------------------------------------------------------
                      2.12      1.70      0.00      0.42    200000/400000     Builder::XmlBase#method_missing
                      2.12      1.70      0.00      0.42    200000/400000     Builder::XmlBase#method_missing-1
   3.63%   2.91%      4.24      3.40      0.00      0.84           400000     Builder::XmlBase#_newline (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:122}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:122
                      0.84      0.84      0.00      0.00   400000/2600000     Fixnum#==
--------------------------------------------------------------------------------
                      3.43      1.56      0.00      1.87    100000/100000     Builder::XmlBase#method_missing-1
   2.94%   1.34%      3.43      1.56      0.00      1.87           100000     Builder::XmlBase#_nested_structures-1 (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:132}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlbase.rb:132
                      0.22      0.22      0.00      0.00    100000/200000     Fixnum#-
                      1.44      1.21      0.00      0.22    100000/100000     Proc#call-1
                      0.21      0.21      0.00      0.00    100000/200000     Fixnum#+
--------------------------------------------------------------------------------
                      1.48      0.97      0.00      0.51    100000/200000     Builder::XmlBase#method_missing
                      1.49      0.98      0.00      0.51    100000/200000     Builder::XmlBase#method_missing-1
   2.55%   1.67%      2.98      1.95      0.00      1.03           200000     Builder::XmlMarkup#_end_tag (/opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:294}  /opt/local/lib/ruby/gems/1.8/gems/builder-2.1.2/lib/builder/xmlmarkup.rb:294
                      0.55      0.55      0.00      0.00    200000/600000     Symbol#to_s
                      0.48      0.48      0.00      0.00    200000/800000     String#<<
--------------------------------------------------------------------------------
                      2.58      2.58      0.00      0.00  1200000/1200000     Hash#[]
   2.21%   2.21%      2.58      2.58      0.00      0.00          1200000     Hash#default (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      2.53      2.53      0.00      0.00  1200000/1200000     Range#===
   2.17%   2.17%      2.53      2.53      0.00      0.00          1200000     Fixnum#<=> (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.93      0.93      0.00      0.00    400000/800000     Builder::XmlMarkup#_start_tag
                      0.48      0.48      0.00      0.00    200000/800000     Builder::XmlMarkup#_end_tag
                      0.49      0.49      0.00      0.00    200000/800000     Hash#each
   1.63%   1.63%      1.90      1.90      0.00      0.00           800000     String#<< (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.56      0.56      0.00      0.00    200000/600000     Builder::XmlMarkup#_start_tag
                      0.55      0.55      0.00      0.00    200000/600000     Builder::XmlMarkup#_end_tag
                      0.54      0.54      0.00      0.00    200000/600000     Hash#each
   1.41%   1.41%      1.64      1.64      0.00      0.00           600000     Symbol#to_s (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      1.56      1.56      0.00      0.00    600000/600000     Fixnum#xchr
   1.34%   1.34%      1.56      1.56      0.00      0.00           600000     Integer#chr (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      1.44      1.21      0.00      0.22    100000/100000     Builder::XmlBase#_nested_structures-1
   1.23%   1.04%      1.44      1.21      0.00      0.22           100000     Proc#call-1 (ruby_runtime:0}  ruby_runtime:0
                      0.22      0.22      0.00      0.00    100000/100000     String#==
--------------------------------------------------------------------------------
                      1.43      1.01      0.00      0.42    200000/200000     Hash#each
   1.23%   0.87%      1.43      1.01      0.00      0.42           200000     Enumerable#member? (ruby_runtime:0}  ruby_runtime:0
                      0.42      0.42      0.00      0.00    200000/600000     Array#each
--------------------------------------------------------------------------------
                      1.26      1.26      0.00      0.00    600000/600000     Fixnum#xchr
   1.08%   1.08%      1.26      1.26      0.00      0.00           600000     Fixnum#< (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.44      0.44      0.00      0.00    200000/400000     Builder::XmlMarkup#_attr_value
                      0.42      0.42      0.00      0.00    200000/400000     Array#each
   0.74%   0.74%      0.86      0.86      0.00      0.00           400000     Module#=== (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.65      0.65      0.00      0.00    200000/200000     Builder::XmlBase#_escape_quote
   0.56%   0.56%      0.65      0.65      0.00      0.00           200000     String#gsub (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.59      0.59      0.00      0.00    200000/200000     String#to_xs
   0.50%   0.50%      0.59      0.59      0.00      0.00           200000     Array#join (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.59      0.59      0.00      0.00    200000/200000     String#to_xs
   0.50%   0.50%      0.59      0.59      0.00      0.00           200000     String#unpack (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.56      0.56      0.00      0.00    200000/200000     Array#each
   0.48%   0.48%      0.56      0.56      0.00      0.00           200000     Hash#merge! (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#method_missing
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#method_missing-1
   0.38%   0.38%      0.44      0.44      0.00      0.00           200000     Kernel#kind_of? (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#method_missing
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#method_missing-1
   0.38%   0.38%      0.44      0.44      0.00      0.00           200000     NilClass#nil? (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#method_missing
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#method_missing-1
   0.38%   0.38%      0.44      0.44      0.00      0.00           200000     Array#first (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.44      0.44      0.00      0.00    200000/200000     Builder::XmlMarkup#_insert_attributes
   0.37%   0.37%      0.44      0.44      0.00      0.00           200000     Kernel#nil? (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.43      0.43      0.00      0.00    200000/200000     Builder::XmlMarkup#_attr_value
   0.37%   0.37%      0.43      0.43      0.00      0.00           200000     String#to_s (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.21      0.21      0.00      0.00    100000/200000     Builder::XmlBase#_nested_structures
                      0.22      0.22      0.00      0.00    100000/200000     Builder::XmlBase#_nested_structures-1
   0.37%   0.37%      0.43      0.43      0.00      0.00           200000     Fixnum#- (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.21      0.21      0.00      0.00    100000/200000     Builder::XmlBase#_nested_structures
                      0.21      0.21      0.00      0.00    100000/200000     Builder::XmlBase#_nested_structures-1
   0.36%   0.36%      0.42      0.42      0.00      0.00           200000     Fixnum#+ (ruby_runtime:0}  ruby_runtime:0
--------------------------------------------------------------------------------
                      0.22      0.22      0.00      0.00    100000/100000     Proc#call-1
   0.19%   0.19%      0.22      0.22      0.00      0.00           100000     String#== (ruby_runtime:0}  ruby_runtime:0

_{forewarning: anyone who goes off about builders complexity or use of method_missing being the source of, well, anyones "problems" doesn't get it, and I will treat your comments with sufficient disregard. The point is the profile difference is a design impact, not an implementation detail. And yeah, I know that looks broken with the box, i'm accepting patches, yeah}

In the above example, I also went through memoize and a number of other ideas, but that turned out to be a lot slower than just building the strings as simply as possible using interpolation, for strings of this length, being used in this manner. It's probably important to note that we were building many small nodes. Oh, and I should also note that it may not be so good for very large nodes.

Also, it's the user experience that counts, so measure based on what the users are actually doing, not the slowest performing method or some such metric. You could spend all the time in the world building up lists of what operator is slower than what under what conditions or what this is faster than what that. If that's you, seriously, drop it. It's bad for you, and your code.

Then seriously, do yourself a favour, and add .svn to your global ignore list.

One of my colleagues committed one yesterday, so I had a fun day re-learning svndumpfilter and friends today.

Of course we can all question how this happened, I know how it happened (and so do you, if you think about it), but seriously, just do it.

I’ve put this under “amusing”, but trust me, I was not amused.

So in the recent Textmate update, the ruby bundle run command just had the following line added:

#!bin/sh

And the result is, raggi finds out that his Leopard account doesn’t seem to load the environment.plist file. I spent a couple of hours searching round, triple checking paths etc. To find no evidence of this file actually being loaded. If there’s anyone out there who can shed some light on this, that would be great… 

Update
The issue was I had an old entry to TM_RUBY in my Preferences…->Advanced->Shell Variables. Remove that, and suddenly environment.plist seems to be being used. The entry in preferences was correct too, it just seems to do very bad things to certain textmate scripts.

I have a new MacBook. It’s less than a month old, and came with Leopard.

My father bought be a Mighty Mouse (wireless) to go with it.

Today, I’m getting angry to the point where I thought about the idea of taking the whole lot back for a full refund. You see, this is the most unstable system I have used since Windows 98, and that’s no exaggeration.

Leopard, is a piece of shit. Ok, that’s possibly a little harsh, but…

• I have had two full kernel panics since I bought this laptop (i.e. in the first month)
• I have had numerous application crashes, mostly with Mail.app and hardware interfaces (bluetooth + USB), but actually, half of the apps currently on my Dock have crashed on me.
• I have not installed any kernel level software (which is what causes other OSes to BSOD/panic)
• The mighty mouse crashed the bluetooth system, twice, and then stopped working completely.
• The USB system has frozen (complete OS deadlock) the laptop, three times, coming out of, or going into standby.
• Spaces is buggy as hell, many of the native apps (including iTunes and Mail.app) don’t Apple+Tab correctly if they’re “Zoomed”. That’s really poor, and suggests a serious lack in real user testing before launch.
• The PGDN + PGUP and HOME + END key bindings (on the MacBook) are so inconsistent it makes me angry about once every 5 minutes.
• The RSS screensaver prevents you from logging in when you come out of standby, and it can’t release control of the screen back to the login prompt (this is pathetic, and likely a security hole) (and it makes the screensaver completely useless for laptop users, really)
• This is a set-top-box – There is no damned excuse for instability. At least EVERY OTHER operating system ON THE PLANET supports a great deal of hardware, and in reality, receives it’s instability through THIRD PARTY SOFTWARE. First party instability in a commercial “production ready” kernel, is pathetic.
• “The Cult” lies about stability issues, and on becoming a mac owner, they start to open up to the truth, that this system is in fact NOT stable – For that, they are due a “Fuck you, liars” from those of us don’t follow “the religion”.

So, you arses, please sort this crap out. I’ve sent you all the bug reports for these crashes, it’s about time you live up to the lies you (and / or your users) have been spreading. And if you wouldn’t mind sorting out the security whilst you’re at it, that would be just dandy (there are plenty of exploits documented (and in my normal usage, I have found more – I’ve been too busy to do an audit, but this OS would fail))

I won’t be returning this stuff yet, at the moment, the stability issues can be worked around (by not using the respective features and devices), and the only reason I’m still here is for the performance of Ruby, Textmate and Terminal.app, and the reasonable quality of the hardware itself – At least that’s making me JUST happy enough to combat my current anger, after a rant. If it wasn’t for these things, I’d be screaming bloody murder right now.

There’s a “problem” with the current version of rubygems that’s causing somewhat of a FAQ, that as far as I can see, Google doesn’t index too well, so this post is for you, those people that find yourselves here via Google, at least until the problem is at least well known or the procedures change.

The relevant entry in the change log is this one:

Executable stubs can now be installed to match ruby’s name, so if ruby is installed as ‘ruby18’, foo_exec will be installed as ‘foo_exec18’

This can be found on Eric Hodels blog.

The current version of gems (1.0.1) installs the gem command as gem18 if your ruby is installed as ruby18.

For now, the fact that the upgrade via “gem update –system” is not doing anything with the old ‘gem’ command, is causing quite a few people to come into the ruby channel complaining about the following error:

gem:23: uninitialized constant Gem::Gem Runner (NameError)

You want to remove your old gem command (found at `which gem`) (i.e. rm `which gem`) and then link or copy the new gem command (likely gem18) to gem.

Anyway, this post is only this long so that it gains a high enough relevance for google to bother indexing it, with the goal of helping out a few of you folks until one of the many possible more permanent resolutions comes about.

Overall, the 1.0.1 release is a great release, seeing a lot of enhancements in rubygems that personally, I’m really happy to see. Thanks for all the hard work Eric, Chad and everyone else involved.

ttfn!

Update:

As it seems to have not been clear to some, on Debian, it may well (n.b. may well != will) be gem1.8, as your ruby may be ruby1.8.

If you need to know which it is, do the following:

ls -la `which ruby`

And this should tell you which ruby file you’re “ruby” is linked to, and where that link is located.