Update path handling errors (#864)

shelfmark/download/clients/base_handler.py

@@ -1,5 +1,6 @@
 """Shared download handler for external torrent/usenet clients."""
 
+import errno
 import shutil
 import time
 from abc import ABC, abstractmethod
@@ -18,6 +19,7 @@ from shelfmark.download.clients import (
     list_configured_clients,
 )
 from shelfmark.download.fs import run_blocking_io
+from shelfmark.download.permissions_debug import log_path_permission_context
 from shelfmark.release_sources import DownloadHandler
 
 if TYPE_CHECKING:
@@ -81,6 +83,29 @@ def _diagnose_path_issue(path: str) -> str:
     )
 
 
+def _format_probe_error(error: OSError | None) -> str:
+    """Render an OSError for inclusion in log/status messages."""
+    if error is None:
+        return "none"
+    code = errno.errorcode.get(error.errno, str(error.errno)) if error.errno else "?"
+    return f"{code}: {error.strerror or error}"
+
+
+def _probe_completed_path(path: Path) -> tuple[bool, OSError | None]:
+    """Probe a completed download path and preserve the underlying stat error.
+
+    `Path.exists()` silently converts every `OSError` to `False`, which hides
+    whether a failure is ENOENT (not yet written), EACCES (permission denied),
+    ESTALE (NFS stale handle), or something else. Callers need the real errno
+    to decide whether the condition is retryable and to surface diagnostics.
+    """
+    try:
+        run_blocking_io(path.stat)
+    except OSError as error:
+        return False, error
+    return True, None
+
+
 class ExternalClientHandler(DownloadHandler, ABC):
     """Shared lifecycle handler for sources that hand off to torrent/usenet clients."""
 
@@ -378,19 +403,21 @@ class ExternalClientHandler(DownloadHandler, ABC):
             remote_path=source_path_obj,
         )
 
-        if log_details:
-            remapped_exists = run_blocking_io(remapped.exists)
-            logger.debug(
-                "Remap result: %s -> %s (exists=%s, changed=%s, matched=%s)",
-                source_path_obj,
-                remapped,
-                remapped_exists,
-                remapped != source_path_obj,
-                matched_mapping,
-            )
-
         if matched_mapping:
-            if run_blocking_io(remapped.exists):
+            remapped_exists, remapped_error = _probe_completed_path(remapped)
+
+            if log_details:
+                logger.debug(
+                    "Remap result: %s -> %s (exists=%s, probe_error=%s, changed=%s, matched=%s)",
+                    source_path_obj,
+                    remapped,
+                    remapped_exists,
+                    _format_probe_error(remapped_error),
+                    remapped != source_path_obj,
+                    matched_mapping,
+                )
+
+            if remapped_exists:
                 logger.info(
                     "Remapped download path for %s (%s): %s -> %s",
                     client.name,
@@ -404,76 +431,76 @@ class ExternalClientHandler(DownloadHandler, ABC):
                 f"Remapped path '{remapped}' does not exist. "
                 f"Check your Docker volume mounts match the Local Path in Settings > Advanced > Remote Path Mappings."
             )
+            failure_log = "Download path does not exist after remapping: %s -> %s (probe_error=%s). Client: %s, ID: %s."
+            failure_args = (
+                raw_path,
+                remapped,
+                _format_probe_error(remapped_error),
+                client.name,
+                download_id,
+            )
             if log_details:
-                logger.error(
-                    "Download path does not exist after remapping: %s -> %s. Client: %s, ID: %s.",
-                    raw_path,
-                    remapped,
-                    client.name,
-                    download_id,
-                )
+                log_path_permission_context("completed_download_remap", remapped)
+                logger.error(failure_log, *failure_args)
             else:
-                logger.debug(
-                    "Download path does not exist after remapping: %s -> %s. Client: %s, ID: %s.",
-                    raw_path,
-                    remapped,
-                    client.name,
-                    download_id,
-                )
+                logger.debug(failure_log, *failure_args)
             return None, message
 
-        if mappings:
-            if run_blocking_io(source_path_obj.exists):
+        source_exists, source_error = _probe_completed_path(source_path_obj)
+
+        if log_details:
+            logger.debug(
+                "Remap result: %s -> %s (exists=%s, probe_error=%s, changed=%s, matched=%s)",
+                source_path_obj,
+                remapped,
+                source_exists,
+                _format_probe_error(source_error),
+                remapped != source_path_obj,
+                matched_mapping,
+            )
+
+        if source_exists:
+            if mappings:
                 logger.info(
                     "No remote path mapping matched for %s (%s); using client path: %s",
                     client.name,
                     download_id,
                     source_path_obj,
                 )
-                return source_path_obj, None
+            return source_path_obj, None
 
-            hint = _diagnose_path_issue(raw_path)
+        hint = _diagnose_path_issue(raw_path)
+        if mappings:
             message = f"{hint} No remote path mapping matched for client '{client.name}'."
-            if log_details:
-                logger.error(
-                    "Download path does not exist and no remote path mapping matched for %s (%s): %s. %s",
-                    client.name,
-                    download_id,
-                    raw_path,
-                    hint,
-                )
-            else:
-                logger.debug(
-                    "Download path does not exist and no remote path mapping matched for %s (%s): %s. %s",
-                    client.name,
-                    download_id,
-                    raw_path,
-                    hint,
-                )
-            return None, message
-
-        if not run_blocking_io(source_path_obj.exists):
-            hint = _diagnose_path_issue(raw_path)
+            failure_label = "completed_download_original"
+            failure_log = "Download path does not exist and no remote path mapping matched for %s (%s): %s (probe_error=%s). %s"
+            failure_args = (
+                client.name,
+                download_id,
+                raw_path,
+                _format_probe_error(source_error),
+                hint,
+            )
+        else:
             message = hint
-            if log_details:
-                logger.error(
-                    "Download path does not exist: %s. Client: %s, ID: %s. %s",
-                    raw_path,
-                    client.name,
-                    download_id,
-                    hint,
-                )
-            else:
-                logger.debug(
-                    "Download path does not exist: %s. Client: %s, ID: %s. %s",
-                    raw_path,
-                    client.name,
-                    download_id,
-                    hint,
-                )
-            return None, message
+            failure_label = "completed_download_direct"
+            failure_log = (
+                "Download path does not exist: %s (probe_error=%s). Client: %s, ID: %s. %s"
+            )
+            failure_args = (
+                raw_path,
+                _format_probe_error(source_error),
+                client.name,
+                download_id,
+                hint,
+            )
 
-        return source_path_obj, None
+        if log_details:
+            log_path_permission_context(failure_label, source_path_obj)
+            logger.error(failure_log, *failure_args)
+        else:
+            logger.debug(failure_log, *failure_args)
+        return None, message
 
     def _wait_for_completed_path(
         self,