I24 serial: commissioning fixes (#645)

* Pin dodal

* Re pin dodal

* Gix fixed-target run script

* Do not reset visit PV when initialising stages

* Fix missing loggers

* Update beam centre values

* Increase buffer in collection time

* Increase sleep in cs_maker

* Increase sleep for cs maker

* Other beamline test fixes

* Fix test

* Try to improve coverage

* Add dcid test

* Add another one

* Try to improve coverage again

src/mx_bluesky/beamlines/i24/serial/dcid.py

@@ -1,6 +1,5 @@
 import datetime
 import json
-import logging
 import math
 import os
 import re
@@ -10,6 +9,7 @@
 
 import requests
 
+from mx_bluesky.beamlines.i24.serial.log import SSX_LOGGER
 from mx_bluesky.beamlines.i24.serial.parameters import SSXType
 from mx_bluesky.beamlines.i24.serial.setup_beamline import (
     Detector,
@@ -25,8 +25,6 @@
 except ImportError:
     pass
 
-logger = logging.getLogger("I24ssx.DCID")
-
 
 # Collection start/end script to kick off analysis
 COLLECTION_START_SCRIPT = "/dls_sw/i24/scripts/RunAtStartOfCollect-i24-ssx.sh"
@@ -41,7 +39,7 @@
 def get_auth_header() -> dict:
     """Read the credentials file and build the Authorisation header"""
     if not os.path.isfile(CREDENTIALS_LOCATION):
-        logger.warning(
+        SSX_LOGGER.warning(
             "Could not read %s; attempting to proceed without credentials",
             CREDENTIALS_LOCATION,
         )
@@ -205,12 +203,12 @@ def generate_dcid(
 
             # Log what we are doing here
             try:
-                logger.info(
+                SSX_LOGGER.info(
                     "BRIDGE: POST /dc --data %s",
                     repr(json.dumps(data)),
                 )
             except Exception:
-                logger.info(
+                SSX_LOGGER.info(
                     "Caught exception converting data to JSON. Data:\n%s\nVERBOSE:\n%s",
                     str({k: type(v) for k, v in data.items()}),
                 )
@@ -224,20 +222,20 @@ def generate_dcid(
             )
             resp.raise_for_status()
             self.dcid = resp.json()["dataCollectionId"]
-            logger.info("Generated DCID %s", self.dcid)
+            SSX_LOGGER.info("Generated DCID %s", self.dcid)
         except requests.HTTPError as e:
             self.error = True
-            logger.error(
+            SSX_LOGGER.error(
                 "DCID generation Failed; Reason from server: %s", e.response.text
             )
             if self.emit_errors:
                 raise
-            logger.exception("Error generating DCID: %s", e)
+            SSX_LOGGER.exception("Error generating DCID: %s", e)
         except Exception as e:
             self.error = True
             if self.emit_errors:
                 raise
-            logger.exception("Error generating DCID: %s", e)
+            SSX_LOGGER.exception("Error generating DCID: %s", e)
 
     def __int__(self):
         return self.dcid
@@ -248,27 +246,27 @@ def notify_start(self):
             return None
         try:
             command = [COLLECTION_START_SCRIPT, str(self.dcid)]
-            logger.info("Running %s", " ".join(command))
+            SSX_LOGGER.info("Running %s", " ".join(command))
             subprocess.Popen(command)
         except Exception as e:
             self.error = True
             if self.emit_errors:
                 raise
-            logger.warning("Error starting start of collect script: %s", e)
+            SSX_LOGGER.warning("Error starting start of collect script: %s", e)
 
     def notify_end(self):
         """Send notifications that the collection has now ended"""
         if self.dcid is None:
             return
         try:
             command = [COLLECTION_END_SCRIPT, str(self.dcid)]
-            logger.info("Running %s", " ".join(command))
+            SSX_LOGGER.info("Running %s", " ".join(command))
             subprocess.Popen(command)
         except Exception as e:
             self.error = True
             if self.emit_errors:
                 raise
-            logger.warning("Error running end of collect notification: %s", e)
+            SSX_LOGGER.warning("Error running end of collect notification: %s", e)
 
     def collection_complete(
         self, end_time: str | datetime.datetime | None = None, aborted: bool = False
@@ -285,7 +283,7 @@ def collection_complete(
             # end_time might be a string from time.ctime
             if isinstance(end_time, str):
                 end_time = datetime.datetime.strptime(end_time, "%a %b %d %H:%M:%S %Y")
-                logger.debug("Parsed end time: %s", end_time)
+                SSX_LOGGER.debug("Parsed end time: %s", end_time)
 
             if not end_time:
                 end_time = datetime.datetime.now().astimezone()
@@ -302,13 +300,13 @@ def collection_complete(
             if self.dcid is None:
                 # Print what we would have sent. This means that if something is failing,
                 # we still have the data to upload in the log files.
-                logger.info(
+                SSX_LOGGER.info(
                     'BRIDGE: No DCID but Would PATCH "/dc/XXXX" --data=%s',
                     repr(json.dumps(data)),
                 )
                 return
 
-            logger.info(
+            SSX_LOGGER.info(
                 'BRIDGE: PATCH "/dc/%s" --data=%s', self.dcid, repr(json.dumps(data))
             )
             response = requests.patch(
@@ -318,7 +316,7 @@ def collection_complete(
                 headers=get_auth_header(),
             )
             response.raise_for_status()
-            logger.info("Successfully updated end time for DCID %d", self.dcid)
+            SSX_LOGGER.info("Successfully updated end time for DCID %d", self.dcid)
         except Exception as e:
             resp_obj = getattr(e, "response", None)
             try:
@@ -333,7 +331,7 @@ def collection_complete(
             self.error = True
             if self.emit_errors:
                 raise
-            logger.warning("Error completing DCID: %s (%s)", e, resp_str)
+            SSX_LOGGER.warning("Error completing DCID: %s (%s)", e, resp_str)
 
 
 def get_pilatus_filename_template_from_pvs() -> str:
@@ -385,9 +383,9 @@ def get_beamsize() -> tuple[float | None, float | None]:
     h_mode = caget("BL24I-OP-MFM-01:G1:TARGETAPPLY")
     # Validate these and note an error otherwise
     if not v_mode.startswith("VMFM") or v_mode[4:] not in focus_modes:
-        logger.error("Unrecognised vertical beam mode %s", v_mode)
+        SSX_LOGGER.error("Unrecognised vertical beam mode %s", v_mode)
     if not h_mode.startswith("HMFM") or h_mode[4:] not in focus_modes:
-        logger.error("Unrecognised horizontal beam mode %s", h_mode)
+        SSX_LOGGER.error("Unrecognised horizontal beam mode %s", h_mode)
     _, h, _ = focus_modes.get(h_mode[4:], (None, None, None))
     _, _, v = focus_modes.get(v_mode[4:], (None, None, None))
 

src/mx_bluesky/beamlines/i24/serial/extruder/i24ssx_Extruder_Collect_py3v2.py

@@ -262,7 +262,7 @@ def main_extruder_plan(
         SSX_LOGGER.info("Using Eiger detector")
 
         SSX_LOGGER.debug(f"Creating the directory for the collection in {filepath}.")
-        Path(filepath).mkdir(parents=True)
+        Path(filepath).mkdir(parents=True, exist_ok=True)
 
         caput(pv.eiger_seqID, int(caget(pv.eiger_seqID)) + 1)
         SSX_LOGGER.info(f"Eiger quickshot setup: filepath {filepath}")

src/mx_bluesky/beamlines/i24/serial/fixed_target/i24ssx_Chip_Collect_py3v1.py

@@ -77,7 +77,7 @@ def calculate_collection_timeout(parameters: FixedTargetParameters) -> float:
     Returns:
         The estimated collection time, in s.
     """
-    buffer = PMAC_MOVE_TIME * parameters.total_num_images + 2
+    buffer = PMAC_MOVE_TIME * parameters.total_num_images + 600
     pump_setting = parameters.pump_repeat
     collection_time = parameters.total_num_images * parameters.exposure_time_s
     if pump_setting in [
@@ -97,7 +97,7 @@ def calculate_collection_timeout(parameters: FixedTargetParameters) -> float:
         )
         if pump_setting == PumpProbeSetting.Medium1:
             # Long delay between pump and probe, with fast shutter opening and closing.
-            timeout = timeout + SHUTTER_OPEN_TIME
+            timeout = timeout + SHUTTER_OPEN_TIME * parameters.total_num_images
     return timeout
 
 
@@ -426,7 +426,11 @@ def start_i24(
         )
 
         SSX_LOGGER.debug("Arm Pilatus. Arm Zebra.")
-        shutter_time_offset = SHUTTER_OPEN_TIME if PumpProbeSetting.Medium1 else 0.0
+        shutter_time_offset = (
+            SHUTTER_OPEN_TIME
+            if parameters.pump_repeat is PumpProbeSetting.Medium1
+            else 0.0
+        )
         yield from setup_zebra_for_fastchip_plan(
             zebra,
             parameters.detector_name,
@@ -449,7 +453,7 @@ def start_i24(
         SSX_LOGGER.info("Using Eiger detector")
 
         SSX_LOGGER.debug(f"Creating the directory for the collection in {filepath}.")
-        Path(filepath).mkdir(parents=True)
+        Path(filepath).mkdir(parents=True, exist_ok=True)
 
         SSX_LOGGER.info(f"Triggered Eiger setup: filepath {filepath}")
         SSX_LOGGER.info(f"Triggered Eiger setup: filename {filename}")
@@ -485,7 +489,11 @@ def start_i24(
         )
 
         SSX_LOGGER.debug("Arm Zebra.")
-        shutter_time_offset = SHUTTER_OPEN_TIME if PumpProbeSetting.Medium1 else 0.0
+        shutter_time_offset = (
+            SHUTTER_OPEN_TIME
+            if parameters.pump_repeat is PumpProbeSetting.Medium1
+            else 0.0
+        )
         yield from setup_zebra_for_fastchip_plan(
             zebra,
             parameters.detector_name,

src/mx_bluesky/beamlines/i24/serial/fixed_target/i24ssx_Chip_Manager_py3v1.py

@@ -93,6 +93,9 @@ def initialise_stages(
     sleep(0.1)
     SSX_LOGGER.info("Clearing General Purpose PVs 1-120")
     for i in range(4, 120):
+        if i == 100:
+            # Do not clear visit PV
+            continue
         pvar = "ME14E-MO-IOC-01:GP" + str(i)
         caput(pvar, 0)
         sys.stdout.write(".")
@@ -840,13 +843,13 @@ def check_dir(val):
     sleep(2.5)
     yield from set_pmac_strings_for_cs(pmac, {"cs1": cs1, "cs2": cs2, "cs3": cs3})
     yield from bps.trigger(pmac.to_xyz_zero)
-    sleep(0.1)
+    sleep(2.5)
     yield from bps.trigger(pmac.home, wait=True)
-    sleep(0.1)
+    sleep(2.5)
     SSX_LOGGER.debug(f"Chip_type is {chip_type}")
     if chip_type == 0:
         yield from bps.abs_set(pmac.pmac_string, "!x0.4y0.4", wait=True)
-        sleep(0.1)
+        sleep(2.5)
         yield from bps.trigger(pmac.home, wait=True)
     else:
         yield from bps.trigger(pmac.home, wait=True)

src/mx_bluesky/beamlines/i24/serial/fixed_target/i24ssx_moveonclick.py

@@ -3,7 +3,6 @@
 Robin Owen 12 Jan 2021
 """
 
-import logging
 from collections.abc import Sequence
 
 import bluesky.plan_stubs as bps
@@ -17,10 +16,9 @@
     i24ssx_Chip_Manager_py3v1 as manager,
 )
 from mx_bluesky.beamlines.i24.serial.fixed_target.ft_utils import Fiducials
+from mx_bluesky.beamlines.i24.serial.log import SSX_LOGGER
 from mx_bluesky.beamlines.i24.serial.parameters.constants import OAV1_CAM
 
-logger = logging.getLogger("I24ssx.moveonclick")
-
 
 def _get_beam_centre(oav: OAV):
     """Extract the beam centre x/y positions from the display.configuration file.
@@ -53,7 +51,7 @@ def _move_on_mouse_click_plan(
     x, y = clicked_position
     xmove = -1 * (beamX - x) * zoomcalibrator
     ymove = 1 * (beamY - y) * zoomcalibrator
-    logger.info(f"Moving X and Y {xmove} {ymove}")
+    SSX_LOGGER.info(f"Moving X and Y {xmove} {ymove}")
     xmovepmacstring = "#1J:" + str(xmove)
     ymovepmacstring = "#2J:" + str(ymove)
     yield from bps.abs_set(pmac.pmac_string, xmovepmacstring, wait=True)
@@ -66,7 +64,7 @@ def onMouse(event, x, y, flags, param):
         RE = param[0]
         pmac = param[1]
         oav = param[2]
-        logger.info(f"Clicked X and Y {x} {y}")
+        SSX_LOGGER.info(f"Clicked X and Y {x} {y}")
         RE(_move_on_mouse_click_plan(oav, pmac, (x, y)))
 
 
@@ -159,7 +157,7 @@ def start_viewer(oav: OAV, pmac: PMAC, RE: RunEngine, oav1: str = OAV1_CAM):
     cv.namedWindow("OAV1view")
     cv.setMouseCallback("OAV1view", onMouse, param=[RE, pmac, oav])  # type: ignore
 
-    logger.info("Showing camera feed. Press escape to close")
+    SSX_LOGGER.info("Showing camera feed. Press escape to close")
     # Read captured video and store them in success and frame
     success, frame = cap.read()
 

src/mx_bluesky/beamlines/i24/serial/run_fixed_target.sh

@@ -15,12 +15,13 @@ edm_path=$1
 # Export env variable for the stages edm to work properly
 export EDMDATAFILES="/dls_sw/prod/R3.14.12.3/support/motor/6-7-1dls14/motorApp/opi/edl"
 
+# Get the directory of this script
+current=$( realpath "$( dirname "$0" )" )
+
+
 if [[ $NO_PROCESERV_TEST == true ]]; then
     echo "Start the blueapi sever"
 
-    # Get the directory of this script
-    current=$( realpath "$( dirname "$0" )" )
-
     # Run script to start blueapi serve
     . $current/start_blueapi.sh
 fi