Hate seeing warnings in your test output? Yeah me too. Came across a fairly weird bug today and this is how I debugged it.
With a recent checkin I started seeing some warnings in the test output, like this:
1 2 3 4 5 6 7 8 9 10 11
If life’s easy, you’ll see the test files name along with the warnings. However, in this case, the trace only contains an erb partial. The partial looked something like this:
1 2 3
Typically this warning happens when you call
#id on an object that
nil. In this case, looks like someone already thought
of that – and used
specifically to avoid this warning.
What gives? What complicates this is that our test suite has 1000+ tests and the partial that shows the erorr is used widely. (You could try deleting the partial and see what fails but in this case 90% of the tests would fail).
After some more trial and error, I started reading the Test::Unit
source on github. That with some introspection showed that you can get
the running test’s name at runtime with the
#name method. Duh!
So I added a
teardown to the suite:
1 2 3 4 5 6 7 8 9 10 11 12 13 14
With that, my test suit printed out the name of every test right after
. – and looking through the output for the warning showed me the
test that was causing it:
1 2 3
This gave me the lead I needed. Now it took some more debugging to
figure out the details (I’ll spare you the rest) but it turns out a
method 4-5 levels down was retruning
false instead of
#try works beautifully for
nil but not for
1 2 3 4 5 6
So there you go. It sure was an entertaining session for me. And if you read it till here…
More techniques about how I could have debugged this more easily are most welcome.