Beware trying to do an Array find() with an ActiveRecord collection, and other various lessons.

Wow, this is something that's been haunting me for a week or two, and I just couldn't figure it out. I've been on a major performance improvement spree on Project Unblowuppable, which has always been a very database intensive application. After building up a decent sized database in production through the private beta, I pulled it down to play around with locally and find the real bottlenecks. One particular page (the one that does by far the most work) for one user was doing over 1200 db queries! Ouch. I've been trying to optimize that for a few weeks by using :include (in several cases nested includes) in my original queries to eager load as much as possible up front, and by rearranging the code to do things like pull db queries out of loops where possible. On most of the pages this was a big win, but not on that One Evil Page. I used the same techniques there, and spent literally a few weeks (in my spare time) going over the code again and again, and looking at what was going on in a debugger (thank you, RubyMine!!). Nothing worked, but watching exactly what was happening in the debugger and doing lots of research on Google was very interesting.

If you watch what gets retrieved in an ActiveRecord find() call in a debugger, you'll see (of course) that by default it doesn't retrieve any of the associated records (via belongs_to, has_many, etc.) automatically. If you use the :include option, you can tell Rails that you want to pull those associations at the same time, so you're not doing more queries later--quite possibly one at a time in a loop, which is terrible if db queries are a bottleneck for your app. An interesting thing if you peek at the query result is that the :included record(s) may not actually be there in the model if you drill down through it. In fact, what you may see is an new attribute for an association you loaded that's nil! I kept seeing this and thinking "WTF?" But looking at the SQL in the server log, I could see that indeed the associated records were being loaded--but where did Rails put the data?

In most cases, using records with eager loaded associated data worked well, but not always. Eventually I was satisfied that the data was somewhere, even though I couldn't drill down to it and view it directly in the debugger. It turns out ActiveRecord does some method_missing magic to pull that data in. Ok, no problem--there's lots of PFM in AR. :) But on the One Evil Page, even though I was pre-loading the data, it was still doing a bunch of queries to pull it from the DB again. What I finally decided to do was switch from using an ActiveRecord find() (find_by() really) to a standard Ruby Array find(). Looking at the types in the debugger, my collection was an Array, so this should work, right? Not necessarily. Rails does some magic with the find() method on these collections (which are actually AssociationProxies) and instead of just doing an in-memory search through the array, it was still doing a db lookup. So I did some looking through the pickaxe book and saw that in Enumerable collections, find() is actually just an alias for detect(). So I replaced 'find' with 'detect' and PRESTO: with all the eager loading set up, I dropped the number of db queries on the Evil Page from over 1200 to under 150! (And I'm still not done--I think I can still cut it a lot more.)

So the moral of the story? I'm not sure. I don't know if this is a bug or a feature in AR, or if it's just a side effect of my design, but wanted to put this out there in case anybody else is having a similar issue. Do some playing around and see if using eager loading and Ruby's Array detect() can cut down your db queries. (Note: the query_reviewer plug-in is an essential tool for checking your db usage. Not only will it give you the total query count, but it will show you duplicate queries and give you the stack trace of exactly where the problem is! It also shows when indices are missing or not being used, which may just be because mysql decided there wasn't enough data yet to bother.) A related note about Array find_all(): according to this thread, it is also hijacked by AR and the equivalent thing to do is use select() instead. But in my case whether I use find_all() or select() the effect is the same. Not sure why this seems to work differently than find()/detect(). Anyway, just be aware of this sort of thing and play around. Hopefully this isn't some bug that future versions of Rails will fix and break in my app. ;)

A similar thing that may help cut down db queries is using Array length() (or size()) instead of count() to get the number of records in a collection. This is great if you've already loaded the records, especially if the count is being done in a loop, which was my case. I was able to shave off a lot of SQL count queries this way.

An aside about using :include: I guess Rails (pre 2.0?) used to do a big Cartesian join when you did includes, which I can imagine was pretty horrible. The things that caused me to do some head scratching following my AR model objects in the debugger are probably a side effect of the fix for that, which is to do separate (and simple) db queries to load the data separately instead of joined. Looking at the number of SQL queries this looks very efficient, and like a very clever solution. I'm betting there was a lot of work to make this happen so transparently--my hat's off to the Rails team for this and all their other hard work!

hpricot and Ruby 1.8.7

So the problems from my Ruby 1.8.7 upgrade aren't over yet...! None of the Rails scripts (including script/server) will run from the terminal on my MacBook, because of an hpricot incompatibility. I've ignored it because everything still seems to work from RubyMine--I run the app there, and can do other things like script/generate. But I decided to try to fix it anyway.

Found a page that said yes indeed, hpricot and Ruby 1.8.7 don't get along, so I pulled down the git fork, tried to build and install, but had build problems with it (it was trying to build for an old darwin target, I think). So I tried pulling down and building Why's git repo per the instructions. Sure enough, that built and installed a new hpricot version--apparently the gem is not up to date.

Some notes: You'll need ragel, which can be installed via macport, and fast_xs, which is available as a gem to build and install hpricot.

Finally fixed 'bundled mysql.rb driver has been removed from Rails 2.2' issue

Well, I finally sorted out what the problem was that was causing the 'bundled mysql.rb driver has been removed from Rails 2.2' error. If you read back a few posts you'll see my saga of updating ruby from 1.8.6 to 1.8.7 and the issues it caused with my gems. Well, I fixed those for my user account, but not for when I used sudo--they give different lists of installed gems when I do 'gem environment'/'sudo gem environment'. Ran the old gem tool and got the same list with and without sudo. Hmmm. So I tried uninstalling/reinstalling the mysql gem with the old gem tool, and bam! problem solved.

Well, almost. After all the stuff I'd done I nuked all my mysql databases (no big deal, only dev/test data, and easy to restore with Rails migrations) but more importantly all my mysql users. So used the MySQL Administrator tool to add back my user, get the permissions set up correctly, and everything running again.

Well...almost. My app runs fine inside RubyMine, but doing script/server from Terminal still fails for some reason (and as far as I can tell, script/server doesn't have a 'verbose' option to give details). Whatever. If I can run it in RubyMine, I can work again. Woohoo!

Oh--and one other handy thing I found: Start and Stop MySql in Mac Os X 10.5 Leopard

Upgrading mysql from 5.0 to 5.1

Ugh. So I saw there was a newer version of mysql out there (5.1) so I decided to upgrade the MacBook Pro to use it instead of 5.0. Before I did that, my Rails app was running fine. After doing the upgrade I started getting this error:

The bundled mysql.rb driver has been removed from Rails 2.2. Please install the mysql gem and try again: gem install mysql.

I've spent hours searching Google (and Bing, even!) for an answer, but haven't found anything that works. I've uninstalled and reinstalled the mysql gem many times, with different command line param combinations, no effect. I even totally cleaned mysql and the mysql gem off the computer (http://akrabat.com/2008/09/11/uninstalling-mysql-on-mac-os-x-leopard/), reinstalled mysql 5.0, and it's still fucked. I'm totally stumped. Put up a question on stackoverflow, but no luck yet.

I don't know how I'm going to fix this, and I'm dead in the water for development because of it. FUCK!!

Upgrading Ruby on Mac OS X Leopard from 1.8.6 to 1.8.7

Today I noticed that some of the unit tests for Project Unblowuppable were failing on my production machine (Linux), but working fine on my dev machine (MacBook Pro running Leopard). The errors were stuff like things in tables being in the wrong place and decimal type mismatches (same value, but different type of number, like BigDecimal). So my first thought was that Ruby or some of my gems were out of sync. Updated all the gems on my production box, and saw that it was running Ruby 1.8.7. Did a 'ruby -v' on my MBP, and it was running the Leopard default 1.8.6. Checked the Ruby on Rails download page and sure enough, the recommended Ruby version is 1.8.7. No problem, should be easy to update, right?

Every time I use MacPorts I seem to need to look up the commands in the MacPorts Guide, which isn't the most user-friendly doc in the world. But eventually I found the commands I wanted:

sudo port selfupgrade
sudo port upgrade outdated

That ran a while and did (according to 'port installed') update Ruby 1.8.7, which it looked like I already had an older version of. Hm...why was 'ruby -v' showing 1.8.6 before? Ran 'ruby -v' again, and still 1.8.6. Obviously I was missing something. Did a bunch of digging on The Oracle and finally found two pages with useful info:

Upgrading to Ruby 1.8.7 using MacPorts

Starting over: MacPorts

Tried the deactivate/activate method from the first link, still no luck. Then from the second page and a few other things The Google found I realized that it was a PATH problem. MacPorts is supposed to prepend some path info onto the PATH in your .profile file, but I didn't have one. (Supposedly MacPorts will create it if necessary, but it didn't work for me.) Created the .profile with this in it:

export PATH=/opt/local/bin:/opt/local/sbin:$PATH
export MANPATH=/opt/local/share/man:$MANPATH

Restarted iTerm to pick up the env changes, did a 'ruby -v', still 1.8.6! But doing a 'which ruby' gave the new MacPort path, and doing a version check with the whole path ('/opt/local/bin/ruby -v') said 1.8.7. Hm. Did the port deactivate/activate again, restarted iTerm one more time, and voila--Ruby 1.8.7! Not sure which part(s) of this were necessary, but that's what worked for me.

My unit tests still ran fine on my Mac with 1.8.7, and updating the gems on the server didn't fix anything either, so in that respect this whole exercise was a bust, but I learned something and I hope it will help other people to have all this info in one place.

UPDATE: Apparently this also impacts all the gems you have installed. I didn't want to reinstall everything, and have two copies of gems sitting around, so I did ' bunch of research until I figured out how to re-use the old gems. I was able to get all my old gems to show up by setting the GEM_HOME env var to the path the old gem tool had them in. You can find the gem location(s) by running 'gem environment' (be sure to run the old gem tool to get the old path(s), for me it was '/usr/bin/gem'). Then I put this into my .profile file:

export GEM_HOME=/Library/Ruby/Gems/1.8

After doing a 'gem list' (running the new gem tool) this time all my old gems showed up. Fixing things in RubyMine took a little more work in the Preferences.

UPDATE 2: Wow, I thought all this would be easy--not so! Updating all my gems (including moving to Rails 2.3) and bumping the Ruby version caused me all sorts of headaches. Instead of getting any development done today, I've been doing this. Not gonna spend a lot of time detailing anything, but I'll list the highlights so a search may hit this post. If you have any questions about what I ran into, contact me (leave a comment, email, etc).

One big headache was a libxml2 problem having to do with nokogiri (which I have because I'm using mechanize). This may have been a 0-day issue, as I updated all my gems earlier in the day, and then when I did it again nokogiri updated. Hard to say with any certainty what caused the issue because I changed so many variables today, but my guess is that a new version of nokogiri has a problem. The issue is that it now throws up a nasty error when you're using an old version of libxml2 (like 2.6.16, which comes with OS X Leopard by default). After playing with gems/macports all day I thought there must be some solution there, and indeed there is a macport. So I installed that, still no love. Read the nokogiri message a little more carefully, and it said to uninstall the gem and reinstall it after updating libxml2 so it would build with the new library. Had some problems uninstalling it because of the ruby/gem changes I made earlier in the day, but finally got it cleaned off by calling the old 'gem' tool to uninstall it and got it cleared from both root and user gem repos. Did a reinstall, and that problem was fixed. (BTW, there is also another way.)

I mentioned earlier that I had some issues with RubyMine after my updates, one was that the mysql gem was somehow wonky. It showed up for Ruby 1.8.6 in the RubyMine prefs, but under 1.8.7 (using the same GEM_HOME for both) everything was ok except for mysql. Tried to reinstall but got an error. Finally found this post which had the right magic command.

Next up was all the issues coming from migrating from Rails 2.2 to 2.3. Basically this was just a matter of Googling error messages and finding the fixes, all small stuff. The worst of it was in my tests, which completely blew up. This page had many of the answers in one place, found the other stuff through Google searches.

Whew! But now all my tests are running (and passing) locally again, and Project Unblowuppable seems to be running fine locally. Not gonna push it out to production today, don't feel like staying up all night to fix it. :)

Get tab key to select form elements in Firefox on the Mac

Project Unblowuppable has some pages where there are intermixed text fields and dropdown (select) elements. In Firefox if you were in a text field and the next element was a dropdown, it would skip the dropdown and go to the next text field. Really annoying for entering data. It worked fine in Safari, and I was wondering if maybe there was some HTML option I had to specify for the select items.

Turns out it's actually a Mac system preference! Just change an option and everything works. Why Firefox has the problem and Safari doesn't, I don't know, but there you go.

Use .blank? instead of .nil? && .empty?

So I had an issue tonight where the app was working fine, but a bunch of my tests were blowing up. Turns out that when you have a blank string field in a form, instead of putting a NULL value in the db, it puts in an empty string. Kind of annoying, but there you go. Unfortunately, in my tests I wasn't passing a param for fields I wasn't explicitly setting, so there it did put NULL in the db.

In my view code, I was calling .empty? on the property, which worked fine in the app (where the db provided a blank string), but choking in the tests, where it became nil.empty?. I thought, 'Well, I could check for both...' but that just rubbed me the wrong way. 'Surely, Ruby and/or Rails has a more elegant solution?' And indeed, Rails does: the blank? method. From Programming Ruby: The Pragmatic Programmers' Guide, Second Edition:

To make it easier to tell whether something has no content, Rails extends all
Ruby objects with the blank? method. It always returns true for nil and false, and
it always returns false for numbers and for true. For all other objects, it returns
true if that object is empty. (A string containing just spaces is considered to be
empty.)
puts [ ].blank? #=> true
puts { 1 => 2}.blank? #=> false
puts " cat ".blank? #=> false
puts "".blank? #=> true
puts " ".blank? #=> true
puts nil.blank? #=> true

Eeeeexcellent.