wip logging life cycle

This commit is contained in:
2026-05-20 19:55:30 +02:00
parent 522c3bc8e6
commit 7933e6e755
4 changed files with 261 additions and 5 deletions
+72
View File
@@ -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)}"
)
@@ -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
@@ -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.
@@ -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: