From 4f49a6673ea4fe6079ba69dd851b2321591d2a36 Mon Sep 17 00:00:00 2001 From: Osayi-ANL Date: Fri, 9 Oct 2026 15:03:19 -0500 Subject: [PATCH 1/3] =?UTF-8?q?fix:=20restore=20live=20HKL=20calculation?= =?UTF-8?q?=20=E2=80=94=20explicit=20HKL.SPEC=20energy/UB=20channels=20win?= =?UTF-8?q?=20over=20generated=20defaults,=20hkl=5Fsetup=20no=20longer=20r?= =?UTF-8?q?equests=20the=20removed=20motor-name=20fields,=20and=20a=20NaN?= =?UTF-8?q?=20motor=20position=20fails=20setup=20with=20a=20logged=20error?= =?UTF-8?q?=20instead=20of=20silently=20giving=20NaN=20HKL?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- src/dashpva/utils/config/resolver.py | 5 +- .../viewer/area_det/area_det_viewer.py | 22 ++------- tests/unit/test_area_det_hkl.py | 49 +++++++++++++++++++ tests/unit/test_config_resolution.py | 16 ++++++ 4 files changed, 72 insertions(+), 20 deletions(-) create mode 100644 tests/unit/test_area_det_hkl.py diff --git a/src/dashpva/utils/config/resolver.py b/src/dashpva/utils/config/resolver.py index 2ceb72c0..73bb6017 100644 --- a/src/dashpva/utils/config/resolver.py +++ b/src/dashpva/utils/config/resolver.py @@ -156,7 +156,10 @@ def resolve_profile_config(raw: Mapping[str, Any] | None) -> dict[str, Any]: } if parameters.get("ENERGY_UNITS") is not None: spec["ENERGY_UNITS"] = _pv(prefix, "spec:Energy:Units") - _managed_section(hkl, "SPEC", spec) + configured_spec = hkl.pop("SPEC", None) + if isinstance(configured_spec, Mapping): + spec.update(configured_spec) + hkl["SPEC"] = spec for name, record, aliases in ( ("PRIMARY_BEAM_DIRECTION", "PrimaryBeamDirection", ()), diff --git a/src/dashpva/viewer/area_det/area_det_viewer.py b/src/dashpva/viewer/area_det/area_det_viewer.py index 4dcaf944..3e74d438 100644 --- a/src/dashpva/viewer/area_det/area_det_viewer.py +++ b/src/dashpva/viewer/area_det/area_det_viewer.py @@ -2008,10 +2008,11 @@ def _values(channels, description): missing = [ channel for channel, value in zip(channels, values) - if value is None + if value is None or ( + isinstance(value, (int, float, np.number)) and not np.isfinite(value)) ] if missing: - raise ValueError(f"Missing {description} PV data: {missing}") + raise ValueError(f"Missing or non-finite {description} PV data: {missing}") return values self.sample_circle_directions = _values( @@ -2022,14 +2023,6 @@ def _values(channels, description): axis_field_channels(self.hkl_config, 'sample', 'POSITION'), 'sample circle position', ) - self.sample_circle_names = _values( - axis_field_channels( - self.hkl_config, - 'sample', - required=False, - ), - 'sample circle motor name', - ) self.det_circle_directions = _values( axis_field_channels(self.hkl_config, 'detector', 'DIRECTION_AXIS'), 'detector circle direction', @@ -2038,15 +2031,6 @@ def _values(channels, description): axis_field_channels(self.hkl_config, 'detector', 'POSITION'), 'detector circle position', ) - self.det_circle_names = _values( - axis_field_channels( - self.hkl_config, - 'detector', - required=False, - ), - 'detector circle motor name', - ) - vector_fields = ('AXIS_NUMBER_1', 'AXIS_NUMBER_2', 'AXIS_NUMBER_3') self.primary_beam_directions = _values( section_field_channels( diff --git a/tests/unit/test_area_det_hkl.py b/tests/unit/test_area_det_hkl.py new file mode 100644 index 00000000..ac45e296 --- /dev/null +++ b/tests/unit/test_area_det_hkl.py @@ -0,0 +1,49 @@ +"""Focused regressions for Area Detector live HKL setup.""" + +import inspect +from types import SimpleNamespace + +import pytest + +pytest.importorskip("PyQt5") +pytest.importorskip("pyqtgraph") + +from dashpva.viewer.area_det import area_det_viewer as mod # noqa: E402 + +VIEWER = mod.DiffractionImageWindow + + +def _code(obj) -> str: + return "\n".join( + line for line in inspect.getsource(obj).splitlines() + if not line.lstrip().startswith("#") + ) + + +def test_hkl_setup_does_not_request_removed_motor_name_fields(): + setup = _code(VIEWER.hkl_setup) + assert "sample_circle_names" not in setup + assert "det_circle_names" not in setup + + +def test_nan_motor_position_fails_setup_with_a_logged_error(monkeypatch, capsys): + monkeypatch.setattr( + mod, "axis_field_channels", + lambda config, kind, field=None, **kw: [f"{kind}:{field}"], + ) + errors = [] + window = SimpleNamespace( + hkl_config={}, + stop_hkl=SimpleNamespace(isChecked=lambda: False), + hkl_data={"sample:DIRECTION_AXIS": "z-", "sample:POSITION": float("nan")}, + logger=SimpleNamespace(error=errors.append), + rsm_geometry_ready=True, + _rsm_geometry_cache=object(), + _rsm_geometry_cache_key=object(), + ) + + VIEWER.hkl_setup(window) + + reported = "".join(errors) + capsys.readouterr().out + assert window.rsm_geometry_ready is False + assert "sample:POSITION" in reported and "non-finite" in reported diff --git a/tests/unit/test_config_resolution.py b/tests/unit/test_config_resolution.py index 8ac34974..458ab162 100644 --- a/tests/unit/test_config_resolution.py +++ b/tests/unit/test_config_resolution.py @@ -105,6 +105,22 @@ def test_canonical_profile_generates_managed_hkl_without_mutating_raw(): assert "SAMPLE_SURFACE_NORMAL_DIRECITON" not in effective["HKL"] +def test_explicit_spec_channels_override_generated_ioc_defaults(): + raw = _canonical_profile() + raw["HKL"]["SPEC"] = { + "ENERGY_VALUE": "beamline:energy", + "UB_MATRIX_VALUE": "beamline:ub", + } + + effective = resolve_profile_config(raw) + + assert effective["HKL"]["SPEC"] == { + "ENERGY_VALUE": "beamline:energy", + "UB_MATRIX_VALUE": "beamline:ub", + "ENERGY_UNITS": "6idb:spec:Energy:Units", + } + + def test_empty_canonical_axis_lists_remove_all_legacy_managed_axes(): raw = _canonical_profile() raw["HKL"]["MU"] = {"POSITION": "legacy:mu"} From 9c05c870536a52f3c27afbf148702a6d585677b0 Mon Sep 17 00:00:00 2001 From: Osayi-ANL Date: Fri, 9 Oct 2026 15:03:19 -0500 Subject: [PATCH 2/3] fix: throttle live HKL updates to PREVIEW['HKL_UPDATE_INTERVAL_MS'] (500 ms) instead of a fixed 100 ms --- src/dashpva/settings.py | 1 + src/dashpva/viewer/area_det/area_det_viewer.py | 7 +++++-- tests/unit/test_area_det_hkl.py | 9 +++++++++ 3 files changed, 15 insertions(+), 2 deletions(-) diff --git a/src/dashpva/settings.py b/src/dashpva/settings.py index 68ed69f6..2cfe0997 100644 --- a/src/dashpva/settings.py +++ b/src/dashpva/settings.py @@ -249,6 +249,7 @@ def resolve_profile_config(raw): "AUTOSCALE_SAMPLES_PER_AXIS": 256, "HKL_MAX_POINTS": 1_000_000, "HKL_MAX_FRAMES": 100, + "HKL_UPDATE_INTERVAL_MS": 500, "LABEL_INTERVAL_MS": 100, "MIN_TIMER_INTERVAL_MS": 1, } diff --git a/src/dashpva/viewer/area_det/area_det_viewer.py b/src/dashpva/viewer/area_det/area_det_viewer.py index 3e74d438..44785970 100644 --- a/src/dashpva/viewer/area_det/area_det_viewer.py +++ b/src/dashpva/viewer/area_det/area_det_viewer.py @@ -297,7 +297,9 @@ def __init__(self, input_channel='pvapy:image'): self.rsm_geometry_ready = False self._hkl_update_timer = QTimer(self) self._hkl_update_timer.setSingleShot(True) - self._hkl_update_timer.setInterval(100) + self._hkl_update_timer.setInterval( + app_settings.PREVIEW['HKL_UPDATE_INTERVAL_MS'] + ) self._hkl_update_timer.timeout.connect(self.handle_hkl_data_update) self._rsm_geometry_cache = None self._rsm_geometry_cache_key = None @@ -1975,7 +1977,8 @@ def hkl_ca_callback(self, pvname, value, **kwargs) -> None: def _schedule_hkl_update(self, _value=True) -> None: """Coalesce bursts of hkl_data_updated emits (one per HKL axis PV - tick) into a single handle_hkl_data_update() call at ~10 fps.""" + tick) and cap expensive full-frame HKL recalculation at the configured + preview interval.""" if not self._hkl_update_timer.isActive(): self._hkl_update_timer.start() diff --git a/tests/unit/test_area_det_hkl.py b/tests/unit/test_area_det_hkl.py index ac45e296..e0885710 100644 --- a/tests/unit/test_area_det_hkl.py +++ b/tests/unit/test_area_det_hkl.py @@ -47,3 +47,12 @@ def test_nan_motor_position_fails_setup_with_a_logged_error(monkeypatch, capsys) reported = "".join(errors) + capsys.readouterr().out assert window.rsm_geometry_ready is False assert "sample:POSITION" in reported and "non-finite" in reported + + +def test_hkl_updates_use_the_configured_preview_throttle(): + source = _code(VIEWER.__init__) + assert "app_settings.PREVIEW['HKL_UPDATE_INTERVAL_MS']" in source + assert mod.app_settings.PREVIEW_DEFAULTS['HKL_UPDATE_INTERVAL_MS'] == 500 + assert mod.app_settings.preview_settings({ + 'PREVIEW': {'HKL_UPDATE_INTERVAL_MS': 250}, + })['HKL_UPDATE_INTERVAL_MS'] == 250 From 3c8a63686a9865e8b428feaf1d9d2976b569f8f2 Mon Sep 17 00:00:00 2001 From: Osayi-ANL Date: Fri, 9 Oct 2026 15:03:19 -0500 Subject: [PATCH 3/3] =?UTF-8?q?add:=20LogManager=20repeat=20filter=20?= =?UTF-8?q?=E2=80=94=20the=20HKL=20calculation=20runs=20every=20frame,=20s?= =?UTF-8?q?o=20one=20failure=20would=20write=20the=20same=20error=20to=20t?= =?UTF-8?q?he=20log=20thousands=20of=20times;=20with=20drop=5Frepeats=20a?= =?UTF-8?q?=20repeated=20message=20is=20written=20once=20per=20repeat=5Fwi?= =?UTF-8?q?ndow=20(default=2060=20s)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit change: area detector HKL messages go through its logger with drop_repeats instead of print() --- src/dashpva/utils/log_manager.py | 43 ++++++++++++++-- .../viewer/area_det/area_det_viewer.py | 24 +++++---- src/dashpva/viewer/core/base_window.py | 5 +- tests/unit/test_area_det_hkl.py | 4 ++ tests/unit/test_log_repeat_filter.py | 49 +++++++++++++++++++ 5 files changed, 110 insertions(+), 15 deletions(-) create mode 100644 tests/unit/test_log_repeat_filter.py diff --git a/src/dashpva/utils/log_manager.py b/src/dashpva/utils/log_manager.py index ea9f214e..64870cc8 100644 --- a/src/dashpva/utils/log_manager.py +++ b/src/dashpva/utils/log_manager.py @@ -86,6 +86,25 @@ def filter(self, record: logging.LogRecord) -> bool: # type: ignore[override] return True +class RepeatFilter(logging.Filter): + """Drop a record whose level and text already went out within ``window`` seconds.""" + + def __init__(self, window: float): + super().__init__() + self.window = float(window) + self._last = {} + + def filter(self, record: logging.LogRecord) -> bool: + key = (record.levelno, record.getMessage()) + last = self._last.get(key) + if last is not None and record.created - last < self.window: + return False + if len(self._last) > 1000: + self._last = {k: t for k, t in self._last.items() if record.created - t < self.window} + self._last[key] = record.created + return True + + class LogManager: """ Central logging manager with a single RotatingFileHandler. @@ -103,8 +122,10 @@ class LogManager: separated regex). If not set, defaults are applied. """ - def __init__(self, app: QApplication = None, app_name: str = "DashPVA", log_file: str = "logs/general.log"): + def __init__(self, app: QApplication = None, app_name: str = "DashPVA", log_file: str = "logs/general.log", + *, repeat_window: float = 60): self.app = app + self.repeat_window = repeat_window self.app_name = app_name # Resolve log path from settings module; fallback to provided default if settings.LOG_PATH: @@ -177,9 +198,20 @@ def __init__(self, app: QApplication = None, app_name: str = "DashPVA", log_file # Install global excepthook self.enable_global_excepthook() - def get_logger(self, name: str) -> logging.Logger: - """Return a logger named as provided, ensuring our rotating file handler is attached once.""" + def get_logger(self, name: str, drop_repeats: bool = False) -> logging.Logger: + """Return a logger named as provided, ensuring our rotating file handler is attached once. + + drop_repeats=True writes the same message at the same level at most once per + ``repeat_window`` seconds (set on the manager, default 60). + + Usage: + logger = get_default_manager().get_logger("Area Detector", drop_repeats=True) + for _ in range(1000): + logger.error("[HKL] setup failed: missing Energy:Value") # written once a minute + """ logger = logging.getLogger(str(name) if name else self.app_name) + if drop_repeats and not any(isinstance(f, RepeatFilter) for f in logger.filters): + logger.addFilter(RepeatFilter(self.repeat_window)) logger.setLevel(self.level) # Avoid duplicate propagation to root to keep single sink logger.propagate = False @@ -224,7 +256,8 @@ def get_default_manager(app: QApplication = None) -> LogManager: class LogMixin: """Mixin providing a drop-in self.logger backed by LogManager.""" - def set_log_manager(self, manager: LogManager = None, viewer_name: str = None) -> None: + def set_log_manager(self, manager: LogManager = None, viewer_name: str = None, + drop_repeats: bool = False) -> None: mgr = manager or get_default_manager() # Allow caller to set/override viewer_name if viewer_name is not None: @@ -233,6 +266,6 @@ def set_log_manager(self, manager: LogManager = None, viewer_name: str = None) - except Exception: self.viewer_name = None name = getattr(self, "viewer_name", None) or f"{self.__module__}.{self.__class__.__name__}" - self.logger = mgr.get_logger(name) + self.logger = mgr.get_logger(name, drop_repeats=drop_repeats) \ No newline at end of file diff --git a/src/dashpva/viewer/area_det/area_det_viewer.py b/src/dashpva/viewer/area_det/area_det_viewer.py index 44785970..e2530572 100644 --- a/src/dashpva/viewer/area_det/area_det_viewer.py +++ b/src/dashpva/viewer/area_det/area_det_viewer.py @@ -198,6 +198,7 @@ class DiffractionImageWindow(BaseWindow): #: area_det_* keys in __init__ -- both running would restore twice, the #: second from an empty key. Dropped when it migrates onto the shared store. persist_state = False + log_drop_repeats = True hkl_data_updated = pyqtSignal(bool) # Emitted from the ROI/Stats connection thread so update_status can run on @@ -1945,14 +1946,19 @@ def start_hkl_monitors(self) -> None: # Share the live HKL values with the reader so its per-frame merge # saves them into the scan H5 (the associator may not attach them). self.reader.hkl_values = self.hkl_data - missing = [n for n, v in self.hkl_data.items() if v is None] - got = len(self.hkl_data) - len(missing) - print(f"[Diffraction Image Viewer] HKL monitors started: " - f"{got}/{len(self.hkl_data)} PVs returned values" - + (f"; missing/None: {missing}" if missing else "")) + got = sum(1 for value in self.hkl_data.values() if value is not None) + self.logger.info( + f'[HKL] {got} of {len(self.hkl_data)} PVs returned values') + missing = [ + name for name, value in self.hkl_data.items() if value is None + ] + if missing: + self.logger.error( + f'[HKL] monitor initialization failed: no value from ' + f'{len(missing)} channel(s): {", ".join(missing)}') self.hkl_data_updated.emit(True) except Exception as e: - print(f"[Diffraction Image Viewer] Failed to initialize HKL monitors: {e}") + self.logger.error(f'[HKL] monitor initialization failed: {e or type(e).__name__}') def hkl_ca_callback(self, pvname, value, **kwargs) -> None: """ @@ -2000,7 +2006,7 @@ def handle_hkl_data_update(self): if self.rsm_geometry_ready: self.update_rsm() except Exception as e: - print(f'[DashPVA] HKL update failed (will retry next frame): {e}') + self.logger.error(f'[HKL] update failed: {e or type(e).__name__}') def hkl_setup(self) -> None: @@ -2100,7 +2106,7 @@ def _values(channels, description): self.rsm_geometry_ready = True except Exception as e: - print(f'[Diffraction Image Viewer] Error Setting up HKL: {e}') + self.logger.error(f'[HKL] setup failed: {e or type(e).__name__}') self.rsm_geometry_ready = False self._rsm_geometry_cache = None self._rsm_geometry_cache_key = None @@ -2176,7 +2182,7 @@ def create_rsm(self) -> np.ndarray: self.det_circle_positions, ) except Exception as e: - print(f'[Diffration Image Viewer] Error Creating RSM: {e}') + self.logger.error(f'[HKL] RSM calculation failed: {e or type(e).__name__}') return else: return diff --git a/src/dashpva/viewer/core/base_window.py b/src/dashpva/viewer/core/base_window.py index 67915b45..11dcb7d8 100644 --- a/src/dashpva/viewer/core/base_window.py +++ b/src/dashpva/viewer/core/base_window.py @@ -76,6 +76,9 @@ class BaseWindow(QMainWindow): #: number shared across viewers would retire every other layout as well. dock_state_version: int = app_settings.DOCK_STATE_VERSION + #: True drops a message this viewer already logged within the LogManager's repeat_window. + log_drop_repeats = False + def __init__(self, ui_file_name=None, viewer_name=None, log_manager: LogManager = None, visible_actions=_SHOW_ALL, size_policy: dict = None): """ @@ -104,7 +107,7 @@ def __init__(self, ui_file_name=None, viewer_name=None, log_manager: LogManager try: logger_name = self.viewer_name or f"{self.__module__}.{self.__class__.__name__}" if self._log_manager is not None: - self.logger = self._log_manager.get_logger(logger_name) + self.logger = self._log_manager.get_logger(logger_name, drop_repeats=self.log_drop_repeats) else: import logging as _logging self.logger = _logging.getLogger(logger_name) diff --git a/tests/unit/test_area_det_hkl.py b/tests/unit/test_area_det_hkl.py index e0885710..d9ba79a7 100644 --- a/tests/unit/test_area_det_hkl.py +++ b/tests/unit/test_area_det_hkl.py @@ -20,6 +20,10 @@ def _code(obj) -> str: ) +def test_area_detector_logger_drops_repeated_hkl_errors(): + assert VIEWER.log_drop_repeats is True + + def test_hkl_setup_does_not_request_removed_motor_name_fields(): setup = _code(VIEWER.hkl_setup) assert "sample_circle_names" not in setup diff --git a/tests/unit/test_log_repeat_filter.py b/tests/unit/test_log_repeat_filter.py new file mode 100644 index 00000000..1f46d7c9 --- /dev/null +++ b/tests/unit/test_log_repeat_filter.py @@ -0,0 +1,49 @@ +"""LogManager repeat suppression is opt-in per logger.""" + +import logging + +from dashpva.utils import log_manager + + +def _manager(monkeypatch, tmp_path): + monkeypatch.setattr(log_manager.settings, "LOG_PATH", str(tmp_path)) + monkeypatch.setattr(log_manager.sys, "excepthook", log_manager.sys.excepthook) + return log_manager.LogManager() + + +def _records(logger): + seen = [] + handler = logging.Handler() + handler.emit = seen.append + logger.addHandler(handler) + return seen + + +def test_repeat_window_writes_a_repeated_message_once(monkeypatch, tmp_path): + logger = _manager(monkeypatch, tmp_path).get_logger("repeat.on", drop_repeats=True) + seen = _records(logger) + for _ in range(5): + logger.error("[HKL] setup failed: missing Energy:Value") + logger.error("[HKL] setup failed: missing UB") + assert [r.getMessage() for r in seen] == [ + "[HKL] setup failed: missing Energy:Value", + "[HKL] setup failed: missing UB", + ] + + +def test_repeat_is_written_again_after_the_window(monkeypatch, tmp_path): + logger = _manager(monkeypatch, tmp_path).get_logger("repeat.window", drop_repeats=True) + seen = _records(logger) + times = iter([1000.0, 1030.0, 1061.0]) + monkeypatch.setattr(logging.time, "time", lambda: next(times)) + for _ in range(3): + logger.error("same") + assert len(seen) == 2 + + +def test_loggers_without_a_window_write_every_message(monkeypatch, tmp_path): + logger = _manager(monkeypatch, tmp_path).get_logger("repeat.off") + seen = _records(logger) + for _ in range(3): + logger.error("same") + assert len(seen) == 3