Fix rescan loop: short-circuited registration dropped files from state

The directory worker registered video files with
'node["changed"] = node["changed"] or await _register_candidate(...)',
so once one file in a directory was found changed, the rest were never
registered: they fell out of known_paths, were pruned from the persisted
seen-mtimes at finalize, and were rediscovered as new on every scan.
That rotating ~10-item subset was reprocessed (metadata, TMDb lookups,
logs) every 30 seconds forever.

Also fix the self-sustaining reprocess loop for items that produce no
index entries (no playable file, no parseable episodes, non-media):
they never appear in the index, so the DB-aware mtime gating alone could
never skip them.  They are now recorded in a persisted empty_mtimes map
(scan-state.json) and skipped while their mtime is unchanged.

Episode/playable/blu-ray finder caches are now cleared at the start of
each scan: an empty result cached before a download finished (or during
a transient network-mount error) previously stuck for the process
lifetime and reported "no episodes found" for series that have episodes.

Logging: a no-change scan now emits a single line with item count and
duration; per-item "up to date" chatter moved to debug; change scans
report the new/changed count plus per-item reason lines (stored vs
current mtime, index/empty-marker membership), finalize prune/commit
traces, and scan-state load/save confirmations.

Add AGENTS.md noting the project's Python 3.14 baseline (PEP 758
unparenthesized except) so tooling does not flag it as a syntax error.

AGENTS.md

@@ -0,0 +1,20 @@
+# MediaHive agent notes
+
+## Python 3.14 syntax: unparenthesized `except` is valid
+
+This project targets Python **>= 3.14** (see `requires-python` in
+`pyproject.toml`). Per [PEP 758](https://peps.python.org/pep-0758/) (Final,
+Python 3.14), multiple exception types may be caught **without parentheses**:
+
+```python
+except OSError, ValueError:   # valid Python 3.14+, equivalent to except (OSError, ValueError):
+```
+
+Parentheses are still required when an `as` clause is used:
+`except (OSError, ValueError) as e:`.
+
+Do not "fix" these into tuple form, and do not flag them as Python 2 remnant
+syntax errors — that rule is obsolete training data. Any syntax validation,
+compilation check, or linting of this codebase must run under Python 3.14+
+(e.g. `python -m py_compile` with a 3.14 interpreter); older interpreters
+will report false SyntaxErrors on this and other 3.14-only constructs.

mediahive/hivescan/indexer.py

@@ -951,7 +951,11 @@ async def _process_series(
         )
 
         if not seasons_data:
-            logger.info("    Skipping %s - no episodes found", display_title)
+            logger.info(
+                "    Skipping %s - no episodes in the %d scanned torrent(s)",
+                display_title,
+                len(items),
+            )
             continue
 
         different_titles = sorted(
@@ -1003,7 +1007,11 @@ async def _process_series(
         )
 
         if not seasons_data:
-            logger.info("    Skipping %s - no episodes found", title)
+            logger.info(
+                "    Skipping %s - no episodes in the %d scanned torrent(s)",
+                title,
+                len(items),
+            )
             continue
 
         item_timestamps = [await get_added_timestamp(item.path) for item in items]

mediahive/hivescan/scanner.py

@@ -29,7 +29,7 @@ from mediahive.hivescan.indexer import _process_movies, _process_series
 from mediahive.hivescan.models import ContentType, ParsedContent
 from mediahive.hivescan.parsing import parse_download
 from mediahive.hivescan.scanignore import ScanIgnore
-from mediahive.hivescan.scanning import categorize_downloads
+from mediahive.hivescan.scanning import categorize_downloads, clear_scan_caches
 from mediahive.hivescan.showreel import (
     episode_reel_exists,
     generate_episode_reel,
@@ -102,6 +102,14 @@ class RootScanner:
         self._showreel_worker_task: asyncio.Task | None = None
         self._rescan_worker_task: asyncio.Task | None = None
         self._seen_mtimes: dict[str, int] = {}
+        # Candidates that were fully processed but produced no index entries
+        # (no playable file, no parseable episodes, or non-media content).
+        # Tracked with their mtime so they are not reprocessed on every
+        # rescan — the DB-aware gating alone cannot skip them, because they
+        # never appear in the index.  An entry is dropped as soon as the
+        # item's mtime changes or it starts producing index entries.
+        self._empty_mtimes: dict[str, int] = {}
+        self._empty_dirty = False
         # Per-directory backoff state (relpath -> {until, streak, items})
         self._dir_state: dict[str, dict] = {}
         self._dir_state_dirty = False
@@ -184,6 +192,15 @@ class RootScanner:
         seen = data.get("seen_mtimes")
         if isinstance(seen, dict):
             self._seen_mtimes = {str(k): int(v) for k, v in seen.items()}
+        empty = data.get("empty_mtimes")
+        if isinstance(empty, dict):
+            self._empty_mtimes = {str(k): int(v) for k, v in empty.items()}
+        logger.info(
+            "Loaded scan state from %s: seen=%d, empty=%d",
+            self._scan_state_path,
+            len(self._seen_mtimes),
+            len(self._empty_mtimes),
+        )
         dir_state = data.get("dir_state")
         if isinstance(dir_state, dict):
             for key, value in dir_state.items():
@@ -199,12 +216,20 @@ class RootScanner:
             payload = json.dumps({
                 "version": 2,
                 "seen_mtimes": self._seen_mtimes,
+                "empty_mtimes": self._empty_mtimes,
                 "dir_state": self._dir_state,
             })
             tmp = self._scan_state_path.with_suffix(".tmp")
             tmp.parent.mkdir(parents=True, exist_ok=True)
             tmp.write_text(payload, encoding="utf-8")
             tmp.replace(self._scan_state_path)
+            logger.info(
+                "Saved scan state to %s: seen=%d, empty=%d, dir_state=%d",
+                self._scan_state_path,
+                len(self._seen_mtimes),
+                len(self._empty_mtimes),
+                len(self._dir_state),
+            )
         except OSError, TypeError, ValueError:
             logger.exception("Failed to save scan state to %s", self._scan_state_path)
 
@@ -477,18 +502,57 @@ class RootScanner:
                 try:
                     mtime = int((await AsyncPath(path).stat()).st_mtime)
                 except OSError, ValueError:
+                    logger.info(
+                        "Skipping candidate, stat failed: %s "
+                        "(in_seen=%s, stored_mtime=%s)",
+                        relpath,
+                        relpath in self._seen_mtimes,
+                        self._seen_mtimes.get(relpath),
+                    )
                     return False
-            if self._seen_mtimes.get(relpath) == mtime:
+            stored = self._seen_mtimes.get(relpath)
-                if indexed is None or relpath in indexed:
+            if stored == mtime:
+                if indexed is not None and relpath in indexed:
+                    # Produces index entries; drop any stale empty-marker.
+                    if relpath in self._empty_mtimes:
+                        del self._empty_mtimes[relpath]
+                        self._empty_dirty = True
+                    return False
+                if indexed is None or self._empty_mtimes.get(relpath) == mtime:
                     return False
                 # Unchanged on disk but missing from the index (snapshot
                 # wiped, upsert lost, ...): reprocess it unless it is not
                 # indexable content anyway.
+                logger.info(
+                    "Reprocessing unchanged item missing from index: %s "
+                    "(stored_mtime=%d == current_mtime=%d, indexed=%s, "
+                    "empty_marker=%s)",
+                    relpath,
+                    stored,
+                    mtime,
+                    "n/a" if indexed is None else "no",
+                    self._empty_mtimes.get(relpath),
+                )
                 parsed = await parse_download(path)
                 if parsed.content_type is ContentType.OTHER:
+                    self._empty_mtimes[relpath] = mtime
+                    self._empty_dirty = True
                     return False
                 downloads.append(parsed)
                 return True
+            logger.info(
+                "Treating as new/changed: %s (stored_mtime=%s, "
+                "current_mtime=%d, in_seen=%s, in_index=%s, empty_marker=%s, "
+                "seen_total=%d, known_total=%d)",
+                relpath,
+                "ABSENT" if stored is None else str(stored),
+                mtime,
+                relpath in self._seen_mtimes,
+                "n/a" if indexed is None else (relpath in indexed),
+                self._empty_mtimes.get(relpath),
+                len(self._seen_mtimes),
+                len(known_paths),
+            )
             found_mtimes[relpath] = mtime
             downloads.append(await parse_download(path))
             return True
@@ -624,20 +688,24 @@ class RootScanner:
                         if video_files:
                             newest = max(fm for _, fm in video_files)
                             mtime = max(mtime or 0, newest)
-                        node["changed"] = node["changed"] or await _register_candidate(
+                        if await _register_candidate(path, rel, mtime):
-                            path, rel, mtime
+                            node["changed"] = True
-                        )
                     else:
                         for file_path, file_mtime in video_files:
                             file_rel = make_relative_path(
                                 str(file_path), media_root_str
                             )
                             node["items"] = True
-                            node["changed"] = node[
+                            # No "or" short-circuit here: every file must be
-                                "changed"
+                            # registered even after an earlier file in this
-                            ] or await _register_candidate(
+                            # directory was found changed, otherwise the
+                            # skipped files fall out of known_paths, get
+                            # pruned at finalize, and are rediscovered as
+                            # "new" on every subsequent scan.
+                            if await _register_candidate(
                                 file_path, file_rel, file_mtime
-                            )
+                            ):
+                                node["changed"] = True
                         await _enqueue_children(node, child_dirs)
                 except Exception:
                     # Never let one bad directory kill the worker or truncate
@@ -652,7 +720,7 @@ class RootScanner:
                         _complete_node(node)
                     queue.task_done()
 
-        logger.info("Starting filesystem discovery at %s", self.media_root)
+        logger.debug("Starting filesystem discovery at %s", self.media_root)
         await _report(f"Scanning: {self.media_root}")
 
         stop_event = threading.Event()
@@ -702,7 +770,7 @@ class RootScanner:
                 w.cancel()
             await asyncio.gather(*workers, return_exceptions=True)
 
-        logger.info(
+        logger.debug(
             "Discovery complete: %d downloads found, %d directories visited",
             len(downloads),
             dirs_visited,
@@ -718,15 +786,42 @@ class RootScanner:
         prunes vanished paths, persists state when anything changed, and sends
         the Sync event that lets the store drop deleted torrents.
         """
+        pruned = sorted(k for k in self._seen_mtimes if k not in known_paths)
+        if pruned:
+            logger.info(
+                "Finalize: pruning %d previously seen path(s) not in this "
+                "scan's known set: %s%s",
+                len(pruned),
+                pruned[:10],
+                " ..." if len(pruned) > 10 else "",
+            )
         committed = {k: v for k, v in self._seen_mtimes.items() if k in known_paths}
         committed.update(found_mtimes)
         state_changed = committed != self._seen_mtimes
         self._seen_mtimes = committed
+        if found_mtimes:
+            logger.info(
+                "Finalize: committing %d new/changed mtime(s): %s%s",
+                len(found_mtimes),
+                sorted(found_mtimes)[:10],
+                " ..." if len(found_mtimes) > 10 else "",
+            )
+
+        # Drop empty-markers for vanished or since-changed paths.
+        pruned_empty = {
+            k: v
+            for k, v in self._empty_mtimes.items()
+            if k in known_paths and committed.get(k) == v
+        }
+        if pruned_empty != self._empty_mtimes:
+            self._empty_mtimes = pruned_empty
+            self._empty_dirty = True
 
         await self._send(Sync(paths=sorted(known_paths)))
 
-        if state_changed or self._dir_state_dirty:
+        if state_changed or self._dir_state_dirty or self._empty_dirty:
             self._dir_state_dirty = False
+            self._empty_dirty = False
             await asyncio.to_thread(self._save_scan_state)
         if probe_records_dirty():
             await asyncio.to_thread(save_probe_records)
@@ -744,9 +839,10 @@ class RootScanner:
         """
         task_id = f"scan-{uuid.uuid4().hex[:8]}"
         media_root_str = self.media_root.as_posix()
+        started_at = time.monotonic()
 
         try:
-            logger.info("Scan started (%s) for root %s", task_id, self.root_id)
+            logger.debug("Scan started (%s) for root %s", task_id, self.root_id)
             await self._send(
                 Task(
                     data=TaskInfo(
@@ -758,12 +854,19 @@ class RootScanner:
                 )
             )
 
+            clear_scan_caches()
             downloads, found_mtimes, known_paths = await self._discover_downloads(
                 task_id
             )
+            elapsed = time.monotonic() - started_at
 
             if not downloads:
-                logger.info("No new downloads found (%s)", task_id)
+                logger.info(
+                    "Scan (%s): no changes — %d items inspected in %.1fs",
+                    task_id,
+                    len(known_paths),
+                    elapsed,
+                )
                 await self._finalize_scan(found_mtimes, known_paths)
                 await self._send(
                     Task(
@@ -777,7 +880,13 @@ class RootScanner:
                 )
                 return
 
-            logger.info("Found %d items to process", len(downloads))
+            logger.info(
+                "Scan (%s): %d new/changed of %d items found in %.1fs",
+                task_id,
+                len(downloads),
+                len(known_paths),
+                elapsed,
+            )
             await self._send(
                 Task(
                     data=TaskInfo(
@@ -851,14 +960,14 @@ class RootScanner:
                             self._showreel_queue.qsize(),
                         )
                     else:
-                        logger.info(
+                        logger.debug(
                             "[%d/%d] Movie: %s (showreel up to date)",
                             processed + 1,
                             total,
                             movie.title,
                         )
                 else:
-                    logger.info(
+                    logger.debug(
                         "[%d/%d] Movie: %s (no showreel task)",
                         processed + 1,
                         total,
@@ -935,7 +1044,7 @@ class RootScanner:
                         self._showreel_queue.qsize(),
                     )
                 else:
-                    logger.info(
+                    logger.debug(
                         "[%d/%d] Series: %s (reels up to date)",
                         processed + 1,
                         total,
@@ -954,6 +1063,26 @@ class RootScanner:
                     )
                 )
 
+            # Record processed candidates that yielded no index entries (no
+            # playable file, no parseable episodes, ...) so later rescans
+            # skip them while their mtime is unchanged instead of
+            # reprocessing — and re-logging — them on every pass.  The
+            # snapshot here predates this scan's upserts, so an item that
+            # just produced content may be marked empty once; the marker is
+            # dropped again on the next pass when it shows up in the index.
+            indexed_snapshot = self._indexed_paths() if self._indexed_paths else set()
+            for item in downloads:
+                rel = make_relative_path(item.path.as_posix(), media_root_str)
+                if rel in indexed_snapshot:
+                    if rel in self._empty_mtimes:
+                        del self._empty_mtimes[rel]
+                        self._empty_dirty = True
+                else:
+                    m = found_mtimes.get(rel, self._seen_mtimes.get(rel))
+                    if m is not None and self._empty_mtimes.get(rel) != m:
+                        self._empty_mtimes[rel] = m
+                        self._empty_dirty = True
+
             await self._finalize_scan(found_mtimes, known_paths)
             await self._send(
                 Task(
@@ -966,11 +1095,13 @@ class RootScanner:
                 )
             )
             logger.info(
-                "Scan complete (%s): %d movies, %d series, showreel queue=%d",
+                "Scan complete (%s): %d movies, %d series updated, "
+                "showreel queue=%d, %.1fs total",
                 task_id,
                 n_movies,
                 n_series,
                 self._showreel_queue.qsize(),
+                time.monotonic() - started_at,
             )
 
         except asyncio.CancelledError:

mediahive/hivescan/scanning.py

@@ -28,12 +28,23 @@ VIDEO_EXTENSIONS = {
     ".m2ts",
 }
 
-# Caches for expensive operations
+# Caches for expensive operations.  These are per-scan only: the scanner
+# clears them at the start of every scan.  Caching across scans is wrong —
+# an empty result recorded before a download finished (or during a transient
+# network-mount error) would stick for the process lifetime and report
+# "no episodes found" for series that do have episodes.
 _episode_files_cache: dict[str, dict[tuple[int, int], list[tuple[str, int]]]] = {}
 _playable_file_cache: dict[str, str | None] = {}
 _bluray_probe_file_cache: dict[str, str | None] = {}
 
 
+def clear_scan_caches() -> None:
+    """Drop all per-scan filesystem caches; called at the start of each scan."""
+    _episode_files_cache.clear()
+    _playable_file_cache.clear()
+    _bluray_probe_file_cache.clear()
+
+
 def _scandir_split(
     directory: Path,
     stop_event: threading.Event,