diff --git a/bec_widgets/utils/bec_widget.py b/bec_widgets/utils/bec_widget.py index 397b936e..33aa16ac 100644 --- a/bec_widgets/utils/bec_widget.py +++ b/bec_widgets/utils/bec_widget.py @@ -1,5 +1,6 @@ from __future__ import annotations +import threading from datetime import datetime from typing import TYPE_CHECKING @@ -327,17 +328,47 @@ class BECWidget(BECConnector): def cleanup(self): """Cleanup the widget.""" + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=cleanup:start | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)} | " + f"thread={threading.current_thread().name}:{threading.get_ident()} | " + f"destroyed={getattr(self, '_destroyed', None)}" + ) with RPCRegister.delayed_broadcast(): # All widgets need to call super().cleanup() in their cleanup method logger.info(f"Registry cleanup for widget {self.__class__.__name__}") self.rpc_register.remove_rpc(self) children = self.findChildren(BECWidget) + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=cleanup:children-found | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)} | child_count={len(children)}" + ) for child in children: if not shiboken6.isValid(child): # If the child is not valid, it means it has already been deleted + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=cleanup:skip-invalid-child | parent={self.objectName()} | " + f"parent_py_id={id(self)} | child_py_id={id(child)}" + ) continue + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=cleanup:closing-child | parent={self.objectName()} | " + f"parent_py_id={id(self)} | child_class={child.__class__.__name__} | " + f"child_object={child.objectName()} | child_py_id={id(child)} | " + f"child_destroyed={getattr(child, '_destroyed', None)}" + ) child.close() child.deleteLater() + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=cleanup:child-deleteLater-called | parent={self.objectName()} | " + f"parent_py_id={id(self)} | child_class={child.__class__.__name__} | " + f"child_object={child.objectName()} | child_py_id={id(child)}" + ) # Tear down busy overlay explicitly to stop spinner and remove filters overlay = getattr(self, "_busy_overlay", None) @@ -357,13 +388,54 @@ class BECWidget(BECConnector): overlay.deleteLater() except Exception as exc: logger.warning(f"Failed to delete busy overlay: {exc}") + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=cleanup:end | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)} | " + f"destroyed={getattr(self, '_destroyed', None)}" + ) def closeEvent(self, event): """Wrap the close even to ensure the rpc_register is cleaned up.""" + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=closeEvent:enter | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)} | " + f"thread={threading.current_thread().name}:{threading.get_ident()} | " + f"destroyed={getattr(self, '_destroyed', None)}" + ) try: if not self._destroyed: self.bec_dispatcher.disconnect_owner(self) + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=closeEvent:before-cleanup | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)}" + ) self.cleanup() self._destroyed = True + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=closeEvent:after-cleanup-set-destroyed | " + f"class={self.__class__.__name__} | object={self.objectName()} | " + f"py_id={id(self)} | destroyed={self._destroyed}" + ) + else: + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=closeEvent:already-destroyed | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)}" + ) finally: + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=closeEvent:calling-super | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)}" + ) super().closeEvent(event) # pylint: disable=no-member + logger.warning( + "BEC WIDGET LIFECYCLE TRACE | " + f"event=closeEvent:exit | class={self.__class__.__name__} | " + f"object={self.objectName()} | py_id={id(self)} | " + f"destroyed={getattr(self, '_destroyed', None)}" + ) diff --git a/bec_widgets/widgets/containers/dock_area/basic_dock_area.py b/bec_widgets/widgets/containers/dock_area/basic_dock_area.py index 088050ae..b794e40f 100644 --- a/bec_widgets/widgets/containers/dock_area/basic_dock_area.py +++ b/bec_widgets/widgets/containers/dock_area/basic_dock_area.py @@ -1,6 +1,7 @@ from __future__ import annotations import inspect +import threading from dataclasses import dataclass from typing import Any, Callable, Literal, Mapping, Sequence, cast @@ -166,9 +167,31 @@ class DockAreaWidget(BECWidget, QWidget): def _default_close_handler(self, dock: CDockWidget, widget: QWidget) -> None: """Default dock close routine used when no custom handler is provided.""" + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=default-close-handler:start | dock={dock.objectName()} | " + f"dock_py_id={id(dock)} | widget={widget.objectName()} | " + f"widget_class={widget.__class__.__name__} | widget_py_id={id(widget)} | " + f"thread={threading.current_thread().name}:{threading.get_ident()}" + ) widget.close() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=default-close-handler:after-widget-close | dock={dock.objectName()} | " + f"dock_valid={isValid(dock)} | widget={widget.objectName()} | " + f"widget_valid={isValid(widget)}" + ) dock.closeDockWidget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=default-close-handler:after-closeDockWidget | dock={dock.objectName()} | " + f"dock_valid={isValid(dock)}" + ) dock.deleteDockWidget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=default-close-handler:end | dock_py_id={id(dock)} | dock_valid={isValid(dock)}" + ) def close_dock(self, dock: CDockWidget, widget: QWidget | None = None) -> None: """ @@ -372,12 +395,45 @@ class DockAreaWidget(BECWidget, QWidget): close_handler = self._resolve_close_handler(widget, on_close) def on_widget_destroyed(): + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=widget_removed-signal:start | dock_py_id={id(dock)} | " + f"dock_valid={isValid(dock)} | widget={widget.objectName()} | " + f"widget_py_id={id(widget)} | thread={threading.current_thread().name}:{threading.get_ident()}" + ) if not isValid(dock): + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=widget_removed-signal:dock-invalid-return | dock_py_id={id(dock)}" + ) return dock.closeDockWidget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=widget_removed-signal:after-closeDockWidget | dock={dock.objectName()} | " + f"dock_valid={isValid(dock)}" + ) dock.deleteDockWidget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=widget_removed-signal:end | dock_py_id={id(dock)} | dock_valid={isValid(dock)}" + ) - dock.closeRequested.connect(lambda: close_handler(dock)) + def on_close_requested(): + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=closeRequested:start | dock={dock.objectName()} | dock_py_id={id(dock)} | " + f"widget={widget.objectName()} | widget_class={widget.__class__.__name__} | " + f"widget_py_id={id(widget)} | thread={threading.current_thread().name}:{threading.get_ident()}" + ) + close_handler(dock) + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=closeRequested:end | dock_py_id={id(dock)} | dock_valid={isValid(dock)} | " + f"widget_py_id={id(widget)} | widget_valid={isValid(widget)}" + ) + + dock.closeRequested.connect(on_close_requested) if hasattr(widget, "widget_removed"): widget.widget_removed.connect(on_widget_destroyed) @@ -410,13 +466,50 @@ class DockAreaWidget(BECWidget, QWidget): return dock def _delete_dock(self, dock: CDockWidget) -> None: + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:start | dock={dock.objectName()} | dock_py_id={id(dock)} | " + f"dock_valid={isValid(dock)} | thread={threading.current_thread().name}:{threading.get_ident()}" + ) widget = dock.widget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:widget-resolved | dock_py_id={id(dock)} | " + f"widget={widget.objectName() if widget else None} | " + f"widget_class={widget.__class__.__name__ if widget else None} | " + f"widget_py_id={id(widget) if widget else None} | " + f"widget_valid={isValid(widget) if widget else None}" + ) if widget and isValid(widget): widget.close() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:after-widget-close | dock_py_id={id(dock)} | " + f"widget={widget.objectName()} | widget_valid={isValid(widget)}" + ) widget.deleteLater() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:after-widget-deleteLater | dock_py_id={id(dock)} | " + f"widget_py_id={id(widget)} | widget_valid={isValid(widget)}" + ) if isValid(dock): dock.closeDockWidget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:after-closeDockWidget | dock={dock.objectName()} | " + f"dock_valid={isValid(dock)}" + ) dock.deleteDockWidget() + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:end | dock_py_id={id(dock)} | dock_valid={isValid(dock)}" + ) + else: + logger.warning( + "DOCK AREA LIFECYCLE TRACE | " + f"event=delete-dock:dock-invalid-skip | dock_py_id={id(dock)}" + ) def _resolve_dock_reference( self, ref: CDockWidget | QWidget | str | None, *, allow_none: bool = True diff --git a/bec_widgets/widgets/control/device_input/device_combobox/device_combobox.py b/bec_widgets/widgets/control/device_input/device_combobox/device_combobox.py index 7cbfcab3..b01f5aa8 100644 --- a/bec_widgets/widgets/control/device_input/device_combobox/device_combobox.py +++ b/bec_widgets/widgets/control/device_input/device_combobox/device_combobox.py @@ -3,6 +3,7 @@ from __future__ import annotations import enum +import threading from bec_lib.callback_handler import EventType from bec_lib.device import ComputedSignal, Device, Positioner, ReadoutPriority @@ -216,12 +217,27 @@ class DeviceComboBox(BECWidget, QComboBox): else: self.setCurrentText("") + self._log_callback_state("init: before DEVICE_UPDATE register") self._callback_id = self.bec_dispatcher.client.callbacks.register( EventType.DEVICE_UPDATE, self.on_device_update ) + self._log_callback_state("init: after DEVICE_UPDATE register") self.device_config_update.connect(self.update_devices_from_filters) + self._log_callback_state("init: device_config_update connected") self.currentTextChanged.connect(self.check_validity) self.check_validity(self.currentText()) + self._log_callback_state("init: finished") + + def _log_callback_state(self, event: str, **details) -> None: + logger.warning( + "DEVICE COMBOBOX CALLBACK TRACE | " + f"event={event} | object={self.objectName()} | py_id={id(self)} | " + f"thread={threading.current_thread().name}:{threading.get_ident()} | " + f"callback_id={getattr(self, '_callback_id', None)} | " + f"destroyed={getattr(self, '_destroyed', None)} | " + f"current={self.currentText()} | devices_count={len(getattr(self, '_devices', []))} | " + f"details={details}" + ) @staticmethod def _process_config(config: DeviceInputConfig | dict | None) -> DeviceInputConfig: @@ -255,16 +271,25 @@ class DeviceComboBox(BECWidget, QComboBox): @SafeSlot() def update_devices_from_filters(self): """Refresh the available device list from current device/readout/signal filters.""" + self._log_callback_state( + "update_devices_from_filters: enter", + apply_filter=self.apply_filter, + device_filter=[entry.value for entry in self.device_filter], + readout_filter=[entry.value for entry in self.readout_filter], + signal_class_filter=self.signal_class_filter, + ) self.config.device_filter = [entry.value for entry in self.device_filter] self.config.readout_filter = [entry.value for entry in self.readout_filter] self.config.signal_class_filter = self.signal_class_filter if not self.apply_filter: + self._log_callback_state("update_devices_from_filters: apply-filter false return") return devices = self._filter_devices_by_signal_class(self.dev.enabled_devices) devices = [device for device in devices if self._check_device_filter(device)] devices = [device for device in devices if self._check_readout_filter(device)] self.devices = [device.name for device in devices] + self._log_callback_state("update_devices_from_filters: finished") @SafeSlot(list) def set_available_devices(self, devices: list[str]): @@ -489,16 +514,26 @@ class DeviceComboBox(BECWidget, QComboBox): action: Device update action emitted by BEC. content: Device update payload. Currently unused. """ + self._log_callback_state("on_device_update: enter", action=action, content=content) if action in ["add", "remove", "reload"]: - logger.warning(f"DEVICE COMBOBOX UPDATE: {action} : {content}") + self._log_callback_state("on_device_update: emitting device_config_update") self.device_config_update.emit() + self._log_callback_state("on_device_update: emitted device_config_update") + else: + self._log_callback_state("on_device_update: ignored action", action=action) def cleanup(self): """Cleanup the widget.""" + self._log_callback_state("cleanup: start") if self._callback_id is not None: + self._log_callback_state("cleanup: removing callback") self.bec_dispatcher.client.callbacks.remove(self._callback_id) self._callback_id = None + self._log_callback_state("cleanup: callback removed") + else: + self._log_callback_state("cleanup: callback already None") super().cleanup() + self._log_callback_state("cleanup: after super") def get_current_device(self) -> object: """Return the current BEC device object. diff --git a/bec_widgets/widgets/control/device_input/signal_combobox/signal_combobox.py b/bec_widgets/widgets/control/device_input/signal_combobox/signal_combobox.py index ee5cc2eb..b3269165 100644 --- a/bec_widgets/widgets/control/device_input/signal_combobox/signal_combobox.py +++ b/bec_widgets/widgets/control/device_input/signal_combobox/signal_combobox.py @@ -2,6 +2,8 @@ from __future__ import annotations +import threading + from bec_lib.callback_handler import EventType from bec_lib.device import Signal as BECSignal from bec_lib.logger import bec_logger @@ -137,10 +139,13 @@ class SignalComboBox(BECWidget, QComboBox): if self.config.autocomplete: self.autocomplete = True + self._log_callback_state("init: before DEVICE_UPDATE register") self._device_update_register = self.bec_dispatcher.client.callbacks.register( - EventType.DEVICE_UPDATE, self.update_signals_from_filters + EventType.DEVICE_UPDATE, self.on_device_update ) + self._log_callback_state("init: after DEVICE_UPDATE register") self.currentTextChanged.connect(self.on_text_changed) + self._log_callback_state("init: currentTextChanged connected") self.set_filter(signal_filter or [Kind.hinted, Kind.normal, Kind.config]) @@ -149,6 +154,18 @@ class SignalComboBox(BECWidget, QComboBox): if default is not None: self.set_signal(default) self.check_validity(self.currentText()) + self._log_callback_state("init: finished") + + def _log_callback_state(self, event: str, **details) -> None: + logger.warning( + "SIGNAL COMBOBOX CALLBACK TRACE | " + f"event={event} | object={self.objectName()} | py_id={id(self)} | " + f"thread={threading.current_thread().name}:{threading.get_ident()} | " + f"callback_id={getattr(self, '_device_update_register', None)} | " + f"destroyed={getattr(self, '_destroyed', None)} | " + f"device={getattr(self, '_device', None)} | current={self.currentText()} | " + f"details={details}" + ) @staticmethod def _process_config(config: SignalComboBoxConfig | dict | None) -> SignalComboBoxConfig: @@ -190,11 +207,18 @@ class SignalComboBox(BECWidget, QComboBox): """ previous_device = self._device valid_device = device if self.validate_device(device) else None + self._log_callback_state( + "set_device: before update_signals_from_filters", + requested_device=device, + previous_device=previous_device, + valid_device=valid_device, + ) self._device = valid_device self.config.device = self._device if valid_device is None or valid_device != previous_device: self.setCurrentText("") self.update_signals_from_filters() + self._log_callback_state("set_device: after update_signals_from_filters") @SafeSlot() @SafeSlot(dict, dict) @@ -207,15 +231,23 @@ class SignalComboBox(BECWidget, QComboBox): content: Optional callback payload from BEC device updates. Currently unused. metadata: Optional callback metadata from BEC device updates. Currently unused. """ + self._log_callback_state( + "update_signals_from_filters: enter", + content=content, + metadata=metadata, + signal_class_filter=self._signal_class_filter, + require_device=self._require_device, + ) self.config.signal_filter = [kind.name for kind in self.signal_filter] - logger.warning(f"SIGNAL COMBOBOX UPDATE: {content}") - if self._signal_class_filter: + self._log_callback_state("update_signals_from_filters: class-filter path") self.update_signals_from_signal_classes() + self._log_callback_state("update_signals_from_filters: class-filter return") return if not self.validate_device(self._device): + self._log_callback_state("update_signals_from_filters: invalid-device return") self._device = None self.config.device = None self._set_signal_groups([], [], []) @@ -225,6 +257,7 @@ class SignalComboBox(BECWidget, QComboBox): device_info = device._info.get("signals", {}) if isinstance(device, BECSignal): + self._log_callback_state("update_signals_from_filters: bec-signal return") self._set_signal_groups([(self._device, {})], [], []) return @@ -248,6 +281,23 @@ class SignalComboBox(BECWidget, QComboBox): device_name=self._device, ), ) + self._log_callback_state( + "update_signals_from_filters: finished", + signal_count=len(self._signals), + hinted_count=len(self._hinted_signals), + normal_count=len(self._normal_signals), + config_count=len(self._config_signals), + ) + + def on_device_update(self, action: str, content: dict) -> None: + """Log BEC device-update callback entry before refreshing filters.""" + self._log_callback_state("on_device_update: enter", action=action, content=content) + if action in ["add", "remove", "reload", "update"]: + self._log_callback_state("on_device_update: before direct update") + self.update_signals_from_filters(action, content) + self._log_callback_state("on_device_update: after direct update") + else: + self._log_callback_state("on_device_update: ignored action", action=action) @Property(str) def device(self) -> str: @@ -590,10 +640,16 @@ class SignalComboBox(BECWidget, QComboBox): def cleanup(self): """Cleanup the widget.""" + self._log_callback_state("cleanup: start") if self._device_update_register is not None: + self._log_callback_state("cleanup: removing callback") self.bec_dispatcher.client.callbacks.remove(self._device_update_register) self._device_update_register = None + self._log_callback_state("cleanup: callback removed") + else: + self._log_callback_state("cleanup: callback already None") super().cleanup() + self._log_callback_state("cleanup: after super") @staticmethod def _normalize_kind(value: Kind | str) -> Kind | None: