Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > comp.lang.python > #68240 > unrolled thread

unittest weirdness

Back to article view | Back to comp.lang.python

Contents

  unittest weirdness Ethan Furman <ethan@stoneleaf.us> - 2014-03-11 13:58 -0700
    Re: unittest weirdness John Gordon <gordon@panix.com> - 2014-03-11 22:13 +0000
      Re: unittest weirdness Ethan Furman <ethan@stoneleaf.us> - 2014-03-11 15:29 -0700
      Re: unittest weirdness Terry Reedy <tjreedy@udel.edu> - 2014-03-11 23:36 -0400
      Re: unittest weirdness Ethan Furman <ethan@stoneleaf.us> - 2014-03-12 03:03 -0700
        Re: unittest weirdness Roy Smith <roy@panix.com> - 2014-03-12 09:44 -0400
          Re: unittest weirdness Ethan Furman <ethan@stoneleaf.us> - 2014-03-12 08:32 -0700
            Re: unittest weirdness Roy Smith <roy@panix.com> - 2014-03-12 13:48 -0400
            Re: unittest weirdness Steven D'Aprano <steve+comp.lang.python@pearwood.info> - 2014-03-12 23:14 +0000
            Re: unittest weirdness Steven D'Aprano <steve+comp.lang.python@pearwood.info> - 2014-03-12 23:47 +0000
              Re: unittest weirdness Ethan Furman <ethan@stoneleaf.us> - 2014-03-12 17:31 -0700
          Re: unittest weirdness Terry Reedy <tjreedy@udel.edu> - 2014-03-12 22:27 -0400
    Re: unittest weirdness Steven D'Aprano <steve+comp.lang.python@pearwood.info> - 2014-03-12 23:38 +0000
      Re: unittest weirdness Ethan Furman <ethan@stoneleaf.us> - 2014-03-12 17:36 -0700

#68240 — unittest weirdness

So I finally got enough data and enough of an understanding to write some unit tests for my code.

These aren't the first unit tests I've written, but the behavior I'm getting is baffling.

I'm using 2.7.4 and I'm testing some routines which attempt to interpret data from a flat file and create a new flat 
file for later programmatic consumption.

The weird behavior I'm getting:

   - when a test fails, I get the E or F, but no summary at the end
     (if the failure occurs in setUpClass before my tested routines
     are actually called, I get the summary; if I run a test method
     individually I get the summary)

   - I have two classes, but only one is being exercised

   - occasionally, one of my gvim windows is unceremoniously killed
    (survived only by its swap file)

I'm running the tests under sudo as the routines expect to be run that way.

Anybody have any ideas?

--
~Ethan~

--snippet of code--

from VSS.path import Path
from unittest import TestCase, main as Run
import wfbrp

class Test_wfbrp_20140225(TestCase):

     @classmethod
     def setUpClass(cls):
         cls.pp = wfbrp.PaymentProcessor(
             '.../lockbox_file',
             '.../aging_file',
             [
                 Path('month_end_1'),
                 Path('month_end_2'),
                 Path('month_end_3'),
                 ],
             )

     def test_xxx_1(self):
         p = self.pp.lockbox_payments[0]
         # affirm we have what we're expecting
         self.assertEqual(
                 (p.payer, p.ck_num, p.credit),
                 ('a customer', '010101', 10000),
                 )
         self.assertEqual(p.invoices.keys(), ['XXXXXXXXXXX'])
         self.assertEqual(p.invoices.values()[0].amount, 10000)
         # now make sure we get back what we're expecting
         np, b = self.pp._match_invoices(p)
         missing = []
         for inv_num in ('123456', '789012', '345678'):
             if inv_num not in b:
                 missing.append(inv_num)
         if missing:
             raise ValueError('invoices %r missing from batch' % missing)

[toc] | [next] | [standalone]

#68242

In <mailman.8062.1394573210.18130.python-list@python.org> Ethan Furman <ethan@stoneleaf.us> writes:

>          if missing:
>              raise ValueError('invoices %r missing from batch' % missing)

It's been a while since I wrote test cases, but I recall using the assert*
methods (assertEqual, assertTrue, etc.) instead of raising exceptions.
Perhaps that's the issue?

-- 
John Gordon         Imagine what it must be like for a real medical doctor to
gordon@panix.com    watch 'House', or a real serial killer to watch 'Dexter'.

[toc] | [prev] | [next] | [standalone]

#68247

On 03/11/2014 03:13 PM, John Gordon wrote:
> Ethan Furman writes:
>
>>           if missing:
>>               raise ValueError('invoices %r missing from batch' % missing)
>
> It's been a while since I wrote test cases, but I recall using the assert*
> methods (assertEqual, assertTrue, etc.) instead of raising exceptions.
> Perhaps that's the issue?

Drat.  Tried it, same issue.  O/S kills it.  :(

--
~Ethan~

[toc] | [prev] | [next] | [standalone]

#68259

On 3/11/2014 6:13 PM, John Gordon wrote:
> In <mailman.8062.1394573210.18130.python-list@python.org> Ethan Furman <ethan@stoneleaf.us> writes:
>
>>           if missing:
>>               raise ValueError('invoices %r missing from batch' % missing)
>
> It's been a while since I wrote test cases, but I recall using the assert*
> methods (assertEqual, assertTrue, etc.) instead of raising exceptions.
> Perhaps that's the issue?

Yes. I believe the methods all raise AssertionError on failure, and the 
test methods are wrapped with try:.. except AssertionError as err:

    if missing:
      raise ValueError('invoices %r missing from batch' % missing)

should be "assertEqual(missing, [], 'invoices missing from batch')" and 
if that fails, the non-empty list is printed along with the message.

-- 
Terry Jan Reedy

[toc] | [prev] | [next] | [standalone]

#68271

On 03/11/2014 08:36 PM, Terry Reedy wrote:
> On 3/11/2014 6:13 PM, John Gordon wrote:
>> In <mailman.8062.1394573210.18130.python-list@python.org> Ethan Furman <ethan@stoneleaf.us> writes:
>>
>>>           if missing:
>>>               raise ValueError('invoices %r missing from batch' % missing)
>>
>> It's been a while since I wrote test cases, but I recall using the assert*
>> methods (assertEqual, assertTrue, etc.) instead of raising exceptions.
>> Perhaps that's the issue?
>
> Yes. I believe the methods all raise AssertionError on failure, and the test methods are wrapped with try:.. except
> AssertionError as err:
>
>     if missing:
>       raise ValueError('invoices %r missing from batch' % missing)
>
> should be "assertEqual(missing, [], 'invoices missing from batch')" and if that fails, the non-empty list is printed
> along with the message.

I've tried it both ways, and both ways my process is being killed, presumably by the O/S.

I will say it's an extra motivating factor to have few failing tests -- if more than two of my tests fail, all I see are 
'.'s, 'E's, and 'F's, with no clues as to which test failed nor why.  Thank goodness for '-v' and being able to specify 
which method of which class to run!

--
~Ethan~

[toc] | [prev] | [next] | [standalone]

#68280

In article <mailman.8082.1394620172.18130.python-list@python.org>,
 Ethan Furman <ethan@stoneleaf.us> wrote:

> I've tried it both ways, and both ways my process is being killed, presumably 
> by the O/S.

What evidence do you have the OS is killing the process?

Some systems have an oom (Out Of Memory) process killer, which nukes 
(semi-random) process when the system exhausts memory.  Is it possible 
this is happening?  If so, you should see some log message in one of 
your system logs.

You didn't mention (or maybe I misssed it) which OS you're using.  I'm 
assuming you've got some kind of system call tracer (strace, truss, 
dtrace, etc).  Try running your tests under that.  If something is 
sending your process a kill signal, you'll see it:

[gazillions of lines elided]
write(1, ">>> ", 4>>> )                     = 4
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
select(1, [0], NULL, NULL, NULL)        = ? ERESTARTNOHAND (To be 
restarted)
--- SIGTERM (Terminated) @ 0 (0) ---
+++ killed by SIGTERM +++

Alternatively, maybe something inside your process is just calling 
sys.exit(), or even os._exit().  You'll see the exit() system call in 
the strace output.

And, of course, the standard suggestion to reduce this down to the 
minimum test case.  You posted:

     def test_xxx_1(self):
         p = self.pp.lockbox_payments[0]
         # affirm we have what we're expecting
         self.assertEqual(
                 (p.payer, p.ck_num, p.credit),
                 ('a customer', '010101', 10000),
                 )
         self.assertEqual(p.invoices.keys(), ['XXXXXXXXXXX'])
         self.assertEqual(p.invoices.values()[0].amount, 10000)
         # now make sure we get back what we're expecting
         np, b = self.pp._match_invoices(p)
         missing = []
         for inv_num in ('123456', '789012', '345678'):
             if inv_num not in b:
                 missing.append(inv_num)
         if missing:
             raise ValueError('invoices %r missing from batch' % missing)

what happens if you reduce that to:

     def test_xxx_1(self):
          self.fail()

do you still get this strange behavior?  What if you get rid of your 
setUpClass()?  Keep hacking away at the test suite until you get down to 
a single line of code which, if run, exhibits the behavior, and if 
commented out, does not.  At that point, you'll have a clue what's 
causing this.  If you're lucky :-)

[toc] | [prev] | [next] | [standalone]

#68287

On 03/12/2014 06:44 AM, Roy Smith wrote:
> In article <mailman.8082.1394620172.18130.python-list@python.org>,
>   Ethan Furman <ethan@stoneleaf.us> wrote:
>
>> I've tried it both ways, and both ways my process is being killed, presumably
>> by the O/S.
>
> What evidence do you have the OS is killing the process?

I put a bare try/except around the call to unittest.main, with a print statement in the except, and nothing ever prints.


> Some systems have an oom (Out Of Memory) process killer, which nukes
> (semi-random) process when the system exhausts memory.  Is it possible
> this is happening?  If so, you should see some log message in one of
> your system logs.

That would explain why my editor windows were being killed.


> You didn't mention (or maybe I misssed it) which OS you're using.

Ubuntu 13 something or other.

> I'm
> assuming you've got some kind of system call tracer (strace, truss,
> dtrace, etc).

Sadly, I have no experience with those programs yet, and until now didn't even know they existed.

> Try running your tests under that.  If something is
> sending your process a kill signal, you'll see it:
>
> [gazillions of lines elided]
> write(1, ">>> ", 4>>> )                     = 4
> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
> select(1, [0], NULL, NULL, NULL)        = ? ERESTARTNOHAND (To be
> restarted)
> --- SIGTERM (Terminated) @ 0 (0) ---
> +++ killed by SIGTERM +++
>
> Alternatively, maybe something inside your process is just calling
> sys.exit(), or even os._exit().  You'll see the exit() system call in
> the strace output.

My bare try/except would have caught that.


> And, of course, the standard suggestion to reduce this down to the
> minimum test case.  You posted:
>
>       def test_xxx_1(self):
>           p = self.pp.lockbox_payments[0]
>           # affirm we have what we're expecting
>           self.assertEqual(
>                   (p.payer, p.ck_num, p.credit),
>                   ('a customer', '010101', 10000),
>                   )
>           self.assertEqual(p.invoices.keys(), ['XXXXXXXXXXX'])
>           self.assertEqual(p.invoices.values()[0].amount, 10000)
>           # now make sure we get back what we're expecting
>           np, b = self.pp._match_invoices(p)
>           missing = []
>           for inv_num in ('123456', '789012', '345678'):
>               if inv_num not in b:
>                   missing.append(inv_num)
>           if missing:
>               raise ValueError('invoices %r missing from batch' % missing)
>
> what happens if you reduce that to:
>
>       def test_xxx_1(self):
>            self.fail()

I only get the strange behavior if more than two (or maybe three) of my test cases fail.  Less than that magic number, 
and everything works just fine.  It doesn't matter which two or three, either.


> do you still get this strange behavior?  What if you get rid of your
> setUpClass()?  Keep hacking away at the test suite until you get down to
> a single line of code which, if run, exhibits the behavior, and if
> commented out, does not.  At that point, you'll have a clue what's
> causing this.  If you're lucky :-)

I strongly suspect it's memory.  When I originally wrote the code I tried to include six months worth of EoM data, but 
had to back it down to three as my process kept mysteriously dying at four or more months.  There must be waaaaaaay too 
much stuff being kept alive by the stack traces of the failed tests.

Thanks for your help!

--
~Ethan~

[toc] | [prev] | [next] | [standalone]

#68289

In article <mailman.8095.1394640002.18130.python-list@python.org>,
 Ethan Furman <ethan@stoneleaf.us> wrote:

> > Alternatively, maybe something inside your process is just calling
> > sys.exit(), or even os._exit().  You'll see the exit() system call in
> > the strace output.
> 
> My bare try/except would have caught that.

A bare except would catch sys.exit(), but not os._exit().  Well, no 
that's not actually true.  Calling os._exit() will raise:

TypeError: _exit() takes exactly 1 argument (0 given)

but it won't catch os._exit(0) :-)

> > what happens if you reduce that to:
> >
> >       def test_xxx_1(self):
> >            self.fail()
> 
> I only get the strange behavior if more than two (or maybe three) of my test 
> cases fail.  Less than that magic number, 
> and everything works just fine.  It doesn't matter which two or three, 
> either.

OK, well, assuming this is a memory problem, what if you do:

      def test_xxx_1(self):
           l = []
           while True:
               l.append(0)

That should eventually run out of memory.  Does that get you the same 
behavior in a single test case?  If so, that at least would be evidence 
supporting the memory exhaustion theory.

> I strongly suspect it's memory.  When I originally wrote the code I tried to 
> include six months worth of EoM data, but 
> had to back it down to three as my process kept mysteriously dying at four or 
> more months.  There must be waaaaaaay too 
> much stuff being kept alive by the stack traces of the failed tests.

One thing you might try is running your tests under nose 
(http://nose.readthedocs.org/).  Nose knows how to run unittest tests, 
and one of the gazillion options it has is to run each test case in an 
isolated process:

  --process-restartworker
                If set, will restart each worker process once their
                tests are done, this helps control memory leaks from
                killing the system. [NOSE_PROCESS_RESTARTWORKER]

that might be what you need.

[toc] | [prev] | [next] | [standalone]

#68310

On Wed, 12 Mar 2014 08:32:29 -0700, Ethan Furman wrote:

> There must
> be waaaaaaay too much stuff being kept alive by the stack traces of the
> failed tests.


I believe that unittest does keep stack traces alive until the process 
ends. I thought that there was a recent bug report for it, but the only 
one I can find was apparently fixed more than a decade ago:

http://bugs.python.org/issue451309





-- 
Steven D'Aprano
http://import-that.dreamwidth.org/

[toc] | [prev] | [next] | [standalone]

#68314

On Wed, 12 Mar 2014 08:32:29 -0700, Ethan Furman wrote:

>> Some systems have an oom (Out Of Memory) process killer, which nukes
>> (semi-random) process when the system exhausts memory.  Is it possible
>> this is happening?  If so, you should see some log message in one of
>> your system logs.
> 
> That would explain why my editor windows were being killed.


Try opening a second console tab and running top in it. It will show the 
amount of memory being used. Then run the tests in the first, jump back 
to top, and watch to see if memory use goes through the roof:

top -Mm -d 0.5

will sort by memory use, display memory in more sensible human-readable 
units instead of bytes, and update the display every 0.5 second. You can 
then hit the "i" key to toggle display of idle processes and only show 
those that are actually doing something (which presumably will include 
Python running the tests).

This at least will allow you to see whether or not memory is the concern.




-- 
Steven D'Aprano
http://import-that.dreamwidth.org/

[toc] | [prev] | [next] | [standalone]

#68316

On 03/12/2014 04:47 PM, Steven D'Aprano wrote:
>
> top -Mm -d 0.5

Cool, thanks!

--
~Ethan~

[toc] | [prev] | [next] | [standalone]

#68320

On 3/12/2014 11:32 AM, Ethan Furman wrote:

> I strongly suspect it's memory.  When I originally wrote the code I
> tried to include six months worth of EoM data, but had to back it down
> to three as my process kept mysteriously dying at four or more months.
> There must be waaaaaaay too much stuff being kept alive by the stack
> traces of the failed tests.

There is an issue or two about unittest not releasing memory. Also, 
modules are not cleared from sys.modules, so anything accessible from 
global scope is kept around.

-- 
Terry Jan Reedy

[toc] | [prev] | [next] | [standalone]

#68313

On Tue, 11 Mar 2014 13:58:17 -0700, Ethan Furman wrote:

> class Test_wfbrp_20140225(TestCase):
> 
>      @classmethod
>      def setUpClass(cls):
>          cls.pp = wfbrp.PaymentProcessor(
>              '.../lockbox_file',
>              '.../aging_file',
>              [
>                  Path('month_end_1'),
>                  Path('month_end_2'),
>                  Path('month_end_3'),
>                  ],
>              )

This has nothing to do with your actual problem, which appears to be the 
Linux(?) OOM killer reaping your applications, just some general 
observations on your test.


>      def test_xxx_1(self):

Having trouble thinking up descriptive names for the test? That's a sign 
that the test might be doing too much. Each test should check one self-
contained thing. That may or may not be a single call to a unittest 
assert* method, but it should be something you can describe in a few 
words:

"it's a regression test for bug 23"
"test that the database isn't on fire"
"invoices should have a valid debtor"
"the foo report ought to report all the foos"
"...and nothing but the foos."

This hints -- its just a hint, mind you, since I lack all specific 
knowledge of your application -- that the following "affirm" tests should 
be pulled out into separate tests.

>          p = self.pp.lockbox_payments[0]
>          # affirm we have what we're expecting 
>          self.assertEqual(
>                  (p.payer, p.ck_num, p.credit),
>                  ('a customer', '010101', 10000),
>                  )
>          self.assertEqual(p.invoices.keys(), ['XXXXXXXXXXX'])
>          self.assertEqual(p.invoices.values()[0].amount, 10000)

which would then leave this to be the Actual Thing Being Tested for this 
test, which then becomes test_no_missing_invoices rather than test_xxx_1.

>          # now make sure we get back what we're expecting 
>          np, b = self.pp._match_invoices(p)
>          missing = []
>          for inv_num in ('123456', '789012', '345678'):
>              if inv_num not in b:
>                  missing.append(inv_num)
>          if missing:
>              raise ValueError('invoices %r missing from batch' %
>              missing)

Raising an exception directly inside the test function should only occur 
if the test function is buggy. As Terry has already suggested, this 
probably communicates your intention much better:

    self.assertEqual(missing, [])



-- 
Steven D'Aprano
http://import-that.dreamwidth.org/

[toc] | [prev] | [next] | [standalone]

#68317

On 03/12/2014 04:38 PM, Steven D'Aprano wrote:
>
> [snip lots of good advice for unit testing]

I was just removing the Personally Identifiable Information.  Each test is pulling a payment from a batch of payments, 
so the first couple asserts are simply making sure I have the payment I think I have, then I run the routine that is 
supposed to match that payment with a bunch of invoices, and then I test to make sure I got back the invoices that I 
have manually verified are the correct ones to be returned.

There are many different tests because there are many different paths through the code, depending on exactly which 
combination of insanities the bank, the customer, and the company choose to inflict at that moment.  ;)

--
~Ethan~

[toc] | [prev] | [standalone]

Back to top | Article view | comp.lang.python

csiph-web