From 3964853a46f807fc3707e0f0b901ffc3a8d3490a Mon Sep 17 00:00:00 2001
From: kdmukai <kdmukai@gmail.com>
Date: Mon, 15 Jul 2024 12:01:45 -0500
Subject: [PATCH] Fixes to restore log access in pytest

---
 pyproject.toml     |  2 +-
 tests/README.md    | 14 +++++++++++
 tests/base.py      | 24 +++++++++++++++++++
 tests/test_main.py | 60 +++++++++++++++++++++++++++-------------------
 4 files changed, 74 insertions(+), 26 deletions(-)

diff --git a/pyproject.toml b/pyproject.toml
index ee185544..a50a40c6 100644
--- a/pyproject.toml
+++ b/pyproject.toml
@@ -58,7 +58,7 @@ branch = true
 
 [tool.pytest.ini_options]
 testpaths = ["tests"]
-addopts = "-p no:logging"
+log_level = "DEBUG"
 
 [tool.setuptools]
 include-package-data = true
diff --git a/tests/README.md b/tests/README.md
index fe2181fe..12f321d3 100644
--- a/tests/README.md
+++ b/tests/README.md
@@ -31,6 +31,20 @@ Run a specific test:
 pytest tests/test_this_file.py::test_this_specific_test
 ```
 
+Force pytest to show logging output:
+```bash
+pytest tests/test_this_file.py::test_this_specific_test -o log_cli=1
+
+# or (same result)
+
+pytest tests/test_this_file.py::test_this_specific_test --log-cli-level=DEBUG
+```
+
+Annoying complications:
+* If you want to see `print()` statements that are in a test file, add `-s`
+* Better idea: use a proper logger in the test file and use one of the above options to display logs
+
+
 ### Test Coverage
 Run tests and generate test coverage
 ```
diff --git a/tests/base.py b/tests/base.py
index e7bb2ddf..964c07bd 100644
--- a/tests/base.py
+++ b/tests/base.py
@@ -18,6 +18,8 @@ from seedsigner.hardware.microsd import MicroSD
 from seedsigner.models.settings import Settings
 from seedsigner.views.view import Destination, MainMenuView, View
 
+import logging
+logger = logging.getLogger(__name__)
 
 
 
@@ -93,6 +95,28 @@ class BaseTest:
 
 
 
+class TestBaseTest(BaseTest):
+    def test_howto_log_from_test(self):
+        """
+            Not actually a test, just a demonstration of how to use/access logs while
+            testing.
+
+            Enable log visibility by running with:
+                --log-cli-level=NOTSET (or the level of your choice)
+                -o log_cli=1
+            
+            Enable print() visibility by running with:
+                -s or --capture=no
+        """
+        print("This is a test print message")
+        logger.info("This is a test log message")
+        logger.debug("This is a test debug message")
+        logger.warning("This is a test warning message")
+        logger.error("This is a test error message")
+        logger.critical("This is a test critical message")
+
+
+
 @dataclass
 class FlowStep:
     """ 
diff --git a/tests/test_main.py b/tests/test_main.py
index f4e48fc8..94029807 100644
--- a/tests/test_main.py
+++ b/tests/test_main.py
@@ -1,40 +1,50 @@
 import logging
+import pytest
 import sys
 from unittest.mock import patch, call
 
-import pytest
+# Must import from base.py before any other SeedSigner dependency to mock out certain imports
+from base import BaseTest
 
 sys.path.insert(0,'src')
 from main import main
 
 
-@patch("main.Controller")
-def test_main__argparse__default(patched_controller):
-    main([])
-    assert logging.root.level == logging.INFO
-    assert logging.getLogger().getEffectiveLevel() == logging.INFO
-    patched_controller.assert_has_calls(
-        [call.get_instance(), call.get_instance().start()]
-    )
+class TestMain(BaseTest):
+    """
+    The `main.Controller` has to be patched / mocked out otherwise the virtual SeedSigner
+    will just keep running and cause the test to hang.
+    """
+    @patch("main.Controller")
+    def test_main__argparse__default(self, patched_controller):
+        main([])
+        assert logging.root.level == logging.INFO
+        assert logging.getLogger().getEffectiveLevel() == logging.INFO
+        patched_controller.assert_has_calls(
+            [call.get_instance(), call.get_instance().start()]
+        )
 
 
-@patch("main.Controller")
-def test_main__argparse__enable_debug_logging(patched_controller):
-    main(["--loglevel", "DEBUG"])
-    assert logging.root.level == logging.DEBUG
-    assert logging.getLogger().getEffectiveLevel() == logging.DEBUG
-    patched_controller.assert_has_calls(
-        [call.get_instance(), call.get_instance().start()]
-    )
+    @patch("main.Controller")
+    def test_main__argparse__enable_debug_logging(self, patched_controller):
+        main(["--loglevel", "DEBUG"])
+        assert logging.root.level == logging.DEBUG
+        assert logging.getLogger().getEffectiveLevel() == logging.DEBUG
+        patched_controller.assert_has_calls(
+            [call.get_instance(), call.get_instance().start()]
+        )
 
 
-def test_main__argparse__invalid_arg():
-    with pytest.raises(SystemExit):
-        main(["--invalid"])
+    def test_main__argparse__invalid_arg(self):
+        with pytest.raises(SystemExit):
+            main(["--invalid"])
 
 
-@patch("main.Controller")
-def test_main__logging__writes_to_stderr(patched_controller, capsys):
-    main([])
-    _, err = capsys.readouterr()
-    assert "Starting SeedSigner" in err and "INFO" in err
+    @patch("main.Controller")
+    def test_main__logging__writes_to_stderr(self, patched_controller, capsys):
+        main([])
+        _, err = capsys.readouterr()
+        assert "Starting SeedSigner" in err and "INFO" in err
+        patched_controller.assert_has_calls(
+            [call.get_instance(), call.get_instance().start()]
+        )
\ No newline at end of file