From dbff2523c6ebf3369bab305babf7fec85c8a6a3d Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Thu, 30 May 2024 16:07:59 -0700 Subject: [PATCH 01/12] REF/ENH/TST: refactor typhos status, improve user experience with timeout messages --- typhos/func.py | 7 +- typhos/positioner.py | 66 ++++++++++++------- typhos/status.py | 98 +++++++++++++++++++++------- typhos/tests/test_positioner.py | 3 +- typhos/tests/test_status.py | 109 +++++++++++++++++++++++++++++--- 5 files changed, 224 insertions(+), 59 deletions(-) diff --git a/typhos/func.py b/typhos/func.py index 257d6d320..911138342 100644 --- a/typhos/func.py +++ b/typhos/func.py @@ -592,12 +592,9 @@ def status_finished(result): self._status_thread.status_started.connect(status_started) self._status_thread.status_finished.connect(status_finished) + # Re-enable the button if it's taking too long + self._status_thread.status_timeout.connect(status_finished) - # Connect the finished signal so that even in the worst case - # scenario, we re-enable the button. Almost always the button will - # be ended by the status_finished signal - self._status_thread.finished.connect(partial(status_finished, - True)) logger.debug("Starting TyphosStatusThread ...") self._status_thread.start() diff --git a/typhos/positioner.py b/typhos/positioner.py index 598ff2567..961944fb1 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -16,7 +16,7 @@ from . import dynamic_font, utils, widgets from .alarm import AlarmLevel, KindLevel, _KindLevel from .panel import SignalOrder, TyphosSignalPanel -from .status import TyphosStatusThread +from .status import TyphosStatusResult, TyphosStatusThread logger = logging.getLogger(__name__) @@ -195,18 +195,32 @@ def _clear_status_thread(self): self._status_thread.disconnect() self._status_thread = None - def _start_status_thread(self, status, timeout): + def _start_status_thread( + self, + status: ophyd.StatusBase, + timeout: float, + timeout_desc: str, + ) -> None: """Start the status monitoring thread for the given status object.""" self._status_thread = thread = TyphosStatusThread( - status, start_delay=self._min_visible_operation, + status, + error_context="Move", + timeout_calc=timeout_desc, + start_delay=self._min_visible_operation, timeout=timeout, parent=self, ) - thread.status_started.connect(self.move_changed) + thread.status_started.connect(self._move_started) thread.status_finished.connect(self._status_finished) + thread.error_message.connect(self._set_status_text) thread.start() - def _get_timeout(self, set_position: float, settle_time: float, rescale: float = 1) -> float | None: + def _get_timeout( + self, + set_position: float, + settle_time: float, + rescale: float = 1, + ) -> tuple[float | None, str]: """ Use positioner's configuration to select a timeout. @@ -250,19 +264,22 @@ def _get_timeout(self, set_position: float, settle_time: float, rescale: float = acc_sig = getattr(self.device, self._acceleration_attr, None) # Not enough info == no timeout if pos_sig is None or vel_sig is None: - return None + return (None, "no timeout, missing info") delta = pos_sig.get() - set_position speed = vel_sig.get() # Bad speed == no timeout if speed == 0: - return None + return (None, "no timeout, speed == 0") # Bad acceleration == ignore acceleration if acc_sig is None: acc_time = 0 else: acc_time = acc_sig.get() # This time is always greater than the kinematic calc - return rescale * (abs(delta/speed) + 2 * abs(acc_time)) + abs(settle_time) + return ( + rescale * (abs(delta/speed) + 2 * abs(acc_time)) + abs(settle_time), + "dist {delta} / velo {speed} + 2 * acc_time {acc_time} + margin", + ) def _set(self, value): """Inner `set` routine - call device.set() and monitor the status.""" @@ -275,7 +292,7 @@ def _set(self, value): try: # Always at least 5s, give 20% extra time as margin for long moves - timeout = self._get_timeout(set_position, settle_time=5, rescale=1.2) + timeout, desc = self._get_timeout(set_position, settle_time=5, rescale=1.2) except Exception: # Something went wrong, just run without a timeout. logger.exception('Unable to estimate motor timeout.') @@ -290,7 +307,7 @@ def _set(self, value): self._status_finished(exc) else: # Send timeout through thread because status timeout stops the move - self._start_status_thread(status, timeout) + self._start_status_thread(status, timeout, desc) @QtCore.Slot(int) def combo_set(self, index): @@ -719,12 +736,13 @@ def alarmKindLevel(self, kind_level: KindLevel): if kind_level != self.alarmKindLevel: self.ui.alarm_circle.kindLevel = kind_level - def move_changed(self): + def _move_started(self) -> None: """Called when a move is begun""" logger.debug("Begin showing move in TyphosPositionerWidget") self.moving = True + self.err_is_timeout = False - def _set_status_text(self, text, *, max_length=60): + def _set_status_text(self, text: str, *, max_length: int = 60) -> None: """Set the status text label to ``text``.""" if len(text) >= max_length: self.ui.status_label.setToolTip(text) @@ -734,18 +752,22 @@ def _set_status_text(self, text, *, max_length=60): self.ui.status_label.setText(text) - def _status_finished(self, result): + def _status_finished(self, result: TyphosStatusResult | Exception) -> None: """Called when a move is complete.""" + success = False if isinstance(result, Exception): - text = f'{result.__class__.__name__} {result}' - else: - text = '' - - self._set_status_text(text) - - success = not isinstance(result, Exception) - logger.debug("Completed move in TyphosPositionerWidget (result=%r)", - result) + # Calling set or move completely broke + self._set_status_text(f"{result.__class__.__name__} {result}") + elif result == TyphosStatusResult.success: + # Clear the status display of any lingering timeout text + self._set_status_text("") + success = True + # Other cases: keep the existing status text, whatever it is. + # This covers any case where the move started, but had an error during the move. + logger.debug( + "Completed move in TyphosPositionerWidget (result=%r)", + result, + ) self._last_move = success self.moving = False diff --git a/typhos/status.py b/typhos/status.py index 032db6aa5..e22aae0a0 100644 --- a/typhos/status.py +++ b/typhos/status.py @@ -1,13 +1,21 @@ +from __future__ import annotations + +import enum import logging import time -from qtpy.QtCore import QThread, Signal +from ophyd.status import Status +from ophyd.utils import (StatusTimeoutError, UnknownStatusFailure, + WaitTimeoutError) +from qtpy.QtCore import QObject, QThread, Signal logger = logging.getLogger(__name__) -class GenericStatusFailure(Exception): - """A stand-in for a status value of ``False`` with no detailed info.""" +class TyphosStatusResult(enum.Enum): + success = enum.auto() + failure = enum.auto() + timeout = enum.auto() class TyphosStatusThread(QThread): @@ -42,40 +50,84 @@ class TyphosStatusThread(QThread): """ status_started = Signal() - status_finished = Signal(object) - - def __init__(self, status, start_delay=0., timeout=10.0, parent=None): + status_timeout = Signal() + status_finished = Signal(TyphosStatusResult) + error_message = Signal(str) + status_exc = Signal(object) + + def __init__( + self, + status: Status, + error_context: str = "Status", + timeout_calc: str = "", + start_delay: float = 0., + timeout: float = 10.0, + parent: QObject | None = None, + ): super().__init__(parent=parent) self.status = status + self.error_context = error_context + self.timeout_calc = timeout_calc self.start_delay = start_delay self.timeout = timeout - def run(self): + def run(self) -> None: """Monitor status object status and emit signals.""" # Don't do anything if we are handed a finished status if self.status.done: logger.debug("Status already completed.") - self._wait_and_emit_finished() + self.wait_and_emit_finished() return # Wait to emit to avoid too much flashing time.sleep(self.start_delay) self.status_started.emit() - self._wait_and_emit_finished() - - def _wait_and_emit_finished(self): + self.wait_and_emit_finished() + + def wait_and_emit_finished(self) -> None: + result = self.wait_and_get_result(use_timeout=True) + if result == TyphosStatusResult.timeout: + result = self.wait_and_get_result(use_timeout=False) + logger.debug("Emitting finished: %r", result) + self.status_finished.emit(result) + + def wait_and_get_result(self, use_timeout: bool) -> TyphosStatusResult: + if use_timeout: + timeout = self.timeout + else: + timeout = None try: - self.status.wait(timeout=self.timeout) - except TimeoutError as ex: - # May be a WaitTimeoutError or a StatusTimeoutError - logger.error("%s: Status %r did not complete in %s seconds", - type(ex).__name__, self.status, self.timeout) - finished_value = ex + self.status.wait(timeout=timeout) + except WaitTimeoutError as ex: + # Status doesn't have a timeout, but this thread does + errmsg = f"{self.error_context} taking longer than expected, > {timeout}s" + if self.timeout_calc: + errmsg += f": {self.timeout_calc}" + logger.debug(errmsg) + self.error_message.emit(errmsg) + self.status_timeout.emit() + self.status_exc.emit(ex) + return TyphosStatusResult.timeout + except StatusTimeoutError as ex: + # Status has an intrinsic timeout, and it's failing now + errmsg = f"{self.error_context} failed with timeout, > {self.status.timeout}s" + logger.debug(errmsg) + self.error_message.emit(errmsg) + self.status_exc.emit(ex) + return TyphosStatusResult.failure + except UnknownStatusFailure as ex: + # Status has failed, but no reason was given. + errmsg = f"{self.error_context} failed with no reason given." + logger.debug(errmsg) + self.error_message.emit(errmsg) + self.status_exc.emit(ex) + return TyphosStatusResult.failure except Exception as ex: - logger.exception('Status wait failed') - finished_value = ex + # There is some other status failure, and it has a specific exception. + logger.debug("Status failed", exc_info=True) + self.error_message.emit(str(ex)) + self.status_exc.emit(ex) + return TyphosStatusResult.failure else: - finished_value = self.status.success or GenericStatusFailure() - - logger.debug("Emitting finished: %r", finished_value) - self.status_finished.emit(finished_value) + # This is only reachable if the status wait succeeds + return TyphosStatusResult.success diff --git a/typhos/tests/test_positioner.py b/typhos/tests/test_positioner.py index a94f80b30..56db0c4e5 100644 --- a/typhos/tests/test_positioner.py +++ b/typhos/tests/test_positioner.py @@ -10,6 +10,7 @@ from typhos.alarm import KindLevel from typhos.positioner import TyphosPositionerWidget +from typhos.status import TyphosStatusResult from typhos.utils import SignalRO from .conftest import RichSignal, show_widget @@ -158,7 +159,7 @@ def test_positioner_widget_last_move(motor_widget): motor, widget = motor_widget assert not widget.successful_move assert not widget.failed_move - widget._status_finished(True) + widget._status_finished(TyphosStatusResult.success) assert widget.successful_move assert not widget.failed_move widget._status_finished(Exception()) diff --git a/typhos/tests/test_status.py b/typhos/tests/test_status.py index b4f959cee..7be3c63fb 100644 --- a/typhos/tests/test_status.py +++ b/typhos/tests/test_status.py @@ -2,9 +2,11 @@ import pytest from ophyd.status import Status +from ophyd.utils import (StatusTimeoutError, UnknownStatusFailure, + WaitTimeoutError) from qtpy.QtWidgets import QWidget -from typhos.status import TyphosStatusThread +from typhos.status import TyphosStatusResult, TyphosStatusThread class Listener(QWidget): @@ -13,7 +15,10 @@ class Listener(QWidget): def __init__(self): super().__init__() self.started = Mock() + self.timeout = Mock() self.finished = Mock() + self.err_msg = Mock() + self.exc = Mock() @pytest.fixture(scope='function') @@ -33,31 +38,119 @@ def listener(qtbot, status): def thread(qtbot, status, listener): thread = TyphosStatusThread(status) thread.status_started.connect(listener.started) + thread.status_timeout.connect(listener.timeout) thread.status_finished.connect(listener.finished) + thread.error_message.connect(listener.err_msg) + thread.status_exc.connect(listener.exc) yield thread if thread.isRunning(): thread.quit() def test_previously_done_status_in_thread(listener, status, thread): + """ + Expected behavior: thread finishes without starting if already done + """ status.set_finished() status.wait() thread.run() assert not listener.started.called + assert not listener.timeout.called assert listener.finished.called + assert not listener.err_msg.called + assert not listener.exc.called def test_status_thread_completed(qtbot, listener, status, thread): + """ + Expected behavior: thread doesn't finish until status does + """ thread.start() qtbot.waitUntil(lambda: listener.started.called, timeout=2000) status.set_finished() qtbot.waitUntil(lambda: listener.finished.called, timeout=2000) + assert not listener.timeout.called + assert not listener.err_msg.called + assert not listener.exc.called + res, = listener.finished.call_args[0] + assert res == TyphosStatusResult.success + + +def test_status_thread_wait_timeout(qtbot, listener, thread, status): + """ + Expected behavior: thread times out but doesn't outright fail + """ + thread.timeout = 0.1 + thread.start() + qtbot.waitUntil(lambda: listener.started.called, timeout=2000) + qtbot.waitUntil(lambda: listener.timeout.called, timeout=2000) + msg, = listener.err_msg.call_args[0] + exc, = listener.exc.call_args[0] + assert "taking longer than expected" in msg + assert isinstance(exc, WaitTimeoutError) + assert not listener.finished.called + # and now we should be able to finish + status.set_finished() + qtbot.waitUntil(lambda: listener.finished.called, timeout=2000) + res, = listener.finished.call_args[0] + assert res == TyphosStatusResult.success -def test_status_thread_timeout(listener, thread, status): - thread.timeout = 0.01 - thread.run() - assert listener.started.called - - ex, = listener.finished.call_args[0] - assert isinstance(ex, TimeoutError) +def test_status_thread_status_timeout(qtbot, listener, thread): + """ + Expected behavior: the status fails, so the thread does too + """ + status = Status(timeout=0.1) + thread.status = status + thread.start() + qtbot.waitUntil(lambda: listener.started.called, timeout=2000) + qtbot.waitUntil(lambda: listener.err_msg.called, timeout=2000) + qtbot.waitUntil(lambda: listener.exc.called, timeout=2000) + qtbot.waitUntil(lambda: listener.finished.called, timeout=2000) + res, = listener.finished.call_args[0] + msg, = listener.err_msg.call_args[0] + exc, = listener.exc.call_args[0] + assert res == TyphosStatusResult.failure + assert "failed with timeout" in msg + assert isinstance(exc, StatusTimeoutError) + assert not listener.timeout.called + + +def test_status_thread_unk_failure(qtbot, listener, status, thread): + """ + Expected behavior: the thread fails when the status does + """ + thread.start() + qtbot.waitUntil(lambda: listener.started.called, timeout=2000) + status._finished(success=False) + qtbot.waitUntil(lambda: listener.err_msg.called, timeout=2000) + qtbot.waitUntil(lambda: listener.exc.called, timeout=2000) + qtbot.waitUntil(lambda: listener.finished.called, timeout=2000) + res, = listener.finished.call_args[0] + msg, = listener.err_msg.call_args[0] + exc, = listener.exc.call_args[0] + assert res == TyphosStatusResult.failure + assert "failed with no reason" in msg + assert isinstance(exc, UnknownStatusFailure) + assert not listener.timeout.called + + +def test_status_thread_specific_failure(qtbot, listener, status, thread): + """ + Expected behavior: the thread fails when the status does + """ + thread.start() + qtbot.waitUntil(lambda: listener.started.called, timeout=2000) + status.set_exception(Exception("test_error")) + qtbot.waitUntil(lambda: listener.err_msg.called, timeout=2000) + qtbot.waitUntil(lambda: listener.exc.called, timeout=2000) + qtbot.waitUntil(lambda: listener.finished.called, timeout=2000) + res, = listener.finished.call_args[0] + msg, = listener.err_msg.call_args[0] + exc, = listener.exc.call_args[0] + assert res == TyphosStatusResult.failure + assert "test_error" in msg + assert not isinstance(exc, WaitTimeoutError) + assert not isinstance(exc, StatusTimeoutError) + assert not isinstance(exc, UnknownStatusFailure) + assert not listener.timeout.called From 904937c3d8c84f5a8cf19fc00cdee4d700158084 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Thu, 30 May 2024 17:02:50 -0700 Subject: [PATCH 02/12] ENH: nitpick timeout message formatting --- typhos/positioner.py | 12 +++++++----- typhos/status.py | 6 +++--- typhos/ui/widgets/positioner_row.ui | 2 +- 3 files changed, 11 insertions(+), 9 deletions(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index 961944fb1..a5dc7b81a 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -275,10 +275,11 @@ def _get_timeout( acc_time = 0 else: acc_time = acc_sig.get() + units = pos_sig.metadata.get("units", "egu") # This time is always greater than the kinematic calc return ( rescale * (abs(delta/speed) + 2 * abs(acc_time)) + abs(settle_time), - "dist {delta} / velo {speed} + 2 * acc_time {acc_time} + margin", + f"{rescale}*({abs(delta):.2f}{units}/{speed:.2f}{units}/s) + 2*{acc_time:.2f}s + {settle_time}s", ) def _set(self, value): @@ -742,14 +743,15 @@ def _move_started(self) -> None: self.moving = True self.err_is_timeout = False - def _set_status_text(self, text: str, *, max_length: int = 60) -> None: + def _set_status_text(self, text: str, *, max_length: int | None = 60) -> None: """Set the status text label to ``text``.""" - if len(text) >= max_length: + if max_length is None: + self.ui.status_label.setToolTip(text) + elif len(text) >= max_length: self.ui.status_label.setToolTip(text) text = text[:max_length] + '...' else: self.ui.status_label.setToolTip('') - self.ui.status_label.setText(text) def _status_finished(self, result: TyphosStatusResult | Exception) -> None: @@ -1035,7 +1037,7 @@ def _link_error_message(self, signal, widget): def new_error_message(self, value, *args, **kwargs): self.update_status_visibility(error_message=value) - def _set_status_text(self, text, *, max_length=80): + def _set_status_text(self, text, *, max_length=None): super()._set_status_text(text, max_length=max_length) self.update_status_visibility(status_text=text) diff --git a/typhos/status.py b/typhos/status.py index e22aae0a0..7c19c8668 100644 --- a/typhos/status.py +++ b/typhos/status.py @@ -100,9 +100,9 @@ def wait_and_get_result(self, use_timeout: bool) -> TyphosStatusResult: self.status.wait(timeout=timeout) except WaitTimeoutError as ex: # Status doesn't have a timeout, but this thread does - errmsg = f"{self.error_context} taking longer than expected, > {timeout}s" + errmsg = f"{self.error_context} taking longer than expected, >{timeout:.2f}s" if self.timeout_calc: - errmsg += f": {self.timeout_calc}" + errmsg += f", calculated as {self.timeout_calc}" logger.debug(errmsg) self.error_message.emit(errmsg) self.status_timeout.emit() @@ -110,7 +110,7 @@ def wait_and_get_result(self, use_timeout: bool) -> TyphosStatusResult: return TyphosStatusResult.timeout except StatusTimeoutError as ex: # Status has an intrinsic timeout, and it's failing now - errmsg = f"{self.error_context} failed with timeout, > {self.status.timeout}s" + errmsg = f"{self.error_context} failed with timeout, >{self.status.timeout:.2f}s" logger.debug(errmsg) self.error_message.emit(errmsg) self.status_exc.emit(ex) diff --git a/typhos/ui/widgets/positioner_row.ui b/typhos/ui/widgets/positioner_row.ui index d68c42d67..4f3926f22 100644 --- a/typhos/ui/widgets/positioner_row.ui +++ b/typhos/ui/widgets/positioner_row.ui @@ -1118,7 +1118,7 @@ Screen (Status label) - true + false 0 From 0b1360756e4b839e8a204c920bfc004834a09ce6 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Thu, 30 May 2024 17:20:30 -0700 Subject: [PATCH 03/12] ENH: avoid duplicate error text in row widget --- typhos/positioner.py | 12 +++- typhos/ui/widgets/positioner_row.ui | 97 ++++++++++++++++++++--------- 2 files changed, 77 insertions(+), 32 deletions(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index a5dc7b81a..c2f935c5d 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -859,6 +859,7 @@ class _TyphosPositionerRowUI(_TyphosPositionerUI): notes_edit: TyphosNotesEdit status_container_widget: QtWidgets.QFrame extended_signal_panel: Optional[TyphosSignalPanel] + status_error_prefix: QtWidgets.QLabel error_prefix: QtWidgets.QLabel switcher: TyphosDisplaySwitcher @@ -1057,8 +1058,10 @@ def update_status_visibility( The goal here to make an illusion that there is only one label in in this space when only one of the labels has text. - If both are empty, we also want to put "something" there to fill the + If both are empty, we want to put "something" there to fill the void, so we opt for a friendly message or an alarm reminder. + + If both are populated, we want to do some best-effort deduplication. """ if error_message is not None: self._error_message = error_message @@ -1078,7 +1081,14 @@ def update_status_visibility( else: self.ui.status_label.setText('Check alarm') has_status = True + has_status_error = False + if has_status and has_error: + # We want to avoid having duplicate information (low effort try) + if error_message in status_text: + has_error = False + has_status_error = True self.ui.status_label.setVisible(has_status) + self.ui.status_error_prefix.setVisible(has_status_error) self.ui.error_label.setVisible(has_error) self.ui.error_prefix.setVisible(has_error) diff --git a/typhos/ui/widgets/positioner_row.ui b/typhos/ui/widgets/positioner_row.ui index 4f3926f22..a900ae989 100644 --- a/typhos/ui/widgets/positioner_row.ui +++ b/typhos/ui/widgets/positioner_row.ui @@ -1091,39 +1091,74 @@ Screen 3 - - - - - 0 - 0 - - - - - 0 - 25 - - - - - 16777215 - 25 - - - - color: black; background-color: none; border-radius: 0px; - - - (Status label) - - - false - - + + + 0 - + + + + + 0 + 0 + + + + + 0 + 25 + + + + + 16777215 + 25 + + + + color: red + + + Error: + + + + + + + + 0 + 0 + + + + + 0 + 25 + + + + + 16777215 + 25 + + + + color: black; background-color: none; border-radius: 0px; + + + (Status label) + + + false + + + 0 + + + + From ce50db6dfa63da9fe5c619adf999e0ebd35d99f4 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 18:56:30 +0000 Subject: [PATCH 04/12] ENH: split status message into explicit text and tooltip portions --- typhos/positioner.py | 68 +++++++++++++++++++++++++++++++++++++------- typhos/status.py | 46 ++++++++++++++++++++++++------ 2 files changed, 95 insertions(+), 19 deletions(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index c2f935c5d..ed9dbdf11 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -16,7 +16,7 @@ from . import dynamic_font, utils, widgets from .alarm import AlarmLevel, KindLevel, _KindLevel from .panel import SignalOrder, TyphosSignalPanel -from .status import TyphosStatusResult, TyphosStatusThread +from .status import TyphosStatusMessage, TyphosStatusResult, TyphosStatusThread logger = logging.getLogger(__name__) @@ -743,16 +743,56 @@ def _move_started(self) -> None: self.moving = True self.err_is_timeout = False - def _set_status_text(self, text: str, *, max_length: int | None = 60) -> None: - """Set the status text label to ``text``.""" - if max_length is None: - self.ui.status_label.setToolTip(text) - elif len(text) >= max_length: - self.ui.status_label.setToolTip(text) - text = text[:max_length] + '...' + def _set_status_text( + self, + message: TyphosStatusMessage | str, + *, + max_length: int | None = 60, + ) -> str: + """ + Set the status text label to the contents of ``message``. + + Message is either a simple string or a dataclass that + has a separate entry for the text and for the tooltip. + + Simple strings or empty string tooltips will result in + a widget with no tooltip, unless the message is longer + than the max length. + + Messages that are longer than the max length will be + truncated and also included in the tooltip. + + Parameters + ---------- + message : TyphosStatusMessage or str + The message to include in the status text. + max_length : int or None, optional + The maximum length for the status text before it gets + truncated and moved to the tooltip. If this is manually + set to ``None``, there will be no limit. + + Returns + ------- + text : str + The text that is displayed in the status label, which + may be truncated. + """ + if isinstance(message, TyphosStatusMessage): + text = message.text + tooltip = message.tooltip + elif isinstance(message, str): + text = message + tooltip = "" + if max_length is None or len(text) < max_length: + self.ui.status_label.setToolTip(tooltip) else: - self.ui.status_label.setToolTip('') + if tooltip: + self.ui.status_label.setToolTip(f"{text}: {tooltip}") + else: + self.ui.status_label.setToolTip(f"{text}") + text = message.text[:max_length] + '...' self.ui.status_label.setText(text) + return text def _status_finished(self, result: TyphosStatusResult | Exception) -> None: """Called when a move is complete.""" @@ -1038,9 +1078,15 @@ def _link_error_message(self, signal, widget): def new_error_message(self, value, *args, **kwargs): self.update_status_visibility(error_message=value) - def _set_status_text(self, text, *, max_length=None): - super()._set_status_text(text, max_length=max_length) + def _set_status_text( + self, + message: TyphosStatusMessage | str, + *, + max_length: int | None = None, + ) -> str: + text = super()._set_status_text(message, max_length=max_length) self.update_status_visibility(status_text=text) + return text def update_alarm_text(self, alarm_level): super().update_alarm_text(alarm_level=alarm_level) diff --git a/typhos/status.py b/typhos/status.py index 7c19c8668..e69fa2b20 100644 --- a/typhos/status.py +++ b/typhos/status.py @@ -1,8 +1,10 @@ from __future__ import annotations +import dataclasses import enum import logging import time +import traceback from ophyd.status import Status from ophyd.utils import (StatusTimeoutError, UnknownStatusFailure, @@ -18,6 +20,12 @@ class TyphosStatusResult(enum.Enum): timeout = enum.auto() +@dataclasses.dataclass +class TyphosStatusMessage: + text: str + tooltip: str + + class TyphosStatusThread(QThread): """ Thread which monitors an ophyd Status object and emits start/stop signals. @@ -52,7 +60,7 @@ class TyphosStatusThread(QThread): status_started = Signal() status_timeout = Signal() status_finished = Signal(TyphosStatusResult) - error_message = Signal(str) + error_message = Signal(TyphosStatusMessage) status_exc = Signal(object) def __init__( @@ -100,11 +108,18 @@ def wait_and_get_result(self, use_timeout: bool) -> TyphosStatusResult: self.status.wait(timeout=timeout) except WaitTimeoutError as ex: # Status doesn't have a timeout, but this thread does - errmsg = f"{self.error_context} taking longer than expected, >{timeout:.2f}s" + errmsg = f"{self.error_context} taking longer than expected, >{timeout}s" if self.timeout_calc: - errmsg += f", calculated as {self.timeout_calc}" - logger.debug(errmsg) - self.error_message.emit(errmsg) + tooltip = f"calculated as {self.timeout_calc}" + else: + tooltip = "" + self.error_message.emit( + TyphosStatusMessage( + text=errmsg, + tooltip=tooltip, + ) + ) + logger.debug(f"{errmsg}, {tooltip}") self.status_timeout.emit() self.status_exc.emit(ex) return TyphosStatusResult.timeout @@ -112,20 +127,35 @@ def wait_and_get_result(self, use_timeout: bool) -> TyphosStatusResult: # Status has an intrinsic timeout, and it's failing now errmsg = f"{self.error_context} failed with timeout, >{self.status.timeout:.2f}s" logger.debug(errmsg) - self.error_message.emit(errmsg) + self.error_message.emit( + TyphosStatusMessage( + text=errmsg, + tooltip="", + ) + ) self.status_exc.emit(ex) return TyphosStatusResult.failure except UnknownStatusFailure as ex: # Status has failed, but no reason was given. errmsg = f"{self.error_context} failed with no reason given." logger.debug(errmsg) - self.error_message.emit(errmsg) + self.error_message.emit( + TyphosStatusMessage( + text=errmsg, + tooltip="", + ) + ) self.status_exc.emit(ex) return TyphosStatusResult.failure except Exception as ex: # There is some other status failure, and it has a specific exception. logger.debug("Status failed", exc_info=True) - self.error_message.emit(str(ex)) + self.error_message.emit( + TyphosStatusMessage( + text=str(ex), + tooltip=traceback.format_exc(), + ) + ) self.status_exc.emit(ex) return TyphosStatusResult.failure else: From 47f2b36067ca3709171d4867387825b470344ba6 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 20:54:07 +0000 Subject: [PATCH 05/12] ENH: round timeout up to the nearest integer --- typhos/positioner.py | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index ed9dbdf11..31fcb4850 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -2,6 +2,7 @@ import inspect import logging +import math import os.path import threading import typing @@ -220,7 +221,7 @@ def _get_timeout( set_position: float, settle_time: float, rescale: float = 1, - ) -> tuple[float | None, str]: + ) -> tuple[int | None, str]: """ Use positioner's configuration to select a timeout. @@ -255,9 +256,10 @@ def _get_timeout( Returns ------- - timeout : float or None + timeout : tuple[int or None, str] The timeout to use for this move, or None if a timeout could - not be calculated. + not be calculated, bundled with an explanation on how it + was calculated. """ pos_sig = getattr(self.device, self._readback_attr, None) vel_sig = getattr(self.device, self._velocity_attr, None) @@ -278,8 +280,9 @@ def _get_timeout( units = pos_sig.metadata.get("units", "egu") # This time is always greater than the kinematic calc return ( - rescale * (abs(delta/speed) + 2 * abs(acc_time)) + abs(settle_time), - f"{rescale}*({abs(delta):.2f}{units}/{speed:.2f}{units}/s) + 2*{acc_time:.2f}s + {settle_time}s", + math.ceil(rescale * (abs(delta/speed) + 2 * abs(acc_time)) + abs(settle_time)), + (f"{rescale}*({abs(delta):.2f}{units}/{speed:.2f}{units}/s) + " + f"2*{acc_time:.2f}s + {settle_time}s, rounded up"), ) def _set(self, value): From 7dbbc7c4d236ae1e231f095690853364970aa32d Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 22:06:19 +0000 Subject: [PATCH 06/12] DOC: pre-release notes --- .../606-enh_wait_status.rst | 28 +++++++++++++++++++ 1 file changed, 28 insertions(+) create mode 100644 docs/source/upcoming_release_notes/606-enh_wait_status.rst diff --git a/docs/source/upcoming_release_notes/606-enh_wait_status.rst b/docs/source/upcoming_release_notes/606-enh_wait_status.rst new file mode 100644 index 000000000..ba43e5c0e --- /dev/null +++ b/docs/source/upcoming_release_notes/606-enh_wait_status.rst @@ -0,0 +1,28 @@ +606 enh_wait_status +################### + +API Breaks +---------- +- ``TyphosStatusThread`` now has a dramatically different signal API. + This is an improved version but if you were using this class take note + of the changes. + +Features +-------- +- Make the timeout messages friendlier and more accurate when the + timeouts come from the ``TyphosPositionerWidget``. +- Make error messages in general (including status timeouts) clearer + when they come from the positioner device class controlled by the + ``TyphosPositionerWidget``. + +Bugfixes +-------- +- N/A + +Maintenance +----------- +- Refactor ``TyphosStatusThread`` to facilitate timeout message changes. + +Contributors +------------ +- zllentz From 2bf97de75940dc911ed43c429b2687d6997624f6 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 22:08:11 +0000 Subject: [PATCH 07/12] TST: account for api change in new tests --- typhos/tests/test_status.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/typhos/tests/test_status.py b/typhos/tests/test_status.py index 7be3c63fb..47fa03ce7 100644 --- a/typhos/tests/test_status.py +++ b/typhos/tests/test_status.py @@ -86,7 +86,7 @@ def test_status_thread_wait_timeout(qtbot, listener, thread, status): qtbot.waitUntil(lambda: listener.timeout.called, timeout=2000) msg, = listener.err_msg.call_args[0] exc, = listener.exc.call_args[0] - assert "taking longer than expected" in msg + assert "taking longer than expected" in msg.text assert isinstance(exc, WaitTimeoutError) assert not listener.finished.called # and now we should be able to finish @@ -111,7 +111,7 @@ def test_status_thread_status_timeout(qtbot, listener, thread): msg, = listener.err_msg.call_args[0] exc, = listener.exc.call_args[0] assert res == TyphosStatusResult.failure - assert "failed with timeout" in msg + assert "failed with timeout" in msg.text assert isinstance(exc, StatusTimeoutError) assert not listener.timeout.called @@ -130,7 +130,7 @@ def test_status_thread_unk_failure(qtbot, listener, status, thread): msg, = listener.err_msg.call_args[0] exc, = listener.exc.call_args[0] assert res == TyphosStatusResult.failure - assert "failed with no reason" in msg + assert "failed with no reason" in msg.text assert isinstance(exc, UnknownStatusFailure) assert not listener.timeout.called @@ -149,7 +149,7 @@ def test_status_thread_specific_failure(qtbot, listener, status, thread): msg, = listener.err_msg.call_args[0] exc, = listener.exc.call_args[0] assert res == TyphosStatusResult.failure - assert "test_error" in msg + assert "test_error" in msg.text assert not isinstance(exc, WaitTimeoutError) assert not isinstance(exc, StatusTimeoutError) assert not isinstance(exc, UnknownStatusFailure) From 9120a88cfab5fc0921b6a495132dd7deafd3c71e Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 22:42:04 +0000 Subject: [PATCH 08/12] ENH: make tooltip text even more verbose and clear --- typhos/positioner.py | 23 +++++++++++++++-------- typhos/status.py | 2 +- 2 files changed, 16 insertions(+), 9 deletions(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index 31fcb4850..e75c6da09 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -279,10 +279,15 @@ def _get_timeout( acc_time = acc_sig.get() units = pos_sig.metadata.get("units", "egu") # This time is always greater than the kinematic calc + dist = abs(delta) + speed = abs(speed) + mult = rescale return ( - math.ceil(rescale * (abs(delta/speed) + 2 * abs(acc_time)) + abs(settle_time)), - (f"{rescale}*({abs(delta):.2f}{units}/{speed:.2f}{units}/s) + " - f"2*{acc_time:.2f}s + {settle_time}s, rounded up"), + math.ceil(rescale * (delta/speed + 2 * abs(acc_time)) + abs(settle_time)), + ("an upper bound on the expected time based on the speed, distance traveled, " + "and acceleration time. Numerically, this is " + f"{mult=}*({dist=:.2f}{units}/{speed=:.2f}{units}/s) + " + f"2*{acc_time=:.2f}s + {settle_time=}s, rounded up."), ) def _set(self, value): @@ -786,15 +791,17 @@ def _set_status_text( elif isinstance(message, str): text = message tooltip = "" - if max_length is None or len(text) < max_length: - self.ui.status_label.setToolTip(tooltip) - else: + if max_length is not None and len(text) >= max_length: if tooltip: - self.ui.status_label.setToolTip(f"{text}: {tooltip}") + tooltip = f"{text}: {tooltip}" else: - self.ui.status_label.setToolTip(f"{text}") + tooltip = text text = message.text[:max_length] + '...' self.ui.status_label.setText(text) + if tooltip and "\n" not in tooltip: + # Force rich text, qt auto line wraps if it detects rich text + tooltip = f"

{tooltip}

" + self.ui.status_label.setToolTip(tooltip) return text def _status_finished(self, result: TyphosStatusResult | Exception) -> None: diff --git a/typhos/status.py b/typhos/status.py index e69fa2b20..859fc8498 100644 --- a/typhos/status.py +++ b/typhos/status.py @@ -110,7 +110,7 @@ def wait_and_get_result(self, use_timeout: bool) -> TyphosStatusResult: # Status doesn't have a timeout, but this thread does errmsg = f"{self.error_context} taking longer than expected, >{timeout}s" if self.timeout_calc: - tooltip = f"calculated as {self.timeout_calc}" + tooltip = f"Calculated as {self.timeout_calc}" else: tooltip = "" self.error_message.emit( From f1fa1339c1e1dbe39cc779cdc9c49462ae8f4d6b Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 22:49:44 +0000 Subject: [PATCH 09/12] FIX: weird tooltip styling --- typhos/ui/widgets/positioner_row.ui | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/typhos/ui/widgets/positioner_row.ui b/typhos/ui/widgets/positioner_row.ui index a900ae989..24e92f7e3 100644 --- a/typhos/ui/widgets/positioner_row.ui +++ b/typhos/ui/widgets/positioner_row.ui @@ -1145,7 +1145,7 @@ Screen - color: black; background-color: none; border-radius: 0px; + QLabel { color: black; background-color: none; border-radius: 0px; } (Status label) From a19290231b436d865d005558f81e290c1d73ed50 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 22:50:56 +0000 Subject: [PATCH 10/12] FIX: accidentally broke the timeout calc --- typhos/positioner.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index e75c6da09..b7ae91f82 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -278,12 +278,13 @@ def _get_timeout( else: acc_time = acc_sig.get() units = pos_sig.metadata.get("units", "egu") - # This time is always greater than the kinematic calc + # Some friendly names for the f-string tooltip reporting dist = abs(delta) speed = abs(speed) mult = rescale + # This time is always greater than the kinematic calc return ( - math.ceil(rescale * (delta/speed + 2 * abs(acc_time)) + abs(settle_time)), + math.ceil(rescale * (dist/speed + 2 * abs(acc_time)) + abs(settle_time)), ("an upper bound on the expected time based on the speed, distance traveled, " "and acceleration time. Numerically, this is " f"{mult=}*({dist=:.2f}{units}/{speed=:.2f}{units}/s) + " From be0a6fc88094a7213d6d725099e9162dbd5df475 Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 23:26:35 +0000 Subject: [PATCH 11/12] MAINT: remove vestigial boolean --- typhos/positioner.py | 1 - 1 file changed, 1 deletion(-) diff --git a/typhos/positioner.py b/typhos/positioner.py index b7ae91f82..5fe441437 100644 --- a/typhos/positioner.py +++ b/typhos/positioner.py @@ -750,7 +750,6 @@ def _move_started(self) -> None: """Called when a move is begun""" logger.debug("Begin showing move in TyphosPositionerWidget") self.moving = True - self.err_is_timeout = False def _set_status_text( self, From 17fa11ce906a2e77fdbd3940ff902b633c3418ea Mon Sep 17 00:00:00 2001 From: Zachary Lentz Date: Tue, 4 Jun 2024 23:34:28 +0000 Subject: [PATCH 12/12] DOC: document new TyphosStatusThread signal APIs --- typhos/status.py | 27 +++++++++++++++++++++++---- 1 file changed, 23 insertions(+), 4 deletions(-) diff --git a/typhos/status.py b/typhos/status.py index 859fc8498..a95d5f935 100644 --- a/typhos/status.py +++ b/typhos/status.py @@ -31,10 +31,29 @@ class TyphosStatusThread(QThread): Thread which monitors an ophyd Status object and emits start/stop signals. The ``status_started`` signal may be emitted after ``start_delay`` seconds, - unless the status has already completed. - - The ``status_finished`` signal is guaranteed to be emitted with a status - boolean indicating success or failure, or timeout. + unless the status has already completed, in which case it will not be + emitted. + + The ``status_timeout`` signal will be emitted if the status starts and the + timeout supplied to the ``TyphosStatusThread`` expires. This is distinct + from an internal timeout from a status object, which is an error. + The ``status_timeout`` is advisory rather than perscriptive and does not + necessarily indicate a severe problem. If you want a status to be marked + as failing after a timeout, pass the timeout to the status's constructor. + + The ``status_finished`` signal is guaranteed to be emitted after the status + completes or fails, with a ``TyphosStatusResult`` enum set to + ``success`` or to ``failure``. + + The ``error_message`` signal emits some information that could be useful + for a GUI to display an error. This is a ``TyphosStatusMessage`` which + contains a short error under ``.text`` and a longer message under + ``.tooltip``, intended for e.g. a label and its mouseover tooltip text. + This will not be emitted if the status succeeds. + + The ``status_exc`` signal emits the literal exception object from a + status failure. This will not be emitted if the status succeeds. + This can be useful for customizing what to do in the case of failure. Parameters ----------