Skip to content

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

Open
@mikeholler

Description

@mikeholler

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    bughelp wantedContributions and outside help would be most welcome!

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions