diff --git a/CONTRIBUTORS b/CONTRIBUTORS index d6a7b94ac..77a9eb842 100644 --- a/CONTRIBUTORS +++ b/CONTRIBUTORS @@ -157,8 +157,9 @@ Marko Sisovic Viktor Ricci Harvey Randall Pedro Lameiras -Kai Knoblich +Kai Knoblich Lucas Scharenbroch +Antonio Cavallo ******************** diff --git a/pylib/anki/collection.py b/pylib/anki/collection.py index b15f0c32c..a8d5d62b4 100644 --- a/pylib/anki/collection.py +++ b/pylib/anki/collection.py @@ -133,9 +133,9 @@ class Collection(DeprecatedNamesMixin): sched: V3Scheduler | DummyScheduler @staticmethod - def initialize_backend_logging(path: str | None = None) -> None: - """Enable terminal and optional file-based logging. Must be called only once.""" - RustBackend.initialize_logging(path) + def initialize_backend_logging() -> None: + """Enable terminal logging. Must be called only once.""" + RustBackend.initialize_logging(None) def __init__( self, diff --git a/qt/aqt/__init__.py b/qt/aqt/__init__.py index d3554324b..08905b8f1 100644 --- a/qt/aqt/__init__.py +++ b/qt/aqt/__init__.py @@ -3,6 +3,7 @@ from __future__ import annotations +import logging import sys if sys.version_info[0] < 3 or sys.version_info[1] < 9: @@ -41,6 +42,7 @@ import locale import os import tempfile import traceback +from pathlib import Path from typing import TYPE_CHECKING, Any, Callable, Optional, cast import anki.lang @@ -50,6 +52,7 @@ from anki.collection import Collection from anki.consts import HELP_SITE from anki.utils import checksum, is_lin, is_mac from aqt import gui_hooks +from aqt.log import setup_logging from aqt.qt import * from aqt.utils import TR, tr @@ -572,7 +575,6 @@ def _run(argv: Optional[list[str]] = None, exec: bool = True) -> Optional[AnkiAp pm = None try: base_folder = ProfileManager.get_created_base_folder(opts.base) - Collection.initialize_backend_logging(str(base_folder / "anki.log")) # default to specified/system language before getting user's preference so that we can localize some more strings lang = anki.lang.get_def_lang(opts.lang) @@ -581,6 +583,8 @@ def _run(argv: Optional[list[str]] = None, exec: bool = True) -> Optional[AnkiAp pm = ProfileManager(base_folder) pmLoadResult = pm.setupMeta() + + Collection.initialize_backend_logging() except: # will handle below traceback.print_exc() @@ -623,6 +627,11 @@ def _run(argv: Optional[list[str]] = None, exec: bool = True) -> Optional[AnkiAp # we've signaled the primary instance, so we should close return None + setup_logging( + pm.addon_logs(), + level=logging.DEBUG if int(os.getenv("ANKIDEV", "0")) else logging.INFO, + ) + if not pm: if i18n_setup: QMessageBox.critical( diff --git a/qt/aqt/addons.py b/qt/aqt/addons.py index 6d2dbb75c..c8d9a1296 100644 --- a/qt/aqt/addons.py +++ b/qt/aqt/addons.py @@ -6,6 +6,7 @@ from __future__ import annotations import html import io import json +import logging import os import re import zipfile @@ -33,6 +34,7 @@ from anki.httpclient import HttpClient from anki.lang import without_unicode_isolation from anki.utils import int_version_to_str from aqt import gui_hooks +from aqt.log import ADDON_LOGGER_PREFIX, find_addon_logger, get_addon_logs_folder from aqt.qt import * from aqt.utils import ( askUser, @@ -662,7 +664,11 @@ class AddonManager: return markdown.markdown(contents, extensions=[md_in_html.makeExtension()]) - def addonFromModule(self, module: str) -> str: + def addonFromModule(self, module: str) -> str: # softly deprecated + return module.split(".")[0] + + @staticmethod + def addon_from_module(module: str) -> str: return module.split(".")[0] def configAction(self, module: str) -> Callable[[], bool | None]: @@ -727,8 +733,9 @@ class AddonManager: def _userFilesBackupPath(self) -> str: return os.path.join(self.addonsFolder(), "files_backup") - def backupUserFiles(self, sid: str) -> None: - p = self._userFilesPath(sid) + def backupUserFiles(self, module: str) -> None: + p = self._userFilesPath(module) + if os.path.exists(p): os.rename(p, self._userFilesBackupPath()) @@ -752,6 +759,38 @@ class AddonManager: def getWebExports(self, module: str) -> str: return self._webExports.get(module) + # Logging + ###################################################################### + + @classmethod + def get_logger(cls, module: str) -> logging.Logger: + """Return a logger for the given add-on module. + + NOTE: This method is static to allow it to be called outside of a + running Anki instance, e.g. in add-on unit tests. + """ + return logging.getLogger( + f"{ADDON_LOGGER_PREFIX}{cls.addon_from_module(module)}" + ) + + def has_logger(self, module: str) -> bool: + return find_addon_logger(self.addon_from_module(module)) is not None + + def is_debug_logging_enabled(self, module: str) -> bool: + if not (logger := find_addon_logger(self.addon_from_module(module))): + return False + return logger.isEnabledFor(logging.DEBUG) + + def toggle_debug_logging(self, module: str, enable: bool) -> None: + if not (logger := find_addon_logger(self.addon_from_module(module))): + return + logger.setLevel(logging.DEBUG if enable else logging.INFO) + + def logs_folder(self, module: str) -> Path: + return get_addon_logs_folder( + self.mw.pm.addon_logs(), self.addon_from_module(module) + ) + # Add-ons Dialog ###################################################################### diff --git a/qt/aqt/log.py b/qt/aqt/log.py new file mode 100644 index 000000000..cc89c30ed --- /dev/null +++ b/qt/aqt/log.py @@ -0,0 +1,101 @@ +# Copyright: Ankitects Pty Ltd and contributors +# License: GNU AGPL, version 3 or later; http://www.gnu.org/licenses/agpl.html + +from __future__ import annotations + +import logging +import sys +from logging.handlers import TimedRotatingFileHandler +from pathlib import Path +from typing import Optional, cast + +# All loggers with the following prefix will be treated as add-on loggers +# +# To instatiate a logger with this prefix, use aqt.AddonManager.get_logger() +# +# NOTE: Add-ons might also directly instantiate a logger with this prefix, e.g. in +# order to avoid depending on the Anki codebase, so this prefix should not +# be changed. +ADDON_LOGGER_PREFIX = "addon." + +# Formatter used for all loggers +FORMATTER = logging.Formatter("%(asctime)s:%(levelname)s:%(name)s: %(message)s") + + +class AnkiLoggerManager(logging.Manager): + # inspired by: https://github.com/abdnh/ankiutils/blob/master/src/ankiutils/log.py + + def __init__( + self, + logs_path: Path | str, + existing_loggers: dict[str, logging.Logger | logging.PlaceHolder], + rootnode: logging.RootLogger, + ): + super().__init__(rootnode) + self.loggerDict = existing_loggers + self.logs_path = Path(logs_path) + + def getLogger(self, name: str) -> logging.Logger: + if not name.startswith(ADDON_LOGGER_PREFIX) or name in self.loggerDict: + return super().getLogger(name) + + # Create a new add-on logger + logger = super().getLogger(name) + + module = name.split(ADDON_LOGGER_PREFIX)[1].partition(".")[0] + path = get_addon_logs_folder(self.logs_path, module=module) / f"{module}.log" + path.parent.mkdir(parents=True, exist_ok=True) + + # Keep the last 10 days of logs + handler = TimedRotatingFileHandler( + filename=path, when="D", interval=1, backupCount=10, encoding="utf-8" + ) + handler.setFormatter(FORMATTER) + + logger.addHandler(handler) + + return logger + + +def get_addon_logs_folder(logs_path: Path | str, module: str) -> Path: + return Path(logs_path) / "addons" / module + + +def find_addon_logger(module: str) -> logging.Logger | None: + return cast( + Optional[logging.Logger], + logging.Logger.manager.loggerDict.get(f"{ADDON_LOGGER_PREFIX}{module}"), + ) + + +def setup_logging(path: Path | str, **kwargs) -> None: + """ + Set up logging for the application. + + Configures the root logger to output logs to stdout by default, with custom + handling for add-on logs. The add-on logs are saved to a separate folder and file + for each add-on, under the path provided. + + Args: + path (Path): The path where the log files should be stored. + **kwargs: Arbitrary keyword arguments for logging.basicConfig + """ + + # Patch root logger manager to handle add-on loggers + logger_manager = AnkiLoggerManager( + path, existing_loggers=logging.Logger.manager.loggerDict, rootnode=logging.root + ) + logging.Logger.manager = logger_manager + + stdout_handler = logging.StreamHandler(stream=sys.stdout) + stdout_handler.setFormatter(FORMATTER) + logging.basicConfig(handlers=[stdout_handler], force=True, **kwargs) + logging.captureWarnings(True) + + # Silence some loggers of external libraries: + silenced_loggers = [ + "waitress.queue", + ] + for logger in silenced_loggers: + logging.getLogger(logger).setLevel(logging.CRITICAL) + logging.getLogger(logger).propagate = False diff --git a/qt/aqt/mediasrv.py b/qt/aqt/mediasrv.py index 3056af94c..80fbd7ca1 100644 --- a/qt/aqt/mediasrv.py +++ b/qt/aqt/mediasrv.py @@ -10,7 +10,6 @@ import os import re import sys import threading -import time import traceback from dataclasses import dataclass from errno import EPROTOTYPE @@ -43,6 +42,7 @@ from aqt.utils import aqt_data_path, show_warning, tr # https://forums.ankiweb.net/t/anki-crash-when-using-a-specific-deck/22266 waitress.wasyncore._DISCONNECTED = waitress.wasyncore._DISCONNECTED.union({EPROTOTYPE}) # type: ignore +logger = logging.getLogger(__name__) app = flask.Flask(__name__, root_path="/fake") flask_cors.CORS(app, resources={r"/*": {"origins": "127.0.0.1"}}) @@ -98,11 +98,6 @@ class MediaServer(threading.Thread): def run(self) -> None: try: - if dev_mode: - # idempotent if logging has already been set up - logging.basicConfig() - logging.getLogger("waitress").setLevel(logging.ERROR) - desired_host = os.getenv("ANKI_API_HOST", "127.0.0.1") desired_port = int(os.getenv("ANKI_API_PORT") or 0) self.server = create_server( @@ -111,11 +106,11 @@ class MediaServer(threading.Thread): port=desired_port, clear_untrusted_proxy_headers=True, ) - if dev_mode: - print( - "Serving on http://%s:%s" - % (self.server.effective_host, self.server.effective_port) # type: ignore - ) + logger.info( + "Serving on http://%s:%s", + self.server.effective_host, # type: ignore[union-attr] + self.server.effective_port, # type: ignore[union-attr] + ) self._ready.set() self.server.run() @@ -300,8 +295,7 @@ def handle_request(pathin: str) -> Response: abort(403) req = _extract_request(pathin) - if dev_mode: - print(f"{time.time():.3f} {flask.request.method} /{pathin}") + logger.debug("%s /%s", flask.request.method, pathin) if isinstance(req, NotFound): print(req.message) diff --git a/qt/aqt/profiles.py b/qt/aqt/profiles.py index 3232f9f04..6bc93f913 100644 --- a/qt/aqt/profiles.py +++ b/qt/aqt/profiles.py @@ -309,6 +309,9 @@ class ProfileManager: def collectionPath(self) -> str: return os.path.join(self.profileFolder(), "collection.anki2") + def addon_logs(self) -> str: + return self._ensureExists(os.path.join(self.base, "logs")) + # Downgrade ######################################################################