reliable unit test logging

[Vyacheslav Maslov]

Hi all!

I have many many many python unit test, which are used for testing some
remote web service.

The most important issue here is logging of test execution process and
result. I strongly need following:
1. start/end timestamp for each test case (most important)
2. immediate report about exceptions (stacktrace)
3. it will be nice to use logging module for output

I have investigated some extension for standard unittest module, e.g.
testoob, nose, etc. They have very nice features but they does not
satisfy first requirement in my list - test execution logs not doesn't
contain timestamps.

Can someone explain my why so simple feature like logging of timestamps
during test execution was not implemented in any extension?

Also i need some advices about how i can implement timestamps logging
myself. I think proper way is develop customized TextTestRunner and use
logging module instead of "print"s. Is it right way or there is more simply?

 

[Ben Finney]

I have many many many python unit test, which are used for testing
some remote web service.

Part of your confusion comes from the fact that "test a remote
service" isn't what a unit test does.

A unit test is one that executes a very *limited* part of the code: it
tests a code unit, not the whole system, and makes a simple set of
assertions about the result. If there are accesses to remote services
over the network, that's far beyond the scope of a unit test.

I don't doubt that you may be using the Python standard library module
'unittest' to perform these tests. But they're not unit tests; they're
integration tests, or system tests, or performance tests, or something
else.

Can someone explain my why so simple feature like logging of
timestamps during test execution was not implemented in any
extension?

Probably because the most important thing to know for the purpose of a
unit test is whether the yes/no assertions were violated. Knowing when
the tests start and finish isn't interesting. If start and finish
times *are* interesting for your tests, you're *not* doing unit
testing, but some other form of testing like performance tests.


That said, you *can* certainly instrument the unittest.TestCase with
timings if you want to use it for a performance test. Every instance
of a TestCase will invoke its setUp method to set up test fixtures,
and its tearDown method to tear down fixtures. You can use that hook
to implement logging.

Untested code, that should give you enough to try it out yourself:

import unittest
import logging

logging.basicConfig(level=logging.INFO,
datefmt="%Y-%m-%d %H:%M:%S",
format="%(asctime)s:%(levelname)s:%(message)s")

class TimedTestCase(unittest.TestCase):
""" A test case that will log its start and end times """

def setUp(self):
""" Set up test fixtures """
logging.info("test case setup")

def tearDown(self):
""" Tear down test fixtures """
logging.info("test case teardown")

class Test_FooBar(TimedTestCase):
""" Test cases for FooBar """

def test_slices_spam(self):
""" FooBar should slice spam """
self.failUnless(sends_spam)

def test_eats_eggs(self):
""" FooBar should eat eggs """
self.failUnless(eats_eggs)

 

[Vyacheslav Maslov]

Part of your confusion comes from the fact that "test a remote
service" isn't what a unit test does.

A unit test is one that executes a very *limited* part of the code: it
tests a code unit, not the whole system, and makes a simple set of
assertions about the result. If there are accesses to remote services
over the network, that's far beyond the scope of a unit test.

I don't doubt that you may be using the Python standard library module
'unittest' to perform these tests. But they're not unit tests; they're
integration tests, or system tests, or performance tests, or something
else.


Probably because the most important thing to know for the purpose of a
unit test is whether the yes/no assertions were violated. Knowing when
the tests start and finish isn't interesting. If start and finish
times *are* interesting for your tests, you're *not* doing unit
testing, but some other form of testing like performance tests.

I understand your opinion, you are right, i use unit tests for some
other kind of work. But anyway it works and produce good results for
project.

Untested code, that should give you enough to try it out yourself:

Thanks i will look into this.

 

[Ben Finney]

I understand your opinion

Hopefully you mean "explanation", not "opinion". I gave what appear to
me to be facts, not opinion, about the definition of a unit test.

you are right, i use unit tests for some other kind of work.

More accurately: you use the Python 'unittest' framework for some
tests that are not unit tests.

But anyway it works and produce good results for project.

Indeed, there's nothing wrong with using the module this way. The only
trouble in this case is confused terminology, that has led you to
believe the module is deficient, when actually it's doing the job it's
meant to do.

Thanks i will look into this.

Glad to help.

 

[Vyacheslav Maslov]

Hopefully you mean "explanation", not "opinion". I gave what appear to
me to be facts, not opinion, about the definition of a unit test.

Yes, i meant "explanation".

I have one more question related to logging module, not unit test. I use
FileHandler to append information to file log, in fact location of log
file depends on some external factor and is calculated during
initialization. Furthermore i want to use configuration file because it
is comfortable way. So i need way to define in configuration file some
variable which should evaluated during logging system initialization, i
try following way:

[handler_hand02]
class=FileHandler
level=NOTSET
formatter=form01
args=(logFileDir+"myfile.log","a",)
logFileDir is defined in scope of module which call
logging.config.fileConfig()

and it produces "name 'logFileDir' is not defined" exception. As i
understand this happens because inside logging module variable
logFileDir is not visible. How i can avoid this?

Thanks!



--

 

[Ben Finney]

I have one more question related to logging module, not unit test.

Please do readers a favour, then, and start a new thread (i.e. compose
a new message, not a reply in an existing thread) for unrelated
questions.

 

[Gabriel Genellina]

I have one more question related to logging module, not unit test. I use
FileHandler to append information to file log, in fact location of log
file depends on some external factor and is calculated during
initialization. Furthermore i want to use configuration file because it
is comfortable way. So i need way to define in configuration file some
variable which should evaluated during logging system initialization, i
try following way:

[handler_hand02]
class=FileHandler
level=NOTSET
formatter=form01
args=(logFileDir+"myfile.log","a",)
logFileDir is defined in scope of module which call
logging.config.fileConfig()

and it produces "name 'logFileDir' is not defined" exception. As i
understand this happens because inside logging module variable
logFileDir is not visible. How i can avoid this?

logging.config uses the ConfigParser class; ConfigParser has some
interpolation mechanism.
I think this should work (but I've not tested it):

[handler_hand02]
class=FileHandler
level=NOTSET
formatter=form01
args=("%(logFileDir)s"+"myfile.log","a",)

and call it using logging.config.fileConfig({"logFileDir":
"your/desired/path"})