Noisy Backtraces Got You Down?

Dec 01, 2007

Bothered by all the noise in my tests' backtraces, I was thrilled when I first saw a thread on the shoulda mailing list with some discussion around making them a little bit easier on the eyes. Assuming that creating such a filter would be a long and tedious process of monkey-patching test/unit, I forgot about the idea, assuming the job better left for somebody with more time to spare than myself.

When Dan Croak revived the thread with some sample code, cooked up at a Boston.rb hackfest, it occurred to me that the job was far more manageable than I had originally conceived. I quickly fired Dan an email asking whether he'd be interested in a pluginization of their concept. With a resounding yes! from Dan, we set off to create quiet_~~stacktrace~~backtrace.

The rest of this post is cross-posted on GIANT ROBOTS

90% of this typical backtrace will not help you hunt and kill bad code:

1) Failure:
test: logged in on get to index should only show projects for the user's account. (ProjectsControllerTest)
[/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/assertions.rb:48:in `assert_block'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/assertions.rb:500:in `_wrap_assertion'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/assertions.rb:46:in `assert_block'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/assertions.rb:63:in `assert'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/assertions.rb:495:in `_wrap_assertion'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/assertions.rb:61:in `assert'
test/functional/projects_controller_test.rb:31:in `__bind_1196527660_342195'
/Users/james/Documents/railsApps/projects/vendor/plugins/shoulda/lib/shoulda/context.rb:98:in `call'
/Users/james/Documents/railsApps/projects/vendor/plugins/shoulda/lib/shoulda/context.rb:98:in `test: logged in on get to index should only show projects for the user's account. '
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testcase.rb:78:in `__send__'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testcase.rb:78:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:34:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:33:in `each'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:33:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:34:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:33:in `each'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/testsuite.rb:33:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/ui/testrunnermediator.rb:46:in `run_suite'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/ui/console/testrunner.rb:67:in `start_mediator'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/ui/console/testrunner.rb:41:in `start'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/ui/testrunnerutilities.rb:29:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/autorunner.rb:216:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit/autorunner.rb:12:in `run'
/System/Library/Frameworks/Ruby.framework/Versions/1.8/usr/lib/ruby/1.8/test/unit.rb:278
test/functional/projects_controller_test.rb:36]:
one or more projects shown does not belong to the current user's account.
&lt;false&gt; is not true.

Noisy backtraces must be ruthlessly silenced like political dissidents in Stalinist Russia. This much is clear.

Quiet Backtrace

Install the gem:

  sudo gem install quietbacktrace

Require quietbacktrace:

## test_helper.rb
require 'quietbacktrace'

Run your Test::Unit tests:

1) Failure:
test: logged in on get to index should only show projects for the user's account. (ProjectsControllerTest)
[test/functional/projects_controller_test.rb:31
vendor/plugins/shoulda/lib/shoulda/context.rb:98
vendor/plugins/shoulda/lib/shoulda/context.rb:98
test/functional/projects_controller_test.rb:36]:
one or more projects shown does not belong to the current user's account.
&lt;false&gt; is not true.

Ooh la la! Now we’re cooking with gas. However, those shoulda-related lines are cluttering an otherwise perfect backtrace. Luckily, Quiet Backtrace is designed to be extended by calling two types of blocks that yield one line of the backtrace at a time.

Silencers and filters

Silencers let you specify conditions that, if true, will remove the line from the backtrace.
Filters let you use Ruby’s succulent set of String methods to modify a line by slicing and stripping and chomping away at anything you deem ugly and unnecessary. (such as the :in `__bind_1196527660_342195’ in the original example)

Say you want to remove Shoulda-related lines… you create a new silencer and add it the Array of backtrace_silencers:

class Test::Unit::TestCase
  self.new_backtrace_silencer :shoulda do |line| 
    line.include? 'vendor/plugins/shoulda'
  end
  
  self.backtrace_silencers << :shoulda
end

Re-run your tests and bask in the sweet sounds of silence:

1) Failure:
test: logged in on get to index should only show projects for the user's account. (ProjectsControllerTest)
[test/functional/projects_controller_test.rb:31
test/functional/projects_controller_test.rb:36]:
one or more projects shown does not belong to the current user's account.
&lt;false&gt; is not true.

Exquisitely sparse. Quiet Backtrace clears distractions from the “getting to green” TDD process like a Buddhist monk keeping his mind clear during meditation.

Getting noisy again

On occasion, you’ll want to see the noisy backtrace. Easy:

class Test::Unit::TestCase
  self.quiet_backtrace = false
end

You can set Test::Unit::TestCase.quiet_backtrace to true or false at any level in your Test::Unit code. Stick it in your test_helper.rb file or get noisy in an individual file or test. More flex than a rubber band.

Using Quiet Bactrace with Rails

After you have installed the gem on your local machine, I recommend using the excellent gemsonrails plugin to freeze it to your vendor/gems directory and automatically add it to your load path.

Install gemsonrails and add it your Rails app if you don’t already have it:

gem install gemsonrails
cd rails-app-folder
gemsonrails

Then freeze quietbacktrace:

rake gems:freeze GEM=quietbacktrace

Quiet Backtrace will now work with your tests, but because this gem is meant to work on any Ruby project with Test::Unit, it does turn any Rails-specific silencers or filters on by default. However, there is one of each, ready to be switched on, that remove the most dastardly lines.

Add these lines to your /test/test_helper.rb file to get perfectly clean Rails backtraces:

class Test::Unit::TestCase
  self.backtrace_silencers << :rails_vendor
  self.backtrace_filters   << :rails_root
end

Ongoing development