From ae233840f191154a8c8ee864f2fc12357f377b0a Mon Sep 17 00:00:00 2001 From: Esteban Ginez <175813+eginez@users.noreply.github.com> Date: Fri, 13 Jun 2025 09:13:21 -0700 Subject: [PATCH 1/2] Add comprehensive debug logging for threading and parallelization decisions Adds debug logging across Rust and Python components to help diagnose threading behavior and parallelization decisions. Includes logging for: - Rust threading decisions in getenv_use_multiple_threads() - PassManager parallel execution choices and process counts - SABRE layout trial count configuration - parallel_map execution paths and results Co-Authored with the help of: Claude --- crates/accelerate/src/lib.rs | 15 ++++++++++- qiskit/passmanager/passmanager.py | 12 +++++++-- .../preset_passmanagers/builtin_plugins.py | 15 ++++++++--- qiskit/utils/parallel.py | 26 ++++++++++++++++--- 4 files changed, 59 insertions(+), 9 deletions(-) diff --git a/crates/accelerate/src/lib.rs b/crates/accelerate/src/lib.rs index a3b6e6fa6e69..096039c6b7be 100644 --- a/crates/accelerate/src/lib.rs +++ b/crates/accelerate/src/lib.rs @@ -74,7 +74,20 @@ pub fn getenv_use_multiple_threads() -> bool { .unwrap_or_else(|_| "FALSE".to_string()) .to_uppercase() == "TRUE"; - !parallel_context || force_threads + + let result = !parallel_context || force_threads; + + // Log threading decision if debug logging is enabled + if env::var("QISKIT_DEBUG_THREADING").is_ok() { + eprintln!( + "Rust threading decision: {} (parallel_context={}, force_threads={})", + if result { "MULTI_THREADED" } else { "SINGLE_THREADED" }, + parallel_context, + force_threads + ); + } + + result } import_exception!(qiskit.exceptions, QiskitError); diff --git a/qiskit/passmanager/passmanager.py b/qiskit/passmanager/passmanager.py index 85f422f181b9..6577ace0c89f 100644 --- a/qiskit/passmanager/passmanager.py +++ b/qiskit/passmanager/passmanager.py @@ -21,7 +21,7 @@ import dill -from qiskit.utils.parallel import parallel_map, should_run_in_parallel +from qiskit.utils.parallel import parallel_map, should_run_in_parallel, CPU_COUNT from .base_tasks import Task, PassManagerIR from .exceptions import PassManagerError from .flow_controllers import FlowControllerLinear @@ -227,7 +227,12 @@ def callback_func(**kwargs): # If we're not going to run in parallel, we want to avoid spending time `dill` serializing # ourselves, since that can be quite expensive. - if len(in_programs) == 1 or not should_run_in_parallel(num_processes): + use_parallel = should_run_in_parallel(num_processes) + if len(in_programs) == 1 or not use_parallel: + if len(in_programs) == 1: + logger.debug("PassManager running single program serially") + else: + logger.debug("PassManager running %d programs serially (parallel disabled)", len(in_programs)) out = [ _run_workflow(program=program, pass_manager=self, callback=callback, **kwargs) for program in in_programs @@ -239,6 +244,9 @@ def callback_func(**kwargs): del callback del kwargs + logger.debug("PassManager running %d programs in parallel with %d processes", + len(in_programs), num_processes or CPU_COUNT) + # Pass manager may contain callable and we need to serialize through dill rather than pickle. # See https://github.com/Qiskit/qiskit-terra/pull/3290 # Note that serialized object is deserialized as a different object. diff --git a/qiskit/transpiler/preset_passmanagers/builtin_plugins.py b/qiskit/transpiler/preset_passmanagers/builtin_plugins.py index 8c928a47f69d..0ba5bcea221f 100644 --- a/qiskit/transpiler/preset_passmanagers/builtin_plugins.py +++ b/qiskit/transpiler/preset_passmanagers/builtin_plugins.py @@ -12,9 +12,12 @@ """Built-in transpiler stage plugins for preset pass managers.""" +import logging import os import warnings +logger = logging.getLogger(__name__) + from qiskit.transpiler.passes.optimization.split_2q_unitaries import Split2QUnitaries from qiskit.transpiler.passmanager import PassManager from qiskit.transpiler.exceptions import TranspilerError @@ -1024,6 +1027,12 @@ def _swap_mapped(property_set): def _get_trial_count(default_trials=5): - if CONFIG.get("sabre_all_threads", None) or os.getenv("QISKIT_SABRE_ALL_THREADS"): - return max(CPU_COUNT, default_trials) - return default_trials + use_all_threads = CONFIG.get("sabre_all_threads", None) or os.getenv("QISKIT_SABRE_ALL_THREADS") + if use_all_threads: + trial_count = max(CPU_COUNT, default_trials) + logger.debug("SABRE using all threads: %d trials (CPU_COUNT=%d, default=%d)", + trial_count, CPU_COUNT, default_trials) + return trial_count + else: + logger.debug("SABRE using default thread configuration: %d trials", default_trials) + return default_trials diff --git a/qiskit/utils/parallel.py b/qiskit/utils/parallel.py index f87eeb815967..548d1f84a14f 100644 --- a/qiskit/utils/parallel.py +++ b/qiskit/utils/parallel.py @@ -50,6 +50,7 @@ from __future__ import annotations +import logging import os from concurrent.futures import ProcessPoolExecutor import sys @@ -58,6 +59,8 @@ from qiskit.utils.multiprocessing import local_hardware_info from qiskit import user_config +logger = logging.getLogger(__name__) + def get_platform_parallel_default(): """ @@ -111,11 +114,24 @@ def should_run_in_parallel(num_processes: int | None = None) -> bool: num_processes: the number of processes requested for use (if given). """ num_processes = CPU_COUNT if num_processes is None else num_processes - return ( + in_parallel = os.getenv("QISKIT_IN_PARALLEL", "FALSE") == "TRUE" + parallel_enabled = CONFIG.get("parallel_enabled", PARALLEL_DEFAULT) + + result = ( num_processes > 1 - and os.getenv("QISKIT_IN_PARALLEL", "FALSE") == "FALSE" - and CONFIG.get("parallel_enabled", PARALLEL_DEFAULT) + and not in_parallel + and parallel_enabled + ) + + logger.debug( + "Parallelization decision: %s (num_processes=%d, in_parallel=%s, parallel_enabled=%s)", + "PARALLEL" if result else "SERIAL", + num_processes, + in_parallel, + parallel_enabled ) + + return result def parallel_map( # pylint: disable=dangerous-default-value @@ -164,6 +180,7 @@ def func(_): return [task(values[0], *task_args, **task_kwargs)] if should_run_in_parallel(num_processes): + logger.debug("Executing parallel_map with %d processes for %d items", num_processes, len(values)) os.environ["QISKIT_IN_PARALLEL"] = "TRUE" try: results = [] @@ -172,8 +189,10 @@ def func(_): future = executor.map(_task_wrapper, param) results = list(future) + logger.debug("Parallel execution completed successfully") except (KeyboardInterrupt, Exception) as error: + logger.debug("Parallel execution failed: %s", str(error)) if isinstance(error, KeyboardInterrupt): os.environ["QISKIT_IN_PARALLEL"] = "FALSE" raise QiskitError("Keyboard interrupt in parallel_map.") from error @@ -184,6 +203,7 @@ def func(_): os.environ["QISKIT_IN_PARALLEL"] = "FALSE" return results + logger.debug("Executing parallel_map serially for %d items", len(values)) results = [] for _, value in enumerate(values): result = task(value, *task_args, **task_kwargs) From e056c81a9c6b1fc34e656ffb2402a00b0410efff Mon Sep 17 00:00:00 2001 From: Esteban Ginez <175813+eginez@users.noreply.github.com> Date: Fri, 13 Jun 2025 09:37:16 -0700 Subject: [PATCH 2/2] Apply suggestions from code review Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com> --- crates/accelerate/src/lib.rs | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/crates/accelerate/src/lib.rs b/crates/accelerate/src/lib.rs index bbf429426ac4..1076a4190df9 100644 --- a/crates/accelerate/src/lib.rs +++ b/crates/accelerate/src/lib.rs @@ -44,7 +44,11 @@ pub fn getenv_use_multiple_threads() -> bool { let result = !parallel_context || force_threads; // Log threading decision if debug logging is enabled - if env::var("QISKIT_DEBUG_THREADING").is_ok() { + if env::var("QISKIT_DEBUG_THREADING") + .unwrap_or_else(|_| "FALSE".to_string()) + .to_uppercase() + == "TRUE" + { eprintln!( "Rust threading decision: {} (parallel_context={}, force_threads={})", if result { "MULTI_THREADED" } else { "SINGLE_THREADED" },