How to use doctest with logging?

Question

The following doctest fails:

import logging
logging.basicConfig(level=logging.DEBUG,format='%(message)s')

def say_hello():
  '''
  >>> say_hello()
  Hello!
  '''
  logging.info('Hello!')

if __name__ == '__main__':
    import doctest
    doctest.testmod()

These pages

• doctest & logging
• use doctest and logging in python program

seem to suggest logging.StreamHandler(sys.stdout) and logger.addHandler(handler) but my attempts failed in this respect. (I am new to python, if it wasn't obvious .)

Please help me fix the above code so that the test passes.

---

Update on Jun 4, 2017: To answer 00prometheus' comments: The accepted answer to use doctest and logging in python program, when I asked this question, seemed unnecessarily complicated. And indeed it is, as the accepted answer here gives a simpler solution. In my highly biased opinion, my question is also clearer than the one I already linked in the original post.

Answer 1

You need to define a "logger" object. This is usually done after import with:

import sys
import logging
log = logging.getLogger(__name__)

When you want to log a message:

log.info('Hello!')

In the code that gets run like a script you set the basicConfig:

if __name__ == '__main__':
    import doctest
    logging.basicConfig(level=logging.DEBUG, stream=sys.stdout, format='%(message)s')
    doctest.testmod()

Edit:

Ok, you were right. It doesn't work, but I got it to work...BUT DO NOT DO THIS! Just use print statements or return what you actually need to check. As your second link says this is just a bad idea. You shouldn't be checking logging output (its for logging). Even the original poster for that second link said they got it to work by switching their logging to using print. But here is the evil code that seems to work:

class MyDocTestRunner(doctest.DocTestRunner):
    def run(self, test, compileflags=None, out=None, clear_globs=True):
        if out is None:
            handler = None
        else:
            handler = logging.StreamHandler(self._fakeout)
            out = sys.stdout.write
        logger = logging.getLogger() # root logger (say)
        if handler:
            logger.addHandler(handler)
        try:
            doctest.DocTestRunner.run(self, test, compileflags, out, clear_globs)
        finally:
            if handler:
                logger.removeHandler(handler)
                handler.close()
    
if __name__ == '__main__':
    logging.basicConfig(level=logging.DEBUG, format='%(message)s')
    tests = doctest.DocTestFinder().find(say_hello, __name__)
    dt_runner = MyDocTestRunner()
    for t in tests:
        dt_runner.run(t, out=True)

Edit (continued):

My attempts also failed when trying what your second link suggested. This is because internally doctest reassigns sys.stdout to self._fakeout. That's why nothing short of my hack will work. I actually tell the logger to write to this "fakeout".

Edit (answer to comment):

It's not exactly the code from the link. If it was the code from the link I would say it's not that bad of an option because its not doing anything too complex. My code, however, is using a "private" internal instance attribute that shouldn't be used by a normal user. That is why it is evil.

And yes, logging can be used for testing output, but it does not make much sense to do so in a unittest/doctest and is probably why doctest doesn't include functionality like this out of the box. The TextTest stuff you linked to is all about functional or integration testing. Unittests (and doctests) should be testing small individual components. If you have to capture logged output to make sure your unittest/doctest is correct then you should maybe think about separating things out or not doing these checks in a doctest.

I personally only use doctests for simple examples and verifications. Mostly for usage examples since any user can see an inline doctest.

Edit (ok last one):

Same solution, simpler code. This code doesn't require that you create a custom runner. You still have to create the default runner and stuff because you need to access the "_fakeout" attribute. There is no way to use doctest to check logging output without logging to this attribute as a stream.

if __name__ == '__main__':
    dt_runner = doctest.DocTestRunner()
    tests = doctest.DocTestFinder().find(sys.modules[__name__])
    logging.basicConfig(level=logging.DEBUG, format='%(message)s', stream=dt_runner._fakeout)
    for t in tests:
        dt_runner.run(t)