From 6feac37f0867974782f27a8b298011659f560b5e Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Thu, 11 Apr 2024 13:42:49 -0400 Subject: [PATCH 01/48] Add log-rules for catalyst --- pennylane/logging/log_config.toml | 20 +++++++++++++++++++- 1 file changed, 19 insertions(+), 1 deletion(-) diff --git a/pennylane/logging/log_config.toml b/pennylane/logging/log_config.toml index 25f3b980e3f..fe06787e31e 100644 --- a/pennylane/logging/log_config.toml +++ b/pennylane/logging/log_config.toml @@ -52,6 +52,12 @@ formatter = "qml_alt_formatter" level = "DEBUG" stream = "ext://sys.stdout" +[handlers.qml_debug_syslog] +class = "logging.handlers.SysLogHandler" +formatter = "local_standard" +level = "DEBUG" +address = "/dev/log" + [handlers.qml_debug_file] class = "logging.handlers.RotatingFileHandler" formatter = "local_standard" @@ -77,7 +83,13 @@ filters = ["qml_LocalProcessFilter", "qml_DebugOnlyFilter"] # Control JAX logging [loggers.jax] handlers = ["qml_debug_stream",] -level = "WARN" +level = "DEBUG" +propagate = false + +# Control JAXlib logging +[loggers.jaxlib] +handlers = ["qml_debug_stream",] +level = "DEBUG" propagate = false # Control logging across pennylane @@ -86,6 +98,12 @@ handlers = ["qml_debug_stream",] level = "DEBUG" # Set to TRACE for highest verbosity propagate = false +# Control logging across catalyst +[loggers.catalyst] +handlers = ["qml_debug_stream"] #, "qml_debug_syslog"] +level = "DEBUG" # Set to TRACE for highest verbosity +propagate = false + # Control logging specifically in the pennylane.qnode module # Note the required quotes to overcome TOML nesting issues [loggers."pennylane.qnode"] From eb0d72e6d75b9003c665b3a48dd1da740ef47ce0 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 12 Apr 2024 13:37:07 -0400 Subject: [PATCH 02/48] Update logging with file and syslog supports --- pennylane/logging/log_config.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pennylane/logging/log_config.toml b/pennylane/logging/log_config.toml index fe06787e31e..d646ee41125 100644 --- a/pennylane/logging/log_config.toml +++ b/pennylane/logging/log_config.toml @@ -100,7 +100,7 @@ propagate = false # Control logging across catalyst [loggers.catalyst] -handlers = ["qml_debug_stream"] #, "qml_debug_syslog"] +handlers = ["qml_debug_stream",] level = "DEBUG" # Set to TRACE for highest verbosity propagate = false From 9bf93c363119132476dcbb7c2c55a4c74c191662 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Tue, 16 Apr 2024 15:35:43 -0400 Subject: [PATCH 03/48] Add support for direct modification of log config --- pennylane/logging/__init__.py | 3 +-- pennylane/logging/configuration.py | 40 +++++++++++++++++++++++++++--- 2 files changed, 37 insertions(+), 6 deletions(-) diff --git a/pennylane/logging/__init__.py b/pennylane/logging/__init__.py index df7c96c8177..6a3807c1bc3 100644 --- a/pennylane/logging/__init__.py +++ b/pennylane/logging/__init__.py @@ -13,8 +13,7 @@ # limitations under the License. """This module enables support for log-level messaging throughout PennyLane, following the native Python logging framework interface. Please see the :doc:`PennyLane logging development guidelines`, and the official Python documentation for details on usage https://docs.python.org/3/library/logging.html""" -from .configuration import enable_logging -from .configuration import config_path +from .configuration import config_path, edit_system_config, enable_logging from .configuration import TRACE from .formatters.formatter import DefaultFormatter, SimpleFormatter from .filter import LocalProcessFilter, DebugOnlyFilter diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 8826146e669..93d311eb81b 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -16,7 +16,7 @@ """ import logging import logging.config -import os +import os, platform, subprocess from importlib import import_module from importlib.util import find_spec @@ -53,7 +53,7 @@ def trace(self, message, *args, **kws): lc.trace = trace -def _configure_logging(config_file): +def _configure_logging(config_file:str , config_override:dict = {}): """ This method allows custom logging configuration throughout PennyLane. All configurations are read through the ``log_config.toml`` file. @@ -71,7 +71,7 @@ def _configure_logging(config_file): logging.config.dictConfig(pl_config) -def enable_logging(): +def enable_logging(config_file: str = "log_config.toml"): """ This method allows to selectively enable logging throughout PennyLane, following the configuration options defined in the ``log_config.toml`` file. @@ -82,7 +82,7 @@ def enable_logging(): >>> qml.logging.enable_logging() """ _add_trace_level() - _configure_logging("log_config.toml") + _configure_logging(config_file) def config_path(): @@ -99,3 +99,35 @@ def config_path(): """ path = os.path.join(_path, "log_config.toml") return path + +def show_system_config(): + """ + This function opens the logging configuration file in the system-default browser. + """ + import webbrowser + webbrowser.open(config_path()) + +def edit_system_config(wait_on_close=False): + """ + This function opens the log configuration file using OS-specific editors. + + Setting the `EDITOR` environment variable will override xdg-open/open on + Linux and MacOS, and allows use of `wait_on_close` for editor close before + continuing execution. + + Warning: As each OS configuration differs user-to-user, you may wish to + instead open this file manually with the `config_path()` provided path. + """ + if (editor := os.getenv("EDITOR")): + p = subprocess.Popen((editor, config_path())) + if wait_on_close: # Only valid when editor is known + p.wait() + elif (s:=platform.system()) in ['Linux', "Darwin"]: + f_cmd = None + if s == "Linux": + f_cmd = "xdg-open" + else: + f_cmd = "open" + subprocess.Popen((f_cmd, config_path())) + else: # Windows + os.startfile(config_path()) \ No newline at end of file From c997ed771d49454c8e125d37fe597ac10746742a Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 17 Apr 2024 12:27:27 -0400 Subject: [PATCH 04/48] Add support for log decorator --- pennylane/logging/__init__.py | 3 +- pennylane/logging/configuration.py | 19 +++++---- pennylane/logging/formatters/formatter.py | 49 +++++++++++++++++++++++ pennylane/logging/log_config.toml | 15 +++++-- 4 files changed, 74 insertions(+), 12 deletions(-) diff --git a/pennylane/logging/__init__.py b/pennylane/logging/__init__.py index 6a3807c1bc3..2c6ffec307d 100644 --- a/pennylane/logging/__init__.py +++ b/pennylane/logging/__init__.py @@ -13,7 +13,8 @@ # limitations under the License. """This module enables support for log-level messaging throughout PennyLane, following the native Python logging framework interface. Please see the :doc:`PennyLane logging development guidelines`, and the official Python documentation for details on usage https://docs.python.org/3/library/logging.html""" -from .configuration import config_path, edit_system_config, enable_logging +from .configuration import config_path, edit_system_config, enable_logging from .configuration import TRACE from .formatters.formatter import DefaultFormatter, SimpleFormatter from .filter import LocalProcessFilter, DebugOnlyFilter +from .decorators import debug_logger diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 93d311eb81b..b7979e4192d 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -53,7 +53,7 @@ def trace(self, message, *args, **kws): lc.trace = trace -def _configure_logging(config_file:str , config_override:dict = {}): +def _configure_logging(config_file: str, config_override: dict = {}): """ This method allows custom logging configuration throughout PennyLane. All configurations are read through the ``log_config.toml`` file. @@ -100,34 +100,37 @@ def config_path(): path = os.path.join(_path, "log_config.toml") return path + def show_system_config(): """ This function opens the logging configuration file in the system-default browser. """ import webbrowser + webbrowser.open(config_path()) + def edit_system_config(wait_on_close=False): """ This function opens the log configuration file using OS-specific editors. - Setting the `EDITOR` environment variable will override xdg-open/open on - Linux and MacOS, and allows use of `wait_on_close` for editor close before + Setting the `EDITOR` environment variable will override xdg-open/open on + Linux and MacOS, and allows use of `wait_on_close` for editor close before continuing execution. Warning: As each OS configuration differs user-to-user, you may wish to instead open this file manually with the `config_path()` provided path. """ - if (editor := os.getenv("EDITOR")): + if editor := os.getenv("EDITOR"): p = subprocess.Popen((editor, config_path())) - if wait_on_close: # Only valid when editor is known + if wait_on_close: # Only valid when editor is known p.wait() - elif (s:=platform.system()) in ['Linux', "Darwin"]: + elif (s := platform.system()) in ["Linux", "Darwin"]: f_cmd = None if s == "Linux": f_cmd = "xdg-open" else: f_cmd = "open" subprocess.Popen((f_cmd, config_path())) - else: # Windows - os.startfile(config_path()) \ No newline at end of file + else: # Windows + os.startfile(config_path()) diff --git a/pennylane/logging/formatters/formatter.py b/pennylane/logging/formatters/formatter.py index e3a6e9893c7..f46e052973f 100644 --- a/pennylane/logging/formatters/formatter.py +++ b/pennylane/logging/formatters/formatter.py @@ -12,6 +12,7 @@ # See the License for the specific language governing permissions and # limitations under the License. """The PennyLane log-level formatters are defined here with default options, and ANSI-terminal color-codes.""" +import inspect import logging from logging import Formatter from typing import NamedTuple, Tuple, Union @@ -114,6 +115,54 @@ def format(self, record): return formatter.format(record) +class DynamicFormatter(Formatter): + """This formatter has the default rules used for formatting PennyLane log messages, with a dynamically updated log format rule""" + + # 0x000000 Background + _text_bg = (0, 0, 0) + + cmap = ColorScheme( + debug=(220, 238, 200), # Grey 1 + debug_bg=_text_bg, + info=(80, 125, 125), # Blue + info_bg=_text_bg, + warning=(208, 167, 133), # Orange + warning_bg=_text_bg, + error=(208, 133, 133), # Red 1 + error_bg=_text_bg, + critical=(135, 53, 53), # Red 2 + critical_bg=(210, 210, 210), # Grey 2 + use_rgb=True, + ) + + def _build_formats(self, fmt_str): + cmap = DynamicFormatter.cmap + local_formats = { + logging.DEBUG: build_code_rgb(cmap.debug, cmap.debug_bg) + fmt_str + _ANSI_CODES["end"], + logging.INFO: build_code_rgb(cmap.info, cmap.info_bg) + fmt_str + _ANSI_CODES["end"], + logging.WARNING: build_code_rgb(cmap.warning, cmap.warning_bg) + + fmt_str + + _ANSI_CODES["end"], + logging.ERROR: build_code_rgb(cmap.error, cmap.error_bg) + fmt_str + _ANSI_CODES["end"], + logging.CRITICAL: build_code_rgb(cmap.critical, cmap.critical_bg) + + fmt_str + + _ANSI_CODES["end"], + } + + return local_formats + + def format(self, record): + f = inspect.getouterframes(inspect.currentframe())[ + 8 + ] # Stack depth from log-func call to format function + + fmt_str = f'[%(asctime)s][%(levelname)s][] - %(name)s.{f.function}()::"%(message)s"' + + log_fmt = self._build_formats(fmt_str).get(record.levelno) + formatter = logging.Formatter(log_fmt) + return formatter.format(record) + + class SimpleFormatter(Formatter): """This formatter has a simplified layout and rules used for formatting PennyLane log messages.""" diff --git a/pennylane/logging/log_config.toml b/pennylane/logging/log_config.toml index d646ee41125..1199fd41db4 100644 --- a/pennylane/logging/log_config.toml +++ b/pennylane/logging/log_config.toml @@ -13,6 +13,9 @@ version = 1 [formatters.qml_default_formatter] "()" = "pennylane.logging.formatters.formatter.DefaultFormatter" +[formatters.qml_dynamic_formatter] +"()" = "pennylane.logging.formatters.formatter.DynamicFormatter" + [formatters.qml_alt_formatter] "()" = "pennylane.logging.formatters.formatter.SimpleFormatter" @@ -46,6 +49,12 @@ formatter = "qml_default_formatter" level = "DEBUG" stream = "ext://sys.stdout" +[handlers.qml_debug_stream_dyn] +class = "logging.StreamHandler" +formatter = "qml_dynamic_formatter" +level = "DEBUG" +stream = "ext://sys.stdout" + [handlers.qml_debug_stream_alt] class = "logging.StreamHandler" formatter = "qml_alt_formatter" @@ -83,13 +92,13 @@ filters = ["qml_LocalProcessFilter", "qml_DebugOnlyFilter"] # Control JAX logging [loggers.jax] handlers = ["qml_debug_stream",] -level = "DEBUG" +level = "WARN" propagate = false # Control JAXlib logging [loggers.jaxlib] handlers = ["qml_debug_stream",] -level = "DEBUG" +level = "WARN" propagate = false # Control logging across pennylane @@ -101,7 +110,7 @@ propagate = false # Control logging across catalyst [loggers.catalyst] handlers = ["qml_debug_stream",] -level = "DEBUG" # Set to TRACE for highest verbosity +level = "TRACE" # Set to TRACE for highest verbosity propagate = false # Control logging specifically in the pennylane.qnode module From ef129d4d0909c21315e1d1db699bccde6c363d38 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 15:53:35 -0400 Subject: [PATCH 05/48] Update logging to latest release --- pennylane/devices/default_qubit.py | 21 ++++-- pennylane/devices/qubit/adjoint_jacobian.py | 10 ++- pennylane/devices/qubit/simulate.py | 12 ++- pennylane/logging/__init__.py | 4 +- pennylane/logging/configuration.py | 45 +++++++++-- pennylane/logging/decorators.py | 82 +++++++++++++++++++++ pennylane/logging/formatters/formatter.py | 51 ++++++++++++- pennylane/logging/log_config.toml | 28 +++++++ pennylane/logging/utils.py | 22 ++++++ pennylane/workflow/qnode.py | 9 ++- 10 files changed, 262 insertions(+), 22 deletions(-) create mode 100644 pennylane/logging/decorators.py create mode 100644 pennylane/logging/utils.py diff --git a/pennylane/devices/default_qubit.py b/pennylane/devices/default_qubit.py index d7957424b00..551f90649d7 100644 --- a/pennylane/devices/default_qubit.py +++ b/pennylane/devices/default_qubit.py @@ -26,6 +26,7 @@ import numpy as np import pennylane as qml +from pennylane.logging import debug_logger, debug_logger_init from pennylane.measurements.mid_measure import MidMeasureMP from pennylane.ops.op_math.condition import Conditional from pennylane.tape import QuantumTape @@ -419,6 +420,7 @@ def reset_prng_key(self): """ # pylint:disable = too-many-arguments + @debug_logger_init def __init__( self, wires=None, @@ -439,6 +441,7 @@ def __init__( self._rng = np.random.default_rng(seed) self._debugger = None + @debug_logger def supports_derivatives( self, execution_config: Optional[ExecutionConfig] = None, @@ -475,6 +478,7 @@ def supports_derivatives( return _supports_adjoint(circuit=circuit) return False + @debug_logger def preprocess( self, execution_config: ExecutionConfig = DefaultExecutionConfig, @@ -566,20 +570,13 @@ def _setup_execution_config(self, execution_config: ExecutionConfig) -> Executio updated_values["device_options"][option] = getattr(self, f"_{option}") return replace(execution_config, **updated_values) + @debug_logger def execute( self, circuits: QuantumTape_or_Batch, execution_config: ExecutionConfig = DefaultExecutionConfig, ) -> Result_or_ResultBatch: self.reset_prng_key() - if logger.isEnabledFor(logging.DEBUG): - logger.debug( - """Entry with args=(circuits=%s) called by=%s""", - circuits, - "::L".join( - str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3] - ), - ) max_workers = execution_config.device_options.get("max_workers", self._max_workers) self._state_cache = {} if execution_config.use_device_jacobian_product else None @@ -618,6 +615,7 @@ def execute( return results + @debug_logger def compute_derivatives( self, circuits: QuantumTape_or_Batch, @@ -637,6 +635,7 @@ def compute_derivatives( return res + @debug_logger def execute_and_compute_derivatives( self, circuits: QuantumTape_or_Batch, @@ -659,6 +658,7 @@ def execute_and_compute_derivatives( return tuple(zip(*results)) + @debug_logger def supports_jvp( self, execution_config: Optional[ExecutionConfig] = None, @@ -678,6 +678,7 @@ def supports_jvp( """ return self.supports_derivatives(execution_config, circuit) + @debug_logger def compute_jvp( self, circuits: QuantumTape_or_Batch, @@ -697,6 +698,7 @@ def compute_jvp( return res + @debug_logger def execute_and_compute_jvp( self, circuits: QuantumTape_or_Batch, @@ -724,6 +726,7 @@ def execute_and_compute_jvp( return tuple(zip(*results)) + @debug_logger def supports_vjp( self, execution_config: Optional[ExecutionConfig] = None, @@ -743,6 +746,7 @@ def supports_vjp( """ return self.supports_derivatives(execution_config, circuit) + @debug_logger def compute_vjp( self, circuits: QuantumTape_or_Batch, @@ -810,6 +814,7 @@ def _state(circuit): return res + @debug_logger def execute_and_compute_vjp( self, circuits: QuantumTape_or_Batch, diff --git a/pennylane/devices/qubit/adjoint_jacobian.py b/pennylane/devices/qubit/adjoint_jacobian.py index d5308e55fb6..1ba684d0f5e 100644 --- a/pennylane/devices/qubit/adjoint_jacobian.py +++ b/pennylane/devices/qubit/adjoint_jacobian.py @@ -12,12 +12,14 @@ # See the License for the specific language governing permissions and # limitations under the License. """Functions to apply adjoint jacobian differentiation""" +import logging from numbers import Number from typing import Tuple import numpy as np import pennylane as qml +from pennylane.logging import debug_logger from pennylane.operation import operation_derivative from pennylane.tape import QuantumTape @@ -27,6 +29,8 @@ # pylint: disable=protected-access, too-many-branches +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) def _dot_product_real(bra, ket, num_wires): """Helper for calculating the inner product for adjoint differentiation.""" @@ -67,7 +71,7 @@ def _adjoint_jacobian_state(tape: QuantumTape): return tuple(jac.flatten() for jac in jacobian) - +@debug_logger def adjoint_jacobian(tape: QuantumTape, state=None): """Implements the adjoint method outlined in `Jones and Gacon `__ to differentiate an input tape. @@ -142,7 +146,7 @@ def adjoint_jacobian(tape: QuantumTape, state=None): # must be 2-dimensional return tuple(tuple(np.array(j_) for j_ in j) for j in jac) - +@debug_logger def adjoint_jvp(tape: QuantumTape, tangents: Tuple[Number], state=None): """The jacobian vector product used in forward mode calculation of derivatives. @@ -315,7 +319,7 @@ def _get_vjp_bras(tape, cotangents, ket): return bras, batch_size, null_batch_indices - +@debug_logger def adjoint_vjp(tape: QuantumTape, cotangents: Tuple[Number], state=None): """The vector jacobian product used in reverse-mode differentiation. diff --git a/pennylane/devices/qubit/simulate.py b/pennylane/devices/qubit/simulate.py index 2095aff3d6d..a1131a67878 100644 --- a/pennylane/devices/qubit/simulate.py +++ b/pennylane/devices/qubit/simulate.py @@ -14,12 +14,15 @@ """Simulate a quantum script.""" # pylint: disable=protected-access from functools import partial +import inspect +import logging from typing import Optional import numpy as np from numpy.random import default_rng import pennylane as qml +from pennylane.logging import debug_logger from pennylane.measurements import MidMeasureMP from pennylane.typing import Result @@ -28,6 +31,9 @@ from .measure import measure from .sampling import jax_random_split, measure_with_samples +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) + INTERFACE_TO_LIKE = { # map interfaces known by autoray to themselves None: None, @@ -106,7 +112,7 @@ def _postselection_postprocess(state, is_state_batched, shots, rng=None, prng_ke state = state / norm return state, shots - +@debug_logger def get_final_state(circuit, debugger=None, **execution_kwargs): """ Get the final state that results from executing the given quantum script. @@ -175,6 +181,7 @@ def get_final_state(circuit, debugger=None, **execution_kwargs): # pylint: disable=too-many-arguments +@debug_logger def measure_final_state(circuit, state, is_state_batched, **execution_kwargs) -> Result: """ Perform the measurements required by the circuit on the provided state. @@ -237,7 +244,7 @@ def measure_final_state(circuit, state, is_state_batched, **execution_kwargs) -> return results - +@debug_logger def simulate( circuit: qml.tape.QuantumScript, debugger=None, @@ -292,6 +299,7 @@ def simulate( return measure_final_state(circuit, state, is_state_batched, rng=rng, prng_key=meas_key) +@debug_logger def simulate_one_shot_native_mcm( circuit: qml.tape.QuantumScript, debugger=None, **execution_kwargs ) -> Result: diff --git a/pennylane/logging/__init__.py b/pennylane/logging/__init__.py index b036d69d66b..2ca8f70ff04 100644 --- a/pennylane/logging/__init__.py +++ b/pennylane/logging/__init__.py @@ -13,6 +13,8 @@ # limitations under the License. """This module enables support for log-level messaging throughout PennyLane, following the native Python logging framework interface. Please see the :doc:`PennyLane logging development guidelines`, and the official Python documentation for details on usage https://docs.python.org/3/library/logging.html""" -from .configuration import TRACE, config_path, enable_logging +from .configuration import TRACE, config_path, edit_system_config, enable_logging +from .decorators import debug_logger, debug_logger_init from .filter import DebugOnlyFilter, LocalProcessFilter from .formatters.formatter import DefaultFormatter, SimpleFormatter +from .utils import _add_logging_all \ No newline at end of file diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 8826146e669..23f0ede55cf 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -16,7 +16,7 @@ """ import logging import logging.config -import os +import os, platform, subprocess from importlib import import_module from importlib.util import find_spec @@ -53,10 +53,10 @@ def trace(self, message, *args, **kws): lc.trace = trace -def _configure_logging(config_file): +def _configure_logging(config_file: str, config_override: dict = {}): """ This method allows custom logging configuration throughout PennyLane. - All configurations are read through the ``log_config.toml`` file. + All configurations are read through the ``log_config.toml`` file, with additional custom options provided through the ``config_override`` dictionary. """ if not has_toml: raise ImportError( @@ -68,10 +68,10 @@ def _configure_logging(config_file): ) with open(os.path.join(_path, config_file), "rb") as f: pl_config = tomllib.load(f) - logging.config.dictConfig(pl_config) + logging.config.dictConfig({**pl_config, **config_override}) -def enable_logging(): +def enable_logging(config_file: str = "log_config.toml"): """ This method allows to selectively enable logging throughout PennyLane, following the configuration options defined in the ``log_config.toml`` file. @@ -82,7 +82,7 @@ def enable_logging(): >>> qml.logging.enable_logging() """ _add_trace_level() - _configure_logging("log_config.toml") + _configure_logging(config_file) def config_path(): @@ -99,3 +99,36 @@ def config_path(): """ path = os.path.join(_path, "log_config.toml") return path + +def show_system_config(): + """ + This function opens the logging configuration file in the system-default browser. + """ + import webbrowser + webbrowser.open(config_path()) + + +def edit_system_config(wait_on_close=False): + """ + This function opens the log configuration file using OS-specific editors. + + Setting the `EDITOR` environment variable will override xdg-open/open on + Linux and MacOS, and allows use of `wait_on_close` for editor close before + continuing execution. + + Warning: As each OS configuration differs user-to-user, you may wish to + instead open this file manually with the `config_path()` provided path. + """ + if editor := os.getenv("EDITOR"): + p = subprocess.Popen((editor, config_path())) + if wait_on_close: # Only valid when editor is known + p.wait() + elif (s := platform.system()) in ["Linux", "Darwin"]: + f_cmd = None + if s == "Linux": + f_cmd = "xdg-open" + else: + f_cmd = "open" + subprocess.Popen((f_cmd, config_path())) + else: # Windows + os.startfile(config_path()) diff --git a/pennylane/logging/decorators.py b/pennylane/logging/decorators.py new file mode 100644 index 00000000000..19c87d4e0f0 --- /dev/null +++ b/pennylane/logging/decorators.py @@ -0,0 +1,82 @@ +import inspect +from functools import partial, wraps +import logging + +# Stack level allows moving up the stack with the log records, and prevents +# the decorator function names appearing in the resulting messages. +_debug_log_kwargs = {"stacklevel": 2} + + +def log_string_debug_func(func, log_level, use_entry, override={}): + """ + This decorator utility generates a string containing the called function, the passed arguments, and the source of the function call. + """ + lgr = logging.getLogger(func.__module__) + + def _get_bound_signature(*args, **kwargs) -> str: + s = inspect.signature(func) + + try: + ba = s.bind(*args, **kwargs) + except Exception as e: + # If kwargs are concat onto args, attempt to unpack. Fail otherwise + if len(args) == 2 and len(kwargs) == 0 and isinstance(args[1], dict): + ba = s.bind(*args[0], **args[1]) + else: + raise e + ba.apply_defaults() + if len(override): + for k, v in override.keys(): + ba[k] = v + + f_string = str(ba).replace("BoundArguments ", func.__name__) + return f_string + + @wraps(func) + def wrapper_entry(*args, **kwargs): + if lgr.isEnabledFor(log_level): # pragma: no cover + f_string = _get_bound_signature(*args, **kwargs) + s_caller = "::L".join( + [str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3]] + ) + lgr.debug( + f"Calling {f_string} from {s_caller}", + **_debug_log_kwargs, + ) + return func(*args, **kwargs) + + @wraps(func) + def wrapper_exit(*args, **kwargs): + output = func(*args, **kwargs) + if lgr.isEnabledFor(log_level): # pragma: no cover + f_string = _get_bound_signature(*args, **kwargs) + s_caller = "::L".join( + [str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3]] + ) + lgr.debug( + f"Calling {f_string}={output} from {s_caller}", + **{"stacklevel": 2}, + ) + return output + + return wrapper_entry if use_entry else wrapper_exit + + +def log_string_debug_class(cl, log_level): + import types + + lgr = logging.getLogger(cl.__module__) + cl_func = inspect.getmembers(cl, predicate=inspect.isfunction) + f_par_entry = partial(log_string_debug_func, log_level=log_level, use_entry=True) + f_par_exit = partial(log_string_debug_func, log_level=log_level, use_entry=False) + + for f_name, f in cl_func: + if f_name == "__init__": + setattr(cl, f_name, types.MethodType(f_par_exit(f), cl)) + else: + setattr(cl, f_name, types.MethodType(f_par_entry(f), cl)) + return cl + +# For ease-of-use ``debug_logger`` is provided for decoration of public methods and free functions, with ``debug_logger_init`` provided for use with class constructors. +debug_logger = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=True) +debug_logger_init = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=False) diff --git a/pennylane/logging/formatters/formatter.py b/pennylane/logging/formatters/formatter.py index e3a6e9893c7..8e6056610fe 100644 --- a/pennylane/logging/formatters/formatter.py +++ b/pennylane/logging/formatters/formatter.py @@ -12,6 +12,7 @@ # See the License for the specific language governing permissions and # limitations under the License. """The PennyLane log-level formatters are defined here with default options, and ANSI-terminal color-codes.""" +import inspect import logging from logging import Formatter from typing import NamedTuple, Tuple, Union @@ -77,7 +78,7 @@ def bash_ansi_codes(): class DefaultFormatter(Formatter): """This formatter has the default rules used for formatting PennyLane log messages.""" - fmt_str = '[%(asctime)s][%(levelname)s][] - %(name)s.%(funcName)s()::"%(message)s"' + fmt_str = '[%(asctime)s][%(levelname)s][] - %(name)s.%(funcName)s::"%(message)s"\n' # 0x000000 Background _text_bg = (0, 0, 0) @@ -114,6 +115,54 @@ def format(self, record): return formatter.format(record) +class DynamicFormatter(Formatter): + """This formatter has the default rules used for formatting PennyLane log messages, with a dynamically updated log format rule""" + + # 0x000000 Background + _text_bg = (0, 0, 0) + + cmap = ColorScheme( + debug=(220, 238, 200), # Grey 1 + debug_bg=_text_bg, + info=(80, 125, 125), # Blue + info_bg=_text_bg, + warning=(208, 167, 133), # Orange + warning_bg=_text_bg, + error=(208, 133, 133), # Red 1 + error_bg=_text_bg, + critical=(135, 53, 53), # Red 2 + critical_bg=(210, 210, 210), # Grey 2 + use_rgb=True, + ) + + def _build_formats(self, fmt_str): + cmap = DynamicFormatter.cmap + local_formats = { + logging.DEBUG: build_code_rgb(cmap.debug, cmap.debug_bg) + fmt_str + _ANSI_CODES["end"], + logging.INFO: build_code_rgb(cmap.info, cmap.info_bg) + fmt_str + _ANSI_CODES["end"], + logging.WARNING: build_code_rgb(cmap.warning, cmap.warning_bg) + + fmt_str + + _ANSI_CODES["end"], + logging.ERROR: build_code_rgb(cmap.error, cmap.error_bg) + fmt_str + _ANSI_CODES["end"], + logging.CRITICAL: build_code_rgb(cmap.critical, cmap.critical_bg) + + fmt_str + + _ANSI_CODES["end"], + } + + return local_formats + + def format(self, record): + f = inspect.getouterframes(inspect.currentframe())[ + 8 + ] # Stack depth from log-func call to format function + + fmt_str = f'[%(asctime)s][%(levelname)s][] - %(name)s.{f.function}()::"%(message)s"' + + log_fmt = self._build_formats(fmt_str).get(record.levelno) + formatter = logging.Formatter(log_fmt) + return formatter.format(record) + + class SimpleFormatter(Formatter): """This formatter has a simplified layout and rules used for formatting PennyLane log messages.""" diff --git a/pennylane/logging/log_config.toml b/pennylane/logging/log_config.toml index 25f3b980e3f..e03c51ff136 100644 --- a/pennylane/logging/log_config.toml +++ b/pennylane/logging/log_config.toml @@ -13,6 +13,9 @@ version = 1 [formatters.qml_default_formatter] "()" = "pennylane.logging.formatters.formatter.DefaultFormatter" +[formatters.qml_dynamic_formatter] +"()" = "pennylane.logging.formatters.formatter.DynamicFormatter" + [formatters.qml_alt_formatter] "()" = "pennylane.logging.formatters.formatter.SimpleFormatter" @@ -46,12 +49,25 @@ formatter = "qml_default_formatter" level = "DEBUG" stream = "ext://sys.stdout" +[handlers.qml_debug_stream_dyn] +class = "logging.StreamHandler" +formatter = "qml_dynamic_formatter" +level = "DEBUG" +stream = "ext://sys.stdout" + [handlers.qml_debug_stream_alt] class = "logging.StreamHandler" formatter = "qml_alt_formatter" level = "DEBUG" stream = "ext://sys.stdout" +[handlers.qml_debug_syslog] +class = "logging.handlers.SysLogHandler" +formatter = "local_standard" +level = "DEBUG" +address = "/dev/log" + + [handlers.qml_debug_file] class = "logging.handlers.RotatingFileHandler" formatter = "local_standard" @@ -80,6 +96,12 @@ handlers = ["qml_debug_stream",] level = "WARN" propagate = false +# Control JAXlib logging +[loggers.jaxlib] +handlers = ["qml_debug_stream",] +level = "WARN" +propagate = false + # Control logging across pennylane [loggers.pennylane] handlers = ["qml_debug_stream",] @@ -93,4 +115,10 @@ handlers = ["qml_debug_stream",] level = "DEBUG" # Set to TRACE for highest verbosity propagate = false +# Control logging across catalyst +[loggers.catalyst] +handlers = ["qml_debug_stream",] +level = "DEBUG" # Set to TRACE for highest verbosity +propagate = false + ############################################################################### diff --git a/pennylane/logging/utils.py b/pennylane/logging/utils.py new file mode 100644 index 00000000000..679131d533f --- /dev/null +++ b/pennylane/logging/utils.py @@ -0,0 +1,22 @@ +import inspect +import sys + + +def _is_local_fn(f, mod_name): + """ + Predicate that validates if argument `f` is a local module `mod_name`. + """ + is_func = inspect.isfunction(f) + is_local_to_mod = inspect.getmodule(f).__name__ == mod_name + return is_func and is_local_to_mod + + +def _add_logging_all(mod_name): + """ + Modifies the module to add logging implicitly to all free-functions. + """ + l_func = inspect.getmembers( + sys.modules[mod_name], predicate=lambda x: _is_local_fn(x, mod_name) + ) + for f_name, f in l_func: + globals()[f_name] = debug_logger(f) diff --git a/pennylane/workflow/qnode.py b/pennylane/workflow/qnode.py index 513abd88e83..57d6e89c28b 100644 --- a/pennylane/workflow/qnode.py +++ b/pennylane/workflow/qnode.py @@ -25,6 +25,7 @@ import pennylane as qml from pennylane import Device +from pennylane.logging import debug_logger from pennylane.measurements import CountsMP, MidMeasureMP, Shots from pennylane.tape import QuantumScript, QuantumTape @@ -577,6 +578,7 @@ def transform_program(self): """The transform program used by the QNode.""" return self._transform_program + @debug_logger def add_transform(self, transform_container): """Add a transform (container) to the transform program. @@ -601,7 +603,7 @@ def _update_gradient_fn(self, shots=None, tape=None): ): diff_method = "parameter-shift" - self.gradient_fn, self.gradient_kwargs, self.device = self.get_gradient_fn( + self.gradient_fn, self.gradient_kwargs, self.device = QNode.get_gradient_fn( self._original_device, self.interface, diff_method, tape=tape ) self.gradient_kwargs.update(self._user_gradient_kwargs or {}) @@ -625,6 +627,7 @@ def _update_original_device(self): # pylint: disable=too-many-return-statements @staticmethod + @debug_logger def get_gradient_fn( device, interface, diff_method="best", tape: Optional["qml.tape.QuantumTape"] = None ): @@ -696,6 +699,7 @@ def get_gradient_fn( ) @staticmethod + @debug_logger def get_best_method(device, interface, tape=None): """Returns the 'best' differentiation method for a particular device and interface combination. @@ -742,6 +746,7 @@ def get_best_method(device, interface, tape=None): return qml.gradients.finite_diff, {}, device @staticmethod + @debug_logger def best_method_str(device, interface): """Similar to :meth:`~.get_best_method`, except return the 'best' differentiation method in human-readable format. @@ -780,6 +785,7 @@ def best_method_str(device, interface): return transform @staticmethod + @debug_logger def _validate_backprop_method(device, interface, tape=None): if isinstance(device, qml.devices.Device): raise ValueError( @@ -912,6 +918,7 @@ def tape(self) -> QuantumTape: qtape = tape # for backwards compatibility + @debug_logger def construct(self, args, kwargs): # pylint: disable=too-many-branches """Call the quantum function with a tape context, ensuring the operations get queued.""" kwargs = copy.copy(kwargs) From f09547906af5c08d59dd784358c317350a8a7da1 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 15:58:44 -0400 Subject: [PATCH 06/48] Run sort n lint --- pennylane/devices/qubit/adjoint_jacobian.py | 4 ++++ pennylane/devices/qubit/simulate.py | 7 +++++-- pennylane/logging/__init__.py | 2 +- pennylane/logging/configuration.py | 6 +++++- pennylane/logging/decorators.py | 3 ++- 5 files changed, 17 insertions(+), 5 deletions(-) diff --git a/pennylane/devices/qubit/adjoint_jacobian.py b/pennylane/devices/qubit/adjoint_jacobian.py index 1ba684d0f5e..7f25cb3a858 100644 --- a/pennylane/devices/qubit/adjoint_jacobian.py +++ b/pennylane/devices/qubit/adjoint_jacobian.py @@ -32,6 +32,7 @@ logger = logging.getLogger(__name__) logger.addHandler(logging.NullHandler()) + def _dot_product_real(bra, ket, num_wires): """Helper for calculating the inner product for adjoint differentiation.""" # broadcasted inner product not summing over first dimension of the bra tensor @@ -71,6 +72,7 @@ def _adjoint_jacobian_state(tape: QuantumTape): return tuple(jac.flatten() for jac in jacobian) + @debug_logger def adjoint_jacobian(tape: QuantumTape, state=None): """Implements the adjoint method outlined in @@ -146,6 +148,7 @@ def adjoint_jacobian(tape: QuantumTape, state=None): # must be 2-dimensional return tuple(tuple(np.array(j_) for j_ in j) for j in jac) + @debug_logger def adjoint_jvp(tape: QuantumTape, tangents: Tuple[Number], state=None): """The jacobian vector product used in forward mode calculation of derivatives. @@ -319,6 +322,7 @@ def _get_vjp_bras(tape, cotangents, ket): return bras, batch_size, null_batch_indices + @debug_logger def adjoint_vjp(tape: QuantumTape, cotangents: Tuple[Number], state=None): """The vector jacobian product used in reverse-mode differentiation. diff --git a/pennylane/devices/qubit/simulate.py b/pennylane/devices/qubit/simulate.py index a1131a67878..ca7b14c17e3 100644 --- a/pennylane/devices/qubit/simulate.py +++ b/pennylane/devices/qubit/simulate.py @@ -12,10 +12,11 @@ # See the License for the specific language governing permissions and # limitations under the License. """Simulate a quantum script.""" -# pylint: disable=protected-access -from functools import partial import inspect import logging + +# pylint: disable=protected-access +from functools import partial from typing import Optional import numpy as np @@ -112,6 +113,7 @@ def _postselection_postprocess(state, is_state_batched, shots, rng=None, prng_ke state = state / norm return state, shots + @debug_logger def get_final_state(circuit, debugger=None, **execution_kwargs): """ @@ -244,6 +246,7 @@ def measure_final_state(circuit, state, is_state_batched, **execution_kwargs) -> return results + @debug_logger def simulate( circuit: qml.tape.QuantumScript, diff --git a/pennylane/logging/__init__.py b/pennylane/logging/__init__.py index 2ca8f70ff04..f670be47e19 100644 --- a/pennylane/logging/__init__.py +++ b/pennylane/logging/__init__.py @@ -17,4 +17,4 @@ from .decorators import debug_logger, debug_logger_init from .filter import DebugOnlyFilter, LocalProcessFilter from .formatters.formatter import DefaultFormatter, SimpleFormatter -from .utils import _add_logging_all \ No newline at end of file +from .utils import _add_logging_all diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 23f0ede55cf..f7e43143a15 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -16,7 +16,9 @@ """ import logging import logging.config -import os, platform, subprocess +import os +import platform +import subprocess from importlib import import_module from importlib.util import find_spec @@ -100,11 +102,13 @@ def config_path(): path = os.path.join(_path, "log_config.toml") return path + def show_system_config(): """ This function opens the logging configuration file in the system-default browser. """ import webbrowser + webbrowser.open(config_path()) diff --git a/pennylane/logging/decorators.py b/pennylane/logging/decorators.py index 19c87d4e0f0..398df29e157 100644 --- a/pennylane/logging/decorators.py +++ b/pennylane/logging/decorators.py @@ -1,6 +1,6 @@ import inspect -from functools import partial, wraps import logging +from functools import partial, wraps # Stack level allows moving up the stack with the log records, and prevents # the decorator function names appearing in the resulting messages. @@ -77,6 +77,7 @@ def log_string_debug_class(cl, log_level): setattr(cl, f_name, types.MethodType(f_par_entry(f), cl)) return cl + # For ease-of-use ``debug_logger`` is provided for decoration of public methods and free functions, with ``debug_logger_init`` provided for use with class constructors. debug_logger = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=True) debug_logger_init = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=False) From 1e4a923420eb4d983dca7d9c0141fc1f85b34cba Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 16:24:11 -0400 Subject: [PATCH 07/48] Fix format --- pennylane/logging/configuration.py | 1 - 1 file changed, 1 deletion(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index d52f4881a5e..f7e43143a15 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -19,7 +19,6 @@ import os import platform import subprocess - from importlib import import_module from importlib.util import find_spec From e721a39221b64d178ebb1e92cf4451d0be0921a1 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 16:39:43 -0400 Subject: [PATCH 08/48] Pylint adhere --- pennylane/devices/default_qubit.py | 1 - pennylane/devices/qubit/simulate.py | 1 - pennylane/logging/configuration.py | 13 +++++++++---- pennylane/logging/decorators.py | 22 +++------------------- pennylane/logging/formatters/formatter.py | 3 ++- pennylane/logging/utils.py | 2 ++ 6 files changed, 16 insertions(+), 26 deletions(-) diff --git a/pennylane/devices/default_qubit.py b/pennylane/devices/default_qubit.py index 551f90649d7..fa4737f3eb1 100644 --- a/pennylane/devices/default_qubit.py +++ b/pennylane/devices/default_qubit.py @@ -16,7 +16,6 @@ """ import concurrent.futures -import inspect import logging from dataclasses import replace from functools import partial diff --git a/pennylane/devices/qubit/simulate.py b/pennylane/devices/qubit/simulate.py index ca7b14c17e3..9278c720f29 100644 --- a/pennylane/devices/qubit/simulate.py +++ b/pennylane/devices/qubit/simulate.py @@ -12,7 +12,6 @@ # See the License for the specific language governing permissions and # limitations under the License. """Simulate a quantum script.""" -import inspect import logging # pylint: disable=protected-access diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index f7e43143a15..ea041ee08fb 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -55,7 +55,7 @@ def trace(self, message, *args, **kws): lc.trace = trace -def _configure_logging(config_file: str, config_override: dict = {}): +def _configure_logging(config_file: str, config_override=None): """ This method allows custom logging configuration throughout PennyLane. All configurations are read through the ``log_config.toml`` file, with additional custom options provided through the ``config_override`` dictionary. @@ -70,7 +70,10 @@ def _configure_logging(config_file: str, config_override: dict = {}): ) with open(os.path.join(_path, config_file), "rb") as f: pl_config = tomllib.load(f) - logging.config.dictConfig({**pl_config, **config_override}) + if config_override: + logging.config.dictConfig(pl_config) + else: + logging.config.dictConfig({**pl_config, **config_override}) def enable_logging(config_file: str = "log_config.toml"): @@ -107,6 +110,7 @@ def show_system_config(): """ This function opens the logging configuration file in the system-default browser. """ + # pylint:disable = import-outside-toplevel import webbrowser webbrowser.open(config_path()) @@ -127,12 +131,13 @@ def edit_system_config(wait_on_close=False): p = subprocess.Popen((editor, config_path())) if wait_on_close: # Only valid when editor is known p.wait() - elif (s := platform.system()) in ["Linux", "Darwin"]: + elif s := platform.system() in ["Linux", "Darwin"]: f_cmd = None if s == "Linux": f_cmd = "xdg-open" else: f_cmd = "open" subprocess.Popen((f_cmd, config_path())) - else: # Windows + else: # Windows-only, does not exist on MacOS/Linux + # pylint:disable = no-member os.startfile(config_path()) diff --git a/pennylane/logging/decorators.py b/pennylane/logging/decorators.py index 398df29e157..b5566ca8be7 100644 --- a/pennylane/logging/decorators.py +++ b/pennylane/logging/decorators.py @@ -7,7 +7,7 @@ _debug_log_kwargs = {"stacklevel": 2} -def log_string_debug_func(func, log_level, use_entry, override={}): +def log_string_debug_func(func, log_level, use_entry, override=None): """ This decorator utility generates a string containing the called function, the passed arguments, and the source of the function call. """ @@ -15,7 +15,7 @@ def log_string_debug_func(func, log_level, use_entry, override={}): def _get_bound_signature(*args, **kwargs) -> str: s = inspect.signature(func) - + # pylint:disable = broad-except try: ba = s.bind(*args, **kwargs) except Exception as e: @@ -25,7 +25,7 @@ def _get_bound_signature(*args, **kwargs) -> str: else: raise e ba.apply_defaults() - if len(override): + if override and len(override): for k, v in override.keys(): ba[k] = v @@ -62,22 +62,6 @@ def wrapper_exit(*args, **kwargs): return wrapper_entry if use_entry else wrapper_exit -def log_string_debug_class(cl, log_level): - import types - - lgr = logging.getLogger(cl.__module__) - cl_func = inspect.getmembers(cl, predicate=inspect.isfunction) - f_par_entry = partial(log_string_debug_func, log_level=log_level, use_entry=True) - f_par_exit = partial(log_string_debug_func, log_level=log_level, use_entry=False) - - for f_name, f in cl_func: - if f_name == "__init__": - setattr(cl, f_name, types.MethodType(f_par_exit(f), cl)) - else: - setattr(cl, f_name, types.MethodType(f_par_entry(f), cl)) - return cl - - # For ease-of-use ``debug_logger`` is provided for decoration of public methods and free functions, with ``debug_logger_init`` provided for use with class constructors. debug_logger = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=True) debug_logger_init = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=False) diff --git a/pennylane/logging/formatters/formatter.py b/pennylane/logging/formatters/formatter.py index 8e6056610fe..09daa5e9570 100644 --- a/pennylane/logging/formatters/formatter.py +++ b/pennylane/logging/formatters/formatter.py @@ -135,7 +135,8 @@ class DynamicFormatter(Formatter): use_rgb=True, ) - def _build_formats(self, fmt_str): + @staticmethod + def _build_formats(fmt_str): cmap = DynamicFormatter.cmap local_formats = { logging.DEBUG: build_code_rgb(cmap.debug, cmap.debug_bg) + fmt_str + _ANSI_CODES["end"], diff --git a/pennylane/logging/utils.py b/pennylane/logging/utils.py index 679131d533f..0df28b3ceb1 100644 --- a/pennylane/logging/utils.py +++ b/pennylane/logging/utils.py @@ -1,6 +1,8 @@ import inspect import sys +from .decorators import debug_logger + def _is_local_fn(f, mod_name): """ From 3d1e81c59bca7288af657f05ec47802fe240aa10 Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Wed, 8 May 2024 16:45:46 -0400 Subject: [PATCH 09/48] [WIP] Update PennyLane pipeline logging support (#5534) ### Before submitting Please complete the following checklist when submitting a PR: - [ ] All new features must include a unit test. If you've fixed a bug or added code that should be tested, add a test to the test directory! - [ ] All new functions and code must be clearly commented and documented. If you do make documentation changes, make sure that the docs build and render correctly by running `make docs`. - [ ] Ensure that the test suite passes, by running `make test`. - [ ] Add a new entry to the `doc/releases/changelog-dev.md` file, summarizing the change, and including a link back to the PR. - [ ] The PennyLane source code conforms to [PEP8 standards](https://www.python.org/dev/peps/pep-0008/). We check all of our code against [Pylint](https://www.pylint.org/). To lint modified files, simply `pip install pylint`, and then run `pylint pennylane/path/to/file.py`. When all the above are checked, delete everything above the dashed line and fill in the pull request template. ------------------------------------------------------------------------------------------------------------ **Context:** This PR expands the logging functionality in PennyLane for both internal and inter-library (e.g. Lightning, Catalyst) use. **Description of the Change:** Add support for decorator-defined logging functions, and updates the internal usage of logging with this. **Benefits:** Allows more ease-of-use by developers to include logging with new functionality to the library. **Possible Drawbacks:** Does not replace custom-defined log-level messages and trace-level expansion of functions. **Related GitHub Issues:** https://github.com/PennyLaneAI/pennylane/pull/5528 --- pennylane/devices/default_qubit.py | 22 ++++--- pennylane/devices/qubit/adjoint_jacobian.py | 8 +++ pennylane/devices/qubit/simulate.py | 10 +++ pennylane/logging/__init__.py | 3 +- pennylane/logging/configuration.py | 19 ++++-- pennylane/logging/decorators.py | 67 +++++++++++++++++++++ pennylane/logging/formatters/formatter.py | 5 +- pennylane/logging/log_config.toml | 6 ++ pennylane/logging/utils.py | 24 ++++++++ pennylane/workflow/qnode.py | 9 ++- 10 files changed, 154 insertions(+), 19 deletions(-) create mode 100644 pennylane/logging/decorators.py create mode 100644 pennylane/logging/utils.py diff --git a/pennylane/devices/default_qubit.py b/pennylane/devices/default_qubit.py index d7957424b00..fa4737f3eb1 100644 --- a/pennylane/devices/default_qubit.py +++ b/pennylane/devices/default_qubit.py @@ -16,7 +16,6 @@ """ import concurrent.futures -import inspect import logging from dataclasses import replace from functools import partial @@ -26,6 +25,7 @@ import numpy as np import pennylane as qml +from pennylane.logging import debug_logger, debug_logger_init from pennylane.measurements.mid_measure import MidMeasureMP from pennylane.ops.op_math.condition import Conditional from pennylane.tape import QuantumTape @@ -419,6 +419,7 @@ def reset_prng_key(self): """ # pylint:disable = too-many-arguments + @debug_logger_init def __init__( self, wires=None, @@ -439,6 +440,7 @@ def __init__( self._rng = np.random.default_rng(seed) self._debugger = None + @debug_logger def supports_derivatives( self, execution_config: Optional[ExecutionConfig] = None, @@ -475,6 +477,7 @@ def supports_derivatives( return _supports_adjoint(circuit=circuit) return False + @debug_logger def preprocess( self, execution_config: ExecutionConfig = DefaultExecutionConfig, @@ -566,20 +569,13 @@ def _setup_execution_config(self, execution_config: ExecutionConfig) -> Executio updated_values["device_options"][option] = getattr(self, f"_{option}") return replace(execution_config, **updated_values) + @debug_logger def execute( self, circuits: QuantumTape_or_Batch, execution_config: ExecutionConfig = DefaultExecutionConfig, ) -> Result_or_ResultBatch: self.reset_prng_key() - if logger.isEnabledFor(logging.DEBUG): - logger.debug( - """Entry with args=(circuits=%s) called by=%s""", - circuits, - "::L".join( - str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3] - ), - ) max_workers = execution_config.device_options.get("max_workers", self._max_workers) self._state_cache = {} if execution_config.use_device_jacobian_product else None @@ -618,6 +614,7 @@ def execute( return results + @debug_logger def compute_derivatives( self, circuits: QuantumTape_or_Batch, @@ -637,6 +634,7 @@ def compute_derivatives( return res + @debug_logger def execute_and_compute_derivatives( self, circuits: QuantumTape_or_Batch, @@ -659,6 +657,7 @@ def execute_and_compute_derivatives( return tuple(zip(*results)) + @debug_logger def supports_jvp( self, execution_config: Optional[ExecutionConfig] = None, @@ -678,6 +677,7 @@ def supports_jvp( """ return self.supports_derivatives(execution_config, circuit) + @debug_logger def compute_jvp( self, circuits: QuantumTape_or_Batch, @@ -697,6 +697,7 @@ def compute_jvp( return res + @debug_logger def execute_and_compute_jvp( self, circuits: QuantumTape_or_Batch, @@ -724,6 +725,7 @@ def execute_and_compute_jvp( return tuple(zip(*results)) + @debug_logger def supports_vjp( self, execution_config: Optional[ExecutionConfig] = None, @@ -743,6 +745,7 @@ def supports_vjp( """ return self.supports_derivatives(execution_config, circuit) + @debug_logger def compute_vjp( self, circuits: QuantumTape_or_Batch, @@ -810,6 +813,7 @@ def _state(circuit): return res + @debug_logger def execute_and_compute_vjp( self, circuits: QuantumTape_or_Batch, diff --git a/pennylane/devices/qubit/adjoint_jacobian.py b/pennylane/devices/qubit/adjoint_jacobian.py index d5308e55fb6..7f25cb3a858 100644 --- a/pennylane/devices/qubit/adjoint_jacobian.py +++ b/pennylane/devices/qubit/adjoint_jacobian.py @@ -12,12 +12,14 @@ # See the License for the specific language governing permissions and # limitations under the License. """Functions to apply adjoint jacobian differentiation""" +import logging from numbers import Number from typing import Tuple import numpy as np import pennylane as qml +from pennylane.logging import debug_logger from pennylane.operation import operation_derivative from pennylane.tape import QuantumTape @@ -27,6 +29,9 @@ # pylint: disable=protected-access, too-many-branches +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) + def _dot_product_real(bra, ket, num_wires): """Helper for calculating the inner product for adjoint differentiation.""" @@ -68,6 +73,7 @@ def _adjoint_jacobian_state(tape: QuantumTape): return tuple(jac.flatten() for jac in jacobian) +@debug_logger def adjoint_jacobian(tape: QuantumTape, state=None): """Implements the adjoint method outlined in `Jones and Gacon `__ to differentiate an input tape. @@ -143,6 +149,7 @@ def adjoint_jacobian(tape: QuantumTape, state=None): return tuple(tuple(np.array(j_) for j_ in j) for j in jac) +@debug_logger def adjoint_jvp(tape: QuantumTape, tangents: Tuple[Number], state=None): """The jacobian vector product used in forward mode calculation of derivatives. @@ -316,6 +323,7 @@ def _get_vjp_bras(tape, cotangents, ket): return bras, batch_size, null_batch_indices +@debug_logger def adjoint_vjp(tape: QuantumTape, cotangents: Tuple[Number], state=None): """The vector jacobian product used in reverse-mode differentiation. diff --git a/pennylane/devices/qubit/simulate.py b/pennylane/devices/qubit/simulate.py index 2095aff3d6d..9278c720f29 100644 --- a/pennylane/devices/qubit/simulate.py +++ b/pennylane/devices/qubit/simulate.py @@ -12,6 +12,8 @@ # See the License for the specific language governing permissions and # limitations under the License. """Simulate a quantum script.""" +import logging + # pylint: disable=protected-access from functools import partial from typing import Optional @@ -20,6 +22,7 @@ from numpy.random import default_rng import pennylane as qml +from pennylane.logging import debug_logger from pennylane.measurements import MidMeasureMP from pennylane.typing import Result @@ -28,6 +31,9 @@ from .measure import measure from .sampling import jax_random_split, measure_with_samples +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) + INTERFACE_TO_LIKE = { # map interfaces known by autoray to themselves None: None, @@ -107,6 +113,7 @@ def _postselection_postprocess(state, is_state_batched, shots, rng=None, prng_ke return state, shots +@debug_logger def get_final_state(circuit, debugger=None, **execution_kwargs): """ Get the final state that results from executing the given quantum script. @@ -175,6 +182,7 @@ def get_final_state(circuit, debugger=None, **execution_kwargs): # pylint: disable=too-many-arguments +@debug_logger def measure_final_state(circuit, state, is_state_batched, **execution_kwargs) -> Result: """ Perform the measurements required by the circuit on the provided state. @@ -238,6 +246,7 @@ def measure_final_state(circuit, state, is_state_batched, **execution_kwargs) -> return results +@debug_logger def simulate( circuit: qml.tape.QuantumScript, debugger=None, @@ -292,6 +301,7 @@ def simulate( return measure_final_state(circuit, state, is_state_batched, rng=rng, prng_key=meas_key) +@debug_logger def simulate_one_shot_native_mcm( circuit: qml.tape.QuantumScript, debugger=None, **execution_kwargs ) -> Result: diff --git a/pennylane/logging/__init__.py b/pennylane/logging/__init__.py index d539664de81..f670be47e19 100644 --- a/pennylane/logging/__init__.py +++ b/pennylane/logging/__init__.py @@ -14,6 +14,7 @@ """This module enables support for log-level messaging throughout PennyLane, following the native Python logging framework interface. Please see the :doc:`PennyLane logging development guidelines`, and the official Python documentation for details on usage https://docs.python.org/3/library/logging.html""" from .configuration import TRACE, config_path, edit_system_config, enable_logging -from .decorators import debug_logger +from .decorators import debug_logger, debug_logger_init from .filter import DebugOnlyFilter, LocalProcessFilter from .formatters.formatter import DefaultFormatter, SimpleFormatter +from .utils import _add_logging_all diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index b7979e4192d..ea041ee08fb 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -16,7 +16,9 @@ """ import logging import logging.config -import os, platform, subprocess +import os +import platform +import subprocess from importlib import import_module from importlib.util import find_spec @@ -53,10 +55,10 @@ def trace(self, message, *args, **kws): lc.trace = trace -def _configure_logging(config_file: str, config_override: dict = {}): +def _configure_logging(config_file: str, config_override=None): """ This method allows custom logging configuration throughout PennyLane. - All configurations are read through the ``log_config.toml`` file. + All configurations are read through the ``log_config.toml`` file, with additional custom options provided through the ``config_override`` dictionary. """ if not has_toml: raise ImportError( @@ -68,7 +70,10 @@ def _configure_logging(config_file: str, config_override: dict = {}): ) with open(os.path.join(_path, config_file), "rb") as f: pl_config = tomllib.load(f) - logging.config.dictConfig(pl_config) + if config_override: + logging.config.dictConfig(pl_config) + else: + logging.config.dictConfig({**pl_config, **config_override}) def enable_logging(config_file: str = "log_config.toml"): @@ -105,6 +110,7 @@ def show_system_config(): """ This function opens the logging configuration file in the system-default browser. """ + # pylint:disable = import-outside-toplevel import webbrowser webbrowser.open(config_path()) @@ -125,12 +131,13 @@ def edit_system_config(wait_on_close=False): p = subprocess.Popen((editor, config_path())) if wait_on_close: # Only valid when editor is known p.wait() - elif (s := platform.system()) in ["Linux", "Darwin"]: + elif s := platform.system() in ["Linux", "Darwin"]: f_cmd = None if s == "Linux": f_cmd = "xdg-open" else: f_cmd = "open" subprocess.Popen((f_cmd, config_path())) - else: # Windows + else: # Windows-only, does not exist on MacOS/Linux + # pylint:disable = no-member os.startfile(config_path()) diff --git a/pennylane/logging/decorators.py b/pennylane/logging/decorators.py new file mode 100644 index 00000000000..b5566ca8be7 --- /dev/null +++ b/pennylane/logging/decorators.py @@ -0,0 +1,67 @@ +import inspect +import logging +from functools import partial, wraps + +# Stack level allows moving up the stack with the log records, and prevents +# the decorator function names appearing in the resulting messages. +_debug_log_kwargs = {"stacklevel": 2} + + +def log_string_debug_func(func, log_level, use_entry, override=None): + """ + This decorator utility generates a string containing the called function, the passed arguments, and the source of the function call. + """ + lgr = logging.getLogger(func.__module__) + + def _get_bound_signature(*args, **kwargs) -> str: + s = inspect.signature(func) + # pylint:disable = broad-except + try: + ba = s.bind(*args, **kwargs) + except Exception as e: + # If kwargs are concat onto args, attempt to unpack. Fail otherwise + if len(args) == 2 and len(kwargs) == 0 and isinstance(args[1], dict): + ba = s.bind(*args[0], **args[1]) + else: + raise e + ba.apply_defaults() + if override and len(override): + for k, v in override.keys(): + ba[k] = v + + f_string = str(ba).replace("BoundArguments ", func.__name__) + return f_string + + @wraps(func) + def wrapper_entry(*args, **kwargs): + if lgr.isEnabledFor(log_level): # pragma: no cover + f_string = _get_bound_signature(*args, **kwargs) + s_caller = "::L".join( + [str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3]] + ) + lgr.debug( + f"Calling {f_string} from {s_caller}", + **_debug_log_kwargs, + ) + return func(*args, **kwargs) + + @wraps(func) + def wrapper_exit(*args, **kwargs): + output = func(*args, **kwargs) + if lgr.isEnabledFor(log_level): # pragma: no cover + f_string = _get_bound_signature(*args, **kwargs) + s_caller = "::L".join( + [str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3]] + ) + lgr.debug( + f"Calling {f_string}={output} from {s_caller}", + **{"stacklevel": 2}, + ) + return output + + return wrapper_entry if use_entry else wrapper_exit + + +# For ease-of-use ``debug_logger`` is provided for decoration of public methods and free functions, with ``debug_logger_init`` provided for use with class constructors. +debug_logger = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=True) +debug_logger_init = partial(log_string_debug_func, log_level=logging.DEBUG, use_entry=False) diff --git a/pennylane/logging/formatters/formatter.py b/pennylane/logging/formatters/formatter.py index f46e052973f..09daa5e9570 100644 --- a/pennylane/logging/formatters/formatter.py +++ b/pennylane/logging/formatters/formatter.py @@ -78,7 +78,7 @@ def bash_ansi_codes(): class DefaultFormatter(Formatter): """This formatter has the default rules used for formatting PennyLane log messages.""" - fmt_str = '[%(asctime)s][%(levelname)s][] - %(name)s.%(funcName)s()::"%(message)s"' + fmt_str = '[%(asctime)s][%(levelname)s][] - %(name)s.%(funcName)s::"%(message)s"\n' # 0x000000 Background _text_bg = (0, 0, 0) @@ -135,7 +135,8 @@ class DynamicFormatter(Formatter): use_rgb=True, ) - def _build_formats(self, fmt_str): + @staticmethod + def _build_formats(fmt_str): cmap = DynamicFormatter.cmap local_formats = { logging.DEBUG: build_code_rgb(cmap.debug, cmap.debug_bg) + fmt_str + _ANSI_CODES["end"], diff --git a/pennylane/logging/log_config.toml b/pennylane/logging/log_config.toml index 1199fd41db4..75e6b3310de 100644 --- a/pennylane/logging/log_config.toml +++ b/pennylane/logging/log_config.toml @@ -120,4 +120,10 @@ handlers = ["qml_debug_stream",] level = "DEBUG" # Set to TRACE for highest verbosity propagate = false +# Control logging across catalyst +[loggers.catalyst] +handlers = ["qml_debug_stream",] +level = "DEBUG" # Set to TRACE for highest verbosity +propagate = false + ############################################################################### diff --git a/pennylane/logging/utils.py b/pennylane/logging/utils.py new file mode 100644 index 00000000000..0df28b3ceb1 --- /dev/null +++ b/pennylane/logging/utils.py @@ -0,0 +1,24 @@ +import inspect +import sys + +from .decorators import debug_logger + + +def _is_local_fn(f, mod_name): + """ + Predicate that validates if argument `f` is a local module `mod_name`. + """ + is_func = inspect.isfunction(f) + is_local_to_mod = inspect.getmodule(f).__name__ == mod_name + return is_func and is_local_to_mod + + +def _add_logging_all(mod_name): + """ + Modifies the module to add logging implicitly to all free-functions. + """ + l_func = inspect.getmembers( + sys.modules[mod_name], predicate=lambda x: _is_local_fn(x, mod_name) + ) + for f_name, f in l_func: + globals()[f_name] = debug_logger(f) diff --git a/pennylane/workflow/qnode.py b/pennylane/workflow/qnode.py index 513abd88e83..57d6e89c28b 100644 --- a/pennylane/workflow/qnode.py +++ b/pennylane/workflow/qnode.py @@ -25,6 +25,7 @@ import pennylane as qml from pennylane import Device +from pennylane.logging import debug_logger from pennylane.measurements import CountsMP, MidMeasureMP, Shots from pennylane.tape import QuantumScript, QuantumTape @@ -577,6 +578,7 @@ def transform_program(self): """The transform program used by the QNode.""" return self._transform_program + @debug_logger def add_transform(self, transform_container): """Add a transform (container) to the transform program. @@ -601,7 +603,7 @@ def _update_gradient_fn(self, shots=None, tape=None): ): diff_method = "parameter-shift" - self.gradient_fn, self.gradient_kwargs, self.device = self.get_gradient_fn( + self.gradient_fn, self.gradient_kwargs, self.device = QNode.get_gradient_fn( self._original_device, self.interface, diff_method, tape=tape ) self.gradient_kwargs.update(self._user_gradient_kwargs or {}) @@ -625,6 +627,7 @@ def _update_original_device(self): # pylint: disable=too-many-return-statements @staticmethod + @debug_logger def get_gradient_fn( device, interface, diff_method="best", tape: Optional["qml.tape.QuantumTape"] = None ): @@ -696,6 +699,7 @@ def get_gradient_fn( ) @staticmethod + @debug_logger def get_best_method(device, interface, tape=None): """Returns the 'best' differentiation method for a particular device and interface combination. @@ -742,6 +746,7 @@ def get_best_method(device, interface, tape=None): return qml.gradients.finite_diff, {}, device @staticmethod + @debug_logger def best_method_str(device, interface): """Similar to :meth:`~.get_best_method`, except return the 'best' differentiation method in human-readable format. @@ -780,6 +785,7 @@ def best_method_str(device, interface): return transform @staticmethod + @debug_logger def _validate_backprop_method(device, interface, tape=None): if isinstance(device, qml.devices.Device): raise ValueError( @@ -912,6 +918,7 @@ def tape(self) -> QuantumTape: qtape = tape # for backwards compatibility + @debug_logger def construct(self, args, kwargs): # pylint: disable=too-many-branches """Call the quantum function with a tape context, ensuring the operations get queued.""" kwargs = copy.copy(kwargs) From e0ae2b55ac2ff47d41ecbea18a07cf96eeba156c Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 17:25:54 -0400 Subject: [PATCH 10/48] Listen to codefactor --- pennylane/logging/configuration.py | 6 +++--- pennylane/logging/decorators.py | 15 +++++++++++++++ pennylane/logging/utils.py | 14 ++++++++++++++ 3 files changed, 32 insertions(+), 3 deletions(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index ea041ee08fb..a1df176f886 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -128,9 +128,9 @@ def edit_system_config(wait_on_close=False): instead open this file manually with the `config_path()` provided path. """ if editor := os.getenv("EDITOR"): - p = subprocess.Popen((editor, config_path())) - if wait_on_close: # Only valid when editor is known - p.wait() + with subprocess.Popen((editor, config_path())) as p: + if wait_on_close: # Only valid when editor is known + p.wait() elif s := platform.system() in ["Linux", "Darwin"]: f_cmd = None if s == "Linux": diff --git a/pennylane/logging/decorators.py b/pennylane/logging/decorators.py index b5566ca8be7..66a9a104efa 100644 --- a/pennylane/logging/decorators.py +++ b/pennylane/logging/decorators.py @@ -1,3 +1,18 @@ +# Copyright 2018-2024 Xanadu Quantum Technologies Inc. + +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at + +# http://www.apache.org/licenses/LICENSE-2.0 + +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +"""This file expands the PennyLane logging functionality to allow additions for function entry and exit logging via decorators.""" + import inspect import logging from functools import partial, wraps diff --git a/pennylane/logging/utils.py b/pennylane/logging/utils.py index 0df28b3ceb1..ff30de585ba 100644 --- a/pennylane/logging/utils.py +++ b/pennylane/logging/utils.py @@ -1,3 +1,17 @@ +# Copyright 2018-2024 Xanadu Quantum Technologies Inc. + +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at + +# http://www.apache.org/licenses/LICENSE-2.0 + +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +"""This file provides developer-facing functionality for the PennyLane logging module.""" import inspect import sys From 42ee75f4554a29b2ab71aecbcbc32d6f96be0d46 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 17:27:43 -0400 Subject: [PATCH 11/48] Ensure Windows function doesn't warn on *nix --- pennylane/logging/configuration.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index a1df176f886..938d3f5067c 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -139,5 +139,4 @@ def edit_system_config(wait_on_close=False): f_cmd = "open" subprocess.Popen((f_cmd, config_path())) else: # Windows-only, does not exist on MacOS/Linux - # pylint:disable = no-member - os.startfile(config_path()) + os.startfile(config_path()) # pylint:disable = no-member From fb64c3d2ab2ff50b475354bfff8c06e79189e707 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 8 May 2024 17:32:13 -0400 Subject: [PATCH 12/48] Disable extraneous warning --- pennylane/logging/configuration.py | 1 + 1 file changed, 1 insertion(+) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 938d3f5067c..f7291ba3e6e 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -128,6 +128,7 @@ def edit_system_config(wait_on_close=False): instead open this file manually with the `config_path()` provided path. """ if editor := os.getenv("EDITOR"): + # pylint:disable = consider-using-with with subprocess.Popen((editor, config_path())) as p: if wait_on_close: # Only valid when editor is known p.wait() From 447782be6f0607b1b260298016e86c7b8357994d Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Fri, 17 May 2024 10:11:26 -0400 Subject: [PATCH 13/48] Apply suggestions from code review Co-authored-by: Mudit Pandey --- pennylane/logging/configuration.py | 8 +++++--- pennylane/logging/utils.py | 4 ++-- 2 files changed, 7 insertions(+), 5 deletions(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index f7291ba3e6e..c7829e3f00a 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -70,7 +70,7 @@ def _configure_logging(config_file: str, config_override=None): ) with open(os.path.join(_path, config_file), "rb") as f: pl_config = tomllib.load(f) - if config_override: + if not config_override: logging.config.dictConfig(pl_config) else: logging.config.dictConfig({**pl_config, **config_override}) @@ -124,8 +124,10 @@ def edit_system_config(wait_on_close=False): Linux and MacOS, and allows use of `wait_on_close` for editor close before continuing execution. - Warning: As each OS configuration differs user-to-user, you may wish to - instead open this file manually with the `config_path()` provided path. + .. warning:: + + As each OS configuration differs user-to-user, you may wish to + instead open this file manually with the `config_path()` provided path. """ if editor := os.getenv("EDITOR"): # pylint:disable = consider-using-with diff --git a/pennylane/logging/utils.py b/pennylane/logging/utils.py index ff30de585ba..e8da7b0b117 100644 --- a/pennylane/logging/utils.py +++ b/pennylane/logging/utils.py @@ -20,7 +20,7 @@ def _is_local_fn(f, mod_name): """ - Predicate that validates if argument `f` is a local module `mod_name`. + Predicate that validates if argument ``f`` is a local function belonging to module ``mod_name``. """ is_func = inspect.isfunction(f) is_local_to_mod = inspect.getmodule(f).__name__ == mod_name @@ -29,7 +29,7 @@ def _is_local_fn(f, mod_name): def _add_logging_all(mod_name): """ - Modifies the module to add logging implicitly to all free-functions. + Modifies the module ``mod_name`` to add logging implicitly to all free-functions. """ l_func = inspect.getmembers( sys.modules[mod_name], predicate=lambda x: _is_local_fn(x, mod_name) From 1c46ff18d439c6d979342849c8d3aab2cf8bbd52 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 17 May 2024 11:25:46 -0400 Subject: [PATCH 14/48] Update logging tests for new structure --- pennylane/logging/log_config.toml | 6 ---- tests/logging/test_logging_autograd.py | 50 ++++++++++++++++++++------ 2 files changed, 39 insertions(+), 17 deletions(-) diff --git a/pennylane/logging/log_config.toml b/pennylane/logging/log_config.toml index 75e6b3310de..dc8fcec97f2 100644 --- a/pennylane/logging/log_config.toml +++ b/pennylane/logging/log_config.toml @@ -107,12 +107,6 @@ handlers = ["qml_debug_stream",] level = "DEBUG" # Set to TRACE for highest verbosity propagate = false -# Control logging across catalyst -[loggers.catalyst] -handlers = ["qml_debug_stream",] -level = "TRACE" # Set to TRACE for highest verbosity -propagate = false - # Control logging specifically in the pennylane.qnode module # Note the required quotes to overcome TOML nesting issues [loggers."pennylane.qnode"] diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 221b13c19d1..21cd809e797 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -31,7 +31,7 @@ def enable_and_configure_logging(): pl_logging.enable_logging() pl_logger = logging.root.manager.loggerDict["pennylane"] - plqn_logger = logging.root.manager.loggerDict["pennylane.qnode"] + plqn_logger = logging.root.manager.loggerDict["pennylane.workflow.qnode"] # Ensure logs messages are propagated for pytest capture pl_logger.propagate = True @@ -42,12 +42,24 @@ def enable_and_configure_logging(): class TestLogging: """Tests for logging integration""" + def test_qd_dev_creation(self, caplog): + "Test logging of device creation" + + enable_and_configure_logging() + caplog.set_level(logging.DEBUG, logger="pennylane.devices.default_qubit") + + with caplog.at_level(logging.DEBUG): + dev = qml.device("default.qubit", wires=2) + + assert len(caplog.records) == 1 + assert "Calling <__init__(self= Date: Fri, 17 May 2024 11:34:08 -0400 Subject: [PATCH 15/48] Update according to reviews --- pennylane/logging/configuration.py | 11 ++++++++++- pennylane/logging/formatters/__init__.py | 2 +- 2 files changed, 11 insertions(+), 2 deletions(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index c7829e3f00a..d46c90fb50e 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -21,6 +21,7 @@ import subprocess from importlib import import_module from importlib.util import find_spec +from typing import Optional has_toml = False toml_libs = ["tomllib", "tomli", "tomlkit"] @@ -55,10 +56,15 @@ def trace(self, message, *args, **kws): lc.trace = trace -def _configure_logging(config_file: str, config_override=None): +def _configure_logging(config_file: str, config_override: Optional[dict] = None): """ This method allows custom logging configuration throughout PennyLane. All configurations are read through the ``log_config.toml`` file, with additional custom options provided through the ``config_override`` dictionary. + + Args: + config_file (str): The path to a given log configuration file, parsed as TOML and adhering to the ``logging.config.dictConfig`` end-point. + + config_override (Optional[dict]): A dictionary with keys-values that override the default configuration options in the given ``config_file`` TOML. """ if not has_toml: raise ImportError( @@ -82,6 +88,9 @@ def enable_logging(config_file: str = "log_config.toml"): Enabling logging through this method will override any externally defined logging configurations. + Args: + config_file (str): The path to a given log configuration file, parsed as TOML and adhering to the ``logging.config.dictConfig`` end-point. The default argument uses the PennyLane ecosystem log-file configuration. + **Example** >>> qml.logging.enable_logging() diff --git a/pennylane/logging/formatters/__init__.py b/pennylane/logging/formatters/__init__.py index 33297d98677..ed35942b601 100644 --- a/pennylane/logging/formatters/__init__.py +++ b/pennylane/logging/formatters/__init__.py @@ -12,4 +12,4 @@ # See the License for the specific language governing permissions and # limitations under the License. """This module defines formatting rules for the PennyLane loggers.""" -from .formatter import DefaultFormatter, SimpleFormatter +from .formatter import DefaultFormatter, DynamicFormatter, SimpleFormatter From cccc436a7ae2ab4f5f6da5931688dd846078af33 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 17 May 2024 11:49:28 -0400 Subject: [PATCH 16/48] Update logging docs --- doc/development/guide/logging.rst | 26 ++++++++++++++++++++------ doc/introduction/logging.rst | 3 +++ 2 files changed, 23 insertions(+), 6 deletions(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index 609107860a4..5003c5a3f1e 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -29,8 +29,21 @@ To add logging support to components of PennyLane, we must define a module logge which will be used within the given module, and track directories, filenames and function names, as we have defined the appropriate types -within the formatter configuration (see :class:`pennylane.logging.DefaultFormatter`). With the logger defined, we can selectively add to the logger by if-else statements, which compare the given module’s log-level to any log record -message it receives. This step is not necessary, as the message will +within the formatter configuration (see :class:`pennylane.logging.DefaultFormatter`). With the logger defined, we can selectively add to the logger via two methods: + +i) using decorators on the required functions and methods in a given module: + +.. code:: python + + # debug_logger can be used to decorate and method or free function + # debug_logger_init can be used to decorate class __init__ methods. + from pennylane.logging import debug_logger, debug_logger_init + + @debug_logger + def my_func(arg1, arg2): + return arg1 + arg2 + +ii) explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will only output if the level is enabled, though if an expensive function call is required to build the string for the log-message, it can be faster to perform this check: @@ -43,10 +56,9 @@ faster to perform this check: arg_name_1, arg_name_2, ..., arg_name_n, ) -The above line can be added below the function/method entry point, -and the provided arguments can be used to populate the log message. This -allows us a way to track the inputs and calls through the stack in the -order they are executed, as is the basis for following a trail of +Both versions provide similar functionality, though the explicit logger call allows more custom message-formatting, such as expanding functions as string representation, filtering of data, and other useful processing for a valid record. + +These logging options allow us a way to track the inputs and calls through the stack in the order they are executed, as is the basis for following a trail of execution as needed. All debug log-statements currently added to the PennyLane execution @@ -82,6 +94,8 @@ messages based on some criteria, we can add these to the respective handlers. As an example, we can go through the configuration file and explore the options. +For ease-of-development, the function :func:`qml.logging.edit_system_config` opens an editor (if the ``EDITOR`` environment variable is set), or a viewer of the existing file configuration, which can be used to modify the existing options. + Modifying the configuration options ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ diff --git a/doc/introduction/logging.rst b/doc/introduction/logging.rst index fb46f5cb4b2..1665d53bb43 100644 --- a/doc/introduction/logging.rst +++ b/doc/introduction/logging.rst @@ -29,4 +29,7 @@ outputs to the default configured handler, which is directed to the standard out level = "DEBUG" # Set to TRACE for highest verbosity propagate = false + +Viewing the existing logging configuration file is possible by calling the :func:`pennylane.logging.edit_system_config` functionm which will open the file in an existing browser or editor window. + For more info on the customization of the logging options, please see the logging development guide at :doc:`/development/guide/logging`, and the `Python logging documentation `_. From 50b764d229b5d6d2a820bbc58fddd492442b5895 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 17 May 2024 11:50:23 -0400 Subject: [PATCH 17/48] Remove unused variable --- tests/logging/test_logging_autograd.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 21cd809e797..a1d3a79155f 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -49,7 +49,7 @@ def test_qd_dev_creation(self, caplog): caplog.set_level(logging.DEBUG, logger="pennylane.devices.default_qubit") with caplog.at_level(logging.DEBUG): - dev = qml.device("default.qubit", wires=2) + qml.device("default.qubit", wires=2) assert len(caplog.records) == 1 assert "Calling <__init__(self= Date: Fri, 17 May 2024 14:33:28 -0400 Subject: [PATCH 18/48] Spellcheck --- doc/introduction/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/introduction/logging.rst b/doc/introduction/logging.rst index 1665d53bb43..a8bf0281992 100644 --- a/doc/introduction/logging.rst +++ b/doc/introduction/logging.rst @@ -30,6 +30,6 @@ outputs to the default configured handler, which is directed to the standard out propagate = false -Viewing the existing logging configuration file is possible by calling the :func:`pennylane.logging.edit_system_config` functionm which will open the file in an existing browser or editor window. +Viewing the existing logging configuration file is possible by calling the :func:`pennylane.logging.edit_system_config` function which will open the file in an existing browser or editor window. For more info on the customization of the logging options, please see the logging development guide at :doc:`/development/guide/logging`, and the `Python logging documentation `_. From 3e7ca345046077a92d4160abeaa516a794eec368 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 17 May 2024 15:40:42 -0400 Subject: [PATCH 19/48] Be more explicit about logging levels in tests --- tests/logging/test_logging_autograd.py | 106 ++++++++++++++++--------- 1 file changed, 68 insertions(+), 38 deletions(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index a1d3a79155f..5c40212af7d 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -13,6 +13,7 @@ # limitations under the License. """Unit tests for the the logging module""" # pylint: disable=import-outside-toplevel, protected-access, no-member +import contextlib import logging import pytest @@ -27,6 +28,28 @@ } +@contextlib.contextmanager +def set_log_level(caplog, modules, levels): + pl_logging.enable_logging() + + pl_logger = logging.root.manager.loggerDict["pennylane"] + plqn_logger = logging.root.manager.loggerDict["pennylane.workflow.qnode"] + + # Ensure logs messages are propagated for pytest capture + pl_logger.propagate = True + plqn_logger.propagate = True + + for l, m in zip(levels, modules): + caplog.set_level(l, logger=m) + yield + modules + ["pennylane", "pennylane.workflow.qnode"] + for m in modules: + caplog.set_level(logging.INFO, logger=m) + + pl_logger.propagate = False + plqn_logger.propagate = False + + def enable_and_configure_logging(): pl_logging.enable_logging() @@ -45,11 +68,10 @@ class TestLogging: def test_qd_dev_creation(self, caplog): "Test logging of device creation" - enable_and_configure_logging() - caplog.set_level(logging.DEBUG, logger="pennylane.devices.default_qubit") - - with caplog.at_level(logging.DEBUG): - qml.device("default.qubit", wires=2) + # enable_and_configure_logging() + with set_log_level(caplog, ["pennylane.devices.default_qubit"], [logging.DEBUG]): + with caplog.at_level(logging.DEBUG): + qml.device("default.qubit", wires=2) assert len(caplog.records) == 1 assert "Calling <__init__(self= Date: Fri, 17 May 2024 16:28:41 -0400 Subject: [PATCH 20/48] Forbid pointless warning --- tests/logging/test_logging_autograd.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 5c40212af7d..0dfe5774ff3 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -41,7 +41,7 @@ def set_log_level(caplog, modules, levels): for l, m in zip(levels, modules): caplog.set_level(l, logger=m) - yield + yield # pylint: disable=pointless-statement modules + ["pennylane", "pennylane.workflow.qnode"] for m in modules: caplog.set_level(logging.INFO, logger=m) From e8118913db4745c66a7d192e4394d5a8983f3417 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 17 May 2024 17:08:11 -0400 Subject: [PATCH 21/48] Silence Pylints verbose complaint --- tests/logging/test_logging_autograd.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 0dfe5774ff3..c9ab06fafa3 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -27,7 +27,7 @@ "parameter-shift": "gradient_fn=", } - +# pylint: disable=pointless-statement @contextlib.contextmanager def set_log_level(caplog, modules, levels): pl_logging.enable_logging() @@ -41,7 +41,7 @@ def set_log_level(caplog, modules, levels): for l, m in zip(levels, modules): caplog.set_level(l, logger=m) - yield # pylint: disable=pointless-statement + yield modules + ["pennylane", "pennylane.workflow.qnode"] for m in modules: caplog.set_level(logging.INFO, logger=m) From a638f36c66309d484f8982e63420f4829ebeb952 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 17 May 2024 17:08:27 -0400 Subject: [PATCH 22/48] Silence Pylints verbose complaint +1 --- tests/logging/test_logging_autograd.py | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index c9ab06fafa3..a31f4bf5cdd 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -27,6 +27,7 @@ "parameter-shift": "gradient_fn=", } + # pylint: disable=pointless-statement @contextlib.contextmanager def set_log_level(caplog, modules, levels): From 9507454deec6f300c134dd27d88c561adf06055f Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Thu, 23 May 2024 11:21:15 -0400 Subject: [PATCH 23/48] Update doc/development/guide/logging.rst Co-authored-by: Mudit Pandey --- doc/development/guide/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index 5003c5a3f1e..b97e527d95c 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -35,7 +35,7 @@ i) using decorators on the required functions and methods in a given module: .. code:: python - # debug_logger can be used to decorate and method or free function + # debug_logger can be used to decorate any method or free function # debug_logger_init can be used to decorate class __init__ methods. from pennylane.logging import debug_logger, debug_logger_init From c45f765af980c53f6b8957bf8af10861cc5e22c7 Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Thu, 23 May 2024 11:21:29 -0400 Subject: [PATCH 24/48] Update doc/development/guide/logging.rst Co-authored-by: Mudit Pandey --- doc/development/guide/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index b97e527d95c..4ea7cfae68a 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -94,7 +94,7 @@ messages based on some criteria, we can add these to the respective handlers. As an example, we can go through the configuration file and explore the options. -For ease-of-development, the function :func:`qml.logging.edit_system_config` opens an editor (if the ``EDITOR`` environment variable is set), or a viewer of the existing file configuration, which can be used to modify the existing options. +For ease-of-development, the function :func:`pennylane.logging.edit_system_config` opens an editor (if the ``EDITOR`` environment variable is set), or a viewer of the existing file configuration, which can be used to modify the existing options. Modifying the configuration options ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ From b8c9a23f8a8a474fd63f7bff3212aefcd1e6e17a Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Thu, 23 May 2024 15:40:53 -0400 Subject: [PATCH 25/48] Indent and enumerate sphinx list --- doc/development/guide/logging.rst | 36 +++++++++++++++---------------- 1 file changed, 18 insertions(+), 18 deletions(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index 4ea7cfae68a..a0201b8ef52 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -31,30 +31,30 @@ which will be used within the given module, and track directories, filenames and function names, as we have defined the appropriate types within the formatter configuration (see :class:`pennylane.logging.DefaultFormatter`). With the logger defined, we can selectively add to the logger via two methods: -i) using decorators on the required functions and methods in a given module: + #. using decorators on the required functions and methods in a given module: -.. code:: python + .. code:: python - # debug_logger can be used to decorate any method or free function - # debug_logger_init can be used to decorate class __init__ methods. - from pennylane.logging import debug_logger, debug_logger_init + # debug_logger can be used to decorate any method or free function + # debug_logger_init can be used to decorate class __init__ methods. + from pennylane.logging import debug_logger, debug_logger_init - @debug_logger - def my_func(arg1, arg2): - return arg1 + arg2 + @debug_logger + def my_func(arg1, arg2): + return arg1 + arg2 -ii) explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will -only output if the level is enabled, though if an expensive function -call is required to build the string for the log-message, it can be -faster to perform this check: + #. explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will + only output if the level is enabled, though if an expensive function + call is required to build the string for the log-message, it can be + faster to perform this check: -.. code:: python + .. code:: python - if logger.isEnabledFor(logging.DEBUG): - logger.debug( - """Entry with args=(arg_name_1=%s, arg_name_2=%s, ..., arg_name_n=%s)""", - arg_name_1, arg_name_2, ..., arg_name_n, - ) + if logger.isEnabledFor(logging.DEBUG): + logger.debug( + """Entry with args=(arg_name_1=%s, arg_name_2=%s, ..., arg_name_n=%s)""", + arg_name_1, arg_name_2, ..., arg_name_n, + ) Both versions provide similar functionality, though the explicit logger call allows more custom message-formatting, such as expanding functions as string representation, filtering of data, and other useful processing for a valid record. From c1f5b9a018b8a1004c0ade67aeffb9f9b3662243 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Thu, 23 May 2024 16:24:29 -0400 Subject: [PATCH 26/48] Fix indentation issue --- doc/development/guide/logging.rst | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index a0201b8ef52..28da014ba2f 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -31,7 +31,7 @@ which will be used within the given module, and track directories, filenames and function names, as we have defined the appropriate types within the formatter configuration (see :class:`pennylane.logging.DefaultFormatter`). With the logger defined, we can selectively add to the logger via two methods: - #. using decorators on the required functions and methods in a given module: +#. using decorators on the required functions and methods in a given module: .. code:: python @@ -43,7 +43,7 @@ within the formatter configuration (see :class:`pennylane.logging.DefaultFormatt def my_func(arg1, arg2): return arg1 + arg2 - #. explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will +#. explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will only output if the level is enabled, though if an expensive function call is required to build the string for the log-message, it can be faster to perform this check: From 1c36a2b2477f204748fc38309d0eb247f0b9f031 Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Fri, 24 May 2024 09:27:46 -0400 Subject: [PATCH 27/48] Update tests/logging/test_logging_autograd.py --- tests/logging/test_logging_autograd.py | 1 - 1 file changed, 1 deletion(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index a31f4bf5cdd..8b99cd12028 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -146,7 +146,6 @@ def circuit(params): def test_dq_qnode_execution_grad(self, caplog, diff_method, num_records): "Test logging of QNode with parameterised gradients" - # enable_and_configure_logging() # Set specific log-levels for validation # enable_and_configure_logging() From bac25c56ff1a640b69c4d0dbc72f926147c76bee Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Fri, 24 May 2024 09:27:52 -0400 Subject: [PATCH 28/48] Update tests/logging/test_logging_autograd.py --- tests/logging/test_logging_autograd.py | 1 - 1 file changed, 1 deletion(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 8b99cd12028..1b13291da5a 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -148,7 +148,6 @@ def test_dq_qnode_execution_grad(self, caplog, diff_method, num_records): # Set specific log-levels for validation - # enable_and_configure_logging() caplog.set_level(logging.INFO, logger="pennylane") caplog.set_level(logging.DEBUG, logger="pennylane.workflow") caplog.set_level(logging.DEBUG, logger="pennylane.devices") From 131b5e922baa292dd71983a46e407245a6b7c116 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 24 May 2024 12:09:27 -0400 Subject: [PATCH 29/48] Add context-manager around test logging --- tests/conftest.py | 32 +++++++++++++ .../test_qutrit_mixed_tracking.py | 33 +++++++------- tests/logging/test_logging_autograd.py | 45 ++----------------- 3 files changed, 52 insertions(+), 58 deletions(-) diff --git a/tests/conftest.py b/tests/conftest.py index 3a9986ad4c6..9d0fe08a5d4 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -15,6 +15,8 @@ Pytest configuration file for PennyLane test suite. """ # pylint: disable=unused-import +import contextlib +import logging import os import pathlib @@ -22,6 +24,7 @@ import pytest import pennylane as qml +import pennylane.logging as pl_logging from pennylane.devices import DefaultGaussian from pennylane.operation import disable_new_opmath_cm, enable_new_opmath_cm @@ -325,3 +328,32 @@ def pytest_runtest_setup(item): pytest.skip( f"\nTest {item.nodeid} only runs with {allowed_interfaces} interfaces(s) but {b} interface provided", ) + + +# pylint: disable=pointless-statement +@pytest.fixture(scope="function") +def set_log_level(): + "Add log-level context-managing fixture to avoid log-levels propagating outside of tests" + + @contextlib.contextmanager + def log_level_fixture(caplog, mod, levels): + try: + pl_logging.enable_logging() + pl_logger = logging.root.manager.loggerDict["pennylane"] + + # Ensure logs messages are propagated for pytest capture + pl_logger.propagate = True + + for l, m in zip(levels, mod): + caplog.set_level(l, logger=m) + yield + except Exception: # pylint: disable=broad-except + raise + finally: + mod + ["pennylane"] + for m in mod: + caplog.set_level(logging.INFO, logger=m) + + pl_logger.propagate = False + + return log_level_fixture diff --git a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py index 8312e5d0fef..c2dcd5e4a33 100644 --- a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py +++ b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py @@ -225,28 +225,23 @@ def test_multiple_expval_with_prods(self): @pytest.mark.logging -def test_execution_debugging(caplog): +def test_execution_debugging(caplog, set_log_level): """Test logging of QNode forward pass from default qutrit mixed.""" - qml.logging.enable_logging() + # Set outer log-level to ensure messages are produced from external paths + with set_log_level(caplog, ["pennylane.workflow.qnode"], [logging.DEBUG]): - pl_logger = logging.root.manager.loggerDict["pennylane"] - plqn_logger = logging.root.manager.loggerDict["pennylane.qnode"] + # Set inner level to log local details + with caplog.at_level(logging.DEBUG): + dev = qml.device("default.qutrit.mixed", wires=2) + params = qml.numpy.array(0.1234) - # Ensure logs messages are propagated for pytest capture - pl_logger.propagate = True - plqn_logger.propagate = True + @qml.qnode(dev, diff_method=None) + def circuit(params): + qml.TRX(params, wires=0) + return qml.expval(qml.GellMann(0, 3)) - with caplog.at_level(logging.DEBUG): - dev = qml.device("default.qutrit.mixed", wires=2) - params = qml.numpy.array(0.1234) - - @qml.qnode(dev, diff_method=None) - def circuit(params): - qml.TRX(params, wires=0) - return qml.expval(qml.GellMann(0, 3)) - - circuit(params) + circuit(params) assert len(caplog.records) == 3 @@ -255,6 +250,10 @@ def circuit(params): "pennylane.workflow.qnode", ["Creating QNode(func= Date: Fri, 24 May 2024 15:14:13 -0400 Subject: [PATCH 30/48] Update log rule context manager --- tests/conftest.py | 4 +- .../test_qutrit_mixed_tracking.py | 1 + tests/logging/test_logging_autograd.py | 44 +++++++++---------- 3 files changed, 26 insertions(+), 23 deletions(-) diff --git a/tests/conftest.py b/tests/conftest.py index 9d0fe08a5d4..5602e0e5fd3 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -347,10 +347,12 @@ def log_level_fixture(caplog, mod, levels): for l, m in zip(levels, mod): caplog.set_level(l, logger=m) yield + except Exception: # pylint: disable=broad-except raise + finally: - mod + ["pennylane"] + mod + ["pennylane", "pennylane.qnode", "catalyst"] for m in mod: caplog.set_level(logging.INFO, logger=m) diff --git a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py index c2dcd5e4a33..1b97d395dec 100644 --- a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py +++ b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py @@ -229,6 +229,7 @@ def test_execution_debugging(caplog, set_log_level): """Test logging of QNode forward pass from default qutrit mixed.""" # Set outer log-level to ensure messages are produced from external paths + # and appropriately disabled upon exit with set_log_level(caplog, ["pennylane.workflow.qnode"], [logging.DEBUG]): # Set inner level to log local details diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 286f620033a..724bd97f1cd 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -81,28 +81,28 @@ def circuit(params): return qml.expval(qml.PauliZ(0)) circuit(params) - assert len(caplog.records) == 3 - log_records_expected = [ - ( - "pennylane.workflow.qnode", - ["Creating QNode(func= Date: Fri, 24 May 2024 17:49:49 -0400 Subject: [PATCH 31/48] Update config --- tests/conftest.py | 2 +- tests/logging/test_logging_autograd.py | 2 -- 2 files changed, 1 insertion(+), 3 deletions(-) diff --git a/tests/conftest.py b/tests/conftest.py index 5602e0e5fd3..f0ba5d85d7e 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -354,7 +354,7 @@ def log_level_fixture(caplog, mod, levels): finally: mod + ["pennylane", "pennylane.qnode", "catalyst"] for m in mod: - caplog.set_level(logging.INFO, logger=m) + caplog.set_level(logging.NOTSET, logger=m) pl_logger.propagate = False diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 724bd97f1cd..a73272dfa92 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -69,7 +69,6 @@ def test_dq_qnode_execution(self, caplog, set_log_level): ["pennylane", "pennylane.workflow.execution", "pennylane.workflow.qnode"], [logging.INFO, logging.DEBUG, logging.DEBUG], ): - dev = qml.device("default.qubit", wires=2) with caplog.at_level(logging.DEBUG): @@ -120,7 +119,6 @@ def test_dq_qnode_execution_grad(self, caplog, diff_method, num_records, set_log ["pennylane", "pennylane.workflow", "pennylane.devices"], [logging.INFO, logging.DEBUG, logging.DEBUG], ): - with caplog.at_level(logging.INFO): dev = qml.device("default.qubit", wires=2) params = qml.numpy.array(0.1234) From a9b714e494f8fa7681b2dad69fd063821a8c9d3c Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Fri, 24 May 2024 18:05:53 -0400 Subject: [PATCH 32/48] Explicit remove all loggers from test config after run --- tests/conftest.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/tests/conftest.py b/tests/conftest.py index f0ba5d85d7e..09cac1daf13 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -352,7 +352,12 @@ def log_level_fixture(caplog, mod, levels): raise finally: - mod + ["pennylane", "pennylane.qnode", "catalyst"] + filter_loggers = ["pennylane", "catalyst"] + mod += [ + lgr + for (lgr, _) in logging.root.manager.loggerDict.items() + if any(filt_lgr in lgr for filt_lgr in filter_loggers) + ] for m in mod: caplog.set_level(logging.NOTSET, logger=m) From a56c1743c0f9854422c29dd229bc8112ae0d7bd7 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Mon, 27 May 2024 12:26:44 -0400 Subject: [PATCH 33/48] Update logging to newer format across devices --- pennylane/devices/default_mixed.py | 12 +++++ pennylane/devices/default_qutrit.py | 10 +++++ pennylane/devices/default_qutrit_mixed.py | 14 +++--- .../test_qutrit_mixed_tracking.py | 45 ------------------- 4 files changed, 27 insertions(+), 54 deletions(-) diff --git a/pennylane/devices/default_mixed.py b/pennylane/devices/default_mixed.py index 80661c7faa3..a4a84a19098 100644 --- a/pennylane/devices/default_mixed.py +++ b/pennylane/devices/default_mixed.py @@ -21,6 +21,7 @@ import functools import itertools +import logging from collections import defaultdict from string import ascii_letters as ABC @@ -29,6 +30,7 @@ import pennylane as qml import pennylane.math as qnp from pennylane import BasisState, DeviceError, QubitDensityMatrix, QubitDevice, Snapshot, StatePrep +from pennylane.logging import debug_logger, debug_logger_init from pennylane.measurements import ( CountsMP, DensityMatrixMP, @@ -47,6 +49,9 @@ from .._version import __version__ +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) + ABC_ARRAY = np.array(list(ABC)) tolerance = 1e-10 @@ -181,6 +186,7 @@ def _asarray(array, dtype=None): res = qnp.cast(array, dtype=dtype) return res + @debug_logger_init def __init__( self, wires, @@ -252,6 +258,7 @@ def state(self): # User obtains state as a matrix return qnp.reshape(self._pre_rotated_state, (dim, dim)) + @debug_logger def density_matrix(self, wires): """Returns the reduced density matrix over the given wires. @@ -266,12 +273,14 @@ def density_matrix(self, wires): wires = self.map_wires(wires) return qml.math.reduce_dm(state, indices=wires, c_dtype=self.C_DTYPE) + @debug_logger def purity(self, mp, **kwargs): # pylint: disable=unused-argument """Returns the purity of the final state""" state = getattr(self, "state", None) wires = self.map_wires(mp.wires) return qml.math.purity(state, indices=wires, c_dtype=self.C_DTYPE) + @debug_logger def reset(self): """Resets the device""" super().reset() @@ -279,6 +288,7 @@ def reset(self): self._state = self._create_basis_state(0) self._pre_rotated_state = self._state + @debug_logger def analytic_probability(self, wires=None): if self._state is None: return None @@ -706,6 +716,7 @@ def _apply_operation(self, operation): # pylint: disable=arguments-differ + @debug_logger def execute(self, circuit, **kwargs): """Execute a queue of quantum operations on the device and then measure the given observables. @@ -760,6 +771,7 @@ def execute(self, circuit, **kwargs): self.measured_wires = qml.wires.Wires.all_wires(wires_list) return super().execute(circuit, **kwargs) + @debug_logger def apply(self, operations, rotations=None, **kwargs): rotations = rotations or [] diff --git a/pennylane/devices/default_qutrit.py b/pennylane/devices/default_qutrit.py index 5e9e346be18..4ac1fe0cbb9 100644 --- a/pennylane/devices/default_qutrit.py +++ b/pennylane/devices/default_qutrit.py @@ -19,16 +19,21 @@ simulation of qutrit-based quantum computing. """ import functools +import logging import numpy as np import pennylane as qml # pylint: disable=unused-import from pennylane import DeviceError, QutritBasisState, QutritDevice from pennylane.devices.default_qubit_legacy import _get_slice +from pennylane.logging import debug_logger, debug_logger_init from pennylane.wires import WireError from .._version import __version__ +logger = logging.getLogger(__name__) +logger.addHandler(logging.NullHandler()) + # tolerance for numerical errors tolerance = 1e-10 @@ -118,6 +123,7 @@ def _asarray(array, dtype=None): res = qml.math.cast(array, dtype=dtype) return res + @debug_logger_init def __init__( self, wires, @@ -165,6 +171,7 @@ def define_wire_map(self, wires): wire_map = zip(wires, consecutive_wires) return dict(wire_map) + @debug_logger def apply(self, operations, rotations=None, **kwargs): # pylint: disable=arguments-differ rotations = rotations or [] @@ -403,6 +410,7 @@ def _create_basis_state(self, index): def state(self): return self._flatten(self._pre_rotated_state) + @debug_logger def density_matrix(self, wires): """Returns the reduced density matrix of a given set of wires. @@ -460,6 +468,7 @@ def _apply_unitary(self, state, mat, wires): inv_perm = np.argsort(perm) # argsort gives inverse permutation return self._transpose(tdot, inv_perm) + @debug_logger def reset(self): """Reset the device""" super().reset() @@ -468,6 +477,7 @@ def reset(self): self._state = self._create_basis_state(0) self._pre_rotated_state = self._state + @debug_logger def analytic_probability(self, wires=None): if self._state is None: return None diff --git a/pennylane/devices/default_qutrit_mixed.py b/pennylane/devices/default_qutrit_mixed.py index 7c264a9d785..0ade57c0c73 100644 --- a/pennylane/devices/default_qutrit_mixed.py +++ b/pennylane/devices/default_qutrit_mixed.py @@ -13,7 +13,6 @@ # limitations under the License. """The default.qutrit.mixed device is PennyLane's standard qutrit simulator for mixed-state computations.""" -import inspect import logging from dataclasses import replace from typing import Callable, Optional, Sequence, Tuple, Union @@ -21,6 +20,7 @@ import numpy as np import pennylane as qml +from pennylane.logging import debug_logger, debug_logger_init from pennylane.ops import _qutrit__channel__ops__ as channels from pennylane.tape import QuantumTape from pennylane.transforms.core import TransformProgram @@ -176,6 +176,7 @@ def name(self): """The name of the device.""" return "default.qutrit.mixed" + @debug_logger_init def __init__( self, wires=None, @@ -192,6 +193,7 @@ def __init__( self._rng = np.random.default_rng(seed) self._debugger = None + @debug_logger def supports_derivatives( self, execution_config: Optional[ExecutionConfig] = None, @@ -238,6 +240,7 @@ def _setup_execution_config(self, execution_config: ExecutionConfig) -> Executio updated_values["device_options"][option] = getattr(self, f"_{option}") return replace(execution_config, **updated_values) + @debug_logger def preprocess( self, execution_config: ExecutionConfig = DefaultExecutionConfig, @@ -283,19 +286,12 @@ def preprocess( return transform_program, config + @debug_logger def execute( self, circuits: QuantumTape_or_Batch, execution_config: ExecutionConfig = DefaultExecutionConfig, ) -> Result_or_ResultBatch: - if logger.isEnabledFor(logging.DEBUG): - logger.debug( - """Entry with args=(circuits=%s) called by=%s""", - circuits, - "::L".join( - str(i) for i in inspect.getouterframes(inspect.currentframe(), 2)[1][1:3] - ), - ) interface = ( execution_config.interface diff --git a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py index 1b97d395dec..0cb99352fba 100644 --- a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py +++ b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py @@ -222,48 +222,3 @@ def test_multiple_expval_with_prods(self): assert dev.tracker.totals["executions"] == expected_exec assert dev.tracker.totals["simulations"] == 1 assert dev.tracker.totals["shots"] == expected_shots - - -@pytest.mark.logging -def test_execution_debugging(caplog, set_log_level): - """Test logging of QNode forward pass from default qutrit mixed.""" - - # Set outer log-level to ensure messages are produced from external paths - # and appropriately disabled upon exit - with set_log_level(caplog, ["pennylane.workflow.qnode"], [logging.DEBUG]): - - # Set inner level to log local details - with caplog.at_level(logging.DEBUG): - dev = qml.device("default.qutrit.mixed", wires=2) - params = qml.numpy.array(0.1234) - - @qml.qnode(dev, diff_method=None) - def circuit(params): - qml.TRX(params, wires=0) - return qml.expval(qml.GellMann(0, 3)) - - circuit(params) - - assert len(caplog.records) == 3 - - log_records_expected = [ - ( - "pennylane.workflow.qnode", - ["Creating QNode(func= Date: Mon, 27 May 2024 12:34:16 -0400 Subject: [PATCH 34/48] Update changelog --- doc/releases/changelog-dev.md | 3 +++ 1 file changed, 3 insertions(+) diff --git a/doc/releases/changelog-dev.md b/doc/releases/changelog-dev.md index 3690638820b..803fdd8b867 100644 --- a/doc/releases/changelog-dev.md +++ b/doc/releases/changelog-dev.md @@ -9,6 +9,9 @@

Improvements 🛠

+* Logging now allows for an easier opt-in across the stack, and also extends control support to `catalyst`. + [(#5528)](https://github.com/PennyLaneAI/pennylane/pull/5528). + * `ctrl` now works with tuple-valued `control_values` when applied to any already controlled operation. [(#5725)](https://github.com/PennyLaneAI/pennylane/pull/5725) From 811b875046b95a89be83b2a851d79ccf70e4da47 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Mon, 27 May 2024 12:39:51 -0400 Subject: [PATCH 35/48] Remove unneeded packages --- tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py | 2 -- tests/logging/test_logging_autograd.py | 2 -- 2 files changed, 4 deletions(-) diff --git a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py index 0cb99352fba..a735157784f 100644 --- a/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py +++ b/tests/devices/qutrit_mixed/test_qutrit_mixed_tracking.py @@ -14,8 +14,6 @@ """ Tests for the tracking capabilities of default qutrit mixed. """ -import logging - import numpy as np import pytest diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index a73272dfa92..5305e9ae449 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -13,13 +13,11 @@ # limitations under the License. """Unit tests for the the logging module""" # pylint: disable=import-outside-toplevel, protected-access, no-member -import contextlib import logging import pytest import pennylane as qml -import pennylane.logging as pl_logging _grad_log_map = { "adjoint": "gradient_fn=adjoint, interface=autograd, grad_on_execution=best, gradient_kwargs={}", From 5fd081c0232d934884c8c1ef266bee96d0456c97 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Mon, 27 May 2024 12:47:35 -0400 Subject: [PATCH 36/48] Remove redundant except --- tests/conftest.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/tests/conftest.py b/tests/conftest.py index 09cac1daf13..10ee9058b7d 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -348,9 +348,6 @@ def log_level_fixture(caplog, mod, levels): caplog.set_level(l, logger=m) yield - except Exception: # pylint: disable=broad-except - raise - finally: filter_loggers = ["pennylane", "catalyst"] mod += [ From b898b0f2c69c98d25512a030369fb777bc4fa7ab Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Mon, 27 May 2024 16:28:26 -0400 Subject: [PATCH 37/48] Update logging config --- tests/conftest.py | 71 ++++++++++++++++++++++++++++------------------- 1 file changed, 43 insertions(+), 28 deletions(-) diff --git a/tests/conftest.py b/tests/conftest.py index 10ee9058b7d..d1c43fe10c3 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -330,34 +330,49 @@ def pytest_runtest_setup(item): ) +class LogExceptionMgr: + """ + This context manager class defines setup and teardown for log-levels as part of testing. It is often required to enable various levels beyond the capability of the in-built caplog setting, so this class allow setting of outter log-level messages, and the inner caplog defined level can be set within the manager as expected. With this, multiple layers of control can be provided for the logging configuration. + """ + + # Use lock due to process-wide modification to configuration + def __init__(self, caplog, mod, levels): + self._caplog = caplog + self._mod = mod + self._levels = levels + self._pl_logger = None + + def __enter__(self): + pl_logging.enable_logging() + self._pl_logger = logging.root.manager.loggerDict["pennylane"] + + # Ensure logs messages are propagated for pytest capture + self._pl_logger.propagate = True + + for l, m in zip(self._levels, self._mod): + self._caplog.set_level(l, logger=m) + + def __exit__(self, *exc): + # Ensure all recently added loggers and handlers are removed + filter_loggers = ["pennylane", "catalyst"] + self._mod += [ + lgr_name + for (lgr_name, _) in logging.root.manager.loggerDict.items() + if any(filt_lgr in lgr_name for filt_lgr in filter_loggers) + ] + for m in self._mod: + self._caplog.set_level(logging.NOTSET, logger=m) + logger = logging.root.manager.loggerDict[m] + logger.setLevel(logging.NOTSET) + logger.propagate = True + logger.filters.clear() + logger.handlers.clear() + logger.disabled = False + + # pylint: disable=pointless-statement @pytest.fixture(scope="function") def set_log_level(): - "Add log-level context-managing fixture to avoid log-levels propagating outside of tests" - - @contextlib.contextmanager - def log_level_fixture(caplog, mod, levels): - try: - pl_logging.enable_logging() - pl_logger = logging.root.manager.loggerDict["pennylane"] - - # Ensure logs messages are propagated for pytest capture - pl_logger.propagate = True - - for l, m in zip(levels, mod): - caplog.set_level(l, logger=m) - yield - - finally: - filter_loggers = ["pennylane", "catalyst"] - mod += [ - lgr - for (lgr, _) in logging.root.manager.loggerDict.items() - if any(filt_lgr in lgr for filt_lgr in filter_loggers) - ] - for m in mod: - caplog.set_level(logging.NOTSET, logger=m) - - pl_logger.propagate = False - - return log_level_fixture + "Wrap LogExceptionMgr to provide fixture function-level support for enabling and disabling logging" + + return LogExceptionMgr From 1b5a2fdcdae839e73ad18a78d8f74676429643e3 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Mon, 27 May 2024 16:50:13 -0400 Subject: [PATCH 38/48] Add qutrit mixed log tests to logging module tests --- tests/logging/test_logging_autograd.py | 53 +++++++++++++++++++++++--- 1 file changed, 48 insertions(+), 5 deletions(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index 5305e9ae449..a9d47a44ce7 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -107,11 +107,6 @@ def circuit(params): def test_dq_qnode_execution_grad(self, caplog, diff_method, num_records, set_log_level): "Test logging of QNode with parameterised gradients" - # Set specific log-levels for validation - caplog.set_level(logging.INFO, logger="pennylane") - caplog.set_level(logging.DEBUG, logger="pennylane.workflow") - caplog.set_level(logging.DEBUG, logger="pennylane.devices") - with set_log_level( caplog, ["pennylane", "pennylane.workflow", "pennylane.devices"], @@ -160,3 +155,51 @@ def circuit(params): for expected, actual in zip(log_records_expected, caplog.records[:2]): assert expected[0] in actual.name assert all(msg in actual.getMessage() for msg in expected[1]) + + def test_execution_debugging_qutrit_mixed(self, caplog, set_log_level): + """Test logging of QNode forward pass from default qutrit mixed.""" + + with set_log_level( + caplog, + ["pennylane", "pennylane.workflow", "pennylane.devices"], + [logging.INFO, logging.DEBUG, logging.DEBUG], + ): + # Set inner level to log local details + with caplog.at_level(logging.DEBUG): + dev = qml.device("default.qutrit.mixed", wires=2) + params = qml.numpy.array(0.1234) + + @qml.qnode(dev, diff_method=None) + def circuit(params): + qml.TRX(params, wires=0) + return qml.expval(qml.GellMann(0, 3)) + + circuit(params) + + assert len(caplog.records) == 6 + + log_records_expected = [ + ( + "pennylane.devices.default_qutrit_mixed", + ["Calling <__init__(self= Date: Tue, 28 May 2024 10:14:57 -0400 Subject: [PATCH 39/48] Update log tests --- tests/conftest.py | 50 ------ tests/logging/test_logging_autograd.py | 221 +++++++++++++++---------- 2 files changed, 137 insertions(+), 134 deletions(-) diff --git a/tests/conftest.py b/tests/conftest.py index d1c43fe10c3..43d1321983e 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -16,7 +16,6 @@ """ # pylint: disable=unused-import import contextlib -import logging import os import pathlib @@ -24,7 +23,6 @@ import pytest import pennylane as qml -import pennylane.logging as pl_logging from pennylane.devices import DefaultGaussian from pennylane.operation import disable_new_opmath_cm, enable_new_opmath_cm @@ -328,51 +326,3 @@ def pytest_runtest_setup(item): pytest.skip( f"\nTest {item.nodeid} only runs with {allowed_interfaces} interfaces(s) but {b} interface provided", ) - - -class LogExceptionMgr: - """ - This context manager class defines setup and teardown for log-levels as part of testing. It is often required to enable various levels beyond the capability of the in-built caplog setting, so this class allow setting of outter log-level messages, and the inner caplog defined level can be set within the manager as expected. With this, multiple layers of control can be provided for the logging configuration. - """ - - # Use lock due to process-wide modification to configuration - def __init__(self, caplog, mod, levels): - self._caplog = caplog - self._mod = mod - self._levels = levels - self._pl_logger = None - - def __enter__(self): - pl_logging.enable_logging() - self._pl_logger = logging.root.manager.loggerDict["pennylane"] - - # Ensure logs messages are propagated for pytest capture - self._pl_logger.propagate = True - - for l, m in zip(self._levels, self._mod): - self._caplog.set_level(l, logger=m) - - def __exit__(self, *exc): - # Ensure all recently added loggers and handlers are removed - filter_loggers = ["pennylane", "catalyst"] - self._mod += [ - lgr_name - for (lgr_name, _) in logging.root.manager.loggerDict.items() - if any(filt_lgr in lgr_name for filt_lgr in filter_loggers) - ] - for m in self._mod: - self._caplog.set_level(logging.NOTSET, logger=m) - logger = logging.root.manager.loggerDict[m] - logger.setLevel(logging.NOTSET) - logger.propagate = True - logger.filters.clear() - logger.handlers.clear() - logger.disabled = False - - -# pylint: disable=pointless-statement -@pytest.fixture(scope="function") -def set_log_level(): - "Wrap LogExceptionMgr to provide fixture function-level support for enabling and disabling logging" - - return LogExceptionMgr diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index a9d47a44ce7..cf4fabd4af6 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -18,6 +18,7 @@ import pytest import pennylane as qml +import pennylane.logging as pl_logging _grad_log_map = { "adjoint": "gradient_fn=adjoint, interface=autograd, grad_on_execution=best, gradient_kwargs={}", @@ -26,6 +27,74 @@ } +class LogExceptionMgr: + """ + This context manager class defines setup and teardown for log-levels as part of testing. It is often required to enable various levels beyond the capability of the in-built caplog setting, so this class allow setting of outter log-level messages, and the inner caplog defined level can be set within the manager as expected. With this, multiple layers of control can be provided for the logging configuration. + """ + + # Use lock due to process-wide modification to configuration + def __init__(self, caplog, mod, levels): + self._caplog = caplog + self._mod = mod + self._levels = levels + self._pl_logger = None + + def __enter__(self): + pl_logging.enable_logging() + self._pl_logger = logging.root.manager.loggerDict["pennylane"] + + # Ensure logs messages are propagated for pytest capture + self._pl_logger.propagate = True + + for l, m in zip(self._levels, self._mod): + self._caplog.set_level(l, logger=m) + + def __exit__(self, *exc): + # Ensure all recently added loggers and handlers are removed + reset_logging() + self._caplog.clear() + + +# pylint: disable=pointless-statement +@pytest.fixture(scope="function") +def set_log_level(): + "Wrap LogExceptionMgr to provide fixture function-level support for enabling and disabling logging" + + return LogExceptionMgr + + +def reset_logging(): + manager = logging.root.manager + manager.disabled = logging.NOTSET + for logger in manager.loggerDict.values(): + if isinstance(logger, logging.Logger): + logger.setLevel(logging.NOTSET) + logger.propagate = True + logger.disabled = False + logger.filters.clear() + handlers = logger.handlers.copy() + for handler in handlers: + # Copied from `logging.shutdown`. + try: + handler.acquire() + handler.flush() + handler.close() + except (OSError, ValueError): + pass + finally: + handler.release() + logger.removeHandler(handler) + + +# pylint: disable=pointless-statement +@pytest.fixture(scope="module") +def disable_logging(): + "Wrap LogExceptionMgr to provide fixture function-level support for enabling and disabling logging" + + yield + logging.shutdown() + + @pytest.mark.logging class TestLogging: """Tests for logging integration""" @@ -33,9 +102,9 @@ class TestLogging: def test_qd_dev_creation(self, caplog, set_log_level): "Test logging of device creation" - with set_log_level(caplog, ["pennylane.devices.default_qubit"], [logging.DEBUG]): - with caplog.at_level(logging.DEBUG): - qml.device("default.qubit", wires=2) + # with set_log_level(caplog, ["pennylane.devices.default_qubit"], [logging.DEBUG]): + with caplog.at_level(logging.DEBUG): + qml.device("default.qubit", wires=2) assert len(caplog.records) == 1 assert "Calling <__init__(self= Date: Tue, 28 May 2024 10:15:26 -0400 Subject: [PATCH 40/48] Remove redundant functions in tests --- tests/logging/test_logging_autograd.py | 69 -------------------------- 1 file changed, 69 deletions(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index cf4fabd4af6..ec04f04681e 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -26,75 +26,6 @@ "parameter-shift": "gradient_fn=", } - -class LogExceptionMgr: - """ - This context manager class defines setup and teardown for log-levels as part of testing. It is often required to enable various levels beyond the capability of the in-built caplog setting, so this class allow setting of outter log-level messages, and the inner caplog defined level can be set within the manager as expected. With this, multiple layers of control can be provided for the logging configuration. - """ - - # Use lock due to process-wide modification to configuration - def __init__(self, caplog, mod, levels): - self._caplog = caplog - self._mod = mod - self._levels = levels - self._pl_logger = None - - def __enter__(self): - pl_logging.enable_logging() - self._pl_logger = logging.root.manager.loggerDict["pennylane"] - - # Ensure logs messages are propagated for pytest capture - self._pl_logger.propagate = True - - for l, m in zip(self._levels, self._mod): - self._caplog.set_level(l, logger=m) - - def __exit__(self, *exc): - # Ensure all recently added loggers and handlers are removed - reset_logging() - self._caplog.clear() - - -# pylint: disable=pointless-statement -@pytest.fixture(scope="function") -def set_log_level(): - "Wrap LogExceptionMgr to provide fixture function-level support for enabling and disabling logging" - - return LogExceptionMgr - - -def reset_logging(): - manager = logging.root.manager - manager.disabled = logging.NOTSET - for logger in manager.loggerDict.values(): - if isinstance(logger, logging.Logger): - logger.setLevel(logging.NOTSET) - logger.propagate = True - logger.disabled = False - logger.filters.clear() - handlers = logger.handlers.copy() - for handler in handlers: - # Copied from `logging.shutdown`. - try: - handler.acquire() - handler.flush() - handler.close() - except (OSError, ValueError): - pass - finally: - handler.release() - logger.removeHandler(handler) - - -# pylint: disable=pointless-statement -@pytest.fixture(scope="module") -def disable_logging(): - "Wrap LogExceptionMgr to provide fixture function-level support for enabling and disabling logging" - - yield - logging.shutdown() - - @pytest.mark.logging class TestLogging: """Tests for logging integration""" From 66a594258c6c6f66409e7621ddd14e1251543c62 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Tue, 28 May 2024 10:28:58 -0400 Subject: [PATCH 41/48] Remove unused import --- tests/logging/test_logging_autograd.py | 13 ++++++------- 1 file changed, 6 insertions(+), 7 deletions(-) diff --git a/tests/logging/test_logging_autograd.py b/tests/logging/test_logging_autograd.py index ec04f04681e..5b57bca85a4 100644 --- a/tests/logging/test_logging_autograd.py +++ b/tests/logging/test_logging_autograd.py @@ -18,7 +18,6 @@ import pytest import pennylane as qml -import pennylane.logging as pl_logging _grad_log_map = { "adjoint": "gradient_fn=adjoint, interface=autograd, grad_on_execution=best, gradient_kwargs={}", @@ -26,21 +25,21 @@ "parameter-shift": "gradient_fn=", } + @pytest.mark.logging class TestLogging: """Tests for logging integration""" - def test_qd_dev_creation(self, caplog, set_log_level): + def test_qd_dev_creation(self, caplog): "Test logging of device creation" - # with set_log_level(caplog, ["pennylane.devices.default_qubit"], [logging.DEBUG]): with caplog.at_level(logging.DEBUG): qml.device("default.qubit", wires=2) assert len(caplog.records) == 1 assert "Calling <__init__(self= Date: Tue, 28 May 2024 11:28:11 -0400 Subject: [PATCH 42/48] Update doc/development/guide/logging.rst Co-authored-by: Mudit Pandey --- doc/development/guide/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index 28da014ba2f..e06e65809ea 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -31,7 +31,7 @@ which will be used within the given module, and track directories, filenames and function names, as we have defined the appropriate types within the formatter configuration (see :class:`pennylane.logging.DefaultFormatter`). With the logger defined, we can selectively add to the logger via two methods: -#. using decorators on the required functions and methods in a given module: +#. Using decorators on the required functions and methods in a given module: .. code:: python From 42c25114b2f36de5e11ebea0256844ce84d4d15c Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Tue, 28 May 2024 11:28:16 -0400 Subject: [PATCH 43/48] Update doc/development/guide/logging.rst Co-authored-by: Mudit Pandey --- doc/development/guide/logging.rst | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/development/guide/logging.rst b/doc/development/guide/logging.rst index e06e65809ea..54f0a0cc349 100644 --- a/doc/development/guide/logging.rst +++ b/doc/development/guide/logging.rst @@ -43,7 +43,7 @@ within the formatter configuration (see :class:`pennylane.logging.DefaultFormatt def my_func(arg1, arg2): return arg1 + arg2 -#. explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will +#. Explicitly by if-else statements, which compare the given module’s log-level to any log record message it receives. This step is not necessary, as the message will only output if the level is enabled, though if an expensive function call is required to build the string for the log-message, it can be faster to perform this check: From 3f3e339a6274f2933071a8b855ae72f792e121ab Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Wed, 29 May 2024 10:08:47 -0400 Subject: [PATCH 44/48] Update pennylane/logging/configuration.py Co-authored-by: Thomas R. Bromley <49409390+trbromley@users.noreply.github.com> --- pennylane/logging/configuration.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index d46c90fb50e..d38ea5db3d7 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -129,8 +129,8 @@ def edit_system_config(wait_on_close=False): """ This function opens the log configuration file using OS-specific editors. - Setting the `EDITOR` environment variable will override xdg-open/open on - Linux and MacOS, and allows use of `wait_on_close` for editor close before + Setting the ``EDITOR`` environment variable will override ``xdg-open/open`` on + Linux and MacOS, and allows use of ``wait_on_close`` for editor close before continuing execution. .. warning:: From 81dc6e8088c64d727f2517472a8cf1877b18aaed Mon Sep 17 00:00:00 2001 From: Lee James O'Riordan Date: Wed, 29 May 2024 10:08:55 -0400 Subject: [PATCH 45/48] Update pennylane/logging/configuration.py Co-authored-by: Thomas R. Bromley <49409390+trbromley@users.noreply.github.com> --- pennylane/logging/configuration.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index d38ea5db3d7..242cd164921 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -136,7 +136,7 @@ def edit_system_config(wait_on_close=False): .. warning:: As each OS configuration differs user-to-user, you may wish to - instead open this file manually with the `config_path()` provided path. + instead open this file manually with the ``config_path()`` provided path. """ if editor := os.getenv("EDITOR"): # pylint:disable = consider-using-with From cda291c9a2a344f48769d7f983e65b2cc9551668 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 29 May 2024 11:46:50 -0400 Subject: [PATCH 46/48] Add parenthesis for safety to env var check --- pennylane/logging/configuration.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 242cd164921..2b172ae2020 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -143,7 +143,7 @@ def edit_system_config(wait_on_close=False): with subprocess.Popen((editor, config_path())) as p: if wait_on_close: # Only valid when editor is known p.wait() - elif s := platform.system() in ["Linux", "Darwin"]: + elif (s := platform.system()) in ["Linux", "Darwin"]: f_cmd = None if s == "Linux": f_cmd = "xdg-open" From 25910f61e2389815f131943ef8ab8eb7cfe961cf Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 29 May 2024 11:55:54 -0400 Subject: [PATCH 47/48] Disable pylint incorrect parenthesis error --- pennylane/logging/configuration.py | 1 + 1 file changed, 1 insertion(+) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 2b172ae2020..6126fc1a0d9 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -143,6 +143,7 @@ def edit_system_config(wait_on_close=False): with subprocess.Popen((editor, config_path())) as p: if wait_on_close: # Only valid when editor is known p.wait() + # pylint:disable = superfluous-parens elif (s := platform.system()) in ["Linux", "Darwin"]: f_cmd = None if s == "Linux": From 77044d84eba668a2405097c0ce7c909606f6c629 Mon Sep 17 00:00:00 2001 From: "Lee J. O'Riordan" Date: Wed, 29 May 2024 17:51:18 -0400 Subject: [PATCH 48/48] Update review feedback --- pennylane/logging/configuration.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pennylane/logging/configuration.py b/pennylane/logging/configuration.py index 6126fc1a0d9..c78ce01beb9 100644 --- a/pennylane/logging/configuration.py +++ b/pennylane/logging/configuration.py @@ -89,7 +89,7 @@ def enable_logging(config_file: str = "log_config.toml"): Enabling logging through this method will override any externally defined logging configurations. Args: - config_file (str): The path to a given log configuration file, parsed as TOML and adhering to the ``logging.config.dictConfig`` end-point. The default argument uses the PennyLane ecosystem log-file configuration. + config_file (str): The path to a given log configuration file, parsed as TOML and adhering to the ``logging.config.dictConfig`` end-point. The default argument uses the PennyLane ecosystem log-file configuration, located at the directory returned from :func:`pennylane.logging.config_path`. **Example**