diff --git a/shelfmark/bypass/external_bypasser.py b/shelfmark/bypass/external_bypasser.py index 39018741..53dad163 100644 --- a/shelfmark/bypass/external_bypasser.py +++ b/shelfmark/bypass/external_bypasser.py @@ -7,6 +7,7 @@ from typing import TYPE_CHECKING, Any import requests from shelfmark.bypass import BypassCancelledError +from shelfmark.bypass.challenge import challenge_marker from shelfmark.bypass.cookie_store import store_extracted_cookies from shelfmark.core.config import config from shelfmark.core.logger import setup_logger @@ -143,6 +144,25 @@ def _fetch_via_bypasser(target_url: str) -> str | None: logger.warning("External bypasser returned empty response for '%s'", target_url) return None + # "Challenge solved!" is the solver's verdict on its own work, and #1289 showed + # it can be reported alongside a page the caller then rejects. Say what actually + # came back, so a later report does not have to infer it from downstream errors. + marker = challenge_marker(html) + logger.debug( + "External bypasser page for '%s': %d bytes, challenge_marker=%r", + target_url, + len(html), + marker, + ) + if marker: + logger.warning( + "External bypasser reported success but returned a challenge page for " + "'%s' (%d bytes, marker=%r) - the solve did not clear the protection", + target_url, + len(html), + marker, + ) + try: _store_solution_clearance(target_url, solution) except AttributeError, KeyError, TypeError, ValueError: diff --git a/shelfmark/release_sources/direct_download.py b/shelfmark/release_sources/direct_download.py index f481599d..83836f7f 100644 --- a/shelfmark/release_sources/direct_download.py +++ b/shelfmark/release_sources/direct_download.py @@ -16,6 +16,7 @@ import requests from bs4 import BeautifulSoup, Tag from bs4.element import NavigableString +from shelfmark.bypass.challenge import MAX_CHALLENGE_HTML_CHARS, challenge_marker from shelfmark.config.env import DEBUG_SKIP_SOURCES, TMP_DIR from shelfmark.core import search_deadline from shelfmark.core.config import config @@ -556,13 +557,6 @@ _AA_PAGE_MARKERS = ( "/fast_download", "/slow_download", ) -_CHALLENGE_MARKERS = ( - "ddos-guard", - "just a moment", - "cloudflare", - "checking your browser", - "cf-browser-verification", -) def _looks_like_aa_page(html: str) -> bool: @@ -572,9 +566,61 @@ def _looks_like_aa_page(html: str) -> bool: def _looks_like_challenge_page(html: str) -> bool: - """Whether ``html`` is a protection interstitial rather than the site behind it.""" - lowered = html.lower() - return any(marker in lowered for marker in _CHALLENGE_MARKERS) + """Whether ``html`` is a protection interstitial rather than the site behind it. + + Delegates to the shared detector rather than substring-matching here. A bare + "ddos-guard"/"cloudflare" scan flags the protected site's *own* pages: DDoS-Guard + links its endpoints on everything it fronts, and AA ships a `DDOS-GUARD` comment in + the inline JS on every page it serves. That misread every real AA response that was + not a results table as an unsolved challenge, and sent users off to fix a bypasser + that had just succeeded - see #1289/#1292. `challenge_marker` caps its scan at + 64 KB, which is what separates a few-KB interstitial from the page behind it. + """ + return challenge_marker(html) is not None + + +# How much of an unreadable search page to quote in the debug log. Enough to carry the +# - title, injected challenge scripts - without pasting a 180 KB page into a log +# file that ships inside the debug bundle. +_PAGE_FINGERPRINT_CHARS = 700 +_TITLE_RE = re.compile(r"]*>(.*?)", re.IGNORECASE | re.DOTALL) + + +def _log_untabled_search_page(url: str, html: str) -> None: + """Record why a search page with no results table is about to be classified. + + #1289 cost a full investigation because the log said only "unsolved protection + challenge" while FlareSolverr said "Challenge solved!", and the debug bundle carries + no response bodies - there was no way to tell a real AA page from an interstitial + after the fact. These are the facts that would have settled it in one line: the size + (the 64 KB cap is what separates the two), which markers matched, and the head of + the document. + + Diagnostics must never be the reason a search fails, so this swallows its own errors. + """ + try: + title_match = _TITLE_RE.search(html[: _PAGE_FINGERPRINT_CHARS * 4]) + title = " ".join(title_match.group(1).split())[:120] if title_match else "" + lowered = html.lower() + aa_markers = [marker for marker in _AA_PAGE_MARKERS if marker in lowered] + logger.info( + "Search page has no results table: %s (bytes=%d, title=%r, aa_markers=%s, " + "challenge_marker=%r, over_challenge_size_cap=%s)", + url, + len(html), + title, + aa_markers or "none", + challenge_marker(html), + len(html) > MAX_CHALLENGE_HTML_CHARS, + ) + logger.debug( + "Untabled search page head (%d of %d bytes): %s", + min(len(html), _PAGE_FINGERPRINT_CHARS), + len(html), + html[:_PAGE_FINGERPRINT_CHARS], + ) + except Exception: + logger.debug("Could not fingerprint the untabled search page", exc_info=True) def _fetch_search_table(url: str, selector: network.AAMirrorSelector) -> tuple[str, Tag | None]: @@ -615,6 +661,19 @@ def _fetch_search_table(url: str, selector: network.AAMirrorSelector) -> tuple[s if "No files found." in html: # A real, genuinely empty answer from a healthy mirror. return html, None + + # A search page with no table is the one shape we cannot read off the response + # alone, and the response body is not in the debug bundle. Fingerprint it here + # so the next report says which branch fired and why, rather than costing + # another round of guesswork - see #1289. + _log_untabled_search_page(attempt_url, html) + + if _looks_like_aa_page(html): + # A real AA response in a shape the caller should report as drift. Checked + # ahead of the challenge branch: AA's own pages carry the protection's + # markers, so an interstitial is only the better explanation once the page + # has nothing of AA's about it. A genuine interstitial has no AA markers. + return html, None if _looks_like_challenge_page(html): # The bypass did not actually clear the protection - the interstitial is # what came back. Rotating is pointless (every mirror shares the same @@ -625,10 +684,6 @@ def _fetch_search_table(url: str, selector: network.AAMirrorSelector) -> tuple[s "Check that the bypasser is reachable and working." ) raise SearchUnavailableError(msg) - if _looks_like_aa_page(html): - # A real AA response in a shape the caller should report as drift. - # Not the mirror's fault. - return html, None new_base, action = selector.next_mirror_or_rotate_dns( fatal=True, reason="responded without an Anna's Archive page" diff --git a/tests/direct_download/test_search_challenge_false_positive.py b/tests/direct_download/test_search_challenge_false_positive.py new file mode 100644 index 00000000..9a0f8ce1 --- /dev/null +++ b/tests/direct_download/test_search_challenge_false_positive.py @@ -0,0 +1,217 @@ +"""A real Anna's Archive page must not be mistaken for a protection interstitial. + +Regression for #1289/#1292. `_looks_like_challenge_page` substring-matched "ddos-guard" +over the whole document, and DDoS-Guard-fronted sites carry that string on their *own* +pages - Anna's Archive ships a `DDOS-GUARD` comment in the inline JS it serves on every +page. Any real AA response that was not a results table was therefore reported as an +unsolved challenge, telling users to go fix a bypasser that had just succeeded. +""" + +import pytest +from bs4 import Tag + +# Verbatim from a live annas-archive.pk 403, trimmed of nothing that matters: this is +# what an interstitial actually looks like, and it is under a kilobyte. +DDOS_GUARD_INTERSTITIAL = ( + 'DDoS-Guard' + '' + '' + '' + '

' + 'Checking your browser before accessing

' + "

Please wait a few seconds.

" +) + +# The marker that made every real AA page look like a challenge, quoted from the live +# site's inline JS, plus enough real page to clear the 64 KB size guard. +_AA_DDG_COMMENT = '// "text/css" for DDOS-GUARD caching.' +AA_PAGE_WITHOUT_TABLE = ( + "Anna’s Archive" + f"" + '
a record' + + ("

real page body content

" * 3000) + + "
" +) + + +class _Selector: + def __init__(self, bases: list[str]) -> None: + self._bases = bases + self._index = 0 + self.current_base = bases[0] + self.quarantined: list[str] = [] + + def rewrite(self, url: str) -> str: + for base in self._bases: + if url.startswith(base): + return url.replace(base, self.current_base, 1) + return url + + def next_mirror_or_rotate_dns(self, *, fatal: bool = False, reason: str = ""): + if fatal: + self.quarantined.append(self.current_base) + self._index += 1 + if self._index >= len(self._bases): + return None, "exhausted" + self.current_base = self._bases[self._index] + return self.current_base, "mirror" + + +def _patch_pages(monkeypatch, pages: list[str]): + import shelfmark.release_sources.direct_download as dd + + calls: list[str] = [] + + def fake_get(url, **_kwargs): + calls.append(url) + return pages[len(calls) - 1] if len(calls) <= len(pages) else "" + + monkeypatch.setattr(dd.downloader, "html_get_page", fake_get) + monkeypatch.setattr(dd.network, "get_available_aa_urls", lambda: ["a", "b"]) + return dd, calls + + +@pytest.fixture +def search_logs(): + """Collect this module's log messages. + + setup_logger builds loggers outside the standard hierarchy, so their records never + reach the root handler caplog installs - see tests/bypass/test_ddg_cookie_reuse.py. + """ + import logging + + import shelfmark.release_sources.direct_download as dd + + messages: list[str] = [] + + class _Capture(logging.Handler): + def emit(self, record: logging.LogRecord) -> None: + messages.append(record.getMessage()) + + handler = _Capture() + dd.logger.addHandler(handler) + previous = dd.logger.level + dd.logger.setLevel(logging.DEBUG) + # Logger.setLevel only invalidates the is-enabled cache through the manager, which + # these loggers are not registered with; without this the DEBUG line stays filtered. + dd.logger._cache.clear() + try: + yield messages + finally: + dd.logger.removeHandler(handler) + dd.logger.setLevel(previous) + + +def test_the_size_guard_is_what_separates_a_real_page_from_an_interstitial(): + """The two inputs this bug turned on, checked directly.""" + import shelfmark.release_sources.direct_download as dd + from shelfmark.bypass.challenge import MAX_CHALLENGE_HTML_CHARS + + assert len(DDOS_GUARD_INTERSTITIAL) < MAX_CHALLENGE_HTML_CHARS + assert len(AA_PAGE_WITHOUT_TABLE) > MAX_CHALLENGE_HTML_CHARS + # Both contain "ddos-guard"; only one is a challenge. + assert "ddos-guard" in AA_PAGE_WITHOUT_TABLE.lower() + assert dd._looks_like_challenge_page(DDOS_GUARD_INTERSTITIAL) + assert not dd._looks_like_challenge_page(AA_PAGE_WITHOUT_TABLE) + + +def test_real_aa_page_without_a_table_is_not_reported_as_a_challenge(monkeypatch): + """The #1289 failure: a served AA page raised "unsolved protection challenge".""" + dd, calls = _patch_pages(monkeypatch, [AA_PAGE_WITHOUT_TABLE]) + selector = _Selector(["https://real.test", "https://other.test"]) + + html, table = dd._fetch_search_table("https://real.test/search?q=malice", selector) + + assert table is None + assert html == AA_PAGE_WITHOUT_TABLE + # A live mirror holding our clearance: neither quarantined nor rotated away from. + assert selector.quarantined == [] + assert len(calls) == 1 + + +def test_aa_markers_win_over_challenge_markers_on_the_same_page(monkeypatch): + """Ordering, not just the size guard, keeps a marker-carrying AA page readable.""" + dd, _calls = _patch_pages(monkeypatch, [AA_PAGE_WITHOUT_TABLE]) + monkeypatch.setattr(dd, "_looks_like_challenge_page", lambda _html: True) + selector = _Selector(["https://real.test", "https://other.test"]) + + _html, table = dd._fetch_search_table("https://real.test/search?q=malice", selector) + + assert table is None + + +def test_genuine_interstitial_still_raises(monkeypatch): + """The behaviour the check exists for is untouched.""" + dd, _calls = _patch_pages(monkeypatch, [DDOS_GUARD_INTERSTITIAL]) + selector = _Selector(["https://real.test", "https://other.test"]) + + with pytest.raises(dd.SearchUnavailableError, match="protection challenge"): + dd._fetch_search_table("https://real.test/search?q=malice", selector) + + assert selector.quarantined == [] + + +def test_results_table_is_still_returned(monkeypatch): + """A page carrying the marker and a table is read as results, as before.""" + page = AA_PAGE_WITHOUT_TABLE.replace( + "
", "
Malice
" + ) + dd, _calls = _patch_pages(monkeypatch, [page]) + selector = _Selector(["https://real.test"]) + + _html, table = dd._fetch_search_table("https://real.test/search?q=malice", selector) + + assert isinstance(table, Tag) + + +def test_untabled_page_is_fingerprinted_in_the_log(monkeypatch, search_logs): + """#1289 was unsolvable from the bundle because no line said what came back. + + The log must carry the facts that separate the two cases, so the next report is read + rather than reverse-engineered: size, whether the size guard applied, the AA markers + found, and the challenge marker (or its absence). + """ + dd, _calls = _patch_pages(monkeypatch, [AA_PAGE_WITHOUT_TABLE]) + selector = _Selector(["https://real.test", "https://other.test"]) + + dd._fetch_search_table("https://real.test/search?q=malice", selector) + + verdict = next(m for m in search_logs if "no results table" in m) + assert f"bytes={len(AA_PAGE_WITHOUT_TABLE)}" in verdict + assert "over_challenge_size_cap=True" in verdict + assert "challenge_marker=None" in verdict + assert "/md5/" in verdict + # The head of the document is quoted too, bounded so a 180 KB page cannot flood the + # log file that ships inside the debug bundle. + head = next(m for m in search_logs if "Untabled search page head" in m) + assert AA_PAGE_WITHOUT_TABLE[:200] in head + assert len(head) < 2000 + + +def test_interstitial_fingerprint_names_the_marker_that_proved_it(monkeypatch, search_logs): + """The same line must also settle the opposite case, without needing the body.""" + dd, _calls = _patch_pages(monkeypatch, [DDOS_GUARD_INTERSTITIAL]) + selector = _Selector(["https://real.test", "https://other.test"]) + + with pytest.raises(dd.SearchUnavailableError): + dd._fetch_search_table("https://real.test/search?q=malice", selector) + + verdict = next(m for m in search_logs if "no results table" in m) + assert "over_challenge_size_cap=False" in verdict + assert "challenge_marker='/.well-known/ddos-guard/'" in verdict + assert "aa_markers=none" in verdict + + +def test_fingerprint_failure_never_breaks_a_search(monkeypatch): + """Diagnostics are best-effort; a bug in them must not cost the user their search.""" + dd, _calls = _patch_pages(monkeypatch, [AA_PAGE_WITHOUT_TABLE]) + + def boom(_html): + raise RuntimeError("marker scan blew up") + + monkeypatch.setattr(dd, "challenge_marker", boom) + selector = _Selector(["https://real.test", "https://other.test"]) + + _html, table = dd._fetch_search_table("https://real.test/search?q=malice", selector) + + assert table is None