From c8c440c25991bd0e2baff200b9c553ffd5641b5b Mon Sep 17 00:00:00 2001 From: appel_c Date: Thu, 22 Jan 2026 20:21:41 +0100 Subject: [PATCH] remove logger wip --- .../epics/delay_generator_csaxs/ddg_1.py | 6 ++--- .../epics/delay_generator_csaxs/ddg_2.py | 3 +++ .../devices/epics/mcs_card/mcs_card_csaxs.py | 25 ++++++++++--------- 3 files changed, 19 insertions(+), 15 deletions(-) diff --git a/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_1.py b/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_1.py index 9dcf7f7..29a0623 100644 --- a/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_1.py +++ b/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_1.py @@ -212,6 +212,7 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS): - We set the delay pairs ef to be triggered after the shutter closes with a width of 1us to trigger the MCS card. - Finally, we add a short sleep to ensure that the IOC and DDG HW process the values properly. """ + start_time = time.time() ######################################## ### Burst mode settings ################ @@ -264,7 +265,7 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS): # This value has been choosen empirically after testing with the HW. It's # also just called once per scan and has been found to improve stability of the HW. time.sleep(0.2) - logger.info("DDG1 configured for upcoming scan.") + logger.info(f"DDG {self.name} on_stage completed in {time.time() - start_time:.3f}s.") def _prepare_mcs_on_trigger(self, mcs: MCSCardCSAXS) -> None: """ @@ -355,7 +356,6 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS): """ - logger.info("Polling DDG1 event status register...") self.state.proc_status.put(1, use_complete=True) # NOTE: Important sleep that has been empirically determined after testing for a long time @@ -417,7 +417,7 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS): # Callback to cancel the status if the device is stopped def cancel_cb(status: CompareStatus) -> None: """Callback to cancel the status if the device is stopped.""" - logger.info("DDG1 end of burst detected, stopping polling loop.") + logger.debug("DDG1 end of burst detected, stopping polling loop.") if status.done: self._stop_polling() diff --git a/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_2.py b/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_2.py index 55dad7c..bf781f3 100644 --- a/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_2.py +++ b/csaxs_bec/devices/epics/delay_generator_csaxs/ddg_2.py @@ -145,6 +145,7 @@ class DDG2(PSIDeviceBase, DelayGeneratorCSAXS): This logic is robust for step scans as well as fly scans, as the DDG2 is triggered by the DDG1 through the EXT/EN channel. """ + start_time = time.time() ######################################## ### Burst mode settings ################ ######################################## @@ -183,6 +184,8 @@ class DDG2(PSIDeviceBase, DelayGeneratorCSAXS): # Trigger detectors with delay 0, and pulse width = exp_time - readout_time self.set_delay_pairs(channel="ab", delay=0, width=burst_pulse_width) + logger.info(f"DDG {self.name} on_stage completed in {time.time() - start_time:.3f}s.") + def on_pre_scan(self): """ diff --git a/csaxs_bec/devices/epics/mcs_card/mcs_card_csaxs.py b/csaxs_bec/devices/epics/mcs_card/mcs_card_csaxs.py index 4ca5f07..1ff3d08 100644 --- a/csaxs_bec/devices/epics/mcs_card/mcs_card_csaxs.py +++ b/csaxs_bec/devices/epics/mcs_card/mcs_card_csaxs.py @@ -286,11 +286,11 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): ) # Once we have received all channels, push data to BEC and reset for next accumulation - logger.info( + logger.debug( f"Received update for {attr_name}, index {self._mca_counter_index}/{self.NUM_MCA_CHANNELS}" ) if len(self._current_data) == self.NUM_MCA_CHANNELS: - logger.info( + logger.debug( f"Current data index {self._current_data_index} complete, pushing to BEC." ) self.mca.put(self._current_data, acquisition_group=self._acquisition_group) @@ -328,6 +328,7 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): - Clear any events and buffers related to async data emission. This includes '_omit_mca_callbacks', '_start_monitor_async_data_emission', '_scan_done_callbacks', and '_current_data'. """ + start_time = time.time() # NOTE: If for some reason, the card is still acquiring, we need to stop it first # This should never happen as the card is properly stopped during unstage @@ -383,6 +384,8 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): # NOTE Make sure that the signal that omits mca callbacks is cleared self._omit_mca_callbacks.clear() + logger.info(f"MCS Card {self.name} on_stage completed in {time.time() - start_time:.3f}s.") + def on_unstage(self) -> None: """ Called when the device is unstaged. This method should be omnipotent and resolve fast. @@ -397,7 +400,7 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): with suppress_mca_callbacks(self): with self._rlock: self._current_data.clear() - self._current_data_index = 0 + self._current_data_index = 0 self.erase_all.put(1) def _monitor_async_data_emission(self) -> None: @@ -414,8 +417,11 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): while not self._scan_done_thread_kill_event.is_set(): while self._start_monitor_async_data_emission.wait(): try: - logger.info(f"Monitoring async data emission for {self.name}...") - if hasattr(self.scan_info.msg, "num_points") and self.scan_info.msg.num_points is not None: + logger.debug(f"Monitoring async data emission for {self.name}...") + if ( + hasattr(self.scan_info.msg, "num_points") + and self.scan_info.msg.num_points is not None + ): if self._current_data_index == self.scan_info.msg.num_points: for callback in self._scan_done_callbacks: callback(exception=None) @@ -434,17 +440,12 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): self._start_monitor_async_data_emission.clear() # Stop monitoring # NOTE Important check as set_finished or set_exception should not be called # if the status is already done (e.g. cancelled externally) - logger.info( - f"Status callback called for {self.name}, exception: {exception} of status {status}." - ) with self._rlock: if status.done: return # Already done and cancelled externally. if exception is not None: - logger.info(f"Setting exception for status of {self.name} in complete.") status.set_exception(exception) else: - logger.info(f"Setting finished for status of {self.name} in complete.") status.set_finished() def _status_failed_callback(self, status: StatusBase) -> None: @@ -482,7 +483,7 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): self._scan_done_callbacks.append(partial(self._status_callback, status_async_data)) # Set the event to start monitoring async data emission - logger.info(f"Starting to monitor async data emission for {self.name}...") + logger.debug(f"Starting to monitor async data emission for {self.name}...") self._start_monitor_async_data_emission.set() # Add CompareStatus for Acquiring DONE @@ -523,7 +524,7 @@ class MCSCardCSAXS(PSIDeviceBase, MCSCard): timeout (int): Total timeout for the recovery procedure. Defaults to 1 second. """ sleep_time = timeout / 2 # 2 sleeps - logger.info( + logger.debug( f"Running recovery procedure for MCS card {self.name} with {sleep_time}s sleep, calling stop_all and erase_all, and another {sleep_time}s sleep" ) # First erase and start ongoing acquisition.