From 3c5cfcb77d75bcb5c07d85675525ee21fb6a63fa Mon Sep 17 00:00:00 2001 From: CaliBrain Date: Tue, 20 Oct 2026 01:55:49 -0400 Subject: [PATCH] fix/redact log secrets (#1488) - fix(logging): mask tracker API keys in log output (#1486) - fix(welib): follow slow_download links through the countdown (#1447) --- shelfmark/core/logger.py | 26 ++++++++- .../direct_download/annas_archive.py | 12 +++++ tests/core/test_logger.py | 53 +++++++++++++++++++ tests/direct_download/test_welib_md5_match.py | 34 ++++++++++++ 4 files changed, 124 insertions(+), 1 deletion(-) diff --git a/shelfmark/core/logger.py b/shelfmark/core/logger.py index b9bdc55e..6a171344 100644 --- a/shelfmark/core/logger.py +++ b/shelfmark/core/logger.py @@ -1,6 +1,7 @@ """Logging configuration and custom logger with error tracing.""" import logging +import re import sys from collections.abc import Mapping from logging.handlers import RotatingFileHandler @@ -16,6 +17,29 @@ if TYPE_CHECKING: _file_handlers: dict[Path, RotatingFileHandler] = {} _file_handlers_lock = Lock() +# Query parameters that carry tracker/indexer credentials. Prowlarr guids are often +# the download URL itself (apikey included), and they end up in task ids that are +# logged all over the download pipeline, so mask them at the formatter instead. +_SECRET_QUERY_PARAM_PATTERN = re.compile( + r"(?<=[?&;])" + r"([a-z0-9_-]*api[_-]?key|api|apitoken|access_token|token|passkey|authkey|rsskey" + r"|torrent_pass|auth|key|password|passwd|pwd|pass|secret|sid|uid)" + r"=[^&\s#'\"<>;:,)\]]+", + re.IGNORECASE, +) + + +def redact_secrets(text: str) -> str: + """Mask credential query parameters in text, keeping the rest of the URL readable.""" + return _SECRET_QUERY_PARAM_PATTERN.sub(r"\1=(removed)", text) + + +class RedactingFormatter(logging.Formatter): + """Formatter that masks credentials in the message, traceback and stack info.""" + + def format(self, record: logging.LogRecord) -> str: + return redact_secrets(super().format(record)) + class CustomLogger(logging.Logger): """Custom logger class with additional error_trace method.""" @@ -162,7 +186,7 @@ def setup_logger(name: str, log_file: Path = LOG_FILE) -> CustomLogger: log_level = getattr(logging, LOG_LEVEL, logging.INFO) logger.setLevel(log_level) - formatter = logging.Formatter( + formatter = RedactingFormatter( "%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(message)s" ) diff --git a/shelfmark/release_sources/direct_download/annas_archive.py b/shelfmark/release_sources/direct_download/annas_archive.py index 64045987..193797de 100644 --- a/shelfmark/release_sources/direct_download/annas_archive.py +++ b/shelfmark/release_sources/direct_download/annas_archive.py @@ -1641,6 +1641,18 @@ def _get_download_url( ) or _find_first_anchor_with_text(soup, "Download", href_contains=md5) if get_btn: url = get_attr(get_btn, "href") or "" + # Welib's "Download" leads to a slow_download page with the same countdown + # as AA's, not to the file. Resolve it like an AA slow link, or the countdown + # HTML is what gets downloaded (#1447). + if "/slow_download/" in url: + return _get_download_url( + downloader.get_absolute_url(link, url), + title, + cancel_flag, + status_callback, + sel, + source_context, + ) elif md5: logger.info("No download link for md5 %s on %s", md5, link) else: diff --git a/tests/core/test_logger.py b/tests/core/test_logger.py index 1b1a2899..45f33932 100644 --- a/tests/core/test_logger.py +++ b/tests/core/test_logger.py @@ -1,7 +1,11 @@ """Tests for Shelfmark's logging configuration.""" +import io +import logging from logging.handlers import RotatingFileHandler +import pytest + import shelfmark.core.logger as logger_module @@ -58,3 +62,52 @@ def test_setup_logger_keeps_separate_handlers_for_separate_files(monkeypatch, tm with logger_module._file_handlers_lock: logger_module._file_handlers.pop(log_file) handler.close() + + +@pytest.mark.parametrize( + ("text", "expected"), + [ + ( + "Task 12:https://tracker.example/api?t=get&id=42&apikey=s3cr3t: starting download", + "Task 12:https://tracker.example/api?t=get&id=42&apikey=(removed): starting download", + ), + ( + "https://t.example/dl.php?passkey=abc&torrent_pass=def&API_KEY=ghi&r=1", + "https://t.example/dl.php?passkey=(removed)&torrent_pass=(removed)" + "&API_KEY=(removed)&r=1", + ), + ( + "url='http://prowlarr:9696/1/download?apikey=xyz&link=abc'", + "url='http://prowlarr:9696/1/download?apikey=(removed)&link=abc'", + ), + ( + "https://t.example/rss?id=7&uid=99&key=k", + "https://t.example/rss?id=7&uid=(removed)&key=(removed)", + ), + ("download_id=7 api_key_set=True", "download_id=7 api_key_set=True"), + ], +) +def test_redact_secrets_masks_credential_query_params(text, expected): + assert logger_module.redact_secrets(text) == expected + + +def test_setup_logger_redacts_messages_args_and_tracebacks(monkeypatch): + """Task ids built from Prowlarr guids carry tracker API keys (#1486).""" + monkeypatch.setattr(logger_module, "ENABLE_LOGGING", False) + logger = logger_module.setup_logger("shelfmark.test.redaction") + stream = io.StringIO() + for handler in logger.handlers: + assert isinstance(handler, logging.StreamHandler) + handler.setStream(stream) + + task_id = "3:https://tracker.example/api?t=get&id=42&apikey=s3cr3t" + logger.info("Task %s: starting download (%s) - %s", task_id, "Prowlarr", "Title") + try: + raise RuntimeError(f"refresh failed for {task_id}") + except RuntimeError: + logger.exception("Prowlarr release refresh failed: %s", task_id) + + output = stream.getvalue() + assert "s3cr3t" not in output + assert output.count("apikey=(removed)") == 3 + assert "id=42" in output diff --git a/tests/direct_download/test_welib_md5_match.py b/tests/direct_download/test_welib_md5_match.py index cf055022..4155938f 100644 --- a/tests/direct_download/test_welib_md5_match.py +++ b/tests/direct_download/test_welib_md5_match.py @@ -63,3 +63,37 @@ def test_a_page_that_is_not_md5_addressed_keeps_taking_the_first_download(): assert ( _resolve("https://example.org/book/42", page) == f"https://example.org/files/{OTHER}.epub" ) + + +def test_a_slow_download_link_is_followed_through_its_countdown(): + """Issue #1447: welib's Download leads to a slow_download page with AA's countdown. + + It was handed straight to the downloader, which got the countdown HTML instead of + the file. It must be resolved like an AA slow link: wait, re-fetch, take the link. + """ + slow_url = f"https://welib.org/slow_download/{WANTED}/0/0" + file_url = f"https://partner.example/files/{WANTED}.epub" + pages = { + WELIB_PAGE: [f'Download'], + slow_url: [ + '1', + f'📚 Download now', + ], + } + fetched: list[str] = [] + + def fake_get_page(url, **_kwargs): + fetched.append(url) + return pages[url].pop(0) + + with ( + patch.object(annas_archive.downloader, "html_get_page", side_effect=fake_get_page), + patch.object( + annas_archive.network, "get_aa_base_url", return_value="https://annas-archive.gl" + ), + patch.object(annas_archive, "_is_configured_zlib_link", return_value=False), + ): + resolved = annas_archive._get_download_url(WELIB_PAGE, "Amorino", selector=object()) # type: ignore[arg-type] + + assert resolved == file_url + assert fetched == [WELIB_PAGE, slow_url, slow_url]