Search code examples
pythonunit-testingtestingloggingpython-unittest

Execute python script, get its print and logging output and assert unittest


Edit: Thanks @eemz for the idea to redesign the structure and use from unittest.mock import patch, but the problem persists.

So I just recently stumbled into unittest and I have a program which I normally start like this python run.py -config /path/to/config.file -y. I wanted to write a simple test in a separate test.py file: Execute the script, pass the mentioned arguments and get all of its output. I pass a prepared config file which is missing certain things, so the run.py will break and exactly log this error using logging.error: "xyz was missing in Config file!" (see example below). I'll get a few words from print() and then the logging instance kicks in and handles from there on. How do I get its output so I can check it? Feel free to rewrite this, as I'm still learning, please bear with me.

Simplified example:

run.py

import logging

def run(args):
  < args.config = /path/to/config.file >
  cnfg = Config(args.config)

  cnfg.logger.info("Let's start with the rest of the code!") # This is NOT in 'output' of the unittest
  < code >

if __name__ == "__main__":
  print("Welcome! Starting execution.") # This is in 'output' of the unittest
  < code to parse arguments 'args' >
  run(args)

Config.py

import logging

class Config:
  def __init__(self):
    print("Creating logging instance, hold on ...") # This is in 'output' of the unittest
    logger = logging.getLogger(__name__)
    console_handler = logging.StreamHandler()
    logger.addHandler(console_handler)
    logger.info("Logging activated, let's go!") # This is NOT in 'output' of the unittest
    self.logger = logger

    if xyz not in config:
      self.logger.error("xyz was missing in Config file!") # This is NOT in 'output' of the unittest
      exit(1)

test.py

import unittest
from unittest.mock import patch

class TestConfigs(unittest.TestCase):
    def test_xyz(self):
        with patch('sys.stdout', new=StringIO()) as capture:
            with self.assertRaises(SystemExit) as cm:
                run("/p/to/f/missing/xyz/f", "", False, True)
        output = capture.getvalue().strip()

        self.assertEqual(cm.exception.code, 1)
        # Following is working, because the print messages are in output
        self.assertTrue("Welcome! Starting execution." in output)
        # Following is NOT working, because the logging messages are not in output
        self.assertTrue("xyz was missing in Config file!" in output)

if __name__ == "__main__":
    unittest.main()

Solution

  • I ended up instantiating the logger of the main program with a specific name, so I could get the logger in the test.py again and assert that the logger was called with a specific text. I didn't know that I could just get the logger by using logging.getLogger("name") with the same name. Simplified example:

    test.py

    import unittest
    from run import run
    from unittest.mock import patch
    
    main_logger = logging.getLogger("main_tool")
    
    class TestConfigs(unittest.TestCase):
        def test_xyz(self):
            with patch('sys.stdout', new=StringIO()) as capture, \
                 self.assertRaises(SystemExit) as cm, \
                 patch.object(main_logger , "info") as mock_log1, \
                 patch.object(main_logger , "error") as mock_log2:
                    run("/path/to/file/missing/xyz.file")
            output = capture.getvalue().strip()
    
            self.assertTrue("Creating logging instance, hold on ..." in output)
            mock_log1.assert_called_once_with("Logging activated, let's go!")
            mock_log2.assert_called_once_with("xyz was missing in Config file!")
            self.assertEqual(cm.exception.code, 1)
    
    if __name__ == "__main__":
        unittest.main()
    

    run.py

    def run(path: str):
      cnfg = Config(path)
      < code >
    
    if __name__ == "__main__":
      < code to parse arguments 'args' >
      path = args.file_path
      run(path)
    

    Config.py

    import logging
    
    class Config:
      def __init__(self, path: str):
        print("Creating logging instance, hold on ...")
        logger = logging.getLogger("main_tool")
        console_handler = logging.StreamHandler()
        logger.addHandler(console_handler)
        logger.info("Logging activated, let's go!")
        self.logger = logger
    
        # Load file, simplified
        config = load(path)
    
        if xyz not in config:
          self.logger.error("xyz was missing in Config file!")
          exit(1)
    

    This method seems to be very complicated and I got to this point by reading through a lot of other posts and the docs. Maybe some one knows a better way to achieve this.