From f93b264bd48b59b61916559de0a12fd5fc5fdbeb Mon Sep 17 00:00:00 2001 From: Feramance Date: Wed, 4 Nov 2026 21:12:18 +0100 Subject: [PATCH 1/2] fix: explain and back off refused torrent removals --- CHANGELOG.md | 3 +- docs/configuration/seeding.md | 14 ++++- docs/features/health-monitoring.md | 6 ++ qBitrr/arss/qbit_side_effects.py | 91 +++++++++++++++++++++++++----- qBitrr/arss/torrent_batch.py | 41 ++++++++------ qBitrr/arss/torrent_inspect.py | 23 ++++---- qBitrr/arss/torrent_limits.py | 37 +++++++----- tests/test_hnr_removal_boundary.py | 82 +++++++++++++++++++++++++++ 8 files changed, 239 insertions(+), 58 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 993a727b..4ad7867d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,7 +17,8 @@ ## Unreleased ### Bug Fixes -- Remove verified empty metadata-stuck magnets after removal policies clear, and prevent them from blocking cleanup of other torrents sharing their save folder (#637). +- Explain refused torrent removals, back off unchanged candidates for five minutes, and report actual removal outcomes separately (#639). +- Remove verified empty metadata-stuck magnets after removal policies clear, and prevent them from blocking cleanup of other torrents sharing their save folder (#637, #527). ## v5.14.7-3 (29/10/2026) diff --git a/docs/configuration/seeding.md b/docs/configuration/seeding.md index 1ea7b720..6375c933 100644 --- a/docs/configuration/seeding.md +++ b/docs/configuration/seeding.md @@ -10,8 +10,18 @@ blocks every removal reason, including custom-format failures and failed categor Completed torrents must pass their effective ratio/time policy using its configured AND/OR mode. Incomplete torrents must pass minimum age and stalled grace: `-1` holds them indefinitely, `0` adds no stalled grace, and positive values require idle minutes. -Blocked requests are reclassified on the next scan. Changed activity, category, location, -or a re-added torrent invalidates the previous decision. Saving settings never deletes torrents. +Blocked candidates remain subject to current classification on each scan. Unchanged refused +candidates back off for five minutes before repeating the final removal and content checks. +Changed activity, progress, ratio, tags, category, location, or a re-added torrent ends that +backoff immediately; tracker or policy changes are checked on the next retry. All protections +are checked again before deletion. Saving settings never deletes torrents. + +The INFO log names each new refusal reason per torrent and qBittorrent instance, including +never-remove policy, age or stalled grace, HnR, changed identity, and unverified shared-content +ownership. Unchanged refusals do not repeat their reason or mark the torrent again during +backoff. `Deletion summary` reports `candidates`, `blocked` (including deferred refusals), +`pending` (uncertain client responses), and `confirmed_removed` (successful client responses) +separately. Arr queue removal and blocklisting still wait for client removal confirmation. ## Overview diff --git a/docs/features/health-monitoring.md b/docs/features/health-monitoring.md index 386c2fda..f0665b76 100644 --- a/docs/features/health-monitoring.md +++ b/docs/features/health-monitoring.md @@ -115,6 +115,12 @@ A torrent is considered "stalled" when: Metadata-stuck torrents use the same `StalledDelay`, `ReSearchStalled`, and `IgnoreTorrentsYoungerThan` settings as stalled downloads. Timing is based on `added_on` for metadata states because qBittorrent can keep updating `last_activity` during metadata retries. +`RemoveTorrent = -1` prevents removal even after stalled grace expires. To enable cleanup, +choose removal mode 1–4 and keep the required HnR protections configured. Refused candidates +log their reason once and retry after five minutes, or sooner when torrent activity changes. +The deletion summary separates candidates, blocked requests, uncertain pending responses, +and successful client removals. + When a metadata-stuck torrent has zero downloaded payload bytes, zero progress, and a verified empty file list, qBitrr removes only its client entry after the removal rules clear. Missing privacy or tracker metadata does not block this empty-magnet cleanup, and the magnet does not block cleanup of other torrents in its save folder. Arr queue removal and blocklisting follow successful client removal. Unknown downloaded bytes disable this shortcut; a failed file-list lookup during metadata-only verification blocks that clearance attempt. Ordinary HnR clearance does not require a downloaded-byte count or file-list lookup, though content deletion still requires verified file ownership. ### Configuration diff --git a/qBitrr/arss/qbit_side_effects.py b/qBitrr/arss/qbit_side_effects.py index d1eb99b8..fdc9e3fb 100644 --- a/qBitrr/arss/qbit_side_effects.py +++ b/qBitrr/arss/qbit_side_effects.py @@ -3,6 +3,7 @@ from __future__ import annotations import contextlib +import time from collections import defaultdict from collections.abc import Callable, Iterable from pathlib import Path @@ -235,6 +236,31 @@ def removal_candidate(torrent: Any) -> tuple: ) +def removal_observation(torrent: Any) -> tuple: + """Capture identity and activity changes that should end removal backoff.""" + return removal_candidate(torrent) + tuple( + getattr(torrent, key, None) + for key in ( + "state_enum", + "progress", + "downloaded", + "ratio", + "seeding_time", + "last_activity", + "tags", + "super_seeding", + ) + ) + + +def removal_retry_deferred(worker: Any, instance: str, torrent: Any) -> bool: + """Defer unchanged refused candidates for five minutes, without authorizing removal.""" + previous = getattr(worker, "_blocked_removals", {}).get((instance, torrent.hash)) + return bool( + previous and previous[0] == removal_observation(torrent) and time.monotonic() < previous[2] + ) + + def content_removal_allowed(worker: Any, paths: list[Path]) -> bool: """Verify HnR for every current torrent referencing any targeted content path.""" owners = [] @@ -345,48 +371,81 @@ def delete_hashes_per_instance( for hash_ in hashes: expected = getattr(worker, "_removal_candidates", {}).get((instance_name, hash_)) + observed = None + + def refuse(reason: str, torrent: Any = None, *, warning: bool = False) -> bool: + """Log a changed refusal once and defer this candidate's next attempt.""" + if not hasattr(worker, "_blocked_removals"): + worker._blocked_removals = {} + key = (instance_name, hash_) + observation = removal_observation(torrent) if torrent is not None else None + previous = worker._blocked_removals.get(key) + if previous is None or previous[:2] != (observation, reason): + log = worker.logger.warning if warning else worker.logger.info + log( + "Removal blocked for %s on %s: %s; retry in 300s or after activity changes", + hash_, + instance_name, + reason, + ) + worker._blocked_removals[key] = (observation, reason, time.monotonic() + 300) + return False + def attempt() -> bool: """Recheck identity and removal protections before each client deletion attempt.""" - nonlocal expected + nonlocal expected, observed current = resolve_removal_torrent(worker, hash_, instance_name) if current is None: if (instance_name, hash_) not in getattr( worker, "_pending_client_removals", {} ): - return False + return refuse("torrent lookup unavailable or torrent absent") client = worker._get_qbit_client(instance_name) if client is None: - return False + return refuse("owning client unavailable") present = any( t.hash.lower() == hash_.lower() for t in client.torrents_info(torrent_hashes=hash_) ) if present: worker._pending_client_removals.pop((instance_name, hash_), None) - return not present + return ( + refuse("torrent still present after uncertain removal") + if present + else True + ) instance, client, torrent = current + observed = torrent key = (instance_name, hash_) # Fresh presence disproves the old uncertain removal, even if this retry refuses. getattr(worker, "_pending_client_removals", {}).pop(key, None) + if expected is not None and removal_retry_deferred(worker, instance, torrent): + return False snapshot = removal_candidate(torrent) if expected is None: expected = snapshot if expected != snapshot: - return False + return refuse("torrent identity or location changed", torrent) reason = getattr(worker, "_removal_reasons", {}).get((instance, hash_)) if reason == "CF unmet deletion" and not ( worker.custom_format_unmet_search and worker.custom_format_unmet_check(torrent) ): - return False + return refuse("custom-format failure no longer applies", torrent) if not worker._deletion_rules_allow( torrent, "final torrent removal", instance_name=instance, client=client ): - return False + return refuse( + getattr(worker, "_removal_rule_reason", "removal rules refused"), torrent + ) metadata_only = is_metadata_only_torrent(client, torrent) if delete_files and not metadata_only: paths = _torrent_file_paths(client, torrent) - if not paths or not content_removal_allowed(worker, paths): - return False + if not paths: + return refuse("no verified content paths", torrent) + if not content_removal_allowed(worker, paths): + return refuse( + "shared content ownership or removal protections refused", torrent + ) # A content scan can be lengthy; refresh the candidate again before mutation. current = resolve_removal_torrent(worker, hash_, instance) if ( @@ -397,7 +456,10 @@ def attempt() -> bool: current[2], "final torrent removal", instance_name=instance, client=client ) ): - return False + return refuse( + "torrent changed or removal protections refused after content scan", + torrent, + ) if not hasattr(worker, "_pending_client_removals"): worker._pending_client_removals = {} peers = {instance_name} | { @@ -416,7 +478,9 @@ def attempt() -> bool: ) if result is False or not worker._pending_client_removals[key][1]: worker._pending_client_removals.pop(key, None) - return result is not False + return ( + refuse("qBittorrent rejected deletion", torrent) if result is False else True + ) try: result = ( @@ -431,13 +495,14 @@ def attempt() -> bool: ) ) if result: + getattr(worker, "_blocked_removals", {}).pop((instance_name, hash_), None) deleted.add((instance_name, hash_)) worker.logger.info( "Removed torrent %s from %s after HnR clearance", hash_, instance_name ) except Exception as exc: - worker.logger.warning( - "Removal retained for %s on %s: %s", hash_, instance_name, type(exc).__name__ + refuse( + f"removal lookup or API failure ({type(exc).__name__})", observed, warning=True ) return deleted diff --git a/qBitrr/arss/torrent_batch.py b/qBitrr/arss/torrent_batch.py index a7d291a4..db58d868 100644 --- a/qBitrr/arss/torrent_batch.py +++ b/qBitrr/arss/torrent_batch.py @@ -259,24 +259,14 @@ def _process_errored(self) -> None: self.timed_ignore_cache.add(k) self.recheck_by_instance = still_pending - def _log_deletion_summary_line(self) -> None: - n_delete = len(self.delete) - n_missing = len(self.missing_files_post_delete) - n_bad_msg = len(self.downloads_with_bad_error_message_blocklist) - n_remove = len(self.remove_from_qbit) - n_remove_by_inst = sum(len(s) for s in self.remove_from_qbit_by_instance.values()) - n_delete_by_inst = sum(len(s) for s in self.delete_by_instance.values()) - n_skip = len(self.skip_blacklist) + def _log_deletion_summary_line(self, candidates: int, removed: int, pending: int) -> None: + """Report actual client outcomes, counting deferred refusals as blocked.""" self.logger.info( - "Deletion summary: delete=%d, missing_files=%d, bad_error_blocklist=%d, " - "remove_from_qbit=%d, remove_by_instance=%d, delete_by_instance=%d, skip_blacklist=%d", - n_delete, - n_missing, - n_bad_msg, - n_remove, - n_remove_by_inst, - n_delete_by_inst, - n_skip, + "Deletion summary: candidates=%d, blocked=%d, pending=%d, confirmed_removed=%d", + candidates, + candidates - removed - pending, + pending, + removed, ) def _log_deletion_sample_debug(self, to_delete_all: set[str]) -> None: @@ -441,7 +431,6 @@ def _process_failed_deletes( or self.delete_by_instance ): return - self._log_deletion_summary_line() self._log_deletion_sample_debug(to_delete_all) from qBitrr.arss.qbit_side_effects import ( complete_removal_followups, @@ -470,6 +459,11 @@ def _process_failed_deletes( for inst_name, hashes in self.delete_by_instance.items(): if hashes: per_instance_batches.setdefault(inst_name, set()).update(hashes) + mapped_hashes = _collect_instance_hash_map_hashes(per_instance_batches) + legacy_hashes = to_delete_all | self.remove_from_qbit | self.skip_blacklist + candidate_count = sum(map(len, per_instance_batches.values())) + len( + legacy_hashes - mapped_hashes + ) confirmed_pairs = delete_hashes_per_instance( self, per_instance_batches, @@ -533,6 +527,17 @@ def _process_failed_deletes( self._process_failed_dispatch_queue_deletes( dispatch_targets, skip_blacklist, cross_arr=cross_arr ) + removed_pairs = confirmed_pairs | primary_pairs + pending_count = sum( + key not in removed_pairs + and ( + key[0] in per_instance_batches + and key[1] in per_instance_batches[key[0]] + or key[1] in legacy_hashes - mapped_hashes + ) + for key in getattr(self, "_pending_client_removals", {}) + ) + self._log_deletion_summary_line(candidate_count, len(removed_pairs), pending_count) all_deleted = confirmed_deleted if self.missing_files_post_delete: self.missing_files_post_delete -= all_deleted diff --git a/qBitrr/arss/torrent_inspect.py b/qBitrr/arss/torrent_inspect.py index a3b0afb0..80472978 100644 --- a/qBitrr/arss/torrent_inspect.py +++ b/qBitrr/arss/torrent_inspect.py @@ -208,18 +208,19 @@ def _mark_for_deletion( % (seeding_time_limit if seeding_time_limit > 0 else "unset") ) extra = " [%s]" % ", ".join(parts) - self.logger.info( - "Marking for deletion (%s): [Progress: %s%%][Ratio: %s][Seeding time: %s] | %s (%s)%s", - reason, - round(torrent.progress * 100, 2), - torrent.ratio, - timedelta(seconds=torrent.seeding_time), - torrent.name, - torrent.hash, - extra, - ) - from qBitrr.arss.qbit_side_effects import removal_candidate + from qBitrr.arss.qbit_side_effects import removal_candidate, removal_retry_deferred + if not removal_retry_deferred(self, instance_name, torrent): + self.logger.info( + "Marking for deletion (%s): [Progress: %s%%][Ratio: %s][Seeding time: %s] | %s (%s)%s", + reason, + round(torrent.progress * 100, 2), + torrent.ratio, + timedelta(seconds=torrent.seeding_time), + torrent.name, + torrent.hash, + extra, + ) if not hasattr(self, "_removal_candidates"): self._removal_candidates = {} self._removal_candidates[(instance_name, torrent.hash)] = removal_candidate(torrent) diff --git a/qBitrr/arss/torrent_limits.py b/qBitrr/arss/torrent_limits.py index 6a1d7d04..071107dd 100644 --- a/qBitrr/arss/torrent_limits.py +++ b/qBitrr/arss/torrent_limits.py @@ -383,24 +383,30 @@ def _deletion_rules_allow( from qBitrr.config import CONFIG, get_ignore_torrents_younger_than_effective from qBitrr.qbit_seeding_config import load_qbit_seeding_config + def refuse(message: str) -> bool: + """Expose the final rule refusal to the shared removal logger.""" + self._removal_rule_reason = message + return False + + self._removal_rule_reason = "removal rules refused" try: for key in ("progress", "ratio", "seeding_time", "added_on", "last_activity"): value = getattr(torrent, key) if isinstance(value, bool) or not math.isfinite(value) or value < 0: - return False + return refuse("invalid or unknown torrent accounting") if torrent.progress > 1: - return False + return refuse("progress exceeds 100%") if not self._hnr_allows_delete( torrent, reason, instance_name=instance_name, client=client ): - return False + return refuse("HnR obligations unmet or unverified") if CONFIG.get(f"{instance_name}.Disabled", fallback=False): - return False + return refuse("qBittorrent instance disabled") tags = {tag.strip() for tag in (getattr(torrent, "tags", "") or "").split(",")} if tags & {"qBitrr-ignored", "qBitrr-free_space_paused"}: - return False + return refuse("ignored or free-space-paused tag") if torrent.super_seeding or torrent.state_enum == TorrentStates.FORCED_UPLOAD: - return False + return refuse("super-seeding or forced upload") loaded = load_qbit_seeding_config(instance_name) policy = dict(loaded["default_seeding"]) matches = [ @@ -429,7 +435,7 @@ def _deletion_rules_allow( ) now = time.time() if not 0 < torrent.added_on <= now or now - torrent.added_on < age: - return False + return refuse("minimum torrent age not reached or added_on invalid") arr_policy = ( CONFIG.get(f"{arr_section}.Torrent.SeedingMode", fallback={}) if arr_section @@ -447,13 +453,13 @@ def _deletion_rules_allow( if key == "MaxSeedingTime": value = parse_duration(value, fallback=float("nan")) if isinstance(value, bool) or not math.isfinite(value): - return False + return refuse("invalid seeding limit") policy[key] = value mode = policy.get("RemoveTorrent", -1) if isinstance(arr_policy, dict): mode = arr_policy.get("RemoveTorrent", -1) if isinstance(mode, bool) or mode not in (1, 2, 3, 4): - return False + return refuse("RemoveTorrent=-1 (never remove) or invalid removal mode") if torrent.progress < 1: delay = parse_duration( policy.get("StalledDelay", loaded.get("stalled_delay", -1)), @@ -470,12 +476,15 @@ def _deletion_rules_allow( in (TorrentStates.METADATA_DOWNLOAD, TorrentStates.FORCED_METADATA_DOWNLOAD) else torrent.last_activity ) - return ( + allowed = ( math.isfinite(delay) and delay >= 0 and 0 < reference <= now and now - reference >= max(age, delay * 60) ) + return allowed or refuse( + "StalledDelay disabled, grace not expired, or activity unknown" + ) actual_hosts = { _extract_tracker_host(t.url) for t in client.torrents_trackers(torrent_hash=torrent.hash) @@ -503,12 +512,14 @@ def _deletion_rules_allow( settings.get("seeding_time_limit", -1), native.get("seeding_time_limit", -1) ) if not math.isfinite(ratio) or not math.isfinite(seed_time): - return False + return refuse("invalid effective seeding limits") if settings.get("ratio_limit", -1) <= 0: ratio = max(ratio, policy.get("MaxUploadRatio", -1)) if settings.get("seeding_time_limit", -1) <= 0: seed_time = max(seed_time, policy.get("MaxSeedingTime", -1)) - return self.torrent_limit_check(torrent, seed_time, ratio, remove_mode=mode) + return self.torrent_limit_check(torrent, seed_time, ratio, remove_mode=mode) or refuse( + "ratio/time removal policy not satisfied" + ) except Exception as exc: self.logger.warning( "Removal rules unavailable for %s on %s: %s", @@ -516,7 +527,7 @@ def _deletion_rules_allow( instance_name, type(exc).__name__, ) - return False + return refuse(f"removal rules unavailable ({type(exc).__name__})") def _hnr_allows_delete( self, diff --git a/tests/test_hnr_removal_boundary.py b/tests/test_hnr_removal_boundary.py index 80ecc0b0..ec57b018 100644 --- a/tests/test_hnr_removal_boundary.py +++ b/tests/test_hnr_removal_boundary.py @@ -143,6 +143,88 @@ def allowed(self): self.torrent, "test", instance_name="one", client=self.client ) + def test_blocked_candidate_backs_off_without_repeated_marking(self) -> None: + """Log a refusal once and retry unchanged candidates only after five minutes.""" + self.torrent.ratio = 2 + self.worker.logger = MagicMock() + self.seeding["default_seeding"]["RemoveTorrent"] = -1 + with patch("qBitrr.arss.qbit_side_effects.time.monotonic", return_value=100) as clock: + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + self.worker._log_deletion_summary_line.assert_called_with(1, 0, 0) + messages = [str(call) for call in self.worker.logger.info.call_args_list] + self.assertTrue(any("RemoveTorrent=-1" in message for message in messages)) + self.worker.logger.reset_mock() + self.worker._reset_removal_requests() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + with patch.object(self.worker, "_deletion_rules_allow") as rules: + self.worker._process_failed() + rules.assert_not_called() + self.worker.logger.info.assert_not_called() + clock.return_value = 400 + self.worker._reset_removal_requests() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + self.assertEqual( + self.worker.logger.info.call_count, 1 + ) # Marking, same refusal stays quiet. + self.client.torrents_delete.assert_not_called() + + def test_backoff_ends_after_activity_change_and_rechecks_protections(self) -> None: + """Activity changes trigger fresh rules and successful deletion clears backoff.""" + self.torrent.ratio = 2 + self.seeding["default_seeding"]["RemoveTorrent"] = -1 + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + self.seeding["default_seeding"]["RemoveTorrent"] = 1 + self.torrent.last_activity = 2 + self.worker._reset_removal_requests() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + self.client.torrents_delete.assert_called_once() + self.worker._log_deletion_summary_line.assert_called_with(1, 1, 0) + self.assertFalse(self.worker._blocked_removals) + + def test_content_and_identity_refusals_are_logged(self) -> None: + """Explain previously silent identity and file-ownership refusals.""" + self.torrent.ratio = 2 + self.worker.logger = MagicMock() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.torrent.added_on = 2 + self.worker._process_failed() + self.assertIn("identity or location changed", str(self.worker.logger.info.call_args)) + self.torrent.last_activity = 2 + self.worker._reset_removal_requests() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + with patch("qBitrr.arss.qbit_side_effects.content_removal_allowed", return_value=False): + self.worker._process_failed() + self.assertIn("shared content ownership", str(self.worker.logger.info.call_args)) + self.client.torrents_delete.assert_not_called() + + def test_summary_counts_instances_and_uncertain_api_results(self) -> None: + """The same hash on two clients represents two separate candidate outcomes.""" + self.torrent.ratio = 2 + other, client = self.worker.add("two", ratio=2) + client.torrents_delete.side_effect = qbittorrentapi.exceptions.APIError("offline") + self.worker.cache = {"SUPERMAN": 17} + for instance, torrent in (("one", self.torrent), ("two", other)): + self.worker._mark_for_deletion(torrent, "Stalled State", instance_name=instance) + self.worker._process_failed() + self.worker._log_deletion_summary_line.assert_called_with(2, 1, 1) + self.worker._process_failed_dispatch_queue_deletes.assert_not_called() + + def test_summary_logs_blocked_and_confirmed_separately(self) -> None: + """Summary values describe outcomes instead of pending-set sizes.""" + self.worker.logger = MagicMock() + TorrentBatch._log_deletion_summary_line(self.worker, 4, 1, 1) + self.worker.logger.info.assert_called_once_with( + "Deletion summary: candidates=%d, blocked=%d, pending=%d, confirmed_removed=%d", + 4, + 2, + 1, + 1, + ) + def test_final_boundary_requires_every_protection(self): """Verify final boundary requires every protection.""" self.torrent.ratio = 2 From 7c7378f6e831723215a44d4469373d2a43547240 Mon Sep 17 00:00:00 2001 From: Feramance Date: Thu, 5 Nov 2026 09:07:36 +0100 Subject: [PATCH 2/2] fix: address removal backoff and accounting review findings --- docs/configuration/seeding.md | 9 +- qBitrr/arss/qbit_side_effects.py | 39 +++++-- qBitrr/arss/torrent_batch.py | 99 +++++++++++------ qBitrr/arss/torrent_inspect.py | 52 ++++++--- tests/test_hnr_removal_boundary.py | 166 +++++++++++++++++++++++++++-- 5 files changed, 295 insertions(+), 70 deletions(-) diff --git a/docs/configuration/seeding.md b/docs/configuration/seeding.md index 6375c933..7c77eb4a 100644 --- a/docs/configuration/seeding.md +++ b/docs/configuration/seeding.md @@ -11,7 +11,10 @@ Completed torrents must pass their effective ratio/time policy using its configu AND/OR mode. Incomplete torrents must pass minimum age and stalled grace: `-1` holds them indefinitely, `0` adds no stalled grace, and positive values require idle minutes. Blocked candidates remain subject to current classification on each scan. Unchanged refused -candidates back off for five minutes before repeating the final removal and content checks. +candidates back off for five minutes before repeating the final removal and content checks, +including direct content-cleanup calls and unavailable targeted lookups. Elapsed seeding +time alone does not cancel the delay. Refusal records are pruned after a scan no longer +observes the candidate. Changed activity, progress, ratio, tags, category, location, or a re-added torrent ends that backoff immediately; tracker or policy changes are checked on the next retry. All protections are checked again before deletion. Saving settings never deletes torrents. @@ -21,7 +24,9 @@ never-remove policy, age or stalled grace, HnR, changed identity, and unverified ownership. Unchanged refusals do not repeat their reason or mark the torrent again during backoff. `Deletion summary` reports `candidates`, `blocked` (including deferred refusals), `pending` (uncertain client responses), and `confirmed_removed` (successful client responses) -separately. Arr queue removal and blocklisting still wait for client removal confirmation. +separately. Hash comparisons ignore case; legacy pending work is counted once per hash. +When a later lookup confirms an uncertain removal, an INFO message identifies the hash +and client instance. Arr queue removal and blocklisting still wait for client removal confirmation. ## Overview diff --git a/qBitrr/arss/qbit_side_effects.py b/qBitrr/arss/qbit_side_effects.py index fdc9e3fb..cd46268e 100644 --- a/qBitrr/arss/qbit_side_effects.py +++ b/qBitrr/arss/qbit_side_effects.py @@ -245,7 +245,6 @@ def removal_observation(torrent: Any) -> tuple: "progress", "downloaded", "ratio", - "seeding_time", "last_activity", "tags", "super_seeding", @@ -255,9 +254,13 @@ def removal_observation(torrent: Any) -> tuple: def removal_retry_deferred(worker: Any, instance: str, torrent: Any) -> bool: """Defer unchanged refused candidates for five minutes, without authorizing removal.""" - previous = getattr(worker, "_blocked_removals", {}).get((instance, torrent.hash)) + key = (instance, torrent.hash.lower()) + observation = removal_observation(torrent) + previous = getattr(worker, "_blocked_removals", {}).get(key) return bool( - previous and previous[0] == removal_observation(torrent) and time.monotonic() < previous[2] + previous + and (previous[0] is None or previous[0] == observation) + and time.monotonic() < previous[2] ) @@ -351,6 +354,10 @@ def reconcile_removal_attempts(worker: Any) -> None: if not absent: continue _confirm_removal_attempt(worker, key) + getattr(worker, "_blocked_removals", {}).pop((instance, hash_.lower()), None) + worker.logger.info( + "Confirmed removal of %s on %s after uncertain response", hash_, instance + ) except Exception as exc: worker.logger.warning( "Removal confirmation will retry %s on %s: %s", hash_, instance, type(exc).__name__ @@ -370,6 +377,18 @@ def delete_hashes_per_instance( for instance_name, hashes in batches.items(): for hash_ in hashes: expected = getattr(worker, "_removal_candidates", {}).get((instance_name, hash_)) + key = (instance_name, hash_.lower()) + if not hasattr(worker, "_removal_observations"): + worker._removal_observations = {} + observation = worker._removal_observations.setdefault(key, None) + previous = getattr(worker, "_blocked_removals", {}).get(key) + if ( + previous + and (previous[0] is None or previous[0] == observation) + and time.monotonic() < previous[2] + and (instance_name, hash_) not in getattr(worker, "_pending_client_removals", {}) + ): + continue observed = None @@ -377,8 +396,12 @@ def refuse(reason: str, torrent: Any = None, *, warning: bool = False) -> bool: """Log a changed refusal once and defer this candidate's next attempt.""" if not hasattr(worker, "_blocked_removals"): worker._blocked_removals = {} - key = (instance_name, hash_) - observation = removal_observation(torrent) if torrent is not None else None + key = (instance_name, hash_.lower()) + observation = ( + removal_observation(torrent) + if torrent is not None + else worker._removal_observations.get(key) + ) previous = worker._blocked_removals.get(key) if previous is None or previous[:2] != (observation, reason): log = worker.logger.warning if warning else worker.logger.info @@ -419,7 +442,7 @@ def attempt() -> bool: key = (instance_name, hash_) # Fresh presence disproves the old uncertain removal, even if this retry refuses. getattr(worker, "_pending_client_removals", {}).pop(key, None) - if expected is not None and removal_retry_deferred(worker, instance, torrent): + if removal_retry_deferred(worker, instance, torrent): return False snapshot = removal_candidate(torrent) if expected is None: @@ -495,7 +518,9 @@ def attempt() -> bool: ) ) if result: - getattr(worker, "_blocked_removals", {}).pop((instance_name, hash_), None) + getattr(worker, "_blocked_removals", {}).pop( + (instance_name, hash_.lower()), None + ) deleted.add((instance_name, hash_)) worker.logger.info( "Removed torrent %s from %s after HnR clearance", hash_, instance_name diff --git a/qBitrr/arss/torrent_batch.py b/qBitrr/arss/torrent_batch.py index db58d868..83c03d47 100644 --- a/qBitrr/arss/torrent_batch.py +++ b/qBitrr/arss/torrent_batch.py @@ -381,6 +381,13 @@ def _reset_removal_requests(self, *, cross_arr: bool = False) -> None: from qBitrr.arss.qbit_side_effects import reconcile_removal_attempts reconcile_removal_attempts(self) + observations = getattr(self, "_removal_observations", {}) + self._blocked_removals = { + key: value + for key, value in getattr(self, "_blocked_removals", {}).items() + if key in observations + } + self._removal_observations = {} # Queue retries must run even when the next torrent listing is empty. if cross_arr: for arr in self.manager.managed_objects.values(): @@ -459,11 +466,15 @@ def _process_failed_deletes( for inst_name, hashes in self.delete_by_instance.items(): if hashes: per_instance_batches.setdefault(inst_name, set()).update(hashes) - mapped_hashes = _collect_instance_hash_map_hashes(per_instance_batches) + candidate_pairs = { + (instance, hash_.lower()) + for instance, hashes in per_instance_batches.items() + for hash_ in hashes + } + mapped_hashes = {hash_ for _, hash_ in candidate_pairs} legacy_hashes = to_delete_all | self.remove_from_qbit | self.skip_blacklist - candidate_count = sum(map(len, per_instance_batches.values())) + len( - legacy_hashes - mapped_hashes - ) + legacy_targets = {hash_.lower() for hash_ in legacy_hashes} - mapped_hashes + candidate_count = len(candidate_pairs) + len(legacy_targets) confirmed_pairs = delete_hashes_per_instance( self, per_instance_batches, @@ -476,13 +487,19 @@ def _process_failed_deletes( mapping[instance].discard(hash_) if not mapping[instance]: del mapping[instance] - pending_per_instance = _collect_instance_hash_map_hashes( - self.delete_by_instance, self.remove_from_qbit_by_instance - ) - per_instance_deleted = {hash_ for _, hash_ in confirmed_pairs} - pending_per_instance + pending_per_instance = { + hash_.lower() + for hash_ in _collect_instance_hash_map_hashes( + self.delete_by_instance, self.remove_from_qbit_by_instance + ) + } + per_instance_deleted = { + hash_ for _, hash_ in confirmed_pairs if hash_.lower() not in pending_per_instance + } deleted_hashes = set(per_instance_deleted) - to_delete_all = to_delete_all - per_instance_deleted - to_delete_default = to_delete_all - pending_per_instance + to_delete_default = { + hash_ for hash_ in to_delete_all if hash_.lower() not in mapped_hashes + } primary_pairs: set[tuple[str, str]] = set() if self.remove_from_qbit or self.skip_blacklist or to_delete_default: if to_delete_default: @@ -499,11 +516,14 @@ def _process_failed_deletes( ) ) if self.remove_from_qbit or self.skip_blacklist: - rest = ( - self.remove_from_qbit.union(self.skip_blacklist) - - deleted_hashes - - pending_per_instance - ) + handled_hashes = mapped_hashes | { + hash_.lower() for _, hash_ in confirmed_pairs | primary_pairs + } + rest = { + hash_ + for hash_ in self.remove_from_qbit | self.skip_blacklist + if hash_.lower() not in handled_hashes + } primary_pairs.update( delete_hashes_on_primary( self, @@ -521,31 +541,42 @@ def _process_failed_deletes( primary_deleted = {hash_ for _, hash_ in primary_pairs} confirmed_deleted = deleted_hashes | primary_deleted self._evict_hashes_from_qbit_side_caches(confirmed_deleted) - dispatch_targets = confirmed_deleted & queue_delete_targets + removed_hashes = {hash_.lower() for hash_ in confirmed_deleted} + dispatch_targets = { + hash_ for hash_ in queue_delete_targets if hash_.lower() in removed_hashes + } if dispatch_targets: complete_removal_followups(self, dispatch_targets) self._process_failed_dispatch_queue_deletes( dispatch_targets, skip_blacklist, cross_arr=cross_arr ) - removed_pairs = confirmed_pairs | primary_pairs - pending_count = sum( - key not in removed_pairs - and ( - key[0] in per_instance_batches - and key[1] in per_instance_batches[key[0]] - or key[1] in legacy_hashes - mapped_hashes - ) - for key in getattr(self, "_pending_client_removals", {}) + removed_pairs = { + (instance, hash_.lower()) for instance, hash_ in confirmed_pairs | primary_pairs + } + removed_legacy = {hash_ for _, hash_ in removed_pairs} & legacy_targets + pending_pairs = { + (instance, hash_.lower()) + for instance, hash_ in getattr(self, "_pending_client_removals", {}) + } + pending_legacy = ({hash_ for _, hash_ in pending_pairs} & legacy_targets) - removed_legacy + pending_count = len((pending_pairs & candidate_pairs) - removed_pairs) + len( + pending_legacy + ) + self._log_deletion_summary_line( + candidate_count, + len(removed_pairs & candidate_pairs) + len(removed_legacy), + pending_count, ) - self._log_deletion_summary_line(candidate_count, len(removed_pairs), pending_count) - all_deleted = confirmed_deleted - if self.missing_files_post_delete: - self.missing_files_post_delete -= all_deleted - if self.downloads_with_bad_error_message_blocklist: - self.downloads_with_bad_error_message_blocklist -= all_deleted - self.skip_blacklist -= all_deleted - self.remove_from_qbit -= all_deleted - self.delete -= all_deleted + for requests in ( + self.missing_files_post_delete, + self.downloads_with_bad_error_message_blocklist, + self.skip_blacklist, + self.remove_from_qbit, + self.delete, + ): + requests.difference_update( + {hash_ for hash_ in requests if hash_.lower() in removed_hashes} + ) def _apply_file_priority_update( self, diff --git a/qBitrr/arss/torrent_inspect.py b/qBitrr/arss/torrent_inspect.py index 80472978..d1acb7fc 100644 --- a/qBitrr/arss/torrent_inspect.py +++ b/qBitrr/arss/torrent_inspect.py @@ -208,7 +208,11 @@ def _mark_for_deletion( % (seeding_time_limit if seeding_time_limit > 0 else "unset") ) extra = " [%s]" % ", ".join(parts) - from qBitrr.arss.qbit_side_effects import removal_candidate, removal_retry_deferred + from qBitrr.arss.qbit_side_effects import ( + removal_candidate, + removal_observation, + removal_retry_deferred, + ) if not removal_retry_deferred(self, instance_name, torrent): self.logger.info( @@ -224,6 +228,11 @@ def _mark_for_deletion( if not hasattr(self, "_removal_candidates"): self._removal_candidates = {} self._removal_candidates[(instance_name, torrent.hash)] = removal_candidate(torrent) + if not hasattr(self, "_removal_observations"): + self._removal_observations = {} + self._removal_observations[(instance_name, torrent.hash.lower())] = removal_observation( + torrent + ) if not hasattr(self, "_removal_reasons"): self._removal_reasons = {} self._removal_reasons[(instance_name, torrent.hash)] = reason @@ -504,27 +513,36 @@ def _process_single_torrent_missing_files( # this ensures that we can safely remove it if the client is reporting # the status of the client as "Missing files" """Queue a missing-files torrent for protected removal without blocklisting.""" - self.logger.info( - "Deleting torrent with missing files: " - "[Progress: %s%%][Added On: %s]" - "[Availability: %s%%][Time Left: %s]" - "[Last active: %s] " - "| [%s] | %s (%s)", - round(torrent.progress * 100, 2), - datetime.fromtimestamp(torrent.added_on), - round(torrent.availability * 100, 2), - timedelta(seconds=torrent.eta), - datetime.fromtimestamp(torrent.last_activity), - torrent.state_enum, - torrent.name, - torrent.hash, + from qBitrr.arss.qbit_side_effects import ( + removal_candidate, + removal_observation, + removal_retry_deferred, ) - # We do not want to blacklist these!! - from qBitrr.arss.qbit_side_effects import removal_candidate + if not removal_retry_deferred(self, instance_name, torrent): + self.logger.info( + "Deleting torrent with missing files: " + "[Progress: %s%%][Added On: %s]" + "[Availability: %s%%][Time Left: %s]" + "[Last active: %s] " + "| [%s] | %s (%s)", + round(torrent.progress * 100, 2), + datetime.fromtimestamp(torrent.added_on), + round(torrent.availability * 100, 2), + timedelta(seconds=torrent.eta), + datetime.fromtimestamp(torrent.last_activity), + torrent.state_enum, + torrent.name, + torrent.hash, + ) if not hasattr(self, "_removal_candidates"): self._removal_candidates = {} self._removal_candidates[(instance_name, torrent.hash)] = removal_candidate(torrent) + if not hasattr(self, "_removal_observations"): + self._removal_observations = {} + self._removal_observations[(instance_name, torrent.hash.lower())] = removal_observation( + torrent + ) self.remove_from_qbit_by_instance.setdefault(instance_name, set()).add(torrent.hash) def _process_single_torrent_uploading( diff --git a/tests/test_hnr_removal_boundary.py b/tests/test_hnr_removal_boundary.py index ec57b018..3cac37c7 100644 --- a/tests/test_hnr_removal_boundary.py +++ b/tests/test_hnr_removal_boundary.py @@ -164,12 +164,142 @@ def test_blocked_candidate_backs_off_without_repeated_marking(self) -> None: clock.return_value = 400 self.worker._reset_removal_requests() self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") - self.worker._process_failed() + with patch.object( + self.worker, "_deletion_rules_allow", wraps=self.worker._deletion_rules_allow + ) as rules: + self.worker._process_failed() + rules.assert_called_once() self.assertEqual( self.worker.logger.info.call_count, 1 ) # Marking, same refusal stays quiet. self.client.torrents_delete.assert_not_called() + def test_seeding_clock_does_not_cancel_backoff(self) -> None: + """Elapsed seeding time alone must not re-run unchanged removal decisions.""" + self.torrent.ratio = 2 + self.worker.logger = MagicMock() + self.seeding["default_seeding"]["RemoveTorrent"] = -1 + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + self.torrent.seeding_time += 6 + self.worker._reset_removal_requests() + self.worker.logger.reset_mock() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + with patch.object(self.worker, "_deletion_rules_allow") as rules: + self.worker._process_failed() + rules.assert_not_called() + self.worker.logger.info.assert_not_called() + + def test_inactive_refusals_are_pruned_without_losing_current_backoff(self) -> None: + """Retain refusals across active scans, then discard entries after a scan without them.""" + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + for _ in range(2): + self.worker._reset_removal_requests() + self.assertIn(("one", "superman"), self.worker._blocked_removals) + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + self.worker._reset_removal_requests() + self.worker._reset_removal_requests() + self.assertFalse(self.worker._blocked_removals) + + def test_lookup_failure_defers_until_expiry_or_changed_observation(self) -> None: + """An unavailable targeted lookup still backs off using the scan's observation.""" + self.worker.logger = MagicMock() + with ( + patch("qBitrr.arss.qbit_side_effects.time.monotonic", return_value=100) as clock, + patch( + "qBitrr.arss.qbit_side_effects.resolve_removal_torrent", return_value=None + ) as lookup, + ): + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + lookup.assert_called_once() + self.worker._reset_removal_requests() + self.worker.logger.reset_mock() + lookup.reset_mock() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + lookup.assert_not_called() + self.worker.logger.info.assert_not_called() + self.torrent.progress += 0.01 + self.worker._reset_removal_requests() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + lookup.assert_called_once() + lookup.reset_mock() + clock.return_value = 400 + self.worker._reset_removal_requests() + self.worker._mark_for_deletion(self.torrent, "Stalled State", instance_name="one") + self.worker._process_failed() + lookup.assert_called_once() + self.client.torrents_delete.assert_not_called() + + def test_direct_removal_without_candidate_snapshot_honors_backoff(self) -> None: + """Content cleanup callers defer refusals and still recheck changed torrent identity.""" + self.assertFalse(delete_hashes_per_instance(self.worker, {"one": {"superman"}})) + with patch.object(self.worker, "_deletion_rules_allow") as rules: + self.assertFalse(delete_hashes_per_instance(self.worker, {"one": {"superman"}})) + rules.assert_not_called() + self.torrent.added_on = 2 + with patch.object(self.worker, "_deletion_rules_allow", return_value=False) as rules: + self.assertFalse(delete_hashes_per_instance(self.worker, {"one": {"superman"}})) + rules.assert_called_once() + self.client.torrents_delete.assert_not_called() + + def test_missing_files_log_honors_backoff(self) -> None: + """Missing-files observations keep their requests without repeating deletion messages.""" + self.torrent.availability = 0 + self.torrent.eta = 0 + self.worker.logger = MagicMock() + self.worker._process_single_torrent_missing_files(self.torrent, "one") + self.worker._process_failed() + self.worker._reset_removal_requests() + self.worker.logger.reset_mock() + self.worker._process_single_torrent_missing_files(self.torrent, "one") + self.worker._process_failed() + self.worker.logger.info.assert_not_called() + self.assertEqual(self.worker.remove_from_qbit_by_instance["one"], {"superman"}) + self.client.torrents_delete.assert_not_called() + + def test_summary_deduplicates_mixed_case_mapped_and_legacy_hashes(self) -> None: + """Hash casing cannot create a second removal request or a fictitious blocked result.""" + self.torrent.ratio = 2 + self.worker.delete_by_instance["one"].add("superman") + self.worker.delete.add("SUPERMAN") + self.worker._process_failed() + self.client.torrents_delete.assert_called_once() + self.worker._log_deletion_summary_line.assert_called_with(1, 1, 0) + self.assertFalse(self.worker.delete) + + def test_mixed_case_copies_wait_for_every_targeted_client(self) -> None: + """An uppercase confirmed request cannot release Arr work while a lowercase copy stays.""" + self.torrent.ratio = 2 + self.worker.add("two") + self.worker.delete_by_instance = {"one": {"SUPERMAN"}, "two": {"superman"}} + self.worker.delete = {"SUPERMAN"} + with patch("qBitrr.arss.qbit_side_effects.content_removal_allowed", return_value=True): + self.worker._process_failed() + self.worker._process_failed_dispatch_queue_deletes.assert_not_called() + self.worker._log_deletion_summary_line.assert_called_with(2, 1, 0) + self.assertEqual(self.worker.delete, {"SUPERMAN"}) + + def test_legacy_pending_summary_counts_hashes_and_prefers_confirmed_results(self) -> None: + """Stale pending records for other instances cannot double-count legacy candidates.""" + self.worker.remove_from_qbit = {"SUPERMAN"} + self.worker._pending_client_removals = { + (instance, "superman"): ((), [], {instance}) for instance in ("one", "two") + } + with patch( + "qBitrr.arss.qbit_side_effects.delete_hashes_on_primary", return_value=set() + ) as delete: + self.worker._process_failed() + self.worker._log_deletion_summary_line.assert_called_with(1, 0, 1) + delete.return_value = {("three", "superman")} + self.worker._process_failed() + self.worker._log_deletion_summary_line.assert_called_with(1, 1, 0) + self.assertFalse(self.worker.remove_from_qbit) + def test_backoff_ends_after_activity_change_and_rechecks_protections(self) -> None: """Activity changes trigger fresh rules and successful deletion clears backoff.""" self.torrent.ratio = 2 @@ -261,9 +391,13 @@ def test_stalled_grace_and_complete_seeding_policy_are_mandatory(self): self.seeding["default_seeding"]["RemoveTorrent"] = 4 self.assertFalse(delete_hashes_per_instance(self.worker, {"one": {"superman"}})) self.seeding["default_seeding"]["RemoveTorrent"] = 3 - self.assertEqual( - delete_hashes_per_instance(self.worker, {"one": {"superman"}}), {("one", "superman")} - ) + with patch( + "qBitrr.arss.qbit_side_effects.time.monotonic", return_value=time.monotonic() + 301 + ): + self.assertEqual( + delete_hashes_per_instance(self.worker, {"one": {"superman"}}), + {("one", "superman")}, + ) def test_candidate_rejects_readded_torrent_but_revalidates_activity(self): """Verify candidate rejects readded torrent but revalidates activity.""" @@ -614,9 +748,13 @@ def test_actual_client_never_remove_cannot_use_another_clients_permission(self): self.client.torrents_delete.assert_not_called() self.seeding["default_seeding"]["RemoveTorrent"] = 1 self.seeding["stalled_delay"] = 0 - self.assertEqual( - delete_hashes_per_instance(self.worker, {"one": {"superman"}}), {("one", "superman")} - ) + with patch( + "qBitrr.arss.qbit_side_effects.time.monotonic", return_value=time.monotonic() + 301 + ): + self.assertEqual( + delete_hashes_per_instance(self.worker, {"one": {"superman"}}), + {("one", "superman")}, + ) def test_completed_cleanup_uses_real_client_and_tracker_limit_merge(self): """Verify completed cleanup uses real client and tracker limit merge.""" @@ -635,9 +773,13 @@ def test_completed_cleanup_uses_real_client_and_tracker_limit_merge(self): ) self.assertFalse(delete_hashes_per_instance(self.worker, {"one": {"superman"}})) self.seeding["trackers"][0]["MaxUploadRatio"] = 1 - self.assertEqual( - delete_hashes_per_instance(self.worker, {"one": {"superman"}}), {("one", "superman")} - ) + with patch( + "qBitrr.arss.qbit_side_effects.time.monotonic", return_value=time.monotonic() + 301 + ): + self.assertEqual( + delete_hashes_per_instance(self.worker, {"one": {"superman"}}), + {("one", "superman")}, + ) def test_shared_content_uses_owners_arr_hnr_policy(self): """Verify shared content uses owners arr hnr policy.""" @@ -873,7 +1015,11 @@ def delete(**kwargs: object) -> None: self.assertTrue(self.worker._pending_client_removals) self.worker.delete_from_queue.assert_not_called() self.client.torrents_info.side_effect = None + self.worker.logger = MagicMock() self.worker._reset_removal_requests() + self.worker.logger.info.assert_called_with( + "Confirmed removal of %s on %s after uncertain response", "superman", "one" + ) self.worker.delete_from_queue.assert_called_once_with( id_=17, remove_from_client=False, blacklist=True )