feat: Print log path in the end of output (#542)

* feat: Print log path in the end of output

Move log file path information to the end of cli output

---------

Co-authored-by: Samuel Allan <[email protected]>

cou/cli.py

@@ -18,13 +18,15 @@
 import logging.handlers
 import sys
 from enum import Enum
+from pathlib import Path
 from signal import SIGINT, SIGTERM
+from typing import Optional
 
 from juju.errors import JujuError
 
 from cou.commands import CLIargs, parse_args
 from cou.exceptions import COUException, HighestReleaseAchieved, TimeoutException
-from cou.logging import setup_logging
+from cou.logging import get_log_file, setup_logging
 from cou.steps import UpgradePlan
 from cou.steps.analyze import Analysis
 from cou.steps.execute import apply_step
@@ -245,11 +247,13 @@ async def _run_command(args: CLIargs) -> None:
 def entrypoint() -> None:
     """Execute 'charmed-openstack-upgrade' command."""
     args = parse_args(sys.argv[1:])
+    log_file: Optional[Path] = None
     try:
         # disable progress indicator when in quiet mode to suppress its console output
         progress_indicator.enabled = not args.quiet
         log_level = get_log_level(quiet=args.quiet, verbosity=args.verbosity)
-        setup_logging(log_level)
+        log_file = get_log_file()
+        setup_logging(log_file, log_level)
 
         loop = asyncio.get_event_loop()
         loop.run_until_complete(_run_command(args))
@@ -291,4 +295,6 @@ def entrypoint() -> None:
     finally:
         if args.command == "upgrade":
             loop.run_until_complete(run_post_upgrade_sanity_check(args))
+        if log_file is not None and not args.quiet:
+            print(f"Full execution log: '{log_file}'")
         progress_indicator.stop()

cou/logging.py

@@ -16,6 +16,7 @@
 import logging
 import logging.handlers
 from datetime import datetime
+from pathlib import Path
 
 from cou.utils import COU_DATA, progress_indicator
 
@@ -39,15 +40,25 @@ def filter(self, record: logging.LogRecord) -> bool:
         return True
 
 
-def setup_logging(log_level: str = "INFO") -> None:
+def get_log_file() -> Path:
+    """Get log file path.
+
+    :return: Returns log file path
+    :rtype: Path
+    """
+    time_stamp = datetime.now().strftime("%Y%m%d%H%M%S")
+    return Path(f"{COU_DIR_LOG}/cou-{time_stamp}.log")
+
+
+def setup_logging(log_file: Path, log_level: str = "INFO") -> None:
     """Do setup for logging.
 
+    :param log_file: Logging file.
+    :type log_level: Path
     :param log_level: Logging level, defaults to "INFO"
     :type log_level: str, optional
     """
     progress_indicator.start("Configuring logging...")
-    time_stamp = datetime.now().strftime("%Y%m%d%H%M%S")
-    file_name = f"{COU_DIR_LOG}/cou-{time_stamp}.log"
     COU_DIR_LOG.mkdir(parents=True, exist_ok=True)
 
     log_formatter_file = logging.Formatter(
@@ -60,7 +71,7 @@ def setup_logging(log_level: str = "INFO") -> None:
     root_logger.setLevel("NOTSET")
 
     # handler for the log file. Log level is "NOTSET"
-    log_file_handler = logging.FileHandler(file_name)
+    log_file_handler = logging.FileHandler(log_file)
     log_file_handler.setFormatter(log_formatter_file)
     # suppress python libjuju and websockets debug logs
     if log_level != "NOTSET":
@@ -78,7 +89,7 @@ def setup_logging(log_level: str = "INFO") -> None:
     root_logger.addHandler(log_file_handler)
     root_logger.addHandler(console_handler)
 
-    progress_indicator.stop_and_persist(text=f"Full execution log: '{file_name}'")
+    progress_indicator.stop_and_persist(text=f"Full execution log: '{log_file}'")
 
 
 def filter_debug_logs(record: logging.LogRecord) -> bool:

tests/unit/test_cli.py

@@ -320,32 +320,46 @@ async def test_run_command(
         mock_apply_upgrade_plan.assert_awaited_once()
 
 
+@patch("cou.cli.print")
+@patch("cou.cli.progress_indicator")
 @patch("cou.cli.run_post_upgrade_sanity_check")
 @patch("cou.cli.sys")
 @patch("cou.cli.parse_args")
+@patch("cou.cli.get_log_file")
 @patch("cou.cli.get_log_level")
 @patch("cou.cli.setup_logging")
 @patch("cou.cli._run_command")
 def test_entrypoint(
     mock_run_command,
     mock_setup_logging,
     mock_get_log_level,
+    mock_get_log_file,
     mock_parse_args,
     mock_sys,
     mock_run_post_upgrade_sanity_check,
+    mock_indicator,
+    mock_print,
 ):
     """Test successful entrypoint execution."""
     mock_sys.argv = ["cou", "upgrade"]
     args = mock_parse_args.return_value
     args.command = "upgrade"
+    args.quiet = False
 
     cli.entrypoint()
 
     mock_parse_args.assert_called_once_with(["upgrade"])
     mock_get_log_level.assert_called_once_with(quiet=args.quiet, verbosity=args.verbosity)
-    mock_setup_logging.assert_called_once_with(mock_get_log_level.return_value)
+    mock_setup_logging.assert_called_once_with(
+        mock_get_log_file.return_value,
+        mock_get_log_level.return_value,
+    )
     mock_run_command.assert_awaited_once_with(args)
     mock_run_post_upgrade_sanity_check.await_count == 2
+    mock_print.assert_called_once_with(
+        f"Full execution log: '{mock_get_log_file.return_value}'",
+    )
+    mock_indicator.stop.assert_called_once()
 
 
 @patch("cou.cli.progress_indicator")
@@ -442,7 +456,7 @@ def test_entrypoint_failure_keyboard_interrupt(
     with pytest.raises(SystemExit, match="130"):
         cli.entrypoint()
 
-    mock_print.assert_called_once_with(message or "charmed-openstack-upgrader has been terminated")
+    mock_print.assert_any_call(message or "charmed-openstack-upgrader has been terminated")
     mock_indicator.fail.assert_called_once_with()
     mock_indicator.stop.assert_called_once_with()
 

tests/unit/test_logging.py

@@ -16,7 +16,12 @@
 
 import pytest
 
-from cou.logging import TracebackInfoFilter, filter_debug_logs, setup_logging
+from cou.logging import (
+    TracebackInfoFilter,
+    filter_debug_logs,
+    get_log_file,
+    setup_logging,
+)
 
 
 def test_filter_clears_exc_info_and_text():
@@ -36,6 +41,7 @@ def test_filter_clears_exc_info_and_text():
 @pytest.mark.parametrize("log_level", ["NOTSET", "DEBUG", "INFO", "WARNING", "ERROR"])
 def test_setup_logging(log_level):
     """Test setting up logging."""
+    log_file = get_log_file()
     with (
         patch("cou.logging.logging") as mock_logging,
         patch("cou.logging.progress_indicator") as mock_indicator,
@@ -46,8 +52,9 @@ def test_setup_logging(log_level):
         mock_logging.FileHandler.return_value = log_file_handler
         mock_logging.StreamHandler.return_value = console_handler
 
-        setup_logging(log_level)
+        setup_logging(log_file, log_level)
 
+        mock_logging.FileHandler.assert_called_with(log_file)
         mock_root_logger.addHandler.assert_any_call(log_file_handler)
         mock_root_logger.addHandler.assert_any_call(console_handler)
         mock_indicator.start.assert_called_once()