From be5f9630cadf69e99aeb298f8e3befb2d4ebda05 Mon Sep 17 00:00:00 2001 From: Julian Stirling Date: Wed, 17 Dec 2025 15:41:22 +0000 Subject: [PATCH] A fond farewell to the last of the InvocationLoggers --- .../stitching.py | 2 +- .../things/smart_scan.py | 93 ++++++++----------- tests/test_scan_directories.py | 3 - tests/test_smart_scan.py | 52 +++++------ tests/test_stage_measure.py | 2 - 5 files changed, 64 insertions(+), 88 deletions(-) diff --git a/src/openflexure_microscope_server/stitching.py b/src/openflexure_microscope_server/stitching.py index e87afe1f..5a984bed 100644 --- a/src/openflexure_microscope_server/stitching.py +++ b/src/openflexure_microscope_server/stitching.py @@ -244,7 +244,7 @@ class FinalStitcher(BaseStitcher): First the scan_data_dict is inspected for values to allow ``overlap`` and ``correlation_resize`` to be set correctly, if these values are not available - then default values are used, and a warning is logged to the invocation logger. + then default values are used, and a warning is logged to the thing logger. :param overlap: overlap as input to __init__ :param correlation_resize: correlation_resize as input to __init__ diff --git a/src/openflexure_microscope_server/things/smart_scan.py b/src/openflexure_microscope_server/things/smart_scan.py index b4ed6c10..0a0f88a0 100644 --- a/src/openflexure_microscope_server/things/smart_scan.py +++ b/src/openflexure_microscope_server/things/smart_scan.py @@ -80,13 +80,13 @@ def _scan_running( This decorator is used by all methods in SmartScanThing that are using the variables set for the scan. It will throw a runtime error if - self._scan_logger is not set, as all scan variables are set at + self._scan_lock is not locked, as all scan variables are set at the same time and released with the lock """ def scan_running_wrapper(self: Self, *args: P.args, **kwargs: P.kwargs) -> T: - # Only start the method is the scan logger is set - if self._scan_logger is not None: + """Only start the requested method if the scan is running.""" + if self._scan_lock.locked(): return method(self, *args, **kwargs) raise ScanNotRunningError( "Calling a @scan_running method can only be done while a scan is running!" @@ -119,13 +119,6 @@ class SmartScanThing(lt.Thing): # Variables set by the scan self._latest_scan_name: Optional[str] = None - # Scan logger is the invocation logger labthings-fastapi creates - # when the `sample_scan` lt.action is called. It is saved as - # private class variable along with many others here. - # Access to these variables requires a scan to be running, - # any method that calls these should be decorated with - # @_scan_running - self._scan_logger: Optional[lt.deps.InvocationLogger] = None self._autofocus: Optional[AutofocusDep] = None self._stage: Optional[StageDep] = None self._cam: Optional[CameraClient] = None @@ -138,7 +131,6 @@ class SmartScanThing(lt.Thing): @lt.action def sample_scan( self, - logger: lt.deps.InvocationLogger, autofocus: AutofocusDep, stage: StageDep, cam: CameraClient, @@ -156,7 +148,6 @@ class SmartScanThing(lt.Thing): raise RuntimeError("Trying to run scan while scan is already running!") # Set private variables for this scan - self._scan_logger = logger self._autofocus = autofocus self._stage = stage self._cam = cam @@ -177,7 +168,7 @@ class SmartScanThing(lt.Thing): self._return_to_starting_position() if not isinstance(e, scan_directories.NotEnoughFreeSpaceError): # Don't stitch if drive is full (already logged) - self._scan_logger.info( + self.logger.info( "Attempting to stitch and archive the images acquired so far." ) self._perform_final_stitch() @@ -185,7 +176,6 @@ class SmartScanThing(lt.Thing): raise e finally: # However the scan finishes, unset all variables and release lock - self._scan_logger = None self._autofocus = None self._stage = None self._cam = None @@ -198,7 +188,7 @@ class SmartScanThing(lt.Thing): self._stack_params = None # Remove any scan folders containing zero images. - self.purge_empty_scans(logger=logger) + self.purge_empty_scans() @_scan_running def _check_background_and_csm_set(self) -> None: @@ -222,7 +212,7 @@ class SmartScanThing(lt.Thing): "Background is not set: you need to calibrate background detection." ) else: - self._scan_logger.warning( + self.logger.warning( "This scan will run in a spiral from the starting point " f"until you cancel it, or until it has moved by {self.max_range} steps " "in every direction. Make sure you watch it run to stop it leaving " @@ -250,7 +240,7 @@ class SmartScanThing(lt.Thing): if z_estimate is None: z_estimate = self._stage.position["z"] - self._scan_logger.info(f"Moving to {next_point}") + self.logger.info(f"Moving to {next_point}") self._stage.move_absolute( x=next_point[0], y=next_point[1], @@ -305,19 +295,19 @@ class SmartScanThing(lt.Thing): dx, dy = self._calc_displacement_from_test_image(overlap) correlation_resize = stitching.STITCHING_RESOLUTION[0] / self.save_resolution[0] - self._scan_logger.debug( + self.logger.debug( f"Resizing images when correlating by a factor of {correlation_resize}" ) - self._scan_logger.info( + self.logger.info( f"Based on an overlap of {overlap}, we will make steps of {dx}, {dy}" ) autofocus_dz = self.autofocus_dz if autofocus_dz == 0: - self._scan_logger.info("Running scan without autofocus") + self.logger.info("Running scan without autofocus") elif autofocus_dz <= 200: - self._scan_logger.warning( + self.logger.warning( f"Your autofocus range is {autofocus_dz} steps, which is too short to " "attempt to focus. Running without autofocus" ) @@ -386,13 +376,13 @@ class SmartScanThing(lt.Thing): self._save_final_scan_data(scan_result="success") except lt.exceptions.InvocationCancelledError: - self._scan_logger.info("Stopping scan because it was cancelled.") + self.logger.info("Stopping scan because it was cancelled.") self._save_final_scan_data(scan_result="cancelled by user") except Exception as e: err_name = type(e).__name__ if self._scan_data is not None: self._save_final_scan_data(scan_result=f"{err_name}: {e}") - self._scan_logger.error( + self.logger.error( f"The scan stopped because of an error: {e}", exc_info=e, ) @@ -457,7 +447,7 @@ class SmartScanThing(lt.Thing): new_pos_xyz, imaged=False, focused=False ) msg = f"Skipping {new_pos_xyz} as it is {bg_message}." - self._scan_logger.info(msg) + self.logger.info(msg) continue focused, focused_height = self._autofocus.run_smart_stack( @@ -482,7 +472,7 @@ class SmartScanThing(lt.Thing): @_scan_running def _return_to_starting_position(self) -> None: """Return to the initial scan position, if set.""" - self._scan_logger.info("Returning to starting position.") + self.logger.info("Returning to starting position.") if self._scan_data is not None: self._stage.move_absolute( **self._scan_data.starting_position, block_cancellation=True @@ -499,20 +489,19 @@ class SmartScanThing(lt.Thing): def _perform_final_stitch(self) -> None: """Update the scan zip and perform final stitch of the data.""" if self._scan_data.image_count <= 3: - self._scan_logger.info("Not performing a stitch as 3 or fewer images taken") + self.logger.info("Not performing a stitch as 3 or fewer images taken") return self._ongoing_scan.zip_files() - self._scan_logger.info("Waiting for background processes to finish...") + self.logger.info("Waiting for background processes to finish...") if self._preview_stitcher is not None: self._preview_stitcher.wait() if self._scan_data.stitch_automatically: - self._scan_logger.info("Stitching final image (may take some time)...") + self.logger.info("Stitching final image (may take some time)...") self.stitch_scan( - logger=self._scan_logger, scan_name=self._ongoing_scan.name, correlation_resize=self._scan_data.correlation_resize, overlap=self._scan_data.overlap, @@ -621,17 +610,17 @@ class SmartScanThing(lt.Thing): 400: {"description": "An error occurred while trying to delete scan"}, }, ) - def delete_scan(self, scan_name: str, logger: lt.deps.InvocationLogger) -> None: + def delete_scan(self, scan_name: str) -> None: """Delete the folder for the specified scan. This endpoint allows scans to be deleted from disk. - Takes the scan name to delete, and the Invocation Logger + :param scan_name: The name of the scan to delete """ if not self._scan_dir_manager.exists(scan_name): - logger.warning(f"Cannot find a scan of name {scan_name}") + self.logger.warning(f"Cannot find a scan of name {scan_name}") raise HTTPException(400, "Scan not found") - deleted_scan_success = self._delete_scan(scan_name, logger) + deleted_scan_success = self._delete_scan(scan_name) if not deleted_scan_success: raise HTTPException(400, "Couldn't delete scan, check log for details") @@ -639,7 +628,7 @@ class SmartScanThing(lt.Thing): "delete", "scans", ) - def delete_all_scans(self, logger: lt.deps.InvocationLogger) -> None: + def delete_all_scans(self) -> None: """Delete all the scans on the microscope. **This will irreversibly remove all scanned data from the @@ -647,30 +636,30 @@ class SmartScanThing(lt.Thing): Use with extreme caution. """ for scan_name in self._scan_dir_manager.all_scans: - self._delete_scan(scan_name, logger) + self._delete_scan(scan_name) @lt.action - def purge_empty_scans(self, logger: lt.deps.InvocationLogger) -> None: + def purge_empty_scans(self) -> None: """Delete all scan folders containing no images at the top level.""" # JSON is ignored as it's created before any images are captured for scan_info in self._get_all_scan_info(): if scan_info.number_of_images == 0: - self._delete_scan(scan_info.name, logger) + self._delete_scan(scan_info.name) - def _delete_scan(self, scan_name: str, logger: lt.deps.InvocationLogger) -> bool: + def _delete_scan(self, scan_name: str) -> bool: """Delete a scan. This is a wrapper around scan manager's delete_scan that logs to the - invocation logger id there is a problem. + things logger if there is a problem. """ if self._ongoing_scan is not None and scan_name == self._ongoing_scan.name: - logger.error("Attempted to delete ongoing scan.") + self.logger.error("Attempted to delete ongoing scan.") return False try: self._scan_dir_manager.delete_scan(scan_name) return True except Exception as e: - logger.warning( + self.logger.warning( "Attempted to delete scan " + scan_name + ", which failed." " Server sent response" + str(e) ) @@ -723,22 +712,19 @@ class SmartScanThing(lt.Thing): @lt.action def stitch_scan( self, - logger: lt.deps.InvocationLogger, scan_name: str, correlation_resize: Optional[float] = None, overlap: Optional[float] = None, ) -> None: - """Generate a stitched image based on stage position metadata. - - Note that as this is a lt.action it needs the logger passed as - a variable if called from another thing action - """ + """Generate a stitched image based on stage position metadata.""" scan_data_dict = self._scan_dir_manager.get_scan_data_dict(scan_name) if scan_data_dict is None: - logger.warning("Couldn't read scan data - it may be missing or corrupt.") + self.logger.warning( + "Couldn't read scan data - it may be missing or corrupt." + ) final_stitcher = stitching.FinalStitcher( self._scan_dir_manager.img_dir_for(scan_name), - logger=logger, + logger=self.logger, overlap=overlap, correlation_resize=correlation_resize, stitch_tiff=self.stitch_tiff, @@ -750,7 +736,7 @@ class SmartScanThing(lt.Thing): # Sleep for 1 second just to allow invocation logs to pass to user. time.sleep(1) except SubprocessError as e: - self._scan_logger.error(f"Stitching failed: {e}", exc_info=e) + self.logger.error(f"Stitching failed: {e}", exc_info=e) @lt.action def download_zip( @@ -765,14 +751,13 @@ class SmartScanThing(lt.Thing): return ZipBlob.from_file(zip_fname) @lt.action - def stitch_all_scans(self, logger: lt.deps.InvocationLogger) -> None: + def stitch_all_scans(self) -> None: """Check the list of scans, and stitch any that don't have a DZI associated with it. :raises RuntimeError: if the microscope is currently running a scan - """ - if self._scan_logger is not None: + if self._scan_lock.locked(): raise RuntimeError("Can't stitch previous scans while a scan is ongoing") for scan in self._get_all_scan_info(): if scan.dzi is None: - self.stitch_scan(logger=logger, scan_name=scan.name) + self.stitch_scan(scan_name=scan.name) diff --git a/tests/test_scan_directories.py b/tests/test_scan_directories.py index 13336b11..ff7af3eb 100644 --- a/tests/test_scan_directories.py +++ b/tests/test_scan_directories.py @@ -24,9 +24,6 @@ from openflexure_microscope_server.scan_directories import ( from .test_scan_data import _fake_scan_data from .utilities import assert_unique_of_length -# A global logger to pass in as an Invocation Logger -LOGGER = logging.getLogger("mock-invocation_logger") - # Use our own dir in the root temp dir not a dynamically generated one so we # have some control of when it is deleted BASE_SCAN_DIR = os.path.join(tempfile.gettempdir(), "scans") diff --git a/tests/test_smart_scan.py b/tests/test_smart_scan.py index 4220db4a..15cd5789 100644 --- a/tests/test_smart_scan.py +++ b/tests/test_smart_scan.py @@ -40,9 +40,6 @@ from .mock_things.mock_camera import MockCameraThing from .mock_things.mock_csm import MockCSMThing from .mock_things.mock_stage import MockStageThing -# A global logger to pass in as an Invocation Logger -LOGGER = logging.getLogger("mock-invocation_logger") - # Use our own dir in the root temp dir not a dynamically generated one so we # have some control of when it is deleted SCAN_DIR = os.path.join(tempfile.gettempdir(), "scans") @@ -92,16 +89,16 @@ def test_private_delete_scan(smart_scan_thing, caplog): # Make the outer scan dir, but not the one to delete os.makedirs(SCAN_DIR) # Attempt to delete the fake scan. Expect it to fail and provide a warning - deleted = smart_scan_thing._delete_scan(fake_scan_name, LOGGER) + deleted = smart_scan_thing._delete_scan(fake_scan_name) assert not deleted assert len(caplog.records) == 1 assert caplog.records[0].levelname == "WARNING" - assert caplog.records[0].name == "mock-invocation_logger" + assert caplog.records[0].name == "labthings_fastapi.things.smartscanthing" # Make a dir for the fake scan and delete it. os.makedirs(fake_scan_path) assert os.path.exists(fake_scan_path) - deleted = smart_scan_thing._delete_scan(fake_scan_name, LOGGER) + deleted = smart_scan_thing._delete_scan(fake_scan_name) assert not os.path.exists(fake_scan_path) assert deleted # Check no extra logs generated @@ -120,18 +117,18 @@ def test_public_delete_scan(smart_scan_thing, caplog): # Attempt to delete the fake scan. Expect it to fail with pytest.raises(HTTPException) as exc_info: - smart_scan_thing.delete_scan(fake_scan_name, LOGGER) + smart_scan_thing.delete_scan(fake_scan_name) # Should raise a 400 error if the scan doesn't exist, not a 404 as the server # was not expecting to receive the scan files assert exc_info.value.status_code == 400 assert len(caplog.records) == 1 assert caplog.records[0].levelname == "WARNING" - assert caplog.records[0].name == "mock-invocation_logger" + assert caplog.records[0].name == "labthings_fastapi.things.smartscanthing" # Make a dir for the fake scan and delete it. os.makedirs(fake_scan_path) assert os.path.exists(fake_scan_path) - smart_scan_thing.delete_scan(fake_scan_name, LOGGER) + smart_scan_thing.delete_scan(fake_scan_name) assert not os.path.exists(fake_scan_path) # Check no extra logs generated assert len(caplog.records) == 1 @@ -151,7 +148,7 @@ def test_delete_all_scans(smart_scan_thing, caplog): fake_scan_path = os.path.join(SCAN_DIR, fake_scan_name) os.makedirs(fake_scan_path) assert os.path.exists(fake_scan_path) - smart_scan_thing.delete_all_scans(LOGGER) + smart_scan_thing.delete_all_scans() for fake_scan_name in fake_scan_names: fake_scan_path = os.path.join(SCAN_DIR, fake_scan_name) assert not os.path.exists(fake_scan_path) @@ -190,7 +187,6 @@ def _run_only_outer_scan(adjust_initial_state: Optional[Callable] = None): """Check scan vars are set up as expected""" assert not self._scan_lock.acquire(timeout=0.1) - assert self._scan_logger is LOGGER assert self._autofocus is af_mock assert self._stage is stage_mock assert self._cam is cam_mock @@ -207,7 +203,6 @@ def _run_only_outer_scan(adjust_initial_state: Optional[Callable] = None): exec_info = None try: mock_ss_thing.sample_scan( - logger=LOGGER, autofocus=af_mock, stage=stage_mock, cam=cam_mock, @@ -219,7 +214,6 @@ def _run_only_outer_scan(adjust_initial_state: Optional[Callable] = None): assert mock_ss_thing._scan_lock.acquire(timeout=0.1) mock_ss_thing._scan_lock.release() - assert mock_ss_thing._scan_logger is None assert mock_ss_thing._autofocus is None assert mock_ss_thing._stage is None assert mock_ss_thing._cam is None @@ -280,23 +274,25 @@ def _expected_scan_data(): @pytest.fixture def scan_thing_mocked_for_scan_data(smart_scan_thing, mocker): """Return a scan thing that is mocked so that _collect_scan_data will run.""" - # Give the scan thing a scan invocation logger so it thinks a scan is running. - smart_scan_thing._scan_logger = LOGGER - mocker.patch.object( - smart_scan_thing, "_calc_displacement_from_test_image", return_value=[100, 100] - ) - mock_ongoing_scan = mocker.Mock() - type(mock_ongoing_scan).name = mocker.PropertyMock(return_value=MOCK_SCAN_NAME) - type(mock_ongoing_scan).images_dir = mocker.PropertyMock(return_value=MOCK_SCAN_DIR) - mock_stage = mocker.Mock() - type(mock_stage).position = mocker.PropertyMock(return_value=MOCK_START_POS) + # Set the lock so it thinks the scan is running + with smart_scan_thing._scan_lock: + mocker.patch.object( + smart_scan_thing, + "_calc_displacement_from_test_image", + return_value=[100, 100], + ) + mock_ongoing_scan = mocker.Mock() + mock_ongoing_scan.name = MOCK_SCAN_NAME + mock_ongoing_scan.images_dir = MOCK_SCAN_DIR + mock_stage = mocker.Mock() + mock_stage.position = MOCK_START_POS - mock_autofocus = mocker.Mock() + mock_autofocus = mocker.Mock() - smart_scan_thing._ongoing_scan = mock_ongoing_scan - smart_scan_thing._stage = mock_stage - smart_scan_thing._autofocus = mock_autofocus - return smart_scan_thing + smart_scan_thing._ongoing_scan = mock_ongoing_scan + smart_scan_thing._stage = mock_stage + smart_scan_thing._autofocus = mock_autofocus + yield smart_scan_thing def test_collect_scan_data(scan_thing_mocked_for_scan_data): diff --git a/tests/test_stage_measure.py b/tests/test_stage_measure.py index 6412771a..5c9e0690 100644 --- a/tests/test_stage_measure.py +++ b/tests/test_stage_measure.py @@ -14,8 +14,6 @@ from openflexure_microscope_server.things.camera_stage_mapping import ( csm_stage_to_img, ) -LOGGER = logging.getLogger("mock-invocation_logger") - # Useful generators def increasing_xy_dict_generator(*_args, **_kwargs):