From 4ba5d12323a1816f5c516b2a1a5a50f8e255aeb9 Mon Sep 17 00:00:00 2001 From: "Jens H. Nielsen" Date: Fri, 16 Oct 2026 13:27:34 +0200 Subject: [PATCH 1/4] Add parameter observers notified of every get and set Add qcodes.parameters.add_parameter_observer, remove_parameter_observer and the observe_parameters context manager. An observer is called with a ParameterAccess after every get and set of every parameter, describing the parameter, value, raw value, start time, duration and any exception. A set that ramps in steps is reported once per step. Any number of observers can be registered, independently of on_set_callback and global_on_set_callback. This makes it possible to record all instrument communication made by a piece of code without changing it or the drivers it uses. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../newsfragments/+parameter_observers.new | 7 + src/qcodes/parameters/__init__.py | 16 ++ src/qcodes/parameters/parameter_base.py | 71 ++++++- src/qcodes/parameters/parameter_observers.py | 167 +++++++++++++++ tests/parameter/test_parameter_observers.py | 193 ++++++++++++++++++ 5 files changed, 450 insertions(+), 4 deletions(-) create mode 100644 docs/changes/newsfragments/+parameter_observers.new create mode 100644 src/qcodes/parameters/parameter_observers.py create mode 100644 tests/parameter/test_parameter_observers.py diff --git a/docs/changes/newsfragments/+parameter_observers.new b/docs/changes/newsfragments/+parameter_observers.new new file mode 100644 index 000000000000..2e5fd0926f13 --- /dev/null +++ b/docs/changes/newsfragments/+parameter_observers.new @@ -0,0 +1,7 @@ +Added parameter observers: ``qcodes.parameters.add_parameter_observer`` registers a callable that is +notified of every ``get`` and ``set`` of every parameter, with a ``qcodes.parameters.ParameterAccess`` +describing the parameter, the value and raw value, when the access started, how long it took and any +exception it raised. A set that ramps in steps is reported once per step. Any number of observers can be +registered (use ``remove_parameter_observer`` or the ``observe_parameters`` context manager to remove them +again), and they are independent of ``on_set_callback`` and ``global_on_set_callback``. This makes it +possible to record all instrument communication made by a piece of code without changing it. diff --git a/src/qcodes/parameters/__init__.py b/src/qcodes/parameters/__init__.py index 4ff68a69fac7..c2171f87f874 100644 --- a/src/qcodes/parameters/__init__.py +++ b/src/qcodes/parameters/__init__.py @@ -86,6 +86,15 @@ ParamRawDataType, invert_val_mapping, ) +from .parameter_observers import ( + ParameterAccess, + ParameterAccessKind, + ParameterObserver, + add_parameter_observer, + observe_parameters, + registered_parameter_observers, + remove_parameter_observer, +) from .parameter_with_setpoints import ParameterWithSetpoints, expand_setpoints_helper from .scaled_paramter import ScaledParameter from .specialized_parameters import ElapsedTimeParameter, InstrumentRefParameter @@ -112,16 +121,23 @@ "ParamSpecBase", "ParamSpecBaseDict", "Parameter", + "ParameterAccess", + "ParameterAccessKind", "ParameterBase", "ParameterBaseKWArgs", "ParameterKWArgs", + "ParameterObserver", "ParameterSet", "ParameterWithSetpoints", "ScaledParameter", "SweepFixedValues", "SweepValues", + "add_parameter_observer", "combine", "create_on_off_val_mapping", "expand_setpoints_helper", "invert_val_mapping", + "observe_parameters", + "registered_parameter_observers", + "remove_parameter_observer", ] diff --git a/src/qcodes/parameters/parameter_base.py b/src/qcodes/parameters/parameter_base.py index 5d6342b04aa9..ff80f14529f9 100644 --- a/src/qcodes/parameters/parameter_base.py +++ b/src/qcodes/parameters/parameter_base.py @@ -37,6 +37,7 @@ ) from ..utils.types import NumberType +from . import parameter_observers as _parameter_observers from .cache import _Cache, _CacheProtocol from .named_repr import named_repr from .permissive_range import permissive_range @@ -984,6 +985,12 @@ def get_wrapper(*args: Any, **kwargs: Any) -> ParameterDataTypeVar: raise NotImplementedError( f"Trying to get an abstract parameter: {self.full_name}" ) + observers = _parameter_observers._observers + timestamp = t0 = 0.0 + if observers: + timestamp = time.time() + t0 = time.perf_counter() + raw_value = None try: # There might be cases where a .get also has args/kwargs raw_value = get_function(*args, **kwargs) @@ -995,12 +1002,37 @@ def get_wrapper(*args: Any, **kwargs: Any) -> ParameterDataTypeVar: self.cache._update_with(value=value, raw_value=raw_value) - return value - except Exception as e: + if observers: + _parameter_observers._notify( + observers, + _parameter_observers.ParameterAccess( + parameter=self, + kind="get", + value=None, + raw_value=raw_value, + timestamp=timestamp, + duration=time.perf_counter() - t0, + exception=e, + ), + ) e.args = (*e.args, f"getting {self}") raise + if observers: + _parameter_observers._notify( + observers, + _parameter_observers.ParameterAccess( + parameter=self, + kind="get", + value=value, + raw_value=raw_value, + timestamp=timestamp, + duration=time.perf_counter() - t0, + ), + ) + return value + return get_wrapper def _wrap_set(self, set_function: Callable[..., None]) -> Callable[..., None]: @@ -1041,8 +1073,26 @@ def set_wrapper(value: ParameterDataTypeVar, **kwargs: Any) -> None: # Start timer to measure execution time of set_function t0 = time.perf_counter() - - set_function(raw_val_step, **kwargs) + observers = _parameter_observers._observers + timestamp = time.time() if observers else 0.0 + + try: + set_function(raw_val_step, **kwargs) + except Exception as e: + if observers: + _parameter_observers._notify( + observers, + _parameter_observers.ParameterAccess( + parameter=self, + kind="set", + value=val_step, + raw_value=raw_val_step, + timestamp=timestamp, + duration=time.perf_counter() - t0, + exception=e, + ), + ) + raise # Update last set time (used for calculating delays) self._t_last_set = time.perf_counter() @@ -1057,6 +1107,19 @@ def set_wrapper(value: ParameterDataTypeVar, **kwargs: Any) -> None: self._call_on_set_callback(val_step) + if observers: + _parameter_observers._notify( + observers, + _parameter_observers.ParameterAccess( + parameter=self, + kind="set", + value=val_step, + raw_value=raw_val_step, + timestamp=timestamp, + duration=t_elapsed, + ), + ) + except Exception as e: e.args = (*e.args, f"setting {self} to {value}") raise diff --git a/src/qcodes/parameters/parameter_observers.py b/src/qcodes/parameters/parameter_observers.py new file mode 100644 index 000000000000..8f6e795f5513 --- /dev/null +++ b/src/qcodes/parameters/parameter_observers.py @@ -0,0 +1,167 @@ +""" +Observers of parameter access. + +An observer is a callable that is notified of every ``get`` and ``set`` of +every parameter in the process, after the access has happened. This makes it +possible to record what a piece of code did to the instruments it controls +without changing the code or the drivers involved:: + + >>> from qcodes.parameters import observe_parameters + >>> accesses = [] + >>> with observe_parameters(accesses.append): + ... dac.ch1(0.1) + ... dmm.v1() + +Unlike :attr:`.ParameterBase.on_set_callback` and +:attr:`.ParameterBase.global_on_set_callback`, any number of observers can be +registered, they see ``get`` as well as ``set``, and they are independent of +the callbacks of individual parameters. + +Observers are called synchronously on the thread that accessed the parameter, +so they should be fast. An exception raised by an observer is logged and does +not affect the access, nor the other observers. +""" + +from __future__ import annotations + +import logging +import threading +from collections.abc import Callable +from contextlib import contextmanager +from dataclasses import dataclass +from typing import TYPE_CHECKING, Any, Literal + +if TYPE_CHECKING: + from collections.abc import Generator + + from .parameter_base import ParameterBase + +LOG = logging.getLogger(__name__) + +ParameterAccessKind = Literal["get", "set"] + + +@dataclass(frozen=True, slots=True) +class ParameterAccess: + """ + A single ``get`` or ``set`` of a parameter, as passed to an observer. + + A set that ramps the parameter in steps (see :attr:`.ParameterBase.step`) + is reported once per step, since each step is a separate call to the + instrument. + """ + + parameter: ParameterBase + """The parameter that was accessed.""" + kind: ParameterAccessKind + """Whether the parameter was read (``"get"``) or written (``"set"``).""" + value: Any + """ + The value that was read, or the value of the step that was written. ``None`` + if a get failed before a value was obtained. + """ + raw_value: Any + """ + The raw value returned by ``get_raw`` or passed to ``set_raw``. ``None`` if + a get failed before the raw value was obtained. + """ + timestamp: float + """Time the access started, in seconds since the epoch (:func:`time.time`).""" + duration: float + """ + Seconds spent in ``get_raw`` or ``set_raw`` and the conversions around it. + Delays configured on the parameter, such as ``post_delay``, are excluded. + """ + exception: BaseException | None = None + """The exception raised by the access, or ``None`` if it succeeded.""" + + +type ParameterObserver = Callable[[ParameterAccess], None] +"""A callable that is notified of every parameter access.""" + +_lock = threading.Lock() +# Replaced rather than mutated, so a reader never needs the lock: it sees the +# tuple that was registered when it started. +_observers: tuple[ParameterObserver, ...] = () + + +def add_parameter_observer(observer: ParameterObserver) -> None: + """ + Register an observer of every parameter ``get`` and ``set``. + + Args: + observer: Called with a :class:`ParameterAccess` after each access. + Registering the same observer twice notifies it twice. + + """ + global _observers + with _lock: + _observers = (*_observers, observer) + + +def remove_parameter_observer(observer: ParameterObserver) -> None: + """ + Unregister an observer added with :func:`add_parameter_observer`. + + If the observer was registered more than once, one registration is removed. + + Args: + observer: The observer to remove. + + Raises: + ValueError: If the observer is not registered. + + """ + global _observers + with _lock: + observers = list(_observers) + observers.remove(observer) + _observers = tuple(observers) + + +@contextmanager +def observe_parameters(observer: ParameterObserver) -> Generator[None, None, None]: + """ + Context manager that registers ``observer`` for the duration of the block. + + Args: + observer: Called with a :class:`ParameterAccess` after each access. + + """ + add_parameter_observer(observer) + try: + yield + finally: + remove_parameter_observer(observer) + + +def registered_parameter_observers() -> tuple[ParameterObserver, ...]: + """ + Return the currently registered observers, in registration order. + """ + return _observers + + +def _notify(observers: tuple[ParameterObserver, ...], access: ParameterAccess) -> None: + for observer in observers: + try: + observer(access) + except Exception: + LOG.warning( + "Exception in parameter observer %r for %s of %s", + observer, + access.kind, + access.parameter.full_name, + exc_info=True, + ) + + +__all__ = [ + "ParameterAccess", + "ParameterAccessKind", + "ParameterObserver", + "add_parameter_observer", + "observe_parameters", + "registered_parameter_observers", + "remove_parameter_observer", +] diff --git a/tests/parameter/test_parameter_observers.py b/tests/parameter/test_parameter_observers.py new file mode 100644 index 000000000000..26ddb9eade1f --- /dev/null +++ b/tests/parameter/test_parameter_observers.py @@ -0,0 +1,193 @@ +from __future__ import annotations + +import threading +from typing import TYPE_CHECKING, Any + +import pytest + +from qcodes.parameters import ( + DelegateParameter, + Parameter, + ParameterAccess, + add_parameter_observer, + observe_parameters, + registered_parameter_observers, + remove_parameter_observer, +) +from qcodes.validators import Numbers + +if TYPE_CHECKING: + from collections.abc import Iterator + + +@pytest.fixture +def accesses() -> Iterator[list[ParameterAccess]]: + recorded: list[ParameterAccess] = [] + with observe_parameters(recorded.append): + yield recorded + + +def test_observer_sees_get_and_set(accesses: list[ParameterAccess]) -> None: + param = Parameter("p", set_cmd=None, get_cmd=None, initial_value=0.0) + accesses.clear() + + param(1.5) + assert param() == 1.5 + + assert [(a.parameter, a.kind, a.value) for a in accesses] == [ + (param, "set", 1.5), + (param, "get", 1.5), + ] + assert all(a.exception is None for a in accesses) + assert all(a.duration >= 0 for a in accesses) + assert all(a.timestamp > 0 for a in accesses) + + +def test_observer_sees_raw_values(accesses: list[ParameterAccess]) -> None: + raw = {"value": 0.0} + param = Parameter( + "p", + set_cmd=lambda value: raw.update(value=value), + get_cmd=lambda: raw["value"], + scale=10, + ) + + param(2) + assert param() == 2 + + set_access, get_access = accesses + assert (set_access.value, set_access.raw_value) == (2, 20) + assert (get_access.value, get_access.raw_value) == (2, 20) + + +def test_observer_sees_every_ramp_step(accesses: list[ParameterAccess]) -> None: + param = Parameter("p", set_cmd=None, get_cmd=None, initial_value=0) + param.step = 1 + accesses.clear() + + param(3) + + assert [(a.kind, a.value) for a in accesses] == [ + ("set", 1), + ("set", 2), + ("set", 3), + ] + + +def test_observer_sees_failed_get(accesses: list[ParameterAccess]) -> None: + def fail() -> float: + raise RuntimeError("instrument did not answer") + + param = Parameter("p", get_cmd=fail) + + with pytest.raises(RuntimeError, match="instrument did not answer"): + param() + + (access,) = accesses + assert access.kind == "get" + assert access.value is None + assert access.raw_value is None + assert isinstance(access.exception, RuntimeError) + + +def test_observer_sees_failed_set(accesses: list[ParameterAccess]) -> None: + def fail(value: float) -> None: + raise RuntimeError("instrument refused") + + param = Parameter("p", set_cmd=fail) + + with pytest.raises(RuntimeError, match="instrument refused"): + param(1) + + (access,) = accesses + assert (access.kind, access.value) == ("set", 1) + assert isinstance(access.exception, RuntimeError) + + +def test_invalid_value_is_not_an_access(accesses: list[ParameterAccess]) -> None: + param = Parameter("p", set_cmd=None, vals=Numbers(0, 1)) + + with pytest.raises(ValueError): + param(5) + + assert accesses == [] + + +def test_delegate_and_source_are_both_reported( + accesses: list[ParameterAccess], +) -> None: + source = Parameter("source", set_cmd=None, get_cmd=None, initial_value=0) + delegate = DelegateParameter("delegate", source=source) + accesses.clear() + + delegate(1) + + assert [(a.parameter, a.kind) for a in accesses] == [ + (source, "set"), + (delegate, "set"), + ] + + +def test_observer_is_independent_of_on_set_callback( + accesses: list[ParameterAccess], +) -> None: + callback_values: list[Any] = [] + param = Parameter( + "p", + set_cmd=None, + on_set_callback=lambda _param, value: callback_values.append(value), + ) + + param(1) + + assert callback_values == [1] + assert [(a.kind, a.value) for a in accesses] == [("set", 1)] + + +def test_failing_observer_does_not_affect_access( + caplog: pytest.LogCaptureFixture, +) -> None: + def broken(access: ParameterAccess) -> None: + raise ValueError("observer bug") + + recorded: list[ParameterAccess] = [] + param = Parameter("p", set_cmd=None, get_cmd=None) + with observe_parameters(broken), observe_parameters(recorded.append): + param(1) + + assert param.cache.get() == 1 + assert [a.kind for a in recorded] == ["set"] + assert "Exception in parameter observer" in caplog.text + + +def test_add_and_remove_observer() -> None: + recorded: list[ParameterAccess] = [] + param = Parameter("p", set_cmd=None, get_cmd=None) + + add_parameter_observer(recorded.append) + assert recorded.append in registered_parameter_observers() + param(1) + remove_parameter_observer(recorded.append) + param(2) + + assert [a.value for a in recorded] == [1] + assert recorded.append not in registered_parameter_observers() + + +def test_remove_unknown_observer_raises() -> None: + with pytest.raises(ValueError): + remove_parameter_observer(lambda access: None) + + +def test_observers_are_called_on_the_accessing_thread( + accesses: list[ParameterAccess], +) -> None: + threads: list[threading.Thread] = [] + param = Parameter("p", set_cmd=None, get_cmd=None) + + with observe_parameters(lambda access: threads.append(threading.current_thread())): + worker = threading.Thread(target=param, args=(1,)) + worker.start() + worker.join() + + assert threads == [worker] From ddba642ddf8d232ccffd7ae2d1d3e05c2ebcec6d Mon Sep 17 00:00:00 2001 From: "Jens H. Nielsen" Date: Wed, 28 Oct 2026 10:57:56 +0100 Subject: [PATCH 2/4] Add an example notebook for parameter observers Show how to record the parameter accesses of a block of code with observe_parameters, what a ParameterAccess contains, that ramped sets are reported per step and failed accesses with their exception, how to see what a measurement did to the instruments, and how to register an observer for longer with add_parameter_observer. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../Parameters/Parameter_Observers.ipynb | 514 ++++++++++++++++++ 1 file changed, 514 insertions(+) create mode 100644 docs/examples/Parameters/Parameter_Observers.ipynb diff --git a/docs/examples/Parameters/Parameter_Observers.ipynb b/docs/examples/Parameters/Parameter_Observers.ipynb new file mode 100644 index 000000000000..c76977461dfa --- /dev/null +++ b/docs/examples/Parameters/Parameter_Observers.ipynb @@ -0,0 +1,514 @@ +{ + "cells": [ + { + "cell_type": "markdown", + "id": "6446d72b", + "metadata": {}, + "source": [ + "# Observing parameter access\n", + "\n", + "QCoDeS can tell you about every `get` and `set` of every parameter in your process. You register an *observer*: any callable that takes a `ParameterAccess`. QCoDeS calls it after each access, with the parameter, the value, the raw value, when the access started, how long it took and the exception it raised, if any.\n", + "\n", + "This lets you see what a piece of code did to your instruments without changing the code or the drivers it uses. You can record what a measurement set and read, find out which parameters are queried most often, or keep an audit log of everything that was set.\n", + "\n", + "Observers are independent of a parameter's `on_set_callback` and of `ParameterBase.global_on_set_callback`. Any number of them can be registered, and they also see `get`." + ] + }, + { + "cell_type": "code", + "execution_count": 1, + "id": "99ea18e0", + "metadata": {}, + "outputs": [], + "source": [ + "import logging\n", + "import sys\n", + "import tempfile\n", + "from collections import Counter\n", + "from pathlib import Path\n", + "\n", + "from qcodes.dataset import (\n", + " do1d,\n", + " initialise_or_create_database_at,\n", + " load_or_create_experiment,\n", + ")\n", + "from qcodes.instrument_drivers.mock_instruments import (\n", + " DummyInstrument,\n", + " DummyInstrumentWithMeasurement,\n", + ")\n", + "from qcodes.parameters import (\n", + " Parameter,\n", + " ParameterAccess,\n", + " add_parameter_observer,\n", + " observe_parameters,\n", + " registered_parameter_observers,\n", + " remove_parameter_observer,\n", + ")" + ] + }, + { + "cell_type": "markdown", + "id": "42c1bb85", + "metadata": {}, + "source": [ + "We use two mock instruments: a DAC with two channels, and a DMM whose readings depend on the DAC's voltages." + ] + }, + { + "cell_type": "code", + "execution_count": 2, + "id": "71dee003", + "metadata": {}, + "outputs": [], + "source": [ + "dac = DummyInstrument(\"dac\", gates=[\"ch1\", \"ch2\"])\n", + "dmm = DummyInstrumentWithMeasurement(\"dmm\", setter_instr=dac)" + ] + }, + { + "cell_type": "markdown", + "id": "97ef03ac", + "metadata": {}, + "source": [ + "## Recording the accesses of a block of code\n", + "\n", + "`observe_parameters` registers an observer for the duration of a `with` block. Here the observer is the `append` method of a list, so the list collects every access made inside the block." + ] + }, + { + "cell_type": "code", + "execution_count": 3, + "id": "d35ab7e1", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "set dac_ch1: 0.5\n", + "get dmm_v1: 4.66492785682728\n" + ] + } + ], + "source": [ + "accesses: list[ParameterAccess] = []\n", + "\n", + "with observe_parameters(accesses.append):\n", + " dac.ch1(0.5)\n", + " dmm.v1()\n", + "\n", + "for access in accesses:\n", + " print(f\"{access.kind} {access.parameter.full_name}: {access.value}\")" + ] + }, + { + "cell_type": "markdown", + "id": "e4979482", + "metadata": {}, + "source": [ + "Accesses outside the block are not recorded:" + ] + }, + { + "cell_type": "code", + "execution_count": 4, + "id": "4884a30e", + "metadata": {}, + "outputs": [ + { + "data": { + "text/plain": [ + "2" + ] + }, + "execution_count": 4, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "dac.ch1(0.7)\n", + "len(accesses)" + ] + }, + { + "cell_type": "markdown", + "id": "b57bb874", + "metadata": {}, + "source": [ + "## What an access contains\n", + "\n", + "Each `ParameterAccess` describes one access:\n", + "\n", + "- `parameter`: the parameter that was read or written.\n", + "- `kind`: `\"get\"` or `\"set\"`.\n", + "- `value`: the value that was read or written.\n", + "- `raw_value`: the value passed to or returned by the instrument, before scaling, offsets or value mappings are applied.\n", + "- `timestamp`: when the access started, in seconds since the epoch.\n", + "- `duration`: how long the access took, in seconds. Delays configured on the parameter, such as `post_delay`, are not included.\n", + "- `exception`: the exception the access raised, or `None`.\n", + "\n", + "The difference between `value` and `raw_value` shows what actually reached the instrument. For example, behind a 1:10 voltage divider, setting 2 V on the sample means setting 20 V on the source:" + ] + }, + { + "cell_type": "code", + "execution_count": 5, + "id": "0ca633f5", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "value=2.0, raw_value=20.0, exception=None\n" + ] + } + ], + "source": [ + "divided = Parameter(\"divided\", unit=\"V\", set_cmd=None, get_cmd=None, scale=10)\n", + "\n", + "set_accesses: list[ParameterAccess] = []\n", + "with observe_parameters(set_accesses.append):\n", + " divided(2.0)\n", + "\n", + "(access,) = set_accesses\n", + "print(\n", + " f\"value={access.value}, raw_value={access.raw_value}, exception={access.exception}\"\n", + ")" + ] + }, + { + "cell_type": "markdown", + "id": "17bd456e", + "metadata": {}, + "source": [ + "## Ramped sets are reported step by step\n", + "\n", + "A parameter with a `step` is set in several steps, each of which is a separate call to the instrument. The observer is notified of every step:" + ] + }, + { + "cell_type": "code", + "execution_count": 6, + "id": "6300ad64", + "metadata": {}, + "outputs": [ + { + "data": { + "text/plain": [ + "[0.1, 0.2, 0.3, 0.4, 0.5]" + ] + }, + "execution_count": 6, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "dac.ch2.step = 0.1\n", + "dac.ch2.inter_delay = 0\n", + "\n", + "ramp: list[ParameterAccess] = []\n", + "with observe_parameters(ramp.append):\n", + " dac.ch2(0.5)\n", + "\n", + "[round(access.value, 2) for access in ramp]" + ] + }, + { + "cell_type": "markdown", + "id": "64d7e685", + "metadata": {}, + "source": [ + "## Failed accesses\n", + "\n", + "An access that raises is reported too, with the exception in `exception`, and the exception then propagates to the caller as usual. A value that fails validation is rejected before the instrument is contacted, so it is not an access and is not reported." + ] + }, + { + "cell_type": "code", + "execution_count": 7, + "id": "daa9d694", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "The caller still sees the error: the sensor did not answer\n", + "The observer saw: get sensor: TimeoutError('the sensor did not answer', 'getting sensor')\n" + ] + } + ], + "source": [ + "def read_unresponsive_sensor() -> float:\n", + " raise TimeoutError(\"the sensor did not answer\")\n", + "\n", + "\n", + "sensor = Parameter(\"sensor\", get_cmd=read_unresponsive_sensor)\n", + "\n", + "failures: list[ParameterAccess] = []\n", + "with observe_parameters(failures.append):\n", + " try:\n", + " sensor()\n", + " except TimeoutError as error:\n", + " print(f\"The caller still sees the error: {error.args[0]}\")\n", + "\n", + "(failure,) = failures\n", + "print(\n", + " f\"The observer saw: {failure.kind} {failure.parameter.full_name}: {failure.exception!r}\"\n", + ")" + ] + }, + { + "cell_type": "markdown", + "id": "6b24f28f", + "metadata": {}, + "source": [ + "## What did a measurement do to the instruments?\n", + "\n", + "Observers see all accesses, including those made by QCoDeS itself, so they can show what a measurement did. Here we run a 1D sweep and count the accesses per parameter." + ] + }, + { + "cell_type": "code", + "execution_count": 8, + "id": "5bc55df7", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "Starting experimental run with id: 1. Using 'qcodes.dataset.do1d'\n" + ] + }, + { + "data": { + "text/plain": [ + "Counter({('dac_ch1', 'set'): 11, ('dmm_v1', 'get'): 11})" + ] + }, + "execution_count": 8, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "initialise_or_create_database_at(Path(tempfile.mkdtemp()) / \"observers.db\")\n", + "load_or_create_experiment(\"observing_parameters\", sample_name=\"no sample\")\n", + "\n", + "sweep: list[ParameterAccess] = []\n", + "with observe_parameters(sweep.append):\n", + " do1d(dac.ch1, 0, 1, 11, 0.0, dmm.v1, do_plot=False)\n", + "\n", + "Counter((access.parameter.full_name, access.kind) for access in sweep)" + ] + }, + { + "cell_type": "markdown", + "id": "9e742443", + "metadata": {}, + "source": [ + "The sweep set the DAC 11 times and read the DMM 11 times. The accesses are in the order they happened, so we can also follow the sweep point by point:" + ] + }, + { + "cell_type": "code", + "execution_count": 9, + "id": "b49d018f", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "set dac_ch1: 0.000\n", + "get dmm_v1: 5.033\n", + "set dac_ch1: 0.100\n", + "get dmm_v1: 4.939\n", + "set dac_ch1: 0.200\n", + "get dmm_v1: 4.915\n" + ] + } + ], + "source": [ + "for access in sweep[:6]:\n", + " print(f\"{access.kind} {access.parameter.full_name}: {access.value:.3f}\")" + ] + }, + { + "cell_type": "markdown", + "id": "fdedf69a", + "metadata": {}, + "source": [ + "Observers see every parameter in the process. To follow one instrument, filter on the root instrument of the accessed parameter:" + ] + }, + { + "cell_type": "code", + "execution_count": 10, + "id": "5bb3b926", + "metadata": {}, + "outputs": [ + { + "data": { + "text/plain": [ + "[0.0, 0.1, 0.2, 0.3, 0.4, 0.5, 0.6, 0.7, 0.8, 0.9, 1.0]" + ] + }, + "execution_count": 10, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "dac_sets = [\n", + " access.value\n", + " for access in sweep\n", + " if access.parameter.root_instrument is dac and access.kind == \"set\"\n", + "]\n", + "[round(float(value), 2) for value in dac_sets]" + ] + }, + { + "cell_type": "markdown", + "id": "76724f54", + "metadata": {}, + "source": [ + "## Observers that stay registered\n", + "\n", + "`add_parameter_observer` registers an observer until it is removed with `remove_parameter_observer`. `registered_parameter_observers` returns the observers registered at the moment.\n", + "\n", + "Here an observer writes every access to a logger:" + ] + }, + { + "cell_type": "code", + "execution_count": 11, + "id": "7b6435ea", + "metadata": {}, + "outputs": [ + { + "data": { + "text/plain": [ + "True" + ] + }, + "execution_count": 11, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "access_log = logging.getLogger(\"parameter_access\")\n", + "access_log.setLevel(logging.INFO)\n", + "access_log.propagate = False\n", + "access_log.addHandler(logging.StreamHandler(sys.stdout))\n", + "\n", + "\n", + "def log_access(access: ParameterAccess) -> None:\n", + " access_log.info(\"%s %s = %r\", access.kind, access.parameter.full_name, access.value)\n", + "\n", + "\n", + "add_parameter_observer(log_access)\n", + "log_access in registered_parameter_observers()" + ] + }, + { + "cell_type": "code", + "execution_count": 12, + "id": "faef755c", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "set dac_ch1 = 0.25\n" + ] + }, + { + "name": "stdout", + "output_type": "stream", + "text": [ + "get dmm_v2 = 0.4601170962709825\n" + ] + } + ], + "source": [ + "dac.ch1(0.25)\n", + "reading = dmm.v2()" + ] + }, + { + "cell_type": "code", + "execution_count": 13, + "id": "dd8ca30b", + "metadata": {}, + "outputs": [ + { + "data": { + "text/plain": [ + "False" + ] + }, + "execution_count": 13, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "remove_parameter_observer(log_access)\n", + "dac.ch1(0) # no longer logged\n", + "log_access in registered_parameter_observers()" + ] + }, + { + "cell_type": "markdown", + "id": "e9b405c0", + "metadata": {}, + "source": [ + "## Good to know\n", + "\n", + "- Observers are called synchronously, on the thread that accessed the parameter, right after the access. Keep them fast: an observer that takes a millisecond slows down every parameter access in the process by a millisecond. To do slow work, such as writing to a database, hand the access over to a queue.\n", + "- An exception raised by an observer is logged as a warning and ignored. It neither affects the access nor stops other observers from being notified.\n", + "- An access to a `DelegateParameter` is reported twice: once for the delegate and once for its source.\n", + "- Observers only see parameters. Commands that a driver sends directly, for example with `Instrument.write` or `Instrument.ask` in a driver method, are not reported. Use the instrument's logger (`visa_log` for VISA instruments) to see the communication on the wire." + ] + }, + { + "cell_type": "code", + "execution_count": 14, + "id": "2b776bd4", + "metadata": {}, + "outputs": [], + "source": [ + "dac.close()\n", + "dmm.close()" + ] + } + ], + "metadata": { + "kernelspec": { + "display_name": "Python 3 (ipykernel)", + "language": "python", + "name": "python3" + }, + "language_info": { + "codemirror_mode": { + "name": "ipython", + "version": 3 + }, + "file_extension": ".py", + "mimetype": "text/x-python", + "name": "python", + "nbconvert_exporter": "python", + "pygments_lexer": "ipython3", + "version": "3.12.15" + } + }, + "nbformat": 4, + "nbformat_minor": 5 +} From 6d82941036ac481e3d34d780a465ca904e3c853d Mon Sep 17 00:00:00 2001 From: "Jens H. Nielsen" Date: Fri, 30 Oct 2026 15:55:01 +0100 Subject: [PATCH 3/4] Record parameter accesses instead of calling observers Replace the parameter observer API (add_parameter_observer and friends) with recording that can only store what happened, so that it cannot be used as a callback, for example to set one parameter in reaction to another: - record_parameter_accesses() appends each access to a plain list (subclasses are refused, so append cannot be overridden); log_parameter_accesses() logs them to the qcodes.parameters.parameter_access logger instead. No user code runs while a parameter is accessed. - A ParameterAccess holds data only: the names of the parameter and its root instrument, the value, raw value, unit, timing and a description of any error, but not the parameter, instrument or exception. - Recording is local to the context it was started in (thread or asyncio task), held in a ContextVar, and can be nested. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../+parameter_access_recording.new | 8 + .../newsfragments/+parameter_observers.new | 7 - ...ipynb => Recording_Parameter_Access.ipynb} | 308 ++++++++++-------- src/qcodes/parameters/__init__.py | 22 +- src/qcodes/parameters/parameter_access.py | 253 ++++++++++++++ src/qcodes/parameters/parameter_base.py | 94 +++--- src/qcodes/parameters/parameter_observers.py | 167 ---------- tests/parameter/test_parameter_access.py | 296 +++++++++++++++++ tests/parameter/test_parameter_observers.py | 193 ----------- 9 files changed, 787 insertions(+), 561 deletions(-) create mode 100644 docs/changes/newsfragments/+parameter_access_recording.new delete mode 100644 docs/changes/newsfragments/+parameter_observers.new rename docs/examples/Parameters/{Parameter_Observers.ipynb => Recording_Parameter_Access.ipynb} (55%) create mode 100644 src/qcodes/parameters/parameter_access.py delete mode 100644 src/qcodes/parameters/parameter_observers.py create mode 100644 tests/parameter/test_parameter_access.py delete mode 100644 tests/parameter/test_parameter_observers.py diff --git a/docs/changes/newsfragments/+parameter_access_recording.new b/docs/changes/newsfragments/+parameter_access_recording.new new file mode 100644 index 000000000000..f0b859208858 --- /dev/null +++ b/docs/changes/newsfragments/+parameter_access_recording.new @@ -0,0 +1,8 @@ +Added recording of parameter access: inside a ``with qcodes.parameters.record_parameter_accesses() as accesses:`` block, +every ``get`` and ``set`` of a parameter made by the current thread (or asyncio task) is appended to ``accesses`` as a +``qcodes.parameters.ParameterAccess``: the names of the parameter and its instrument, the value and raw value, when the +access started, how long it took and the error it raised, if any. A set that ramps in steps is recorded once per step. +``qcodes.parameters.log_parameter_accesses`` logs the accesses to the ``qcodes.parameters.parameter_access`` logger +instead. Recording only stores data: no user code runs while a parameter is accessed, and a record holds names rather +than the parameter or instrument. This makes it possible to see all instrument communication made by a piece of code +without changing it. diff --git a/docs/changes/newsfragments/+parameter_observers.new b/docs/changes/newsfragments/+parameter_observers.new deleted file mode 100644 index 2e5fd0926f13..000000000000 --- a/docs/changes/newsfragments/+parameter_observers.new +++ /dev/null @@ -1,7 +0,0 @@ -Added parameter observers: ``qcodes.parameters.add_parameter_observer`` registers a callable that is -notified of every ``get`` and ``set`` of every parameter, with a ``qcodes.parameters.ParameterAccess`` -describing the parameter, the value and raw value, when the access started, how long it took and any -exception it raised. A set that ramps in steps is reported once per step. Any number of observers can be -registered (use ``remove_parameter_observer`` or the ``observe_parameters`` context manager to remove them -again), and they are independent of ``on_set_callback`` and ``global_on_set_callback``. This makes it -possible to record all instrument communication made by a piece of code without changing it. diff --git a/docs/examples/Parameters/Parameter_Observers.ipynb b/docs/examples/Parameters/Recording_Parameter_Access.ipynb similarity index 55% rename from docs/examples/Parameters/Parameter_Observers.ipynb rename to docs/examples/Parameters/Recording_Parameter_Access.ipynb index c76977461dfa..49c71a8a8806 100644 --- a/docs/examples/Parameters/Parameter_Observers.ipynb +++ b/docs/examples/Parameters/Recording_Parameter_Access.ipynb @@ -2,28 +2,33 @@ "cells": [ { "cell_type": "markdown", - "id": "6446d72b", + "id": "9d5a1058", "metadata": {}, "source": [ - "# Observing parameter access\n", + "# Recording parameter access\n", "\n", - "QCoDeS can tell you about every `get` and `set` of every parameter in your process. You register an *observer*: any callable that takes a `ParameterAccess`. QCoDeS calls it after each access, with the parameter, the value, the raw value, when the access started, how long it took and the exception it raised, if any.\n", + "QCoDeS can record every `get` and `set` of every parameter that a piece of code makes. Each access is recorded as a `ParameterAccess`: the names of the parameter and its instrument, the value and raw value, when the access started, how long it took, and the error it raised, if any.\n", "\n", - "This lets you see what a piece of code did to your instruments without changing the code or the drivers it uses. You can record what a measurement set and read, find out which parameters are queried most often, or keep an audit log of everything that was set.\n", + "This lets you see what a piece of code did to your instruments without changing the code or the drivers it uses. You can record what a measurement set and read, find out which parameters are queried most often, or keep a log of everything that was set.\n", "\n", - "Observers are independent of a parameter's `on_set_callback` and of `ParameterBase.global_on_set_callback`. Any number of them can be registered, and they also see `get`." + "Recording only stores what happened:\n", + "\n", + "- Accesses are appended to a plain `list`, or logged to a fixed QCoDeS logger. No code of yours runs while a parameter is accessed, so recording cannot be used to react to an access, for example by setting another parameter.\n", + "- A record holds data only: the names of the parameter and its instrument rather than the objects, and a description of an error rather than the exception.\n", + "- Only accesses made in the context recording was started in are recorded: the current thread, or the current asyncio task." ] }, { "cell_type": "code", "execution_count": 1, - "id": "99ea18e0", + "id": "cb341e86", "metadata": {}, "outputs": [], "source": [ "import logging\n", "import sys\n", "import tempfile\n", + "import threading\n", "from collections import Counter\n", "from pathlib import Path\n", "\n", @@ -39,16 +44,14 @@ "from qcodes.parameters import (\n", " Parameter,\n", " ParameterAccess,\n", - " add_parameter_observer,\n", - " observe_parameters,\n", - " registered_parameter_observers,\n", - " remove_parameter_observer,\n", + " log_parameter_accesses,\n", + " record_parameter_accesses,\n", ")" ] }, { "cell_type": "markdown", - "id": "42c1bb85", + "id": "d2d38547", "metadata": {}, "source": [ "We use two mock instruments: a DAC with two channels, and a DMM whose readings depend on the DAC's voltages." @@ -57,7 +60,7 @@ { "cell_type": "code", "execution_count": 2, - "id": "71dee003", + "id": "361ea797", "metadata": {}, "outputs": [], "source": [ @@ -67,18 +70,18 @@ }, { "cell_type": "markdown", - "id": "97ef03ac", + "id": "deed3b96", "metadata": {}, "source": [ "## Recording the accesses of a block of code\n", "\n", - "`observe_parameters` registers an observer for the duration of a `with` block. Here the observer is the `append` method of a list, so the list collects every access made inside the block." + "`record_parameter_accesses` records the accesses made inside a `with` block in a list, in the order they complete." ] }, { "cell_type": "code", "execution_count": 3, - "id": "d35ab7e1", + "id": "7551cd51", "metadata": {}, "outputs": [ { @@ -86,24 +89,22 @@ "output_type": "stream", "text": [ "set dac_ch1: 0.5\n", - "get dmm_v1: 4.66492785682728\n" + "get dmm_v1: 4.3682652935244874\n" ] } ], "source": [ - "accesses: list[ParameterAccess] = []\n", - "\n", - "with observe_parameters(accesses.append):\n", + "with record_parameter_accesses() as accesses:\n", " dac.ch1(0.5)\n", " dmm.v1()\n", "\n", "for access in accesses:\n", - " print(f\"{access.kind} {access.parameter.full_name}: {access.value}\")" + " print(f\"{access.kind} {access.parameter_name}: {access.value}\")" ] }, { "cell_type": "markdown", - "id": "e4979482", + "id": "d4c10c17", "metadata": {}, "source": [ "Accesses outside the block are not recorded:" @@ -112,7 +113,7 @@ { "cell_type": "code", "execution_count": 4, - "id": "4884a30e", + "id": "0eb5add7", "metadata": {}, "outputs": [ { @@ -133,74 +134,108 @@ }, { "cell_type": "markdown", - "id": "b57bb874", + "id": "4ca4a1bc", + "metadata": {}, + "source": [ + "You can also pass in the list to record in. It has to be a plain `list`: recording only ever appends to it." + ] + }, + { + "cell_type": "code", + "execution_count": 5, + "id": "6f5387c7", + "metadata": {}, + "outputs": [ + { + "data": { + "text/plain": [ + "[0.1, 0.2]" + ] + }, + "execution_count": 5, + "metadata": {}, + "output_type": "execute_result" + } + ], + "source": [ + "everything: list[ParameterAccess] = []\n", + "with record_parameter_accesses(everything):\n", + " dac.ch2(0.1)\n", + "with record_parameter_accesses(everything):\n", + " dac.ch2(0.2)\n", + "\n", + "[access.value for access in everything]" + ] + }, + { + "cell_type": "markdown", + "id": "ad911579", "metadata": {}, "source": [ - "## What an access contains\n", + "## What a record contains\n", "\n", "Each `ParameterAccess` describes one access:\n", "\n", - "- `parameter`: the parameter that was read or written.\n", + "- `parameter_name`: the full name of the parameter.\n", + "- `instrument_name`: the full name of the parameter's root instrument, or `None`.\n", "- `kind`: `\"get\"` or `\"set\"`.\n", "- `value`: the value that was read or written.\n", "- `raw_value`: the value passed to or returned by the instrument, before scaling, offsets or value mappings are applied.\n", + "- `unit`: the parameter's unit.\n", "- `timestamp`: when the access started, in seconds since the epoch.\n", "- `duration`: how long the access took, in seconds. Delays configured on the parameter, such as `post_delay`, are not included.\n", - "- `exception`: the exception the access raised, or `None`.\n", + "- `error`: the type and message of the exception the access raised, or `None`.\n", "\n", "The difference between `value` and `raw_value` shows what actually reached the instrument. For example, behind a 1:10 voltage divider, setting 2 V on the sample means setting 20 V on the source:" ] }, { "cell_type": "code", - "execution_count": 5, - "id": "0ca633f5", + "execution_count": 6, + "id": "6dbb149b", "metadata": {}, "outputs": [ { "name": "stdout", "output_type": "stream", "text": [ - "value=2.0, raw_value=20.0, exception=None\n" + "value=2.0, raw_value=20.0, error=None\n" ] } ], "source": [ "divided = Parameter(\"divided\", unit=\"V\", set_cmd=None, get_cmd=None, scale=10)\n", "\n", - "set_accesses: list[ParameterAccess] = []\n", - "with observe_parameters(set_accesses.append):\n", + "with record_parameter_accesses() as set_accesses:\n", " divided(2.0)\n", "\n", "(access,) = set_accesses\n", - "print(\n", - " f\"value={access.value}, raw_value={access.raw_value}, exception={access.exception}\"\n", - ")" + "print(f\"value={access.value}, raw_value={access.raw_value}, error={access.error}\")" ] }, { "cell_type": "markdown", - "id": "17bd456e", + "id": "b554d90e", "metadata": {}, "source": [ - "## Ramped sets are reported step by step\n", + "## Ramped sets are recorded step by step\n", "\n", - "A parameter with a `step` is set in several steps, each of which is a separate call to the instrument. The observer is notified of every step:" + "A parameter with a `step` is set in several steps, each of which is a separate call to the instrument. Every step is recorded:" ] }, { "cell_type": "code", - "execution_count": 6, - "id": "6300ad64", + "execution_count": 7, + "id": "cacd002a", "metadata": {}, "outputs": [ { "data": { "text/plain": [ - "[0.1, 0.2, 0.3, 0.4, 0.5]" + "[0.3, 0.4, 0.5]" ] }, - "execution_count": 6, + "execution_count": 7, "metadata": {}, "output_type": "execute_result" } @@ -209,8 +244,7 @@ "dac.ch2.step = 0.1\n", "dac.ch2.inter_delay = 0\n", "\n", - "ramp: list[ParameterAccess] = []\n", - "with observe_parameters(ramp.append):\n", + "with record_parameter_accesses() as ramp:\n", " dac.ch2(0.5)\n", "\n", "[round(access.value, 2) for access in ramp]" @@ -218,18 +252,18 @@ }, { "cell_type": "markdown", - "id": "64d7e685", + "id": "9caa7b47", "metadata": {}, "source": [ "## Failed accesses\n", "\n", - "An access that raises is reported too, with the exception in `exception`, and the exception then propagates to the caller as usual. A value that fails validation is rejected before the instrument is contacted, so it is not an access and is not reported." + "An access that raises is recorded too, with a description of the exception in `error`, and the exception then propagates to the caller as usual. A value that fails validation is rejected before the instrument is contacted, so it is not an access and is not recorded." ] }, { "cell_type": "code", - "execution_count": 7, - "id": "daa9d694", + "execution_count": 8, + "id": "9c54d07b", "metadata": {}, "outputs": [ { @@ -237,7 +271,7 @@ "output_type": "stream", "text": [ "The caller still sees the error: the sensor did not answer\n", - "The observer saw: get sensor: TimeoutError('the sensor did not answer', 'getting sensor')\n" + "Recorded: get sensor: TimeoutError: the sensor did not answer\n" ] } ], @@ -248,33 +282,30 @@ "\n", "sensor = Parameter(\"sensor\", get_cmd=read_unresponsive_sensor)\n", "\n", - "failures: list[ParameterAccess] = []\n", - "with observe_parameters(failures.append):\n", + "with record_parameter_accesses() as failures:\n", " try:\n", " sensor()\n", " except TimeoutError as error:\n", " print(f\"The caller still sees the error: {error.args[0]}\")\n", "\n", "(failure,) = failures\n", - "print(\n", - " f\"The observer saw: {failure.kind} {failure.parameter.full_name}: {failure.exception!r}\"\n", - ")" + "print(f\"Recorded: {failure.kind} {failure.parameter_name}: {failure.error}\")" ] }, { "cell_type": "markdown", - "id": "6b24f28f", + "id": "dc58e4a4", "metadata": {}, "source": [ "## What did a measurement do to the instruments?\n", "\n", - "Observers see all accesses, including those made by QCoDeS itself, so they can show what a measurement did. Here we run a 1D sweep and count the accesses per parameter." + "Recording sees all accesses made in its context, including those QCoDeS makes itself, so it can show what a measurement did. Here we run a 1D sweep and count the accesses per parameter." ] }, { "cell_type": "code", - "execution_count": 8, - "id": "5bc55df7", + "execution_count": 9, + "id": "0aa93da2", "metadata": {}, "outputs": [ { @@ -290,25 +321,24 @@ "Counter({('dac_ch1', 'set'): 11, ('dmm_v1', 'get'): 11})" ] }, - "execution_count": 8, + "execution_count": 9, "metadata": {}, "output_type": "execute_result" } ], "source": [ - "initialise_or_create_database_at(Path(tempfile.mkdtemp()) / \"observers.db\")\n", - "load_or_create_experiment(\"observing_parameters\", sample_name=\"no sample\")\n", + "initialise_or_create_database_at(Path(tempfile.mkdtemp()) / \"recording.db\")\n", + "load_or_create_experiment(\"recording_parameter_access\", sample_name=\"no sample\")\n", "\n", - "sweep: list[ParameterAccess] = []\n", - "with observe_parameters(sweep.append):\n", + "with record_parameter_accesses() as sweep:\n", " do1d(dac.ch1, 0, 1, 11, 0.0, dmm.v1, do_plot=False)\n", "\n", - "Counter((access.parameter.full_name, access.kind) for access in sweep)" + "Counter((access.parameter_name, access.kind) for access in sweep)" ] }, { "cell_type": "markdown", - "id": "9e742443", + "id": "840b7ca6", "metadata": {}, "source": [ "The sweep set the DAC 11 times and read the DMM 11 times. The accesses are in the order they happened, so we can also follow the sweep point by point:" @@ -316,8 +346,8 @@ }, { "cell_type": "code", - "execution_count": 9, - "id": "b49d018f", + "execution_count": 10, + "id": "58960777", "metadata": {}, "outputs": [ { @@ -325,31 +355,31 @@ "output_type": "stream", "text": [ "set dac_ch1: 0.000\n", - "get dmm_v1: 5.033\n", + "get dmm_v1: 4.946\n", "set dac_ch1: 0.100\n", - "get dmm_v1: 4.939\n", + "get dmm_v1: 4.862\n", "set dac_ch1: 0.200\n", - "get dmm_v1: 4.915\n" + "get dmm_v1: 4.809\n" ] } ], "source": [ "for access in sweep[:6]:\n", - " print(f\"{access.kind} {access.parameter.full_name}: {access.value:.3f}\")" + " print(f\"{access.kind} {access.parameter_name}: {access.value:.3f}\")" ] }, { "cell_type": "markdown", - "id": "fdedf69a", + "id": "63c58da9", "metadata": {}, "source": [ - "Observers see every parameter in the process. To follow one instrument, filter on the root instrument of the accessed parameter:" + "To follow one instrument, filter on the instrument name:" ] }, { "cell_type": "code", - "execution_count": 10, - "id": "5bb3b926", + "execution_count": 11, + "id": "e4072ce8", "metadata": {}, "outputs": [ { @@ -358,7 +388,7 @@ "[0.0, 0.1, 0.2, 0.3, 0.4, 0.5, 0.6, 0.7, 0.8, 0.9, 1.0]" ] }, - "execution_count": 10, + "execution_count": 11, "metadata": {}, "output_type": "execute_result" } @@ -367,91 +397,66 @@ "dac_sets = [\n", " access.value\n", " for access in sweep\n", - " if access.parameter.root_instrument is dac and access.kind == \"set\"\n", + " if access.instrument_name == \"dac\" and access.kind == \"set\"\n", "]\n", "[round(float(value), 2) for value in dac_sets]" ] }, { "cell_type": "markdown", - "id": "76724f54", + "id": "c5b922e6", "metadata": {}, "source": [ - "## Observers that stay registered\n", - "\n", - "`add_parameter_observer` registers an observer until it is removed with `remove_parameter_observer`. `registered_parameter_observers` returns the observers registered at the moment.\n", + "## Recording is local to a thread\n", "\n", - "Here an observer writes every access to a logger:" + "Only accesses made by the thread (or asyncio task) that started recording are recorded. Work in other threads, even while the block runs, is not:" ] }, { "cell_type": "code", - "execution_count": 11, - "id": "7b6435ea", + "execution_count": 12, + "id": "23a74c87", "metadata": {}, "outputs": [ { "data": { "text/plain": [ - "True" + "[0.3]" ] }, - "execution_count": 11, + "execution_count": 12, "metadata": {}, "output_type": "execute_result" } ], "source": [ - "access_log = logging.getLogger(\"parameter_access\")\n", - "access_log.setLevel(logging.INFO)\n", - "access_log.propagate = False\n", - "access_log.addHandler(logging.StreamHandler(sys.stdout))\n", - "\n", + "with record_parameter_accesses() as here:\n", + " worker = threading.Thread(target=dac.ch1, args=(0.9,))\n", + " worker.start()\n", + " worker.join()\n", + " dac.ch1(0.3)\n", "\n", - "def log_access(access: ParameterAccess) -> None:\n", - " access_log.info(\"%s %s = %r\", access.kind, access.parameter.full_name, access.value)\n", - "\n", - "\n", - "add_parameter_observer(log_access)\n", - "log_access in registered_parameter_observers()" + "[access.value for access in here]" ] }, { - "cell_type": "code", - "execution_count": 12, - "id": "faef755c", + "cell_type": "markdown", + "id": "fe51b03d", "metadata": {}, - "outputs": [ - { - "name": "stdout", - "output_type": "stream", - "text": [ - "set dac_ch1 = 0.25\n" - ] - }, - { - "name": "stdout", - "output_type": "stream", - "text": [ - "get dmm_v2 = 0.4601170962709825\n" - ] - } - ], "source": [ - "dac.ch1(0.25)\n", - "reading = dmm.v2()" + "Recordings can be nested. Each one receives every access made while it is active:" ] }, { "cell_type": "code", "execution_count": 13, - "id": "dd8ca30b", + "id": "13031c57", "metadata": {}, "outputs": [ { "data": { "text/plain": [ - "False" + "([0.1, 0.2], [0.2])" ] }, "execution_count": 13, @@ -460,28 +465,73 @@ } ], "source": [ - "remove_parameter_observer(log_access)\n", - "dac.ch1(0) # no longer logged\n", - "log_access in registered_parameter_observers()" + "with record_parameter_accesses() as outer:\n", + " dac.ch1(0.1)\n", + " with record_parameter_accesses() as inner:\n", + " dac.ch1(0.2)\n", + "\n", + "[access.value for access in outer], [access.value for access in inner]" ] }, { "cell_type": "markdown", - "id": "e9b405c0", + "id": "5861ab28", "metadata": {}, "source": [ - "## Good to know\n", + "## Logging accesses\n", "\n", - "- Observers are called synchronously, on the thread that accessed the parameter, right after the access. Keep them fast: an observer that takes a millisecond slows down every parameter access in the process by a millisecond. To do slow work, such as writing to a database, hand the access over to a queue.\n", - "- An exception raised by an observer is logged as a warning and ignored. It neither affects the access nor stops other observers from being notified.\n", - "- An access to a `DelegateParameter` is reported twice: once for the delegate and once for its source.\n", - "- Observers only see parameters. Commands that a driver sends directly, for example with `Instrument.write` or `Instrument.ask` in a driver method, are not reported. Use the instrument's logger (`visa_log` for VISA instruments) to see the communication on the wire." + "`log_parameter_accesses` logs the accesses made inside a `with` block to the `qcodes.parameters.parameter_access` logger, at `DEBUG` level unless you choose another. Each log record carries the `ParameterAccess` as its `parameter_access` attribute, so a handler can store it in structured form." ] }, { "cell_type": "code", "execution_count": 14, - "id": "2b776bd4", + "id": "63ce152c", + "metadata": {}, + "outputs": [ + { + "name": "stdout", + "output_type": "stream", + "text": [ + "set dac_ch1 = 0.25\n" + ] + }, + { + "name": "stdout", + "output_type": "stream", + "text": [ + "get dmm_v2 = 0.4612975233041446\n" + ] + } + ], + "source": [ + "access_log = logging.getLogger(\"qcodes.parameters.parameter_access\")\n", + "access_log.setLevel(logging.DEBUG)\n", + "access_log.propagate = False\n", + "access_log.addHandler(logging.StreamHandler(sys.stdout))\n", + "\n", + "with log_parameter_accesses():\n", + " dac.ch1(0.25)\n", + " reading = dmm.v2()" + ] + }, + { + "cell_type": "markdown", + "id": "ea5ce8be", + "metadata": {}, + "source": [ + "## Good to know\n", + "\n", + "- Recording adds a little work to every access made while it is active, and none otherwise.\n", + "- Values are recorded as the parameter returned or received them, not copied.\n", + "- An access to a `DelegateParameter` is recorded twice: once for the delegate and once for its source.\n", + "- Only parameters are recorded. Commands that a driver sends directly, for example with `Instrument.write` or `Instrument.ask` in a driver method, are not. Use the instrument's logger (`visa_log` for VISA instruments) to see the communication on the wire." + ] + }, + { + "cell_type": "code", + "execution_count": 15, + "id": "0c6b690d", "metadata": {}, "outputs": [], "source": [ diff --git a/src/qcodes/parameters/__init__.py b/src/qcodes/parameters/__init__.py index c2171f87f874..f92b83ad2aa1 100644 --- a/src/qcodes/parameters/__init__.py +++ b/src/qcodes/parameters/__init__.py @@ -78,6 +78,12 @@ from .multi_channel_instrument_parameter import MultiChannelInstrumentParameter from .multi_parameter import MultiParameter from .parameter import ManualParameter, Parameter, ParameterKWArgs +from .parameter_access import ( + ParameterAccess, + ParameterAccessKind, + log_parameter_accesses, + record_parameter_accesses, +) from .parameter_base import ( ParamDataType, ParameterBase, @@ -86,15 +92,6 @@ ParamRawDataType, invert_val_mapping, ) -from .parameter_observers import ( - ParameterAccess, - ParameterAccessKind, - ParameterObserver, - add_parameter_observer, - observe_parameters, - registered_parameter_observers, - remove_parameter_observer, -) from .parameter_with_setpoints import ParameterWithSetpoints, expand_setpoints_helper from .scaled_paramter import ScaledParameter from .specialized_parameters import ElapsedTimeParameter, InstrumentRefParameter @@ -126,18 +123,15 @@ "ParameterBase", "ParameterBaseKWArgs", "ParameterKWArgs", - "ParameterObserver", "ParameterSet", "ParameterWithSetpoints", "ScaledParameter", "SweepFixedValues", "SweepValues", - "add_parameter_observer", "combine", "create_on_off_val_mapping", "expand_setpoints_helper", "invert_val_mapping", - "observe_parameters", - "registered_parameter_observers", - "remove_parameter_observer", + "log_parameter_accesses", + "record_parameter_accesses", ] diff --git a/src/qcodes/parameters/parameter_access.py b/src/qcodes/parameters/parameter_access.py new file mode 100644 index 000000000000..f334d9eeb108 --- /dev/null +++ b/src/qcodes/parameters/parameter_access.py @@ -0,0 +1,253 @@ +""" +Recording of parameter access. + +Every ``get`` and ``set`` of a parameter can be recorded as a +:class:`ParameterAccess`: what was accessed, the value, when and for how long, +and whether it failed. This makes it possible to see what a piece of code did +to the instruments it controls without changing the code or the drivers:: + + >>> from qcodes.parameters import record_parameter_accesses + >>> with record_parameter_accesses() as accesses: + ... dac.ch1(0.1) + ... dmm.v1() + >>> [(access.kind, access.parameter_name) for access in accesses] + [('set', 'dac_ch1'), ('get', 'dmm_v1')] + +Recording is deliberately restricted to storing what happened: + +* Accesses are appended to a plain :class:`list` or logged to a fixed logger + (:func:`log_parameter_accesses`). No user-supplied code runs while a + parameter is accessed, so recording cannot react to an access, for example + by setting another parameter. +* A :class:`ParameterAccess` holds data only: the names of the parameter and + its instrument rather than the objects themselves, and a description of an + error rather than the exception. +* Recording is local to the context it was started in: the current thread, or + the current :mod:`asyncio` task. Accesses made in other threads are not + recorded. Recordings can be nested; each one receives every access made + while it is active. +""" + +from __future__ import annotations + +import logging +from contextlib import contextmanager +from contextvars import ContextVar +from dataclasses import dataclass +from typing import TYPE_CHECKING, Any, Literal + +if TYPE_CHECKING: + from collections.abc import Generator + + from .parameter_base import ParameterBase + +LOG = logging.getLogger(__name__) +"""The logger :func:`log_parameter_accesses` logs accesses to.""" + +ParameterAccessKind = Literal["get", "set"] + + +@dataclass(frozen=True, slots=True) +class ParameterAccess: + """ + A single ``get`` or ``set`` of a parameter. + + A set that ramps the parameter in steps (see :attr:`.ParameterBase.step`) + is recorded once per step, since each step is a separate call to the + instrument. + """ + + parameter_name: str + """The full name of the parameter that was accessed.""" + instrument_name: str | None + """The full name of the parameter's root instrument, if it has one.""" + kind: ParameterAccessKind + """Whether the parameter was read (``"get"``) or written (``"set"``).""" + value: Any + """ + The value that was read, or the value of the step that was written. ``None`` + if a get failed before a value was obtained. The value is recorded as the + parameter returned or received it, not copied. + """ + raw_value: Any + """ + The raw value returned by ``get_raw`` or passed to ``set_raw``. ``None`` if + a get failed before the raw value was obtained. + """ + unit: str + """The unit of the parameter.""" + timestamp: float + """Time the access started, in seconds since the epoch (:func:`time.time`).""" + duration: float + """ + Seconds spent in ``get_raw`` or ``set_raw`` and the conversions around it. + Delays configured on the parameter, such as ``post_delay``, are excluded. + """ + error: str | None = None + """ + The type and message of the exception the access raised, such as + ``"TimeoutError: no reply"``, or ``None`` if it succeeded. + """ + + +class _ListSink: + """Appends accesses to a list.""" + + __slots__ = ("_records",) + + def __init__(self, records: list[ParameterAccess]) -> None: + self._records = records + + def record(self, access: ParameterAccess) -> None: + self._records.append(access) + + +class _LogSink: + """Logs accesses to :data:`LOG`.""" + + __slots__ = ("_level",) + + def __init__(self, level: int) -> None: + self._level = level + + def record(self, access: ParameterAccess) -> None: + if not LOG.isEnabledFor(self._level): + return + if access.error is None: + message, args = ( + "%s %s = %r", + ( + access.kind, + access.parameter_name, + access.value, + ), + ) + else: + message, args = ( + "%s %s failed: %s", + ( + access.kind, + access.parameter_name, + access.error, + ), + ) + LOG.log( + self._level, + message, + *args, + extra={ + "parameter_access": access, + "parameter_name": access.parameter_name, + "instrument_name": access.instrument_name, + }, + ) + + +_Sink = _ListSink | _LogSink + +_active_sinks: ContextVar[tuple[_Sink, ...]] = ContextVar( + "qcodes_parameter_access_sinks", default=() +) + + +@contextmanager +def record_parameter_accesses( + records: list[ParameterAccess] | None = None, +) -> Generator[list[ParameterAccess], None, None]: + """ + Record every parameter access made in the current context in a list. + + Accesses made by the current thread (or asyncio task) while the block runs + are appended to the list, in the order they complete. An access that + raises is recorded too, with its :attr:`ParameterAccess.error`. + + Args: + records: The list to append to. A new list is used if ``None``. + + Yields: + The list the accesses are appended to. + + Raises: + TypeError: If ``records`` is not a :class:`list`. Subclasses are + refused too, so that recording can only ever append. + + """ + if records is None: + records = [] + if type(records) is not list: + raise TypeError( + "Parameter accesses can only be recorded in a list, " + f"not in {type(records).__name__}." + ) + with _sink_active(_ListSink(records)): + yield records + + +@contextmanager +def log_parameter_accesses( + level: int = logging.DEBUG, +) -> Generator[None, None, None]: + """ + Log every parameter access made in the current context. + + Accesses made by the current thread (or asyncio task) while the block runs + are logged to the ``qcodes.parameters.parameter_access`` logger. Each log + record carries the :class:`ParameterAccess` as its ``parameter_access`` + attribute, and the parameter and instrument names as its + ``parameter_name`` and ``instrument_name`` attributes. + + Args: + level: The level to log accesses at. + + """ + with _sink_active(_LogSink(level)): + yield + + +@contextmanager +def _sink_active(sink: _Sink) -> Generator[None, None, None]: + token = _active_sinks.set((*_active_sinks.get(), sink)) + try: + yield + finally: + _active_sinks.reset(token) + + +def _record( + sinks: tuple[_Sink, ...], + parameter: ParameterBase, + kind: ParameterAccessKind, + value: Any, + raw_value: Any, + timestamp: float, + duration: float, + exception: BaseException | None = None, +) -> None: + root = parameter.root_instrument + access = ParameterAccess( + parameter_name=parameter.full_name, + instrument_name=None if root is None else root.full_name, + kind=kind, + value=value, + raw_value=raw_value, + unit=getattr(parameter, "unit", ""), + timestamp=timestamp, + duration=duration, + error=None if exception is None else _describe(exception), + ) + for sink in sinks: + sink.record(access) + + +def _describe(exception: BaseException) -> str: + # The arguments only: the context QCoDeS appends to e.args (e.g. + # "getting dac_ch1") is added after the access is recorded. + return f"{type(exception).__name__}: {exception}" + + +__all__ = [ + "ParameterAccess", + "ParameterAccessKind", + "log_parameter_accesses", + "record_parameter_accesses", +] diff --git a/src/qcodes/parameters/parameter_base.py b/src/qcodes/parameters/parameter_base.py index ff80f14529f9..e92940f3f938 100644 --- a/src/qcodes/parameters/parameter_base.py +++ b/src/qcodes/parameters/parameter_base.py @@ -37,7 +37,7 @@ ) from ..utils.types import NumberType -from . import parameter_observers as _parameter_observers +from . import parameter_access as _parameter_access from .cache import _Cache, _CacheProtocol from .named_repr import named_repr from .permissive_range import permissive_range @@ -985,9 +985,9 @@ def get_wrapper(*args: Any, **kwargs: Any) -> ParameterDataTypeVar: raise NotImplementedError( f"Trying to get an abstract parameter: {self.full_name}" ) - observers = _parameter_observers._observers + sinks = _parameter_access._active_sinks.get() timestamp = t0 = 0.0 - if observers: + if sinks: timestamp = time.time() t0 = time.perf_counter() raw_value = None @@ -1003,33 +1003,29 @@ def get_wrapper(*args: Any, **kwargs: Any) -> ParameterDataTypeVar: self.cache._update_with(value=value, raw_value=raw_value) except Exception as e: - if observers: - _parameter_observers._notify( - observers, - _parameter_observers.ParameterAccess( - parameter=self, - kind="get", - value=None, - raw_value=raw_value, - timestamp=timestamp, - duration=time.perf_counter() - t0, - exception=e, - ), + if sinks: + _parameter_access._record( + sinks, + self, + "get", + value=None, + raw_value=raw_value, + timestamp=timestamp, + duration=time.perf_counter() - t0, + exception=e, ) e.args = (*e.args, f"getting {self}") raise - if observers: - _parameter_observers._notify( - observers, - _parameter_observers.ParameterAccess( - parameter=self, - kind="get", - value=value, - raw_value=raw_value, - timestamp=timestamp, - duration=time.perf_counter() - t0, - ), + if sinks: + _parameter_access._record( + sinks, + self, + "get", + value=value, + raw_value=raw_value, + timestamp=timestamp, + duration=time.perf_counter() - t0, ) return value @@ -1073,24 +1069,22 @@ def set_wrapper(value: ParameterDataTypeVar, **kwargs: Any) -> None: # Start timer to measure execution time of set_function t0 = time.perf_counter() - observers = _parameter_observers._observers - timestamp = time.time() if observers else 0.0 + sinks = _parameter_access._active_sinks.get() + timestamp = time.time() if sinks else 0.0 try: set_function(raw_val_step, **kwargs) except Exception as e: - if observers: - _parameter_observers._notify( - observers, - _parameter_observers.ParameterAccess( - parameter=self, - kind="set", - value=val_step, - raw_value=raw_val_step, - timestamp=timestamp, - duration=time.perf_counter() - t0, - exception=e, - ), + if sinks: + _parameter_access._record( + sinks, + self, + "set", + value=val_step, + raw_value=raw_val_step, + timestamp=timestamp, + duration=time.perf_counter() - t0, + exception=e, ) raise @@ -1107,17 +1101,15 @@ def set_wrapper(value: ParameterDataTypeVar, **kwargs: Any) -> None: self._call_on_set_callback(val_step) - if observers: - _parameter_observers._notify( - observers, - _parameter_observers.ParameterAccess( - parameter=self, - kind="set", - value=val_step, - raw_value=raw_val_step, - timestamp=timestamp, - duration=t_elapsed, - ), + if sinks: + _parameter_access._record( + sinks, + self, + "set", + value=val_step, + raw_value=raw_val_step, + timestamp=timestamp, + duration=t_elapsed, ) except Exception as e: diff --git a/src/qcodes/parameters/parameter_observers.py b/src/qcodes/parameters/parameter_observers.py deleted file mode 100644 index 8f6e795f5513..000000000000 --- a/src/qcodes/parameters/parameter_observers.py +++ /dev/null @@ -1,167 +0,0 @@ -""" -Observers of parameter access. - -An observer is a callable that is notified of every ``get`` and ``set`` of -every parameter in the process, after the access has happened. This makes it -possible to record what a piece of code did to the instruments it controls -without changing the code or the drivers involved:: - - >>> from qcodes.parameters import observe_parameters - >>> accesses = [] - >>> with observe_parameters(accesses.append): - ... dac.ch1(0.1) - ... dmm.v1() - -Unlike :attr:`.ParameterBase.on_set_callback` and -:attr:`.ParameterBase.global_on_set_callback`, any number of observers can be -registered, they see ``get`` as well as ``set``, and they are independent of -the callbacks of individual parameters. - -Observers are called synchronously on the thread that accessed the parameter, -so they should be fast. An exception raised by an observer is logged and does -not affect the access, nor the other observers. -""" - -from __future__ import annotations - -import logging -import threading -from collections.abc import Callable -from contextlib import contextmanager -from dataclasses import dataclass -from typing import TYPE_CHECKING, Any, Literal - -if TYPE_CHECKING: - from collections.abc import Generator - - from .parameter_base import ParameterBase - -LOG = logging.getLogger(__name__) - -ParameterAccessKind = Literal["get", "set"] - - -@dataclass(frozen=True, slots=True) -class ParameterAccess: - """ - A single ``get`` or ``set`` of a parameter, as passed to an observer. - - A set that ramps the parameter in steps (see :attr:`.ParameterBase.step`) - is reported once per step, since each step is a separate call to the - instrument. - """ - - parameter: ParameterBase - """The parameter that was accessed.""" - kind: ParameterAccessKind - """Whether the parameter was read (``"get"``) or written (``"set"``).""" - value: Any - """ - The value that was read, or the value of the step that was written. ``None`` - if a get failed before a value was obtained. - """ - raw_value: Any - """ - The raw value returned by ``get_raw`` or passed to ``set_raw``. ``None`` if - a get failed before the raw value was obtained. - """ - timestamp: float - """Time the access started, in seconds since the epoch (:func:`time.time`).""" - duration: float - """ - Seconds spent in ``get_raw`` or ``set_raw`` and the conversions around it. - Delays configured on the parameter, such as ``post_delay``, are excluded. - """ - exception: BaseException | None = None - """The exception raised by the access, or ``None`` if it succeeded.""" - - -type ParameterObserver = Callable[[ParameterAccess], None] -"""A callable that is notified of every parameter access.""" - -_lock = threading.Lock() -# Replaced rather than mutated, so a reader never needs the lock: it sees the -# tuple that was registered when it started. -_observers: tuple[ParameterObserver, ...] = () - - -def add_parameter_observer(observer: ParameterObserver) -> None: - """ - Register an observer of every parameter ``get`` and ``set``. - - Args: - observer: Called with a :class:`ParameterAccess` after each access. - Registering the same observer twice notifies it twice. - - """ - global _observers - with _lock: - _observers = (*_observers, observer) - - -def remove_parameter_observer(observer: ParameterObserver) -> None: - """ - Unregister an observer added with :func:`add_parameter_observer`. - - If the observer was registered more than once, one registration is removed. - - Args: - observer: The observer to remove. - - Raises: - ValueError: If the observer is not registered. - - """ - global _observers - with _lock: - observers = list(_observers) - observers.remove(observer) - _observers = tuple(observers) - - -@contextmanager -def observe_parameters(observer: ParameterObserver) -> Generator[None, None, None]: - """ - Context manager that registers ``observer`` for the duration of the block. - - Args: - observer: Called with a :class:`ParameterAccess` after each access. - - """ - add_parameter_observer(observer) - try: - yield - finally: - remove_parameter_observer(observer) - - -def registered_parameter_observers() -> tuple[ParameterObserver, ...]: - """ - Return the currently registered observers, in registration order. - """ - return _observers - - -def _notify(observers: tuple[ParameterObserver, ...], access: ParameterAccess) -> None: - for observer in observers: - try: - observer(access) - except Exception: - LOG.warning( - "Exception in parameter observer %r for %s of %s", - observer, - access.kind, - access.parameter.full_name, - exc_info=True, - ) - - -__all__ = [ - "ParameterAccess", - "ParameterAccessKind", - "ParameterObserver", - "add_parameter_observer", - "observe_parameters", - "registered_parameter_observers", - "remove_parameter_observer", -] diff --git a/tests/parameter/test_parameter_access.py b/tests/parameter/test_parameter_access.py new file mode 100644 index 000000000000..80ab64e390d1 --- /dev/null +++ b/tests/parameter/test_parameter_access.py @@ -0,0 +1,296 @@ +from __future__ import annotations + +import asyncio +import logging +import threading +from collections import UserList +from typing import Any + +import pytest + +from qcodes.instrument_drivers.mock_instruments import DummyInstrument +from qcodes.parameters import ( + DelegateParameter, + Parameter, + ParameterAccess, + log_parameter_accesses, + record_parameter_accesses, +) +from qcodes.validators import Numbers + + +def test_records_get_and_set() -> None: + param = Parameter("p", set_cmd=None, get_cmd=None, unit="V", initial_value=0.0) + + with record_parameter_accesses() as accesses: + param(1.5) + assert param() == 1.5 + + assert [(a.parameter_name, a.kind, a.value, a.unit) for a in accesses] == [ + ("p", "set", 1.5, "V"), + ("p", "get", 1.5, "V"), + ] + assert all(a.error is None for a in accesses) + assert all(a.duration >= 0 for a in accesses) + assert all(a.timestamp > 0 for a in accesses) + + +def test_records_names_not_objects() -> None: + instrument = DummyInstrument("recorded_dac", gates=["ch1"]) + try: + with record_parameter_accesses() as accesses: + instrument.ch1(0.5) + finally: + instrument.close() + + (access,) = accesses + assert access.parameter_name == "recorded_dac_ch1" + assert access.instrument_name == "recorded_dac" + # A record is data: it holds no reference to a parameter or instrument. + for field_value in (access.parameter_name, access.instrument_name, access.unit): + assert isinstance(field_value, str) + with pytest.raises(AttributeError): + access.parameter # type: ignore[attr-defined] # noqa: B018 + + +def test_records_are_immutable() -> None: + param = Parameter("p", set_cmd=None) + with record_parameter_accesses() as accesses: + param(1) + + with pytest.raises(AttributeError): + accesses[0].value = 2 # type: ignore[misc] + + +def test_records_raw_values() -> None: + raw = {"value": 0.0} + param = Parameter( + "p", + set_cmd=lambda value: raw.update(value=value), + get_cmd=lambda: raw["value"], + scale=10, + ) + + with record_parameter_accesses() as accesses: + param(2) + assert param() == 2 + + set_access, get_access = accesses + assert (set_access.value, set_access.raw_value) == (2, 20) + assert (get_access.value, get_access.raw_value) == (2, 20) + + +def test_records_every_ramp_step() -> None: + param = Parameter("p", set_cmd=None, get_cmd=None, initial_value=0) + param.step = 1 + + with record_parameter_accesses() as accesses: + param(3) + + assert [(a.kind, a.value) for a in accesses] == [ + ("set", 1), + ("set", 2), + ("set", 3), + ] + + +def test_records_failed_get() -> None: + def fail() -> float: + raise RuntimeError("instrument did not answer") + + param = Parameter("p", get_cmd=fail) + + with ( + record_parameter_accesses() as accesses, + pytest.raises(RuntimeError, match="instrument did not answer"), + ): + param() + + (access,) = accesses + assert access.kind == "get" + assert access.value is None + assert access.raw_value is None + assert access.error == "RuntimeError: instrument did not answer" + + +def test_records_failed_set() -> None: + def fail(value: float) -> None: + raise RuntimeError("instrument refused") + + param = Parameter("p", set_cmd=fail) + + with ( + record_parameter_accesses() as accesses, + pytest.raises(RuntimeError, match="instrument refused"), + ): + param(1) + + (access,) = accesses + assert (access.kind, access.value) == ("set", 1) + assert access.error == "RuntimeError: instrument refused" + + +def test_invalid_value_is_not_an_access() -> None: + param = Parameter("p", set_cmd=None, vals=Numbers(0, 1)) + + with record_parameter_accesses() as accesses, pytest.raises(ValueError): + param(5) + + assert accesses == [] + + +def test_delegate_and_source_are_both_recorded() -> None: + source = Parameter("source", set_cmd=None, get_cmd=None, initial_value=0) + delegate = DelegateParameter("delegate", source=source) + + with record_parameter_accesses() as accesses: + delegate(1) + + assert [(a.parameter_name, a.kind) for a in accesses] == [ + ("source", "set"), + ("delegate", "set"), + ] + + +def test_recording_is_independent_of_on_set_callback() -> None: + callback_values: list[Any] = [] + param = Parameter( + "p", + set_cmd=None, + on_set_callback=lambda _param, value: callback_values.append(value), + ) + + with record_parameter_accesses() as accesses: + param(1) + + assert callback_values == [1] + assert [(a.kind, a.value) for a in accesses] == [("set", 1)] + + +def test_nothing_is_recorded_outside_the_block() -> None: + param = Parameter("p", set_cmd=None, get_cmd=None) + + with record_parameter_accesses() as accesses: + param(1) + param(2) + + assert [a.value for a in accesses] == [1] + + +def test_records_into_a_given_list() -> None: + param = Parameter("p", set_cmd=None) + records: list[ParameterAccess] = [] + + with record_parameter_accesses(records) as accesses: + param(1) + + assert accesses is records + assert [a.value for a in records] == [1] + + +@pytest.mark.parametrize("records", [(), set(), UserList(), type("L", (list,), {})()]) +def test_only_a_plain_list_is_accepted(records: Any) -> None: + with ( + pytest.raises(TypeError, match="only be recorded in a list"), + record_parameter_accesses(records), + ): + pass + + +def test_nested_recordings_both_record() -> None: + param = Parameter("p", set_cmd=None) + + with record_parameter_accesses() as outer: + param(1) + with record_parameter_accesses() as inner: + param(2) + param(3) + + assert [a.value for a in outer] == [1, 2, 3] + assert [a.value for a in inner] == [2] + + +def test_other_threads_are_not_recorded() -> None: + param = Parameter("p", set_cmd=None) + + with record_parameter_accesses() as accesses: + worker = threading.Thread(target=param, args=(1,)) + worker.start() + worker.join() + param(2) + + assert [a.value for a in accesses] == [2] + + +def test_recording_follows_asyncio_tasks() -> None: + param = Parameter("p", set_cmd=None) + + async def set_in_task(value: float) -> None: + param(value) + + async def main() -> list[ParameterAccess]: + with record_parameter_accesses() as recorded: + # A task runs in a copy of the context it was created in. + await asyncio.create_task(set_in_task(1)) + await asyncio.create_task(set_in_task(2)) + return recorded + + assert [a.value for a in asyncio.run(main())] == [1] + + +def test_logs_accesses(caplog: pytest.LogCaptureFixture) -> None: + param = Parameter("logged_p", set_cmd=None, get_cmd=None) + + with caplog.at_level(logging.DEBUG, logger="qcodes.parameters.parameter_access"): + with log_parameter_accesses(): + param(1) + param() + # Not logged: outside the block. + param(2) + + records = [ + r for r in caplog.records if r.name == "qcodes.parameters.parameter_access" + ] + assert [r.getMessage() for r in records] == [ + "set logged_p = 1", + "get logged_p = 1", + ] + access = records[0].parameter_access # type: ignore[attr-defined] + assert isinstance(access, ParameterAccess) + assert records[0].parameter_name == "logged_p" # type: ignore[attr-defined] + + +def test_logs_failed_accesses(caplog: pytest.LogCaptureFixture) -> None: + def fail(value: float) -> None: + raise RuntimeError("instrument refused") + + param = Parameter("logged_p", set_cmd=fail) + + with ( + caplog.at_level(logging.INFO, logger="qcodes.parameters.parameter_access"), + log_parameter_accesses(logging.INFO), + pytest.raises(RuntimeError), + ): + param(1) + + (record,) = [ + r for r in caplog.records if r.name == "qcodes.parameters.parameter_access" + ] + assert record.levelno == logging.INFO + assert ( + record.getMessage() == "set logged_p failed: RuntimeError: instrument refused" + ) + + +def test_recording_and_logging_together(caplog: pytest.LogCaptureFixture) -> None: + param = Parameter("p", set_cmd=None) + + with ( + caplog.at_level(logging.DEBUG, logger="qcodes.parameters.parameter_access"), + record_parameter_accesses() as accesses, + log_parameter_accesses(), + ): + param(1) + + assert [a.value for a in accesses] == [1] + assert any(r.name == "qcodes.parameters.parameter_access" for r in caplog.records) diff --git a/tests/parameter/test_parameter_observers.py b/tests/parameter/test_parameter_observers.py deleted file mode 100644 index 26ddb9eade1f..000000000000 --- a/tests/parameter/test_parameter_observers.py +++ /dev/null @@ -1,193 +0,0 @@ -from __future__ import annotations - -import threading -from typing import TYPE_CHECKING, Any - -import pytest - -from qcodes.parameters import ( - DelegateParameter, - Parameter, - ParameterAccess, - add_parameter_observer, - observe_parameters, - registered_parameter_observers, - remove_parameter_observer, -) -from qcodes.validators import Numbers - -if TYPE_CHECKING: - from collections.abc import Iterator - - -@pytest.fixture -def accesses() -> Iterator[list[ParameterAccess]]: - recorded: list[ParameterAccess] = [] - with observe_parameters(recorded.append): - yield recorded - - -def test_observer_sees_get_and_set(accesses: list[ParameterAccess]) -> None: - param = Parameter("p", set_cmd=None, get_cmd=None, initial_value=0.0) - accesses.clear() - - param(1.5) - assert param() == 1.5 - - assert [(a.parameter, a.kind, a.value) for a in accesses] == [ - (param, "set", 1.5), - (param, "get", 1.5), - ] - assert all(a.exception is None for a in accesses) - assert all(a.duration >= 0 for a in accesses) - assert all(a.timestamp > 0 for a in accesses) - - -def test_observer_sees_raw_values(accesses: list[ParameterAccess]) -> None: - raw = {"value": 0.0} - param = Parameter( - "p", - set_cmd=lambda value: raw.update(value=value), - get_cmd=lambda: raw["value"], - scale=10, - ) - - param(2) - assert param() == 2 - - set_access, get_access = accesses - assert (set_access.value, set_access.raw_value) == (2, 20) - assert (get_access.value, get_access.raw_value) == (2, 20) - - -def test_observer_sees_every_ramp_step(accesses: list[ParameterAccess]) -> None: - param = Parameter("p", set_cmd=None, get_cmd=None, initial_value=0) - param.step = 1 - accesses.clear() - - param(3) - - assert [(a.kind, a.value) for a in accesses] == [ - ("set", 1), - ("set", 2), - ("set", 3), - ] - - -def test_observer_sees_failed_get(accesses: list[ParameterAccess]) -> None: - def fail() -> float: - raise RuntimeError("instrument did not answer") - - param = Parameter("p", get_cmd=fail) - - with pytest.raises(RuntimeError, match="instrument did not answer"): - param() - - (access,) = accesses - assert access.kind == "get" - assert access.value is None - assert access.raw_value is None - assert isinstance(access.exception, RuntimeError) - - -def test_observer_sees_failed_set(accesses: list[ParameterAccess]) -> None: - def fail(value: float) -> None: - raise RuntimeError("instrument refused") - - param = Parameter("p", set_cmd=fail) - - with pytest.raises(RuntimeError, match="instrument refused"): - param(1) - - (access,) = accesses - assert (access.kind, access.value) == ("set", 1) - assert isinstance(access.exception, RuntimeError) - - -def test_invalid_value_is_not_an_access(accesses: list[ParameterAccess]) -> None: - param = Parameter("p", set_cmd=None, vals=Numbers(0, 1)) - - with pytest.raises(ValueError): - param(5) - - assert accesses == [] - - -def test_delegate_and_source_are_both_reported( - accesses: list[ParameterAccess], -) -> None: - source = Parameter("source", set_cmd=None, get_cmd=None, initial_value=0) - delegate = DelegateParameter("delegate", source=source) - accesses.clear() - - delegate(1) - - assert [(a.parameter, a.kind) for a in accesses] == [ - (source, "set"), - (delegate, "set"), - ] - - -def test_observer_is_independent_of_on_set_callback( - accesses: list[ParameterAccess], -) -> None: - callback_values: list[Any] = [] - param = Parameter( - "p", - set_cmd=None, - on_set_callback=lambda _param, value: callback_values.append(value), - ) - - param(1) - - assert callback_values == [1] - assert [(a.kind, a.value) for a in accesses] == [("set", 1)] - - -def test_failing_observer_does_not_affect_access( - caplog: pytest.LogCaptureFixture, -) -> None: - def broken(access: ParameterAccess) -> None: - raise ValueError("observer bug") - - recorded: list[ParameterAccess] = [] - param = Parameter("p", set_cmd=None, get_cmd=None) - with observe_parameters(broken), observe_parameters(recorded.append): - param(1) - - assert param.cache.get() == 1 - assert [a.kind for a in recorded] == ["set"] - assert "Exception in parameter observer" in caplog.text - - -def test_add_and_remove_observer() -> None: - recorded: list[ParameterAccess] = [] - param = Parameter("p", set_cmd=None, get_cmd=None) - - add_parameter_observer(recorded.append) - assert recorded.append in registered_parameter_observers() - param(1) - remove_parameter_observer(recorded.append) - param(2) - - assert [a.value for a in recorded] == [1] - assert recorded.append not in registered_parameter_observers() - - -def test_remove_unknown_observer_raises() -> None: - with pytest.raises(ValueError): - remove_parameter_observer(lambda access: None) - - -def test_observers_are_called_on_the_accessing_thread( - accesses: list[ParameterAccess], -) -> None: - threads: list[threading.Thread] = [] - param = Parameter("p", set_cmd=None, get_cmd=None) - - with observe_parameters(lambda access: threads.append(threading.current_thread())): - worker = threading.Thread(target=param, args=(1,)) - worker.start() - worker.join() - - assert threads == [worker] From fc2ea8d408a8b0fdbb136fb49e50abe1f4a453b3 Mon Sep 17 00:00:00 2001 From: "Jens H. Nielsen" Date: Fri, 30 Oct 2026 16:01:27 +0100 Subject: [PATCH 4/4] Name the newsfragment after PR 8684 Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../newsfragments/{+parameter_access_recording.new => 8684.new} | 0 1 file changed, 0 insertions(+), 0 deletions(-) rename docs/changes/newsfragments/{+parameter_access_recording.new => 8684.new} (100%) diff --git a/docs/changes/newsfragments/+parameter_access_recording.new b/docs/changes/newsfragments/8684.new similarity index 100% rename from docs/changes/newsfragments/+parameter_access_recording.new rename to docs/changes/newsfragments/8684.new