diff --git a/OpenLIFULib/OpenLIFULib/util.py b/OpenLIFULib/OpenLIFULib/util.py index 9a5ab517..2a9930a7 100644 --- a/OpenLIFULib/OpenLIFULib/util.py +++ b/OpenLIFULib/OpenLIFULib/util.py @@ -73,6 +73,12 @@ def __init__(self, name_to_print, use_dialogs=True, *args, **kwargs): self.use_dialogs = use_dialogs def emit(self, record): + # Qt UI calls are only safe on the main thread. If this log record was emitted + # from a background thread (e.g. UART monitor/read threads), skip Qt interactions + # entirely to avoid QObject::setParent and processEvents cross-thread crashes. + if qt.QThread.currentThread() is not slicer.app.thread(): + return + if record.levelno == logging.ERROR: method_to_use = self.handle_error_with_dialog if self.use_dialogs else self.handle_error_without_dialog elif record.levelno == logging.WARNING: diff --git a/OpenLIFUSonicationControl/OpenLIFUSonicationControl.py b/OpenLIFUSonicationControl/OpenLIFUSonicationControl.py index 9a07e403..2c2c5ff9 100644 --- a/OpenLIFUSonicationControl/OpenLIFUSonicationControl.py +++ b/OpenLIFUSonicationControl/OpenLIFUSonicationControl.py @@ -2,8 +2,6 @@ import asyncio import logging import re -import asyncio -import sys import threading from datetime import datetime from enum import Enum @@ -203,6 +201,7 @@ def cur_solution_on_hardware_state(self) -> SolutionOnHardwareState: def setup(self) -> None: """Called when the user opens the module the first time and the widget is initialized.""" + logging.debug("OpenLIFUSonicationControlWidget.setup() called") ScriptedLoadableModuleWidget.setup(self) # Load widget from .ui file (created by Qt Designer). @@ -263,6 +262,7 @@ def setup(self) -> None: # Initialize UI self.updateRunProgressBar() self.updateDeviceConnectedStateFromDevice() + self.updateVersionLabels() self.updateWidgetSolutionOnHardwareState(SolutionOnHardwareState.NOT_SENT) # Add an observer on the Data module's parameter node @@ -285,16 +285,20 @@ def setup(self) -> None: def cleanup(self) -> None: """Called when the application closes and the module widget is destroyed.""" + logging.debug("OpenLIFUSonicationControlWidget.cleanup() called") self.removeObservers() def enter(self) -> None: """Called each time the user opens this module.""" + logging.debug("OpenLIFUSonicationControlWidget.enter() called") # Make sure parameter node exists and observed self.initializeParameterNode() + self.updateVersionLabels() self.updateWorkflowControls() def exit(self) -> None: """Called each time the user opens a different module.""" + logging.debug("OpenLIFUSonicationControlWidget.exit() called") # Do not react to parameter node changes (GUI will be updated when the user enters into the module) if self._parameterNode: self._parameterNode.disconnectGui(self._parameterNodeGuiTag) @@ -302,11 +306,13 @@ def exit(self) -> None: def onSceneStartClose(self, caller, event) -> None: """Called just before the scene is closed.""" + logging.debug("onSceneStartClose() called") # Parameter node will be reset, do not use it anymore self.setParameterNode(None) def onSceneEndClose(self, caller, event) -> None: """Called just after the scene is closed.""" + logging.debug("onSceneEndClose() called") # If this module is shown while the scene is closed then recreate a new parameter node immediately if self.parent.isEntered: self.initializeParameterNode() @@ -335,6 +341,7 @@ def setParameterNode(self, inputParameterNode: Optional[OpenLIFUSonicationContro self._parameterNodeGuiTag = self._parameterNode.connectGui(self.ui) def onDataParameterNodeModified(self, caller=None, event=None) -> None: + logging.debug("onDataParameterNodeModified() called") self.updateAllButtonsEnabled() if (solution_parameter_pack := get_openlifu_data_parameter_node().loaded_solution) is None: self._cur_solution_id = None @@ -359,7 +366,7 @@ def updateReinitializeLIFUInterfacePushButtonEnabled(self): @display_errors def updateManuallyGetDeviceStatusPushButtonEnabled(self, checked=False): - if not self.logic.get_lifu_device_connected(): + if self._cur_device_connected_state != DeviceConnectedState.CONNECTED: enabled = False tooltip = "The LIFU device must be connected to get its status." else: @@ -375,7 +382,7 @@ def updateSendSonicationSolutionToDevicePushButtonEnabled(self): if solution is None: enabled = False tooltip = "To run a sonication, first generate and approve a solution in the sonication planning module." - elif not self.logic.get_lifu_device_connected(): + elif self._cur_device_connected_state != DeviceConnectedState.CONNECTED: enabled = False tooltip = "To send a sonication solution to the device, the LIFU device must be connected." elif not solution.is_approved(): @@ -433,8 +440,8 @@ def onRunCompleted(self, new_sonication_run_complete_state: bool): """If the soniction_run_complete variable changes from False to True, then open the RunComplete dialog to determine whether the run should be saved. Saving the run creates a SlicerOpenLIFURun object and writes the run to the database (only if there is an active session).""" - self.logic.cur_lifu_interface.stop_sonication() - + + logging.debug(f" onRunCompleted() called with run_complete={new_sonication_run_complete_state}") self.ui.runHardwareStatusLabel.setProperty("text", "Run Completed.") if new_sonication_run_complete_state: @@ -446,25 +453,30 @@ def onRunCompleted(self, new_sonication_run_complete_state: bool): self.updateAllButtonsEnabled() @display_errors - def onDeviceConnected(self): + def onDeviceConnected(self): + logging.debug("onDeviceConnected() called") # Even though this call explicitly tells us whether "Connected" or # "Disconnected", we still update from the actual hardware for the best # possible synchronization self.updateDeviceConnectedStateFromDevice() self.updateWidgetSolutionOnHardwareState(SolutionOnHardwareState.NOT_SENT) self.updateAllButtonsEnabled() + self.updateVersionLabels() @display_errors def onDeviceDisconnected(self): + logging.debug("onDeviceDisconnected() called") # Even though this call explicitly tells us whether "Connected" or # "Disconnected", we still update from the actual hardware for the best # possible synchronization self.updateDeviceConnectedStateFromDevice() self.updateWidgetSolutionOnHardwareState(SolutionOnHardwareState.NOT_SENT) self.updateAllButtonsEnabled() + self.updateVersionLabels() @display_errors def onReinitializeLIFUInterfacePushButtonClicked(self, checked=False): + logging.debug("onReinitializeLIFUInterfacePushButtonClicked() called") slicer.util.warningDisplay( text = f"Reinitializing the LIFUInterface in test mode is not fully supported and may result in unexpected application behavior. If this was a mistake, restart the app and use the real transducer hardware.", @@ -472,7 +484,7 @@ def onReinitializeLIFUInterfacePushButtonClicked(self, checked=False): ) new_test_mode_state = not self.logic.cur_lifu_interface._test_mode - logging.info("Reinitializing LIFUInterface with test_mode =", new_test_mode_state) + logging.info("Reinitializing LIFUInterface with test_mode = %s", new_test_mode_state) self.logic.reinitialize_lifu_interface(test_mode=new_test_mode_state) self.updateDeviceConnectedStateFromDevice() @@ -482,18 +494,21 @@ def onReinitializeLIFUInterfacePushButtonClicked(self, checked=False): @display_errors def onSendSonicationSolutionToDevicePushButtonClicked(self, checked=False): + logging.debug("onSendSonicationSolutionToDevicePushButtonClicked() called") try: self.logic.cur_lifu_interface.set_solution(get_openlifu_data_parameter_node().loaded_solution.solution.solution) if self.logic.cur_lifu_interface.get_status() != openlifu_lz().io.LIFUInterfaceStatus.STATUS_READY: raise RuntimeError("Interface not ready") self.logic.cur_solution_on_hardware = get_openlifu_data_parameter_node().loaded_solution.solution.solution + logging.debug("Solution successfully sent to device") self.updateWidgetSolutionOnHardwareState(SolutionOnHardwareState.SUCCESSFUL_SEND) except Exception as e: - logging.error("Exception thrown:", e) + logging.error("Exception thrown: %s", e) import traceback traceback.print_exc() + logging.debug(f" Failed to send solution to device: {e}") self.updateWidgetSolutionOnHardwareState(SolutionOnHardwareState.FAILED_SEND, self.logic.cur_lifu_interface.get_status()) self.updateWorkflowControls() @@ -502,6 +517,7 @@ def onManuallyGetDeviceStatusPushButtonClicked(self, checked=False): slicer.util.infoDisplay(text=f"{self.logic.cur_lifu_interface.get_status().name}", windowTitle="Device Status") def onRunningChanged(self, new_running_state:bool): + logging.debug(f" onRunningChanged() called with running={new_running_state}") self.updateReinitializeLIFUInterfacePushButtonEnabled() self.updateSendSonicationSolutionToDevicePushButtonEnabled() self.updateRunEnabled() @@ -509,6 +525,7 @@ def onRunningChanged(self, new_running_state:bool): self.updateRunHardwareStatusLabel() def onRunClicked(self): + logging.debug("onRunClicked() called") if not slicer.util.getModuleLogic('OpenLIFUData').validate_solution(): raise RuntimeError("Invalid solution; not running sonication.") self.ui.runProgressBar.value = 0 @@ -517,6 +534,7 @@ def onRunClicked(self): self.updateWorkflowControls() def onAbortClicked(self): + logging.debug("onAbortClicked() called") self.logic.abort() runCompleteDialog = OnRunCompletedDialog(False) returncode, run_parameters = runCompleteDialog.customexec_() @@ -547,6 +565,53 @@ def updateRunHardwareStatusLabel(self, new_run_hardware_status_value=None): else: # not running self.ui.runHardwareStatusLabel.setProperty("text", "Run not in progress.") + def updateVersionLabels(self): + """Populate SDK / console / TX firmware version labels when both devices are connected.""" + if self._cur_device_connected_state == DeviceConnectedState.CONNECTED: + try: + sdk_ver = openlifu_lz().io.LIFUInterface.get_sdk_version() + except Exception as e: + logging.warning("Could not read SDK version: %s", e) + sdk_ver = "unknown" + self.ui.sdkVersionLabel.setText(f"SDK: {sdk_ver or 'unknown'}") + + try: + con_ver = self.logic.cur_lifu_interface.hvcontroller.get_version() + except Exception as e: + logging.warning("Could not read console firmware version: %s", e) + con_ver = "unknown" + self.ui.consoleVersionLabel.setText(f"Console FW: {con_ver}") + + try: + module_count = self.logic.cur_lifu_interface.txdevice.get_module_count() + except Exception as e: + module_count = 0 + logging.warning("Could not read TX module count: %s", e) + + modules_info = [] + display_text = "" + + try: + for module_idx in range(module_count): + tx_ver = self.logic.cur_lifu_interface.txdevice.get_version(module=module_idx) + modules_info.append({ + "Module": module_idx, + "FW": tx_ver + }) + + display_text = "\n".join( + f"TX {m['Module']} FW: v{m['FW']}" + for m in modules_info + ) if modules_info else "TX FW: unknown" + except Exception as e: + logging.warning("Could not read TX firmware version: %s", e) + display_text = "TX FW: unknown" + self.ui.txVersionLabel.setText(display_text) + else: + self.ui.sdkVersionLabel.setText("") + self.ui.consoleVersionLabel.setText("") + self.ui.txVersionLabel.setText("") + def updateDeviceConnectedStateFromDevice(self): if self.logic.get_lifu_device_connected(): self.updateDeviceConnectedState(DeviceConnectedState.CONNECTED) @@ -554,7 +619,7 @@ def updateDeviceConnectedStateFromDevice(self): self.updateDeviceConnectedState(DeviceConnectedState.NOT_CONNECTED) def updateDeviceConnectedState(self, connected_state: DeviceConnectedState): - self._cur_solution_on_hardware_state = connected_state + self._cur_device_connected_state = connected_state if connected_state == DeviceConnectedState.CONNECTED: self.ui.connectedStateLabel.setProperty("text", "🟢 LIFU Device (connected)") elif connected_state == DeviceConnectedState.NOT_CONNECTED: @@ -597,6 +662,9 @@ def updateWorkflowControls(self): class LIFUQtSignals(qt.QObject): runProgressUpdated = qt.Signal(float) # Expecting pulse_train_percent as float finishScanning = qt.Signal(bool) # Signal to indicate that scanning is finished + deviceConnected = qt.Signal() # Emitted from monitor thread; Qt queues to main thread + deviceDisconnected = qt.Signal() # Emitted from monitor thread; Qt queues to main thread + dataReceived = qt.Signal(str, str) # (descriptor, message) def __init__(self, parent=None): super().__init__(parent) @@ -622,6 +690,7 @@ def _run_monitor_loop(self): def __init__(self) -> None: """Called when the logic class is instantiated. Can be used for initializing member variables.""" + logging.debug("OpenLIFUSonicationControlLogic.__init__() called") ScriptedLoadableModuleLogic.__init__(self) self._running : bool = False @@ -662,8 +731,19 @@ def __init__(self) -> None: self.qt_signals = LIFUQtSignals() + # These connections cross the monitor-thread → main-thread boundary. + # Qt auto-detects the thread mismatch and queues the calls safely. + self.qt_signals.deviceConnected.connect(self._dispatch_device_connected) + self.qt_signals.deviceDisconnected.connect(self._dispatch_device_disconnected) + self.qt_signals.dataReceived.connect(self._dispatch_data_received) + self.cur_lifu_interface = openlifu_lz().io.LIFUInterface(run_async=True, TX_test_mode=False, HV_test_mode=False) + # Connect signals before starting the monitor thread to avoid missing early events + self.cur_lifu_interface.signal_connect.connect(self.on_lifu_device_connected) + self.cur_lifu_interface.signal_disconnect.connect(self.on_lifu_device_disconnected) + self.cur_lifu_interface.signal_data_received.connect(self.on_lifu_data_received) + # Set up asyncio event loop and monitoring thread self._monitor_loop = asyncio.new_event_loop() self._monitor_thread = threading.Thread( @@ -677,29 +757,68 @@ def __init__(self) -> None: self.monitoring_timer.timeout.connect(self._pumpMonitoringLoop) self.monitoring_timer.start() - # Connect signals - self.cur_lifu_interface.signal_connect.connect(self.on_lifu_device_connected) - self.cur_lifu_interface.signal_disconnect.connect(self.on_lifu_device_disconnected) - self.cur_lifu_interface.signal_data_received.connect(self.on_lifu_data_received) - self.cur_solution_on_hardware: Optional[openlifu.plan.Solution] = None """The active Solution object last sent to the ultrasound hardware.""" # Set logging - logging.getLogger("LIFUInterface").setLevel(logging.WARNING) - logging.getLogger("UART").setLevel(logging.WARNING) - logging.getLogger("LIFUHVController").setLevel(logging.WARNING) - logging.getLogger("LIFUTXDevice").setLevel(logging.WARNING) + logging.getLogger("LIFUInterface").setLevel(logging.ERROR) + logging.getLogger("UART").setLevel(logging.ERROR) + logging.getLogger("LIFUHVController").setLevel(logging.ERROR) + logging.getLogger("LIFUTXDevice").setLevel(logging.ERROR) def stop_monitoring(self): if self.cur_lifu_interface: self.cur_lifu_interface.stop_monitoring() - if self._monitor_loop.is_running(): - self._monitor_loop.call_soon_threadsafe(self._monitor_loop.stop) + + if hasattr(self, "_monitor_loop") and self._monitor_loop: + if self._monitor_loop.is_running(): + self._monitor_loop.call_soon_threadsafe(self._monitor_loop.stop) + + if hasattr(self, "_monitor_thread") and self._monitor_thread: + if self._monitor_thread.is_alive(): + self._monitor_thread.join(timeout=2) + + if hasattr(self, "_monitor_loop") and self._monitor_loop: + try: + self._monitor_loop.close() + except Exception as e: + logging.warning("Error closing monitor loop: %s", e) def reinitialize_lifu_interface(self, test_mode: bool = False): """Cleanly shut down and reinitialize the LIFUInterface.""" - pass + logging.debug("reinitialize_lifu_interface() called with test_mode=%s", test_mode) + + try: + self.monitoring_timer.stop() + self.stop_monitoring() + + if self.cur_lifu_interface: + self.cur_lifu_interface.close() + + except Exception as e: + logging.warning("[LIFU] Error during interface cleanup: %s", e) + + # Recreate interface + self.cur_lifu_interface = openlifu_lz().io.LIFUInterface( + run_async=True, + TX_test_mode=test_mode, + HV_test_mode=test_mode + ) + + # Reconnect signals + self.cur_lifu_interface.signal_connect.connect(self.on_lifu_device_connected) + self.cur_lifu_interface.signal_disconnect.connect(self.on_lifu_device_disconnected) + self.cur_lifu_interface.signal_data_received.connect(self.on_lifu_data_received) + + # Create fresh loop + thread + self._monitor_loop = asyncio.new_event_loop() + self._monitor_thread = threading.Thread( + target=self._run_monitor_loop, + daemon=True + ) + self._monitor_thread.start() + + self.monitoring_timer.start() def __del__(self): print("OpenLIFUSonicationControlLogic.__del__ called") @@ -800,8 +919,8 @@ def parse_status_string(self, status_str): } try: - # Match top-level fields - pattern = re.compile( + # Try pattern WITH PULSE field + pattern_with_pulse = re.compile( r"STATUS:(\w+)," r"MODE:(\w+)," r"PULSE_TRAIN:\[(\d+)/(\d+)\]," @@ -809,32 +928,61 @@ def parse_status_string(self, status_str): r"TEMP_TX:([0-9.]+)," r"TEMP_AMBIENT:([0-9.]+)" ) - match = pattern.match(status_str.strip()) - - if not match: - raise ValueError("Input string format is invalid.") - - ( - status, - mode, - pt_current, pt_total, - p_current, p_total, - temp_tx, - temp_ambient - ) = match.groups() - - # Convert and compute percentages - pt_current = int(pt_current) - pt_total = int(pt_total) - p_current = int(p_current) - p_total = int(p_total) - - result["status"] = status - result["mode"] = mode - result["pulse_train_percent"] = (pt_current / pt_total * 100) if pt_total > 0 else 0 - result["pulse_percent"] = (p_current / p_total * 100) if p_total > 0 else 0 - result["temp_tx"] = float(temp_tx) - result["temp_ambient"] = float(temp_ambient) + match = pattern_with_pulse.match(status_str.strip()) + + if match: + ( + status, + mode, + pt_current, pt_total, + p_current, p_total, + temp_tx, + temp_ambient + ) = match.groups() + + pt_current = int(pt_current) + pt_total = int(pt_total) + p_current = int(p_current) + p_total = int(p_total) + + result["status"] = status + result["mode"] = mode + result["pulse_train_percent"] = (pt_current / pt_total * 100) if pt_total > 0 else 0 + result["pulse_percent"] = (p_current / p_total * 100) if p_total > 0 else 0 + result["temp_tx"] = float(temp_tx) + result["temp_ambient"] = float(temp_ambient) + + else: + # Try pattern WITHOUT PULSE field + pattern_without_pulse = re.compile( + r"STATUS:(\w+)," + r"MODE:(\w+)," + r"PULSE_TRAIN:\[(\d+)/(\d+)\]," + r"TEMP_TX:([0-9.]+)," + r"TEMP_AMBIENT:([0-9.]+)" + ) + match = pattern_without_pulse.match(status_str.strip()) + + if not match: + raise ValueError("Input string format is invalid.") + + ( + status, + mode, + pt_current, pt_total, + temp_tx, + temp_ambient + ) = match.groups() + + pt_current = int(pt_current) + pt_total = int(pt_total) + + result["status"] = status + result["mode"] = mode + result["pulse_train_percent"] = (pt_current / pt_total * 100) if pt_total > 0 else 0 + result["pulse_percent"] = None + result["temp_tx"] = float(temp_tx) + result["temp_ambient"] = float(temp_ambient) return result @@ -842,23 +990,25 @@ def parse_status_string(self, status_str): logging.error(f"Failed to parse status string: {e}") return result - def on_lifu_device_connected(self, descriptor, port): - # This would be useful to uncomment if debugging hardware/software integration - logging.info(f"🔌 CONNECTED: {descriptor} on port {port}") - + def _dispatch_device_connected(self): for f in self._on_lifu_device_connected_callbacks: f() - slicer.app.processEvents() - - def on_lifu_device_disconnected(self, descriptor, port): - # This would be useful to uncomment if debugging hardware/software integration - logging.info(f"❌ DISCONNECTED: {descriptor} from port {port}") - + def _dispatch_device_disconnected(self): for f in self._on_lifu_device_disconnected_callbacks: f() - slicer.app.processEvents() + def _dispatch_data_received(self, descriptor, message): + for f in self._on_lifu_device_data_received_callbacks: + f(descriptor, message) + + def on_lifu_device_connected(self, descriptor, port): + logging.info(f"🔌 CONNECTED: {descriptor} on port {port}") + self.qt_signals.deviceConnected.emit() + + def on_lifu_device_disconnected(self, descriptor, port): + logging.info(f"❌ DISCONNECTED: {descriptor} from port {port}") + self.qt_signals.deviceDisconnected.emit() def on_lifu_data_received(self, descriptor, message): """Called when the LIFUInterface receives data from the hardware. @@ -885,13 +1035,11 @@ def on_lifu_data_received(self, descriptor, message): logging.error(f"Failed to parse and update trigger state: {e}") - for f in self._on_lifu_device_data_received_callbacks: - f(descriptor, message) - - slicer.app.processEvents() + self.qt_signals.dataReceived.emit(descriptor, message) def run(self): " Returns True when the sonication control algorithm is done" + logging.debug("Logic.run() called") if get_openlifu_data_parameter_node().loaded_solution is None: raise RuntimeError("No solution loaded; cannot run sonication.") @@ -906,6 +1054,7 @@ def run(self): self.cur_lifu_interface.start_sonication() def stop(self): + logging.debug("Logic.stop() called") # ---- Start the run ---- self.running = False @@ -913,6 +1062,7 @@ def stop(self): self.cur_lifu_interface.stop_sonication() def abort(self) -> None: + logging.debug("Logic.abort() called") # Assumes that the sonication control algorithm will have a callback function to abort run, # that callback can be called here. @@ -925,6 +1075,7 @@ def abort(self) -> None: self.running = False def create_openlifu_run(self, run_parameters: Dict) -> SlicerOpenLIFURun: + logging.debug(f" create_openlifu_run() called with success_flag={run_parameters.get('success_flag')}") loaded_session = get_openlifu_data_parameter_node().loaded_session loaded_solution = get_openlifu_data_parameter_node().loaded_solution @@ -953,6 +1104,7 @@ def create_openlifu_run(self, run_parameters: Dict) -> SlicerOpenLIFURun: # Add SlicerOpenLIFURun to data parameter node run = SlicerOpenLIFURun(run_openlifu) + logging.debug(f" create_openlifu_run() created run with id={run_id}") slicer.util.getModuleLogic('OpenLIFUData').set_run(run) return run @@ -960,6 +1112,7 @@ def create_openlifu_run(self, run_parameters: Dict) -> SlicerOpenLIFURun: def get_lifu_device_connected(self) -> bool: tx_connected = self.cur_lifu_interface.txdevice.is_connected() hv_connected = self.cur_lifu_interface.hvcontroller.is_connected() + logging.debug(f" get_lifu_device_connected(): tx={tx_connected}, hv={hv_connected}") return tx_connected and hv_connected diff --git a/OpenLIFUSonicationControl/Resources/UI/OpenLIFUSonicationControl.ui b/OpenLIFUSonicationControl/Resources/UI/OpenLIFUSonicationControl.ui index 25d4c8bc..a6291c98 100644 --- a/OpenLIFUSonicationControl/Resources/UI/OpenLIFUSonicationControl.ui +++ b/OpenLIFUSonicationControl/Resources/UI/OpenLIFUSonicationControl.ui @@ -66,6 +66,27 @@ + + + + Qt::AlignCenter + + + + + + + Qt::AlignCenter + + + + + + + Qt::AlignCenter + + +