Archive for December, 2008

ruby defined? # => “expression”

Thursday, December 11th, 2008

Ever spend a long time debugging something, only to find out an hour or two later that you were staring at the problem all along, and you should have realized it from the beginning? And then, of course, the solution only requires a tiny tweak to one line, perhaps merely the addition of a few parenthesis.

>> defined? RAILS_ENV
=> "constant"
>> defined? RAILS_ENV && RAILS_ENV == "development"
=> "expression"
>> (defined? RAILS_ENV) && (RAILS_ENV == "development")
=> false

D’oh! (let’s ignore for now the issue of whether or not the “fixed” code is reasonable to run anyway)

I was curious to see if the expression was evaluated, and it appears that it is… sort of:

>> def foo
>>   $stderr.puts ":foo"
>> end
=> nil
>> def bar
>>   $stderr.puts ":bar"
>>   raise "hell"
>> end
=> nil
>> defined? foo
=> "method"
>> defined? bar
=> "method"
>> defined? foo || 1
:foo
=> "expression"
:bar
>> defined? bar || 1
=> nil

Notice: the methods were executed, but the exception from bar was caught and squirreled away somewhere, and defined? the returned nil, even though the method and expression were certainly “defined”.

a better progress bar for rspec

Tuesday, December 9th, 2008

Updated 2008-12-10: added screenshot and video.

I’ve always been a little bit bemused by the default ruby test/unit and rspec output: a series of dots, one for each passing test (or example), and the dots become “F” characters in the event of a failure.  Most importantly: it’s simple, unambiguous about pass/fail, and easy to read at a glance, so no problem there.  You get a feel for the speed at which the tests are running, and you can visualize how many tests have run already.  And it’s easy enough to have them output in color (red or green), to make the errors visually pop out.  And it’s drop dead simple.  That’s good.

So what’s missing?

(for my tastes)

  • Immediate Feedback: Yeah, the default output gives me an “F”, but what am I supposed to do with an “F”? I won’t know where and what that “F” was until the end of the entire test run, when the summary is dumped.  When running through a (functional) test suite that takes three minutes or even fifteen minutes, that just doesn’t work.
  • Concise output: if everything is passing, I don’t need to see 4000+ dots displayed across my screen. It would be nice if the entire output would fit into a single line (when there are no failures).
  • Percentage: A nice to have, not a need to have. But knowing how many tests have already run is generally not as interesting to me as how many tests are there total, and what percentage of them have run.
  • ETA: This isn’t so important for the short test runs that I do over and over again during the BDD cycle… because I expect those tests to finish in under 10 seconds anyway.  But anything more than 10 seconds, and I get distracted. An ETA helps me limit my distraction.

So what do I do about it?

Basically, what I want is a progress bar and that the errors and warnings be displayed immediately. I also want warnings to be printed for slow specs. When using color, I want the entire progress bar printed in green if everything is good, yellow if there has been a warning, and red if there has been an error.

Fortunately, rspec makes it very simple to write a custom output formatter. So, a couple of weekends ago, I threw something together in about half an hour. I’ve used it ever since, and I’m pretty happy with it (I’ve tweaked it a little bit).

What does it look like?

A static image doesn’t really show off the progress bar very well, but here’s a screenshot (click thumbnail for full-size):

And here is a video, so you can see it in action (very low quality, sorry):

The code

http://ekenosen.net/bzr/rspec_support/compact_progress_bar_formatter.rb

It’s currently hosted in a bzr branch, but I’ll stick it up on github if anyone really cares about that.  Also, it depends upon the progressbar gem, so you’ll need to install that.

To use it

The location you download the script to is not important, but this is where I’m (currently) keeping it. You could also use bzr to pull down the entire branch.

$ gem install progressbar
 
$ mkdir -p ~/lib/rspec/
$ cd ~/lib/rspec
$ wget http://ekenosen.net/bzr/rspec_support/compact_progress_bar_formatter.rb
 
$ spec --require ~/lib/rspec/compact_progress_bar_formatter.rb -c -f Spec::Runner::Formatter::CompactProgressBarFormatter path/to/specs

I’m currently using some bash aliases to keep the spec command line nice and short. Perhaps there’s a better way?  In ~/.bash_aliases:

alias  spb='spec        --require ~/lib/rspec/compact_progress_bar_formatter.rb --format Spec::Runner::Formatter::CompactProgressBarFormatter --color'
alias sspb='script/spec --require ~/lib/rspec/compact_progress_bar_formatter.rb --format Spec::Runner::Formatter::CompactProgressBarFormatter --color'

For rake tasks, I use a spec/local_spec.opts (spec/spec.opts is checked into version control as a default).

Nitpicking

I cheated: I didn’t develop it BDD-style.  I intend to fix that soon by rewriting it spec-first; certainly before adding any more functionality. TATFT indeed.

I’d really like to be able to send the threshold (for reporting of slow specs) in on the command line.  It might be easy to do, I haven’t looked into it… I’m currently just editing the file every time I want to change the threshold (e.g. normal specs run with a threshold of 0.1 sec, functional specs run with a threshold of 5 or 10 seconds).  Messy.

Also, it would be nice if the command line didn’t need to be so long… perhaps a supported gem/plugin system for rspec?  If that were easily doable, then I would probably package this up into a gem.

I had to break into the progressbar’s internals a little bit… it didn’t publically expose all of the functionality I wanted.  Still, that’s better than creating my own progressbar library.

Times and time zones considered dangerous (especially in tests)

Friday, December 5th, 2008

Just wanted to put out a note of caution to other developers.  Any code (test/spec or production) that depends on global environment settings or non-deterministic functions needs to be treated with fear and trembling.  As a concrete example of this maxim, code that deals with Time, Date, and DateTime has the possibility to trip you up with both global environment and non-determinism.  I recently discovered a potential bug related to this… but it took me 45 minutes to track down… so I wrote up the following afterwards:


nota bene: some of the methods described herein are not defined by Ruby’s core library’s but by Rails’ ActiveSupport.

Any non-determinism in tests is dangerous, and Time.now and its close cousins are certainly on that list.  Whether the code which depends on the current date is in the production code or in the spec code, we’ll need to be very careful of it, lest it trip us up.

I’ve known this for a long time… but I just spent about 45 minutes perplexed with a particularly stupid bug that simply required an attentive eye to unravel… I’ll gladly share my debugging session (condensed for time and minus the aggravation and going in circles), and hopefully save someone else the hassle:

>> DateTime.yesterday < DateTime.now
=> true
>> DateTime.tomorrow < DateTime.now
=> true

Well that shouldn’t ever happen.  Confused yet?  Or do you already know where this is going?  I spent a great deal of time wondering if it was some weird interaction between the Date, Time, and DateTime classes (and trust me, those weird interactions do exist, although maybe they weren’t the cause of this particular bug).

>> DateTime.tomorrow
=> Sun, 24 Aug 2008
>> DateTime.yesterday
=> Fri, 22 Aug 2008
>> DateTime.now
=> Sat, 23 Aug 2008 23:24:35 -0400

Ummm… nothing that would explain the comparison results above… but that’s curious… DateTime.now gives a different inspect output than the others.  I wonder why?

>> DateTime.yesterday.class
=> Date
>> DateTime.tomorrow.class
=> Date
>> DateTime.now.class
=> DateTime

Intriguing.  Certainly not what I expected, given that all of these values were obtained from class methods on DateTime.  Perhaps this means that the comparison requires some coercion to work…  I didn’t investigate the source to see if it uses “to_datetime” as opposed to “to_time”, but I’m assuming that it does, because of the following:

>> DateTime.tomorrow.to_time < DateTime.now.to_time
=> false
>> DateTime.tomorrow.to_datetime < DateTime.now.to_datetime
=> true

So what does Date#to_datetime do to screw us over?

>> DateTime.yesterday.to_datetime
=> Fri, 22 Aug 2008 00:00:00 0000
>> DateTime.tomorrow.to_datetime
=> Sun, 24 Aug 2008 00:00:00 0000
>> DateTime.now.to_datetime
=> Sat, 23 Aug 2008 23:28:11 -0400

Do you see it?  The answer is right there, but it’s easy to miss.  I missed it over and over again for about 40 minutes.  ”-0400” — the timezone.  The timezone had been screwing me up all along.  The DateTime object has my timezone from the get-go, but the Date objects were converted as UTC. Lovely… just lovely.

Now, I wasn’t the original author of the code.  Just an archaeologist.  My guess: the code worked when it was built (during business hours, not in the wee hours of the night when the timezones would trip them up), and it looked like the simplest thing needed.  Generally, you really can’t fault a developer for going that route. I certainly don’t.  But times and dates and especially anything related to the current time and date… well, these are special animals, and need to be dealt with special care.

The long and short of it?  Timezones are global environment state, and you need to be aware of it with any code (especially tests) that deal with time.  Avoid DateTime.yesterday or DateTime.tomorrow like the plague in your test/spec code (unless you enjoy tests that spuriously fail near the witching hour).  You should write your tests (and your production code) in such a way that you can simulate different timezones and different times of day in order to tease out bugs.  And if you need to compare or convert dates and times in your production code, be very aware of what time and timezone your business rules will require, especially if you have any Date objects that might be automatically coerced into DateTime objects.