feat: write logs to a rotating file

This gives less technical users an easy way to find and send logs
when they run into problems. A few startup and environment messages
move up to info level so the default log carries enough context to
diagnose issues without needing to enable debug mode.

Author: trin94

.github/ISSUE_TEMPLATE/bug_report.md

@@ -33,5 +33,9 @@ If applicable, add screenshots to help explain your problem.
 
 - If you have modified the mpv configuration (`Options` ⟶ `Edit mpv.conf...`), list all your changes or a copy of your config
 
+**Logs**
+
+- Please attach the log file. Open `Help` ⟶ `Open App Data Folder...`, then grab `mpvQC.log` from the `logs/` folder
+
 **Additional context**
 Add any other context about the problem here.

mpvqc/logging_utils.py

@@ -9,18 +9,25 @@
 import re
 import sys
 from enum import StrEnum
+from logging.handlers import RotatingFileHandler
 from typing import TYPE_CHECKING, Final, override
 
-from PySide6.QtCore import QtMsgType
+from PySide6.QtCore import QtMsgType, qInstallMessageHandler
 
 if TYPE_CHECKING:
     from collections.abc import Callable
+    from pathlib import Path
 
     from PySide6.QtCore import QMessageLogContext
 
 MPV_LEVEL: Final[int] = 25
 logging.addLevelName(MPV_LEVEL, "MPV")
 
+FILE_LOG_MAX_BYTES: Final[int] = 1_000_000
+FILE_LOG_BACKUP_COUNT: Final[int] = 5
+
+_URL_SCHEME_PATTERN: Final = re.compile(r"^\w+:")
+
 
 class AnsiColor(StrEnum):
     RESET = "\033[0m"
@@ -49,9 +56,9 @@ def use_color() -> bool:
 
 
 class MpvqcFormatter(logging.Formatter):
-    def __init__(self) -> None:
+    def __init__(self, *, colored: bool) -> None:
         super().__init__()
-        self._use_color = use_color()
+        self._use_color = colored
 
     @override
     def format(self, record: logging.LogRecord) -> str:
@@ -84,6 +91,12 @@ def format(self, record: logging.LogRecord) -> str:
 
 
 def setup_mpvqc_logging() -> None:
+    _setup_console_logging()
+    _setup_file_logging()
+    qInstallMessageHandler(_qt_log_handler())
+
+
+def _setup_console_logging() -> None:
     is_debug = os.getenv("MPVQC_DEBUG")
 
     root_logger = logging.getLogger()
@@ -93,7 +106,7 @@ def setup_mpvqc_logging() -> None:
         root_logger.removeHandler(handler)
 
     console_handler = logging.StreamHandler(sys.stdout)
-    console_handler.setFormatter(MpvqcFormatter())
+    console_handler.setFormatter(MpvqcFormatter(colored=use_color()))
     root_logger.addHandler(console_handler)
 
     if is_debug:
@@ -102,15 +115,29 @@ def setup_mpvqc_logging() -> None:
             logging.getLogger(name).setLevel(logging.WARNING)
 
 
-_URL_SCHEME_PATTERN: Final = re.compile(r"^\w+:")
+def _setup_file_logging() -> None:
+    try:
+        from mpvqc.services.application_paths import ApplicationPathsService
 
+        paths = ApplicationPathsService()
+        paths.dir_logs.mkdir(parents=True, exist_ok=True)
+        attach_file_logging(paths.file_log)
+    except Exception:
+        logging.getLogger(__name__).exception("Could not set up file logging")
 
-def logger_name_from(path: str) -> str:
-    path = _URL_SCHEME_PATTERN.sub("", path).lstrip("/").removeprefix("qt/qml/")
-    return path.replace("/", ".").removesuffix(".qml")
+
+def attach_file_logging(log_file: Path) -> None:
+    handler = RotatingFileHandler(
+        log_file,
+        maxBytes=FILE_LOG_MAX_BYTES,
+        backupCount=FILE_LOG_BACKUP_COUNT,
+        encoding="utf-8",
+    )
+    handler.setFormatter(MpvqcFormatter(colored=False))
+    logging.getLogger().addHandler(handler)
 
 
-def qt_log_handler() -> Callable[[QtMsgType, QMessageLogContext, str], None]:
+def _qt_log_handler() -> Callable[[QtMsgType, QMessageLogContext, str], None]:
     levels: Final[dict[QtMsgType, int]] = {
         QtMsgType.QtDebugMsg: logging.DEBUG,
         QtMsgType.QtInfoMsg: logging.INFO,
@@ -144,3 +171,8 @@ def handler(message_type: QtMsgType, context: QMessageLogContext, message: str)
         qml_logger.handle(record)
 
     return handler
+
+
+def logger_name_from(path: str) -> str:
+    path = _URL_SCHEME_PATTERN.sub("", path).lstrip("/").removeprefix("qt/qml/")
+    return path.replace("/", ".").removesuffix(".qml")

mpvqc/services/application_paths.py

@@ -13,6 +13,7 @@
 class _Directories:
     backup: Path
     config: Path
+    logs: Path
     screenshots: Path
     export_templates: Path
 
@@ -25,6 +26,7 @@ def _portable_directories(executing_directory: Path) -> _Directories:
     return _Directories(
         backup=executing_directory / "appdata" / "backups",
         config=executing_directory / "appdata",
+        logs=executing_directory / "appdata" / "logs",
         screenshots=executing_directory / "appdata" / "screenshots",
         export_templates=executing_directory / "appdata" / "export-templates",
     )
@@ -36,6 +38,7 @@ def _xdg_directories() -> _Directories:
     return _Directories(
         backup=Path(config) / appname / "backups",
         config=Path(config) / appname,
+        logs=Path(config) / appname / "logs",
         screenshots=Path(config) / appname / "screenshots",
         export_templates=Path(config) / appname / "export-templates",
     )
@@ -60,6 +63,10 @@ def dir_backup(self) -> Path:
     def dir_config(self) -> Path:
         return self._dirs.config
 
+    @property
+    def dir_logs(self) -> Path:
+        return self._dirs.logs
+
     @property
     def dir_screenshots(self) -> Path:
         return self._dirs.screenshots
@@ -76,6 +83,10 @@ def file_input_conf(self) -> Path:
     def file_mpv_conf(self) -> Path:
         return self.dir_config / "mpv.conf"
 
+    @property
+    def file_log(self) -> Path:
+        return self.dir_logs / "mpvQC.log"
+
     @property
     def file_settings(self) -> Path:
         return self.dir_config / "settings.ini"

mpvqc/services/host_environment/portals.py

@@ -33,7 +33,7 @@ def __init__(self) -> None:
 
     def __enter__(self) -> Self:
         if not QTDBUS_AVAILABLE:
-            logger.debug("QtDBus not available, cannot read portal settings")
+            logger.info("QtDBus not available, cannot read portal settings")
             return self
 
         self._connection = connection = QDBusConnection.connectToBus(
@@ -52,7 +52,7 @@ def __enter__(self) -> Self:
         )
 
         if not interface.isValid():
-            logger.debug("D-Bus settings portal interface is not valid")
+            logger.info("D-Bus settings portal interface is not valid")
 
         return self
 
@@ -81,7 +81,7 @@ def _portal_version(self) -> int:
             if version is not None:
                 return int(version)
         except (TypeError, ValueError):
-            logger.debug("Could not determine Settings portal version")
+            logger.info("Could not determine Settings portal version")
 
         return 0
 
@@ -116,12 +116,12 @@ def _read_setting(self, interface: QDBusInterface, namespace: str, key: str, por
             method_name = "ReadOne"
         else:
             method_name = "Read"
-            logger.debug("Using deprecated Read() method (portal version: %s)", portal_version)
+            logger.info("Using deprecated Read() method (portal version: %s)", portal_version)
 
         reply = interface.call(method_name, namespace, key)
 
         if reply.type() == QDBusMessage.MessageType.ErrorMessage:
-            logger.debug("D-Bus error reading %s %s: %s", namespace, key, reply.errorMessage())
+            logger.info("D-Bus error reading %s %s: %s", namespace, key, reply.errorMessage())
             return None
 
         dbus_variant = reply.arguments()[0]
@@ -132,7 +132,7 @@ def _read_setting(self, interface: QDBusInterface, namespace: str, key: str, por
             value = dbus_variant.variant().variant()
 
         if value is None:
-            logger.debug("Portal setting %s %s returned None", namespace, key)
+            logger.info("Portal setting %s %s returned None", namespace, key)
             return None
 
         return str(value)

mpvqc/services/host_environment/service.py

@@ -65,6 +65,6 @@ def is_tiling_window_manager() -> bool:
     is_tiling_wm = bool(desktops & tiling_wms)
 
     if is_tiling_wm:
-        logger.debug("Running on tiling window manager")
+        logger.info("Running on tiling window manager")
 
     return is_tiling_wm

mpvqc/services/i18n.py

@@ -30,7 +30,7 @@ def retranslate(self, app: QGuiApplication, language_code: str) -> None:
         app.removeTranslator(self._translator_qt)
 
         locale: QLocale = create_locale_from(language_code)
-        logger.debug("Loading mpvQC translation %s for locale %s", language_code, locale.name())
+        logger.info("Loading mpvQC translation %s for locale %s", language_code, locale.name())
 
         QLocale.setDefault(locale)
         logger.debug("Set default Qt locale to %s", locale.name())

mpvqc/services/importer/service.py

@@ -57,7 +57,7 @@ def _set_busy(self, value: bool) -> None:
 
     def open(self, document_paths: list[Path], video_paths: list[Path], subtitle_paths: list[Path]) -> None:
         if self._busy:
-            logger.debug(
+            logger.warning(
                 "Skipping import while another is in progress; documents=%s videos=%s subtitles=%s",
                 document_paths,
                 video_paths,

mpvqc/services/main_window.py

@@ -67,7 +67,7 @@ def initialize(self) -> None:
         self._zoom_monitor = zoom_monitor = _DisplayZoomMonitor(window, self._on_zoom_factor_changed)
         window.installEventFilter(zoom_monitor)
 
-        logger.debug("wired up main window service")
+        logger.debug("Wired up main window service")
 
     def install_event_filter(self, event_filter: QObject) -> None:
         self._active_window.installEventFilter(event_filter)

mpvqc/startup.py

@@ -45,12 +45,9 @@ def configure_qt_settings() -> None:
 
 
 def configure_logging() -> None:
-    from PySide6 import QtCore
-
-    from mpvqc.logging_utils import qt_log_handler, setup_mpvqc_logging
+    from mpvqc.logging_utils import setup_mpvqc_logging
 
     setup_mpvqc_logging()
-    QtCore.qInstallMessageHandler(qt_log_handler())
 
 
 def configure_dependency_injection() -> None:

test/services/test_application_paths.py

@@ -12,9 +12,11 @@ def test_portable(tmp_path):
     assert "appdata" in f"{service.dir_config}"
     assert service.dir_backup == tmp_path / "appdata" / "backups"
     assert service.dir_config == tmp_path / "appdata"
+    assert service.dir_logs == tmp_path / "appdata" / "logs"
     assert service.dir_screenshots == tmp_path / "appdata" / "screenshots"
     assert service.dir_export_templates == tmp_path / "appdata" / "export-templates"
     assert service.file_input_conf == tmp_path / "appdata" / "input.conf"
+    assert service.file_log == tmp_path / "appdata" / "logs" / "mpvQC.log"
     assert service.file_mpv_conf == tmp_path / "appdata" / "mpv.conf"
     assert service.file_settings == tmp_path / "appdata" / "settings.ini"
 
@@ -24,4 +26,6 @@ def test_non_portable(tmp_path):
 
     assert "appdata" not in f"{service.dir_config}"
     assert service.dir_backup == service.dir_config / "backups"
+    assert service.dir_logs == service.dir_config / "logs"
     assert service.dir_screenshots == service.dir_config / "screenshots"
+    assert service.file_log == service.dir_config / "logs" / "mpvQC.log"