feat(pathfinder): opt-in diagnostic logging for load_nvidia_dynamic_lib

cuda_pathfinder/cuda/pathfinder/_dynamic_libs/load_nvidia_dynamic_lib.py

@@ -35,6 +35,7 @@
     parse_dynamic_lib_subprocess_payload,
 )
 from cuda.pathfinder._dynamic_libs.supported_nvidia_libs import ALL_AVAILABLE_LIBNAMES
+from cuda.pathfinder._utils.diagnostic_log import LOGGER, search_extra
 from cuda.pathfinder._utils.platform_aware import IS_WINDOWS
 
 if TYPE_CHECKING:
@@ -162,11 +163,32 @@ def _try_ctk_root_canary(ctx: SearchContext) -> str | None:
     return None
 
 
+def _log_resolved(loaded: LoadedDL, libname: str) -> LoadedDL:
+    """Log a successful resolution and return it unchanged."""
+    if LOGGER is not None:
+        LOGGER.info(
+            "resolved %s to %s via %s",
+            libname,
+            loaded.abs_path,
+            loaded.found_via,
+            extra=search_extra(
+                libname,
+                pathfinder_abs_path=loaded.abs_path,
+                pathfinder_found_via=loaded.found_via,
+                pathfinder_was_already_loaded=loaded.was_already_loaded_from_elsewhere,
+            ),
+        )
+    return loaded
+
+
 def _load_lib_no_cache(libname: str) -> LoadedDL:
     desc = LIB_DESCRIPTORS[libname]
 
     if libname in _DRIVER_ONLY_LIBNAMES:
-        return _load_driver_lib_no_cache(desc)
+        return _log_resolved(_load_driver_lib_no_cache(desc), libname)
+
+    if LOGGER is not None:
+        LOGGER.debug("starting search for %s", libname, extra=search_extra(libname))
 
     ctx = SearchContext(desc)
 
@@ -179,24 +201,30 @@ def _load_lib_no_cache(libname: str) -> LoadedDL:
     loaded = LOADER.check_if_already_loaded_from_elsewhere(desc, find is not None)
     load_dependencies(desc, load_nvidia_dynamic_lib)
     if loaded is not None:
-        return loaded
+        return _log_resolved(loaded, libname)
 
     # Phase 3: Load from found path, or fall back to system search + late find.
     if find is not None:
-        return LOADER.load_with_abs_path(desc, find.abs_path, find.found_via)
+        return _log_resolved(LOADER.load_with_abs_path(desc, find.abs_path, find.found_via), libname)
 
     loaded = LOADER.load_with_system_search(desc)
     if loaded is not None:
-        return loaded
+        return _log_resolved(loaded, libname)
+    if LOGGER is not None:
+        LOGGER.debug(
+            "system search did not resolve %s; trying late find steps",
+            libname,
+            extra=search_extra(libname, pathfinder_step="load_with_system_search", pathfinder_matched=False),
+        )
 
     find = run_find_steps(ctx, LATE_FIND_STEPS)
     if find is not None:
-        return LOADER.load_with_abs_path(desc, find.abs_path, find.found_via)
+        return _log_resolved(LOADER.load_with_abs_path(desc, find.abs_path, find.found_via), libname)
 
     if desc.ctk_root_canary_anchor_libnames:
         canary_abs_path = _try_ctk_root_canary(ctx)
         if canary_abs_path is not None:
-            return LOADER.load_with_abs_path(desc, canary_abs_path, "system-ctk-root")
+            return _log_resolved(LOADER.load_with_abs_path(desc, canary_abs_path, "system-ctk-root"), libname)
 
     ctx.raise_not_found()
 

cuda_pathfinder/cuda/pathfinder/_dynamic_libs/search_steps.py

@@ -28,6 +28,7 @@
 from cuda.pathfinder._dynamic_libs.lib_descriptor import LibDescriptor
 from cuda.pathfinder._dynamic_libs.load_dl_common import DynamicLibNotFoundError
 from cuda.pathfinder._dynamic_libs.search_platform import PLATFORM, SearchPlatform
+from cuda.pathfinder._utils.diagnostic_log import LOGGER, search_extra
 from cuda.pathfinder._utils.env_vars import get_cuda_path_or_home
 
 # ---------------------------------------------------------------------------
@@ -63,6 +64,20 @@ def lib_searched_for(self) -> str:
     def raise_not_found(self) -> NoReturn:
         err = ", ".join(self.error_messages)
         att = "\n".join(self.attachments)
+        if LOGGER is not None:
+            # The exception below already carries this information, always on.
+            # Logging it too gives consumers the candidate list as structured
+            # fields rather than as text they would have to parse back out.
+            LOGGER.error(
+                "search failed for %s: no candidate matched",
+                self.lib_searched_for,
+                extra=search_extra(
+                    self.libname,
+                    pathfinder_searched_for=self.lib_searched_for,
+                    pathfinder_error_messages=list(self.error_messages),
+                    pathfinder_attachments=list(self.attachments),
+                ),
+            )
         raise DynamicLibNotFoundError(f'Failure finding "{self.lib_searched_for}": {err}\n{att}')
 
 
@@ -224,6 +239,28 @@ def run_find_steps(ctx: SearchContext, steps: tuple[FindStep, ...]) -> FindResul
     """Run find steps in order, returning the first hit."""
     for step in steps:
         result = step(ctx)
+        if LOGGER is not None:
+            if result is None:
+                LOGGER.debug(
+                    "step %s: no match for %s",
+                    step.__name__,
+                    ctx.lib_searched_for,
+                    extra=search_extra(ctx.libname, pathfinder_step=step.__name__, pathfinder_matched=False),
+                )
+            else:
+                LOGGER.debug(
+                    "step %s: matched %s via %s",
+                    step.__name__,
+                    result.abs_path,
+                    result.found_via,
+                    extra=search_extra(
+                        ctx.libname,
+                        pathfinder_step=step.__name__,
+                        pathfinder_matched=True,
+                        pathfinder_abs_path=result.abs_path,
+                        pathfinder_found_via=result.found_via,
+                    ),
+                )
         if result is not None:
             return result
     return None

cuda_pathfinder/cuda/pathfinder/_utils/diagnostic_log.py

@@ -0,0 +1,107 @@
+# SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved.
+# SPDX-License-Identifier: Apache-2.0
+
+"""Opt-in diagnostic logging for cuda.pathfinder.
+
+Disabled by default. Set ``CUDA_PATHFINDER_LOG_LEVEL`` to a standard level name
+(``DEBUG``, ``INFO``, ``WARNING``, ``ERROR``, ``CRITICAL``) or to a numeric
+level to enable it::
+
+    CUDA_PATHFINDER_LOG_LEVEL=DEBUG python -c "import cuda.pathfinder as p; p.load_nvidia_dynamic_lib('cudart')"
+
+Design notes
+------------
+``logging`` is **not** imported unless the environment variable is set. Importing
+it pulls in seven additional modules (``logging``, ``atexit``, ``string``,
+``_string``, ``textwrap``, ``traceback``, ``_colorize``) and measurably slows
+``import cuda.pathfinder``, which sits on the import hot path of every consumer.
+Deferring the import keeps the disabled path free rather than merely cheap.
+
+Call sites guard on ``LOGGER is not None`` so that a disabled logger costs one
+module-global lookup and an identity check, and so that no message string or
+``extra`` dict is built when logging is off.
+
+The environment variable is read exactly once, at import. This matches
+:func:`cuda.pathfinder._utils.env_vars.get_cuda_path_or_home`, which is
+``functools.cache``-d and documents the same read-once policy.
+
+This module never configures the root logger, never calls ``basicConfig``, and
+attaches only a ``NullHandler``. Consumers remain in full control of handlers
+and formatting.
+"""
+
+from __future__ import annotations
+
+import os
+import warnings
+from typing import TYPE_CHECKING, Any
+
+if TYPE_CHECKING:
+    import logging
+
+#: Environment variable that enables logging. Matches the existing
+#: ``CUDA_PATHFINDER_*`` prefix used elsewhere in this package.
+ENV_VAR_NAME = "CUDA_PATHFINDER_LOG_LEVEL"
+
+#: Logger name. Mirrors the import path so consumers can filter on it.
+LOGGER_NAME = "cuda.pathfinder"
+
+_VALID_LEVEL_NAMES = ("CRITICAL", "ERROR", "WARNING", "INFO", "DEBUG")
+
+
+def _resolve_level(raw: str) -> int | None:
+    """Map an environment-variable value to a logging level, or None if invalid."""
+    import logging
+
+    name = raw.strip().upper()
+    if name in _VALID_LEVEL_NAMES:
+        return int(getattr(logging, name))
+    try:
+        return int(raw.strip())
+    except ValueError:
+        return None
+
+
+def _make_logger() -> logging.Logger | None:
+    """Build the package logger, or return None when logging is disabled.
+
+    ``logging`` is imported only on the enabled path.
+    """
+    raw = os.environ.get(ENV_VAR_NAME)
+    if not raw or not raw.strip():
+        return None
+
+    level = _resolve_level(raw)
+    if level is None:
+        warnings.warn(
+            f"{ENV_VAR_NAME}={raw!r} is not a valid logging level; "
+            f"expected one of {', '.join(_VALID_LEVEL_NAMES)} or an integer. "
+            "cuda.pathfinder logging stays disabled.",
+            UserWarning,
+            stacklevel=2,
+        )
+        return None
+
+    import logging
+
+    logger = logging.getLogger(LOGGER_NAME)
+    # NullHandler keeps "No handlers could be found" quiet without imposing a
+    # destination; consumers attach their own handler if they want output.
+    logger.addHandler(logging.NullHandler())
+    logger.setLevel(level)
+    return logger
+
+
+#: The package logger, or ``None`` when logging is disabled. Guard every call
+#: site with ``if LOGGER is not None:`` so the disabled path builds nothing.
+LOGGER: logging.Logger | None = _make_logger()
+
+
+def search_extra(libname: str, **fields: Any) -> dict[str, Any]:
+    """Build the ``extra`` mapping shared by pathfinder log records.
+
+    Only ever called from inside a ``LOGGER is not None`` guard, so it costs
+    nothing when logging is disabled. Consumers can filter on these fields
+    instead of parsing the message text.
+    """
+    return {"pathfinder_libname": libname, **fields}