threehv

Today, Caius made a discovery that shocked me.

He had a class, descending from ActiveRecord::Base, with a custom constructor (initialize method). To debug it, he had the constructor raise an exception. In the console, Thingy.new(params) raised the exception as expected. But wotsit.thingies.find_by_field(value) did not. Even though it was instantiating an instance of Thingy and returning it.

“It must not be calling the constructor” he said.
“Rubbish” said I, “it’s a constructor. Constructors are always called. That’s the point of them”.

But as he dug deeper it certainly looked like the constructor wasn’t being called.

And then he found an article explaining that you should never rely on things being set up on in an Active Record constructor. Mainly because Active Record uses allocate to instantiate associated objects. And what is this mysterious allocate? Why explains it all.

To be honest, I’ve got mixed feelings about this. I can see the use of “allocate” – why’s example of marshalling an object makes sense (I’m slightly less sure about the way that Active Record uses it to load associations). But, to my mind, the definition of a constructor is “the code that is always called when an object is created”. So maybe I should just stop thinking of initialize as a constructor and more as an initialiser.

I always forget how to do this so I’m writing it down (especially as it’s really easy and git, as usual, makes me feel stupid as Linus is so much smarter than me).

Suppose you’ve been working in branch X and you’re about to merge those changes into branch Y …

• work in branch X and make your commits as needed
• switch to branch Y git checkout Y
• compare the differences between X and Y git log Y..X – the order here is important; it is merge-target..merge-source
• merge the changes from X (merge-source) into Y (merge-target) git merge X

Even better, before doing the merge, while you are still in branch X, you can squash multiple commits into a single one. This way, branch Y, when you examine the log, has a single entry “implemented feature X”, instead of thirty-five entries all related to feature X in some way.

• examine the log git log or even better git log --pretty=oneline
• choose the commit that immediately precedes the one that starts your piece of work (probably the last one before you branched to start work on feature X)
• start an interactive rebase session – this is git-fancy-talk for picking some commits and typing a message – git rebase -i THE-COMMIT-ID-OF-THE-COMMIT-YOU-SELECTED-ABOVE
• Your favourite editor (or nano) will open listing the commits for feature X – edit the word “pick” to “squash” for all except the top entry, save and exit
• Your favourite editor will open again – again showing your commit messages – add a line at the top stating something like “implementation of feature X” and leave the list of individual commits on separate lines below it (adding in a Fixes #123 or whatever your issue tracker demands as the last line), save and exit
• Now if you do a git log you will see a single commit with a nice “implementation of feature X” log message
• And you’re all set to merge to your master branch without cluttering its history with a long string of commit messages

A project I’ve been working on was recently moved up to Rails 2.2 (Rails 2.3 migration coming soon, but we wanted to take things one step at a time).

All the tests passed. Poking it on the staging server worked well. On to production and all was good.

Time passed.

Then, the app needed to be moved to a new server. Actually to a cluster. Slightly more nerve-wracking, but some playing around with the ghost gem and DNS settings and the deployment completed.

More time passed.

And then disaster struck. Well, not disaster, but it wasn’t good. Not at all.

The app had a rake task that was cronned to run every night. And it failed silently. We found out the day after and I scanned the production log file looking for evidence of what went wrong. Nowt. It didn’t even look like the rake task had run – but it had, as I had the data in front of me.

And the day after, it failed again. Another scan of the production log revealed nothing. Things were getting serious.

I suspected the cluster deployment. Maybe cron didn’t have permission to write to the log file, even though Passenger did. But everything looked good on that front. Maybe there was something else weird about the cluster setup – all the cron jobs were set to run on one of the app-servers; maybe moving it would make a difference?

To test this, I opened the Rails console and started manually recreating what the rake task was doing, on a different app-server. Which is when I noticed that script/console wasn’t writing to the production log either. What?

After a couple of hours of head scratching, I finally found out that the cluster deployment was not at fault. In fact, it seems to be the move to Rails 2.2 that had happened many weeks before – in particular it appears that the logger object no longer auto-flushes itself after writing.

We added a quick Rails.logger.auto_flushing = 1 to an initialiser and both script/console and the rake tasks wrote to the log as expected. Phew!