Chris Cruft

I am a complete Perl novice.  But there are occasions when I need to install perl modules.  I have learned that

perl -MCPAN -e ‘install (module-name)’

will allow you to install a perl module from the CPAN respository.

So I have been developing MemoryMiner (as my introduction to Rails) for almost six months now, and performance issues are starting to become recognizable. In a desperate attempt to kill two birds with one stone, I upgraded my Linux server (bmw) to Fedora Core 5 this past weekend. It was not uneventful but I finished with MySQL 5.0.22 installed and running for my Rails apps. I also now have ruby 1.8.5 and Edge Rails.   Unfortunately, the performance is still inadequate, and while I’m perfectly willing to suffer due to limited hardware, I’m pretty sure there is some bloat that needs to be trimmed -particularly in the area of database query tuning.

The first order of business was to get a handle on where my application was spending time. The classic solution, a profiler, applies to Rails as well. I tried the built-in profiler (script/performance/profiler) but was not blown away. Then I found ruby-prof and its graph profiles. I installed the gem and added a real simple around filter in the controller to generate an HTML Graph Profile. Cool -I could exercise a method/URL in a controller and immediately (in another browser) see the results in an easy-to-digest format.

Unfortunately, I could not find a smoking gun.
References:

1. http://ruby-prof.rubyforge.org/graph.txt
2. http://ruby-prof.rubyforge.org/
   
3. http://glu.ttono.us/articles/2006/06/23/stefen-kaes-optimizing-rails
4. http://www.thoughtstoblog.com/articles/2006/10/24/rails-performance-tool-box
5. http://blog.kovyrin.net/2006/08/28/ruby-performance-results/

1. Good example of benchmarking -with useful server-vs-server results.

For the second time this year, I struggled debugging the dreaded “A copy of XXX has been removed from the module tree but is still active”.  Last time, I learned the lesson of letting Rails autoload wherever possible and to not try to manage the loading myself.  Kind of a Zen thing.

But there are limitations with that approach.  For starters, we all know this only applies to Rails, not Ruby in general.  And so when writing gems, require is your friend.  An edge case is plugins.  The auto-dependency mechanism does not reload plugin code (at least not by default), but it will autoload it initially.  That’s a code smell, in my opinion, that leads to the error noted in the first paragraph when “locked in” code references autoloaded code.  It kinda works like this as best I can tell: don’t let Rails autoload code that it is not also reloading.

Given that plugins are (normally) not be reloaded, you need to avoid having Rails grab const_missing and autoload your code.  So, in plugin code, use your normal arsenal of Ruby-standard load/require to load stuff.  Here’s a neat trick to find where you’ve failed to make the grade: start the console and run

>> print ActiveSupport::Dependencies.history.grep(/plugin/).join(”\n”)

Any plugin code listed is probably counting on Rails’ dependency resolution/autoloader.  You may need to muck around with your code a bit to trigger stuff getting autoloaded, but in my case there was plenty to work on just post-initialization.

I switched the test database for one of my plugins to SQLite3 today -I like the idea of not requiring a database setup step for plugin tests and the in-memory option for SQLite3 nicely sidesteps that requirement.  Immediately my tests all failed with:

ActiveRecord::StatementInvalid: SQLite3::SQLException: unrecognized token: <INSERT statement mixed in with a bunch of binary gobbledygook>

The weak link here is Ruby.  Think about this chain of custody for my binary data:

1. YAML fixture with “!binary” directive
2. Ruby String
3. SQLite3 Blob

The second custodian (prior to 1.9 only, I hope) loses the “binariness” of my data and thus fails to properly quote it for insertion into SQLite3 (interestingly, MySQL does not appear to require special quoting).  Normally ActiveRecord knows how to restore the binariness of the data on insert by looking at the destination column type (you can see this code in fixtures.rb).  But it gets this column information in a strange way: despite knowing the table into which the fixture is to be inserted, ActiveRecord gets the column data by referencing the model class associated with the table.  The model class is guessed from the name of the fixture’s DB table -which fails to find a match whenever the model class is not in the root namespace.  Head spinning yet?

<fixture file name> => <database table> => <model class> => <column details>

(The irony is that a model class knows its column types because it inspected the table during initialization.  Why doesn’t the Fixtures class (which also knows which table to inspect) do the same thing?  Like this:

<fixture file name> => <database table> => <column details>

Who knows?)Anyway, without a model class and thus column type hints, ActiveRecord happily inserts fixtures with generic quoting.  Ruby strings, for example, are assumed to be destined for plain string columns.  For blob columns in SQLite3, this causes a shower of sparks.All hope is not lost, however.  Rails provides the #set_fixture_class method which allows you to explicitly link the fixture file to a model class.  For example:

set_fixture_class {:widgets => My::Deeply::Nested:Widget, :thingys => My::Deeply::Nested::Thingy}

Problem solved.

Recently I decided to jack up my profiling abilities for my Rails apps.  At some point, looking at call graphs started to hurt my brain so I went to install kcachegrind on my Snow Leopard machine.  To make a long story short, I ended up doing an across-the-board upgrade of Mac Ports (sudo port selfupdate followed by sudo port upgrade).  Despite still having some lingering problems with kdeinit whining about not being able to bind to the socket (claiming the address was already in use), I was able to use kcachegrind to study the profiler output from Rails’ spiffy profiler tests (ActionController::PerformanceTest).  Whoopee!

Too bad that having upgraded all my ports sent me directly to the next step in dependency chain hell.  First problem: rmagick won’t load.  Hoping for the best, I fired off an update of the rmagick gem (sudo gem update rmagick).  YeeHaa!  I’m on a roll.  The only thing left is a tiny little warning when running my test suite about “WARNING: Nokogiri was built against LibXML version 2.7.6, but has dynamically loaded 2.7.7″ and how hard could a little warning be?  After all, my test suite passed just fine.  But, I’m a bit to OCD to let that warning ride, so I started digging.

First, let’s evaluate that message: nokogiri is complaining about LibXML being too new.  OK, that’s easy, let’s get a newer version of Nokogiri that’s more comfortable with that newer version of LibXML (which probably came along with Mac Ports).  Easy peasy upgrade (sudo gem update nokogiri) from 1.3.3 to 1.4.1.  Unfortunately, the warning is still there.  On a hunch, I open my Rails console…

# ./script/console>> Nokogiri::VERSION=> “1.3.3″

Uh,  excuse me, who is loading the outdated version of Nokogiri?  I check my environment files (I’m not yet on Rails 3) to confirm that my app is not tied to a specific version… nope.  Now I have to hunt down the offending party.  Here’s how I fingered him…Remove the config.gem line for nokogiri and see if anybody complains during the test suite.  Sure enough, we have a smoking gun:

in `activate’: can’t activate nokogiri (~> 1.3.3, runtime) for [”sanitize-1.1.0″], already activated nokogiri-1.4.1 for [”webrat-0.5.3″]

To make a long story short, that little tilde (’~') in the error message above has a very specific meaning.  The above error message means that sanitize wants nokogiri version 1.3.3 or later, but only as long as it shares the same major (1) and minor (3) versions.  So “1.3.956″ works, but “1.4.0″ does not.  Sadly, I can’t find this interpretation of the tilde in gem dependency specs documented anywhere.  Strange, considering its impact.  I have found a couple of blogs and such that point out that the tilde has this role, but nothing formal in the docs.Solution: update sanitize (and thankfully the sanitize author had updated it to be compatible with nokogiri 1.4).Afterthought: the gem dependency command shows clearly the dependency of sanitize 1.1.0 on nokogiri 1.3.x:# gem dependency -R nokogiri

Gem nokogiri-1.3.3

racc (>= 0, development)

rexical (>= 0, development)

rake-compiler (>= 0, development)

hoe (>= 2.3.2, development)

Used by

sanitize-1.1.0 (nokogiri (~> 1.3.3, runtime))

webrat-0.5.3 (nokogiri (>= 1.2.0, runtime))

mime-types-1.16 (nokogiri (~> 1.2, development))

Git is da bomb, written by The Man, all the kewl kidz sing its praises.  The Rails community has dropped Subversion like penicillin on clap.   And I’m really looking forward to taking advantage of the distributed nature of Git.

But I have existing projects that use Subversion, including projects that represent Rails plugins.  Plugins are indispensable when working with Rails and probably a bajillion other frameworks, tool sets and such use them to compose independently developed code.

Too bad, then, that Git’s support for composed projects sucks.  It cannot match the simplistic yet effective behavior of svn:externals.  At least for me, Subversion’s externals do the following Good Things:

• Records my project’s dependency on external plugins, either to a specific version or the latest version (edge) of that plugin.
• Supports transparent commits to my project’s code with no regard to fact that there are external plugin dependencies.
• Supports transparent commits to a plugin’s code with the same tools and commands as changes to my project’s code -this can be valuable if you use plugins to factor your own common functionality into a self-maintained plugin or if you are a contributor to plugin project.
• Transparently promulgates macro operations on my project code base to the plugins, i.e. one can checkout my project and get updates on my project with no concern that it is composed of plugins.

Git can do some of this through submodules -but there are holes.  I’m far from competent with Git, but just trying to setup a Git project with submodules seems to have these issues:

It’s not possible to track the latest version of a submodule.

And while there are tools that attempt to address the problem, I’m left with the nagging feeling that this is a fundamental design flaw or a limitation from the distributed nature of Git.  Anyone?  Anyone?

I’ve got a family of (ARes) resources that are available through an external web service.  These resources are used pervasively throughout my site -they appear on about 75% of my site’s pages.  When testing, of course I don’t want to hit the web service and endure the vagaries of performance and availability.  The nice people developing ActiveResource seem to have accommodated this desire by providing the HttpMock class.

But…  HttpMock is very exacting in its demands for matching requests -it’s all or nothing.  That means that if I make fifty different requests, all identical save for a tiny change in the URL params, I need to make fifty different mocks.  Ouch.

So I decided to mock the mocker.  No, really.  Using mocha, I mock the HttpMock::Request#== method to always return true.  Now, regardless of the request path, HttpMock always sees a match and returns my mock data.

The denouement, using the Rails docs as a starting point:

def setup
  @matz  = { :id => 1, :name => "Matz" }.to_xml(:root => "person")
  ActiveResource::HttpMock.respond_to do |mock|
    mock.post   "/people.xml",   {}, @matz, 201, "Location" => "/people/1.xml"
    mock.get    "/people/1.xml", {}, @matz
    mock.put    "/people/1.xml", {}, nil, 204
    mock.delete "/people/1.xml", {}, nil, 200
    req_res = mock.get "/", {}, "Constant Data Goes Here", 200
    req_res.last.first.stubs(:==).returns(true)
 end
end

So I’ve got a couple of projects that I like to claim run on “Edge Rails”.  But the reality is that I let them slip for a month or two before playing catch up.  Today I decided to update an application that had somehow gotten behind 2-3-stable by hundreds of commits.  Being bold, I jumped straight to HEAD and was met with a shower of sparks running rake.  Where to start?

In a word or two: git bisect

I started the bisection run and told git that head was bad and my current commit was good.  Note: I use a git submodule to track Rails…

[…vendor/rails]# git bisect start

[…vendor/rails]# git bisect good

[…vendor/rails]# git bisect bad 2-3-stable

(and in another terminal window)

[myapp] # rake

Then it was just a matter of marking each auto-selected commit as good or bad with git bisect good or git bisect bad.  Worked great.  Next time, I’m going to automate the whole thing with git bisect run.

Somehow, someway my gem installation became subtly corrupt.  Specifically, many of my gems are not available in the cache directory.  That’s not a very intuitive erroneous situation, but there are gem commands that clearly expect a gem file in the cache directory -and they can’t recover the situation if the file is missing.  Doesn’t sound like my definition of a cache, but it’s time to move on.

Symptom:
1. whiny errors while attempting to unpack a gem like:

[cch1@bimota:~/Documents/Development/t]$ gem unpack exifr
ERROR:  While executing gem … (Gem::Exception)
Cannot load gem at [/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8/cache/exifr-0.10.7.gem] in /Users/cch1/Documents/Development/t

or

[cch1@bimota:~/Documents/Development/t]$ gem pristine exifr
Restoring gem(s) to pristine condition…
ERROR:  Cached gem for exifr-0.10.7 not found, use `gem install` to restore

2. Indeed, no .gem file exists in the referenced cache directory.

Note that in OSX Leopard, gems are typically installed in several locations:

[cch1@bimota:~/Documents/Development/t]$ gem env paths
/Users/cch1/.gem/ruby/1.8:/Library/Ruby/Gems/1.8:/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/gems/1.8

My theory is that earlier versions of gem (such as the one I got with my distribution of Leopard in early 2008) had problems installing and updating gems other than those originally packaged with the system.  Using the gems by requiring the library file typically worked fine.  But by not building the cache file (or perhaps building it in the wrong one of the multiple gem directories), problems crept up months later trying to unpack the gem.

Sadly, the only solution I can find is to re-install the gem:

[cch1@bimota:~/Documents/Development/t]$ gem list exifr

*** LOCAL GEMS ***

exifr (0.10.7)
[cch1@bimota:~/Documents/Development/t]$ sudo gem install exifr –version ‘=0.10.7′
Password:
Successfully installed exifr-0.10.7
1 gem installed
Installing ri documentation for exifr-0.10.7…
Installing RDoc documentation for exifr-0.10.7…

Now the commands that depend on the “cached” version will work:

[cch1@bimota:~/Documents/Development/t]$ gem unpack exifr
Unpacked gem: ‘/Users/cch1/Documents/Development/t/exifr-0.10.7′

Since moving to more recent versions of Rails, I’ve noticed that the auto-generated Rails tests assume that the myapp/test directory is on the load path.  And the bundled Rake testing tasks do indeed take care of that requirement.  But the Aptana RadRails plugins for Eclipse don’t.  The result is that whenever you run a test, either with the test buttons or the Run As | Test::UnitTest context menu, you get something like the following:

./test/unit/user_test.rb:1:in `require': no such file to load -- test_helper (LoadError)

There is an open issue on the Aptana issue tracker, but it doesn’t seem to be resolved yet.  Some people have suggested prefixing your requires with the test directory when requiring the test_helper file at the start of your test files -but I don’t think that’s a good solution, especially if you’re working with multiple developers.  Frustrated by not getting my daily green bar fix, I found this work-around:

1. From the Eclipse Preferences option, choose Ruby | Installed Interpreters
2. Select your interpreter (I use the Standard VM default interpreter named usr) and choose ‘Edit’. 
3. Add -Itest to the Default VM Arguments option.  Don’t forget the leading dash!
4. Click ‘OK’. 

You should now be able to run your tests without having to edit each one to include the test directory.  The downside is that you now have an ‘extra’ directory in your load path which will give you a (tiny) performance hit to all your ruby ops -not just tests.  Conceivably this could also introduce an incompatibility if you have some conflicting stuff in the test directory -extremely unlikely if you only have test_helper.rb in there.

Tested against Edge Rails (d37e6413366c9a3fafa02c4298a2946dc8327a42), Aptana RadRails 1.0.3.200807071913NGT, Ruby 1.8.6 patchlevel 114 running under Darwin 9.4.0