Case study: debugging failed assertRaises bug

S

Steven D'Aprano

I've just spent two hours banging my head against what I *thought*
(wrongly!) was a spooky action-at-a-distance bug in unittest, so I
thought I'd share it with anyone reading.

I have a unit test which I inherit from a mixin class that looks
something like this:

def testBadArgType(self):
# Test failures with bad argument types.
for d in (None, 23, object(), "spam"):
self.assertRaises(TypeError, self.func, d)

Seems pretty simple, right? But it was mysteriously failing with one of
my functions. The first problem is that assertRaises doesn't take a
custom error message when it fails, so all I was seeing was this:

Traceback (most recent call last):
File "src/test_stats_extras.py", line 1122, in testBadArgType
self.assertRaises(TypeError, self.func, d)
AssertionError: TypeError not raised by <lambda>

Don't be put off by the lambda. That's just a thin wrapper around the
function I actually am testing: the mixin test class assumes the test
function takes a single argument, but my function actually requires two.
So I use a lambda as a wrapper to provide the second argument.

Since I'm pretty sure that my function really does fail with TypeError, I
add a line to fail *hard*. Immediately before the assertRaises, I add an
extra call like this:

_ = self.func(d)

Sure enough, it fails on the direct call to self.func, but not on the
assertRaises. Now I'm getting seriously weirded out: if I call the test
function (or its wrapper) directly, I get the expected TypeError, but if
I call it via assertRaises, it doesn't raise.

So I bang away on the test for a while, replace the assertRaises with an
assertEqual, and sure enough the assertEqual fails with an exception. At
this point I'm *convinced* it's some weird bug in unittest, and I'm
trying to come up with a short example so I can raise a bug report. But I
can't replicate the bug.

So I ended up putting this in my test code:

# This next line now PASSES (i.e. exception is raised),
# but ONLY if it is followed by another (failing) test!
self.assertRaises(Exception, self.func, d)
self.assertEqual(self.func(d), 100)

and was nearly ready to throw in the towel and just flag the test as
"skipped" and deal with it later, when I thought of the good old
fashioned "add some prints inside your code". That's a bit trickier for
unittest, because it prints its output to stderr rather than stdout, but
in Python 3 that's easy to deal with. So I ended up with:


func = self.func
print("expecting TypeError ", end='', file=sys.stderr)
try:
_ = func(d)
except TypeError:
# I expect TypeError.
print("and got it ", end='', file=sys.stderr)
else:
print("but got %r " % _, end='', file=sys.stderr)
# This FAILS (i.e. no exception is raised).
self.assertRaises(TypeError, func, d)


and unit test prints:

.......................... expecting TypeError and got it expecting
TypeError and got it expecting TypeError and got it expecting TypeError
but got 'm' F......................................................
======================================================================
FAIL: testBadArgType (__main__.QuantileBehaviourTest)
----------------------------------------------------------------------
Traceback (most recent call last):
File "src/test_stats_extras.py", line 1122, in testBadArgType
self.assertRaises(TypeError, func, d)
AssertionError: TypeError not raised by <lambda>


/facepalm/


That explains everything, even the spooky action-at-a-distance stuff. It
is a bug in my own code, not unittest, not the mixin, not the lambda, but
my function should be failing when called with a string but doesn't.

So, lessons learned...

(1) assertRaises REALLY needs a better error message. If not a custom
message, at least it should show the result it got instead of an
exception.

(2) Never underestimate the power of print. Sticking a print statement in
the middle of problematic code is a powerful debugging technique.

(3) If you think you've found a bug in Python, it almost certainly is a
bug in your own code. I knew that already, but now I have the scars to
prove it.

(4) Unit tests should test one thing, not four. I thought my loop over
four different "bad input" arguments was one conceptual test, and that
ended up biting me. If the failing test was "testBadArgTypeStr" I would
have realised what was going on much faster.

(5) There's only so many tiny little tests you can write before your head
explodes, so I'm going to keep putting "for arg in spam" loops in my
tests. But now I know to unroll those suckers into individual tests on
the first sign of trouble.
 
R

Raymond Hettinger

I've just spent two hours banging my head against what I *thought*
(wrongly!) was a spooky action-at-a-distance bug in unittest, so I
thought I'd share it with anyone reading.

Thanks for telling your story.
I'm sure the lessons learned
will be helpful to your readers.


Raymond
twitter: @raymondh
 
R

R David Murray

Ben Finney said:
+1

Is this one of the many improvements in Python 3.2's ‘unittest’ that
Michael Foord presided over? Or are we still stuck with the terrible
behaviour of ‘assertRaises’?

No, but issue 10775 [1] is just waiting for Michael (or someone else
who has time) to commit the patch.

--David

[1] http://bugs.python.org/issue10775
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Members online

Forum statistics

Threads
473,768
Messages
2,569,574
Members
45,049
Latest member
Allen00Reed

Latest Threads

Top