python tests offer the -b flag to suppress output on success. The documentation says:

The standard output and standard error streams are buffered during the test run. Output during a passing test is discarded. Output is echoed normally on test fail or error and is added to the failure messages.

https://docs.python.org/3/library/unittest.html#cmdoption-unittest-b

unittests are part of the standard library, and so is logging https://docs.python.org/3/library/logging.html?highlight=loggging

Logging accepts configuration. Depending on how the logging is configured, messages can go to the standard output or standard error. A very minimal configuration looks like this:

import logging.config

logging_conf = { "version": 1,
    "handlers": { "console": { "class": "logging.StreamHandler", }, },
    "root": { "handlers": ["console"], }, }

logging.config.dictConfig(logging_conf)

The unexpected behaviour

Assuming this program:

import unittest
import logging
import logging.config

configure_logging = True

if configure_logging:
    logging_conf = { "version": 1,
        "handlers": { "console": { "class": "logging.StreamHandler", }, },
        "root": { "handlers": ["console"], }, }

    logging.config.dictConfig(logging_conf)

class MyCase(unittest.TestCase):
    def test_logging(self):
        try: raise Exception
        except Exception: logging.exception("AAAA")

if I run python -m unittest -b test.py , should I display the logging error?

$ python -m unittest test.py 
AAAA
Traceback (most recent call last):
  File "/home/nesaro/test.py", line 16, in test_logging
    try: raise Exception
Exception
.
----------------------------------------------------------------------
Ran 1 test in 0.000s

OK

If I run the same program but with configure_logging = False , the output is:

$ python -m unittest -b test.py 
.
----------------------------------------------------------------------
Ran 1 test in 0.000s

OK

The explanation

If we print sys.stdout before and after the test,

import unittest
import logging
import logging.config
import sys
print(sys.stdout) # print 1

configure_logging = False

if configure_logging:
    logging_conf = { "version": 1,
        "handlers": { "console": { "class": "logging.StreamHandler", }, },
        "root": { "handlers": ["console"], }, }

    logging.config.dictConfig(logging_conf)

class MyCase(unittest.TestCase):
    def test_logging(self):
        print(sys.stdout) # print2
        try: raise Exception
        except Exception: logging.exception("AAAA")
        self.assertTrue(False)

the output looks like this

======================================================================
FAIL: test_logging (test.MyCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/nesaro/test.py", line 21, in test_logging
    self.assertTrue(False)
AssertionError: False is not true

Stdout:
<_io.StringIO object at 0x7f9ac74e9ab0>

Stderr:
ERROR:root:AAAA
Traceback (most recent call last):
  File "/home/nesaro/test.py", line 19, in test_logging
    try: raise Exception
Exception

----------------------------------------------------------------------
Ran 1 test in 0.000s

FAILED (failures=1)

The flag -b has replaced sys.stdout with a StringIo object.

If we print the handler stream:

class MyCase(unittest.TestCase):
    def test_logging(self):
        print(sys.stderr)
        print(logging.getLogger('root').handlers[0].stream)
        ...

the output looks like this

Stdout:
<_io.StringIO object at 0x7f0a18db7e20>
<_io.TextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>

And the solution assuming keeping logging enabled is needed:

class MyCase(unittest.TestCase):
    def test_logging(self):
        logging.getLogger('root').handlers[0].setStream(sys.stderr)
        ...

Which is way more complicated than disabling logging.

There are other variations of the same solution described in https://stackoverflow.com/questions/7472863/pydev-unittesting-how-to-capture-text-logged-to-a-logging-logger-in-captured-o

The problem

The problem is a consequence these 2 implementations:

  • -b is implemented by patching sys.stdout and sys.stderr
  • logging configuration doesn’t have any mechanism to defer the reading of the stream

There isn’t a good error message explaining any of this.

An easy but not great solution is to add a flag or a callable to the logging configuration to defer the read of the stream.

A draconian solution would be not to start the tests if the -b flag is set and the logging configured.

A warning on this condition would help, although it would only affect if the errors go through sys.stdout or sys.stderr

Quite an unexpected behaviour


#python