[IPython-dev] Test failures and errors in trunk

Wed Mar 18 18:11:13 EDT 2009

Howdy,

On Wed, Mar 18, 2009 at 1:24 PM, Brian Granger <ellisonbg.net at gmail.com> wrote:
> Hi,
>
> I pulled the latest trunk this morning and ran the test suite.  I got
> a huge mess of errors and failures.  My pre-merge branch had none of
> this, so the recent merges have introduced many new bugs.
>
> Some of these bugs look to be very subtle and related to the deep
> mysteries of Twisted.

............................................................................................................................................................................................E...........F.........F.......S....S......SS..SSS..............SSS....
> ======================================================================
> ERROR: Failure: ImportError (No module named Numeric)
> ----------------------------------------------------------------------

This one should be protected so it doesn't run without numeric, like
Jorgen said earlier.  I didn't realize I'd left a Numeric-dependent
test in there.  My Python install has just about everything, so I
didn't see these.

> ======================================================================
> ERROR: testExecuteFailuresEngineService_0
> ----------------------------------------------------------------------
> Traceback (most recent call last):
>  File "/Users/bgranger/Library/Python/2.5/site-packages/Twisted-8.2.0pre1-py2.5-macosx-10.5-i386.egg/twisted/internet/base.py",
> line 729, in runUntilCurrent
>    f(*a, **kw)
>  File "/Users/bgranger/Library/Python/2.5/site-packages/Twisted-8.2.0pre1-py2.5-macosx-10.5-i386.egg/twisted/internet/defer.py",
> line 269, in errback
>    self._startRunCallbacks(fail)
>  File "/Users/bgranger/Library/Python/2.5/site-packages/Twisted-8.2.0pre1-py2.5-macosx-10.5-i386.egg/twisted/internet/defer.py",
> line 298, in _startRunCallbacks
>    raise AlreadyCalledError
> AlreadyCalledError

This one, I've seen occasionally, and I remember we've talked about it
several times.  It's completely non-deterministic, and you said that
you'd also seen it some times.  I'd love to know how to track it, but
I have no clue: it's obviously deep in Twisted.
This isn't just a Heisenbug, it's a Twisted Heisenbug :)

> ======================================================================
> FAIL: Doctest: IPython.testing.plugin.dtexample.ipfunc
> ----------------------------------------------------------------------
> Traceback (most recent call last):
>  File "/Users/bgranger/Documents/Computation/IPython/Code/ipython/IPython/testing/plugin/ipdoctest.py",
> line 382, in runTest
>    raise self.failureException(self.format_failure(new.getvalue()))
> AssertionError: Failed doctest test for IPython.testing.plugin.dtexample.ipfunc
>  File "/Users/bgranger/Documents/Computation/IPython/Code/ipython/IPython/testing/plugin/dtexample.py",
> line 27, in ipfunc
>
> ----------------------------------------------------------------------
> File "/Users/bgranger/Documents/Computation/IPython/Code/ipython/IPython/testing/plugin/dtexample.py",
> line 44, in IPython.testing.plugin.dtexample.ipfunc
> Failed example:
>    _ip.system("echo hello")
> Exception raised:
>    Traceback (most recent call last):
>      File "/System/Library/Frameworks/Python.framework/Versions/2.5/lib/python2.5/doctest.py",
> line 1212, in __run
>        compileflags, 1) in test.globs
>      File "<doctest IPython.testing.plugin.dtexample.ipfunc[3]>",
> line 1, in <module>
>        _ip.system("echo hello")
>      File "/Users/bgranger/Documents/Computation/IPython/Code/ipython/IPython/testing/plugin/ipdoctest.py",
> line 137, in xsys
>        sys.stdout.write(commands.getoutput(cmd))
>      File "/System/Library/Frameworks/Python.framework/Versions/2.5/lib/python2.5/commands.py",
> line 44, in getoutput
>        return getstatusoutput(cmd)[1]
>      File "/System/Library/Frameworks/Python.framework/Versions/2.5/lib/python2.5/commands.py",
> line 54, in getstatusoutput
>        text = pipe.read()
>    IOError: [Errno 4] Interrupted system call

Now, these stump me: you see several of these, which I've never ever
seen.  I wonder if the commands.py module behaves differently on
different OSes.

It's important that we can run these tests reliably, because those are
the ones that let us do full 'real ipython' testing.

> Ran 515 tests in 57.113s
> FAILED (SKIP=11, errors=3, failures=2)

In all, you get three errors, so it's not *that bad*, considering we
added over 100 new tests.  Those are:

1. The twisted heisenbug.  No idea, this one has been haunting us for
well over a year (I remember talking to you about it back when I was
still in Boulder).  It's only that now I see it more often (I'd say
now I see it ~80% of the time, before it was more like ~40%).

2. The Numeric dependency.  Easy to fix.  In fact, I need to clean
many more of those, for people who don't have MPL or other packages
(c.f. conversation earlier with Jorgen).

3. The IOError on OSX.  I have no clue on that one, but I'll think
about it.  It's extremely strange.

On my box, I get:

Ran 515 tests in 43.525s

FAILED (SKIP=11, errors=1)

The error is #1 above, I don't get 2 and 3 (2 because I have Numeric,
3 I don't know).

I'm actually much more worried about the fact that today, John Hunter
discovered that my lovely fix to

 https://bugs.launchpad.net/ipython/+bug/269966

actually can cause problems with MPL (open figure objects hold
references to the old module objects that get zeroed out).  I'm
actually starting to wonder if this isn't a bug with Python itself, in
how it clears module objects ignoring reference counts (or that's what
appears to be happening, at least).

Relax :)  That's why I wanted all that testing support code merged in:
because by enabling many more tests to run, it's likely to show us
these problems.  Now we can actually target them for fixing :)

Cheers,

f