nose-devs/nose2

Test that has child process logging to stdout not consistent when run with python -m unittest vs nose2

Open

#496 opened on Mar 16, 2021

View on GitHub
 (1 comment) (1 reaction) (0 assignees)Python (137 forks)batch import
bughelp wanted

Repository metrics

Stars
 (757 stars)
PR merge metrics
 (Avg merge 5d 9h) (4 merged PRs in 30d)

Description

I have a command line command that I'm trying to write an end-to-end test for to make sure everything is working well. I wanted to invoke the CLI via a multiprocessing.Process, because when the CLI starts running it configures the root logger, and I want to test that, along with everything else, without creating inconsistencies in my test suite. Below is a simple of the type of test I'm interested in doing. You can see that I have child, which is the entrypoint of my CLI, you can see that it configures logging, and also that it makes a couple of print statements. The test itself verifies both the print statement and the log message show up in stdout, which is redirected to a file in a child process.

When I run this test with unittests, everything passes. When I run with nose2, I get a failure. See below for details.

tests/test_example.py

import logging
import sys
import tempfile
import unittest

from pathlib import Path
from multiprocessing import Process


def child():
    logging.basicConfig(
        handlers=[logging.StreamHandler(sys.stdout)],
        level=logging.INFO,
        format="%(message)s",
        datefmt="%Y-%m-%dT%H:%M:%S%z",
    )

    print("MY PRINT STATEMENT")
    logging.info("MY LOG MESSAGE")


def child_wrapper(target, stdout_file, stderr_file):
    sys.stdout = stdout_file.open("w")
    sys.stderr = stderr_file.open("w")

    try:
        target()
    finally:
        sys.stdout.flush()
        sys.stderr.flush()


class TestLoggingInChildProc(unittest.TestCase):
    def test_logging_in_child_proc(self):
        with tempfile.TemporaryDirectory() as d:
            stdout_file = Path(f"{d}/stdout.txt")
            stderr_file = Path(f"{d}/stderr.txt")

            p = Process(
                target=child_wrapper,
                args=[child, stdout_file, stderr_file],
            )
            p.start()
            p.join()
            p.close()

            self.assertEqual(
                "MY PRINT STATEMENT\nMY LOG MESSAGE",
                stdout_file.read_text().strip()
            )

            self.assertEqual("", stderr_file.read_text().strip())

When I run tree ., I see:

.
└── tests
    ├── __init__.py
    └── test_example.py

1 directory, 2 files

When I run python -m unittest tests.test_example the test passes, but when I run nose2 test_example the test fails. Here is the failure text:

F
======================================================================
FAIL: test_logging_in_child_proc (tests.test_example.TestLoggingInChildProc)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/tests/test_example.py", line 47, in test_logging_in_child_proc
    self.assertEqual(
AssertionError: 'MY PRINT STATEMENT\nMY LOG MESSAGE' != 'MY PRINT STATEMENT'
- MY PRINT STATEMENT
?                   -
+ MY PRINT STATEMENT- MY LOG MESSAGE

----------------------------------------------------------------------
Ran 1 test in 0.004s

FAILED (failures=1)

When I invoke this test using python -m unittest test_example.py the test passes. However, when I invoke this script using nose2

Contributor guide