fix(cont_grid): wait for the move to reach the motor before triggering
CI for csaxs_bec / test (push) Successful in 2m5s
CI for csaxs_bec / test (push) Successful in 2m5s
at_each_point issues the line move and then sleeps before firing the
burst. The sleep was acc_time alone, which covers the acceleration ramp
and nothing else -- while the move still has to cross the scan server ->
device server -> EPICS -> controller path first. acc_time shrinks with
the scan velocity; that path does not. On a slow scan the burst
therefore began well before the stage moved, and the first points of
every line piled up at the line start.
Measured from the position readback of five commissioning scans, as the
distance the stage was behind the trigger grid once the lag stopped
growing:
scan exp_time v_cmd lag latency
254 20 ms 0.5 mm/s 29.7 pts 0.594 s
450 50 ms 0.1 mm/s 11.9 pts 0.595 s
324 15 ms 0.667 mm/s 41.5 pts 0.623 s
473 100 ms 0.065 mm/s 6.3 pts 0.630 s
411 50 ms 0.1 mm/s 12.7 pts 0.635 s
Constant to +-3.5% across a 6.7x range of exposure and a 10x range of
velocity, on two axes. Scan 473 is sampled 74 times per line and shows
the shape plainly: the lag appears in the first interval and then holds
at 6.3-6.4 points for the rest of the line while the velocity sits at
exactly the commanded 0.065 mm/s. A start-up offset, not a velocity
error, and the stage itself is blameless.
Deliberately not solved by polling for motion. Observing the readback
costs a round trip of this same ~0.6 s, so it would trade a systematic
offset for a jitter of similar size -- and a constant offset displaces
every line equally, where a varying one shears the image line by line
and cannot be undone afterwards. The reproducibility is the asset here,
not the enemy.
The value lives on ddg1 next to the shutter delay, with a setter in
USER_ACCESS, because that is where cont_grid already fetches its trigger
timing. It is not a property of the delay generator and the docstring
says so. Setting it to 0 reproduces exactly the previous timing without
a redeploy, which is the intended way back if this makes things worse.
The real fix is to trigger the DDG from the motor
(scan_type: hardware_triggered), taking the round trip out of the timing
chain rather than compensating for it. This is the stopgap until then,
and it rests on the latency staying constant -- which is worth
re-checking with the same measurement whenever the deployment changes.
This commit is contained in:
@@ -128,6 +128,45 @@ DEFAULT_SHUTTER_TO_OPEN_DELAY = 8e-3
|
||||
# fat-fingered value would quietly stretch every line rather than fail.
|
||||
MAX_SHUTTER_TO_OPEN_DELAY = 50e-3
|
||||
|
||||
# NOTE How long it takes a move issued by the scan server to reach the motor.
|
||||
#
|
||||
# cont_grid issues the line move and fires the burst a few milliseconds later, on
|
||||
# the assumption that the only thing in between is the acceleration ramp. It is
|
||||
# not: the move first has to cross the scan server -> device server -> EPICS ->
|
||||
# controller chain, and that latency does not shrink when the scan is slow while
|
||||
# the computed acc_time does. The burst therefore starts before the stage.
|
||||
#
|
||||
# Measured 2026-08-25 from the position readback of five commissioning scans, as
|
||||
# the distance the stage was behind the trigger grid once the lag stopped growing:
|
||||
#
|
||||
# scan exp_time v_cmd lag latency
|
||||
# 254 20 ms 0.5 mm/s 29.7 pts 0.594 s
|
||||
# 450 50 ms 0.1 mm/s 11.9 pts 0.595 s
|
||||
# 324 15 ms 0.667 mm/s 41.5 pts 0.623 s
|
||||
# 473 100 ms 0.065 mm/s 6.3 pts 0.630 s
|
||||
# 411 50 ms 0.1 mm/s 12.7 pts 0.635 s
|
||||
#
|
||||
# Constant to +-3.5% across a 6.7x range of exposure and a 10x range of velocity,
|
||||
# on two axes, which is what makes compensating with a constant sound. In scan
|
||||
# 473, sampled 74 times per line, the lag appears in the first interval and then
|
||||
# holds at 6.3-6.4 points for the rest of the line while the velocity sits at
|
||||
# exactly the commanded 0.065 mm/s: a start-up offset, not a velocity error.
|
||||
#
|
||||
# Deliberately NOT solved by polling for motion. Observing the readback costs a
|
||||
# round trip of this same ~0.6 s, so it would trade a systematic offset for a
|
||||
# jitter of similar size -- and a constant offset displaces every line equally,
|
||||
# where a varying one shears the image line by line and cannot be undone
|
||||
# afterwards. The real fix is to trigger the DDG from the motor
|
||||
# (scan_type: hardware_triggered), taking the round trip out of the timing chain
|
||||
# altogether; this is the stopgap until then.
|
||||
#
|
||||
# Set to 0 to get the previous behaviour back without redeploying.
|
||||
DEFAULT_MOVE_START_LATENCY = 0.6
|
||||
|
||||
# Guard rail for set_move_start_latency. Paid once per line, like the shutter
|
||||
# delay, so an implausible value costs scan time rather than raising.
|
||||
MAX_MOVE_START_LATENCY = 5.0
|
||||
|
||||
# NOTE Default readout times for each channel, can be adapted as needed.
|
||||
# These values are relevant to calculate proper widths of the timing signals.
|
||||
# They also define a minimum exposure time that can be used as they are subtracted
|
||||
@@ -177,6 +216,8 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS):
|
||||
"set_trigger",
|
||||
"get_shutter_to_open_delay",
|
||||
"set_shutter_to_open_delay",
|
||||
"get_move_start_latency",
|
||||
"set_move_start_latency",
|
||||
"prepare_mcs_on_trigger",
|
||||
]
|
||||
|
||||
@@ -211,6 +252,7 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS):
|
||||
name=name, prefix=prefix, scan_info=scan_info, device_manager=device_manager, **kwargs
|
||||
)
|
||||
self._shutter_to_open_delay = DEFAULT_SHUTTER_TO_OPEN_DELAY
|
||||
self._move_start_latency = DEFAULT_MOVE_START_LATENCY
|
||||
self.device_manager = device_manager
|
||||
self._poll_thread = threading.Thread(target=self._poll_event_status, daemon=True)
|
||||
self._poll_thread_run_event = threading.Event()
|
||||
@@ -281,6 +323,36 @@ class DDG1(PSIDeviceBase, DelayGeneratorCSAXS):
|
||||
"""Get the current delay that is set to open the shutter before the exposure time."""
|
||||
return self._shutter_to_open_delay
|
||||
|
||||
def get_move_start_latency(self) -> float:
|
||||
"""Get the delay a scan should leave between issuing a line move and triggering."""
|
||||
return self._move_start_latency
|
||||
|
||||
def set_move_start_latency(self, latency: float) -> None:
|
||||
"""Set how long a scan waits after issuing a line move before it triggers.
|
||||
|
||||
This is not a property of the delay generator. It is the latency of the
|
||||
scan server -> device server -> EPICS -> controller path, and it lives here
|
||||
because this is where cont_grid already fetches its trigger timing. Too
|
||||
small and the burst starts before the stage does, so the first points of
|
||||
every line pile up at the line start; too large and the stage runs past
|
||||
the start of the line before the first gate fires.
|
||||
|
||||
Set to 0 for the behaviour that preceded this parameter.
|
||||
|
||||
Args:
|
||||
latency (float): Delay in seconds.
|
||||
|
||||
Raises:
|
||||
ValueError: If negative or above MAX_MOVE_START_LATENCY.
|
||||
"""
|
||||
latency = float(latency)
|
||||
if not 0 <= latency <= MAX_MOVE_START_LATENCY:
|
||||
raise ValueError(
|
||||
f"Move-start latency must be between 0 and {MAX_MOVE_START_LATENCY} s,"
|
||||
f" got {latency}."
|
||||
)
|
||||
self._move_start_latency = latency
|
||||
|
||||
def set_shutter_to_open_delay(self, delay: float) -> None:
|
||||
"""Set how long the shutter is given to open before the first gate fires.
|
||||
|
||||
|
||||
@@ -44,6 +44,7 @@ class ContinuousMotorParameter(TypedDict):
|
||||
acc_time: float | None
|
||||
premove_distance: float | None
|
||||
shutter_open_delay: float | None
|
||||
move_start_latency: float | None
|
||||
num_lines: int | None
|
||||
|
||||
|
||||
@@ -270,7 +271,15 @@ class ContGrid(ScanBase):
|
||||
self.fast_axis.velocity.set(self._cont_motor_params["target_velocity"]).wait(timeout=5)
|
||||
self.fast_axis.acceleration.set(self._cont_motor_params["acc_time"]).wait(timeout=5)
|
||||
move_status = self.actions.set(motors, positions, wait=False)
|
||||
time.sleep(self._cont_motor_params["acc_time"])
|
||||
# Wait for the move to reach the motor, and then for the stage to get up to
|
||||
# speed. Only the second of those is acc_time; the first is the latency of
|
||||
# the scan server -> device server -> EPICS -> controller path, which does
|
||||
# not shrink with the scan velocity while acc_time does. Without it the
|
||||
# burst starts before the stage and the first points of every line pile up
|
||||
# at the line start. See DEFAULT_MOVE_START_LATENCY for the measurement.
|
||||
time.sleep(
|
||||
self._cont_motor_params["move_start_latency"] + self._cont_motor_params["acc_time"]
|
||||
)
|
||||
self.ddg1.trigger_shot.put(1)
|
||||
while not move_status.done:
|
||||
self.actions.read_monitored_devices(wait=True)
|
||||
@@ -350,6 +359,7 @@ class ContGrid(ScanBase):
|
||||
|
||||
def _fetch_device_params(self):
|
||||
self._cont_motor_params["shutter_open_delay"] = self.ddg1.get_shutter_to_open_delay()
|
||||
self._cont_motor_params["move_start_latency"] = self.ddg1.get_move_start_latency()
|
||||
self._cont_motor_params["original_acceleration"] = self.fast_axis.acceleration.get()
|
||||
self._cont_motor_params["original_velocity"] = self.fast_axis.velocity.get()
|
||||
self._cont_motor_params["base_velocity"] = self.fast_axis.base_velocity.get()
|
||||
|
||||
@@ -23,7 +23,9 @@ from csaxs_bec.devices.epics.delay_generator_csaxs.ddg_1 import (
|
||||
DEFAULT_TRIGGER_SOURCE as DDG1_DEFAULT_TRIGGER_SOURCE,
|
||||
)
|
||||
from csaxs_bec.devices.epics.delay_generator_csaxs.ddg_1 import (
|
||||
DEFAULT_MOVE_START_LATENCY,
|
||||
DEFAULT_SHUTTER_TO_OPEN_DELAY,
|
||||
MAX_MOVE_START_LATENCY,
|
||||
MAX_SHUTTER_TO_OPEN_DELAY,
|
||||
)
|
||||
from csaxs_bec.devices.epics.delay_generator_csaxs.ddg_1 import PROC_EVENT_MODE
|
||||
@@ -276,6 +278,43 @@ def test_ddg1_prepare_mcs(mock_ddg1: DDG1, mock_mcs_csaxs: MCSCardCSAXS):
|
||||
assert st.success is True
|
||||
|
||||
|
||||
def test_ddg1_move_start_latency_default(mock_ddg1: DDG1):
|
||||
assert mock_ddg1.get_move_start_latency() == DEFAULT_MOVE_START_LATENCY
|
||||
|
||||
|
||||
def test_ddg1_move_start_latency_round_trips(mock_ddg1: DDG1):
|
||||
mock_ddg1.set_move_start_latency(0.25)
|
||||
assert mock_ddg1.get_move_start_latency() == 0.25
|
||||
# zero is the escape hatch back to the timing that preceded the parameter
|
||||
mock_ddg1.set_move_start_latency(0)
|
||||
assert mock_ddg1.get_move_start_latency() == 0
|
||||
|
||||
|
||||
@pytest.mark.parametrize("bad", [-0.1, MAX_MOVE_START_LATENCY + 0.1])
|
||||
def test_ddg1_move_start_latency_is_bounded(mock_ddg1: DDG1, bad: float):
|
||||
with pytest.raises(ValueError):
|
||||
mock_ddg1.set_move_start_latency(bad)
|
||||
assert mock_ddg1.get_move_start_latency() == DEFAULT_MOVE_START_LATENCY
|
||||
|
||||
|
||||
def test_ddg1_move_start_latency_is_reachable_from_the_client(mock_ddg1: DDG1):
|
||||
"""cont_grid reads it over RPC and users tune it over RPC; without these it is
|
||||
unreachable from either."""
|
||||
assert "get_move_start_latency" in DDG1.USER_ACCESS
|
||||
assert "set_move_start_latency" in DDG1.USER_ACCESS
|
||||
|
||||
|
||||
def test_ddg1_move_start_latency_is_independent_of_the_shutter_delay(mock_ddg1: DDG1):
|
||||
"""Two timing constants on the same device with different natures -- one is
|
||||
hardware (how long the shutter takes to open), one is software (how long a move
|
||||
takes to reach the motor). Neither may disturb the other."""
|
||||
mock_ddg1.set_move_start_latency(0.25)
|
||||
mock_ddg1.set_shutter_to_open_delay(0.009)
|
||||
assert mock_ddg1.get_move_start_latency() == 0.25
|
||||
mock_ddg1.keep_shutter_open_during_scan(True)
|
||||
assert mock_ddg1.get_move_start_latency() == 0.25
|
||||
|
||||
|
||||
def test_ddg1_shutter_delay_default(mock_ddg1: DDG1):
|
||||
assert mock_ddg1.get_shutter_to_open_delay() == DEFAULT_SHUTTER_TO_OPEN_DELAY
|
||||
|
||||
|
||||
@@ -65,6 +65,9 @@ def _assemble_cont_grid_scan(v4_scan_assembler, device_manager):
|
||||
signal_read_values={"ddg1": 0.0},
|
||||
)
|
||||
custom_ddg1.get_shutter_to_open_delay = mock.MagicMock(return_value=2e-3)
|
||||
# 0.0 so the hook tests do not spend a real 0.6 s per line; the value itself
|
||||
# is exercised explicitly further down.
|
||||
custom_ddg1.get_move_start_latency = mock.MagicMock(return_value=0.0)
|
||||
custom_mcs = MockCustomDevice(
|
||||
"mcs",
|
||||
device_info={
|
||||
@@ -110,6 +113,58 @@ def test_cont_grid_post_scan_waits_for_completion_and_moves_back_when_relative(
|
||||
assert completion_status.wait_calls == 1
|
||||
|
||||
|
||||
def test_cont_grid_waits_for_the_move_to_reach_the_motor_before_triggering(
|
||||
v4_scan_assembler, device_manager, nth_done_status_mock
|
||||
):
|
||||
"""The burst must not start before the stage does.
|
||||
|
||||
at_each_point issues the line move and then sleeps before firing the trigger.
|
||||
That sleep used to be acc_time alone, which covers the acceleration ramp and
|
||||
nothing else -- while the move still has to cross the scan server -> device
|
||||
server -> EPICS -> controller path first. acc_time shrinks with the scan
|
||||
velocity; that path does not, so on a slow scan the burst began about 0.6 s
|
||||
before the stage moved and the first points of every line piled up at the
|
||||
line start.
|
||||
"""
|
||||
scan = _assemble_cont_grid_scan(v4_scan_assembler, device_manager)
|
||||
scan.device_manager.devices["ddg1"].get_move_start_latency = mock.MagicMock(
|
||||
return_value=0.35
|
||||
)
|
||||
scan.prepare_scan()
|
||||
|
||||
scan.actions.set = mock.MagicMock(return_value=nth_done_status_mock(resolve_after=1))
|
||||
scan.ddg1 = mock.MagicMock()
|
||||
# after prepare_scan, so acc_time is still the value the real mock device gave
|
||||
scan.fast_axis = mock.MagicMock()
|
||||
scan.actions.read_monitored_devices = mock.MagicMock()
|
||||
|
||||
with mock.patch("csaxs_bec.scans.scans_v4.cont_grid.time.sleep") as sleep:
|
||||
scan.at_each_point(scan.motors, scan.positions[0], nth_done_status_mock(resolve_after=1))
|
||||
|
||||
assert scan._cont_motor_params["move_start_latency"] == 0.35
|
||||
sleep.assert_called_once_with(0.35 + scan._cont_motor_params["acc_time"])
|
||||
|
||||
|
||||
def test_cont_grid_move_start_latency_of_zero_restores_the_previous_timing(
|
||||
v4_scan_assembler, device_manager, nth_done_status_mock
|
||||
):
|
||||
"""The escape hatch: setting the latency to 0 on the device reproduces exactly
|
||||
what the scan did before this parameter existed, with no redeploy."""
|
||||
scan = _assemble_cont_grid_scan(v4_scan_assembler, device_manager)
|
||||
scan.prepare_scan()
|
||||
|
||||
scan.actions.set = mock.MagicMock(return_value=nth_done_status_mock(resolve_after=1))
|
||||
scan.ddg1 = mock.MagicMock()
|
||||
# after prepare_scan, so acc_time is still the value the real mock device gave
|
||||
scan.fast_axis = mock.MagicMock()
|
||||
scan.actions.read_monitored_devices = mock.MagicMock()
|
||||
|
||||
with mock.patch("csaxs_bec.scans.scans_v4.cont_grid.time.sleep") as sleep:
|
||||
scan.at_each_point(scan.motors, scan.positions[0], nth_done_status_mock(resolve_after=1))
|
||||
|
||||
sleep.assert_called_once_with(scan._cont_motor_params["acc_time"])
|
||||
|
||||
|
||||
def test_cont_grid_prepare_scan_keeps_generated_positions_stable(v4_scan_assembler, device_manager):
|
||||
scan = _assemble_cont_grid_scan(v4_scan_assembler, device_manager)
|
||||
|
||||
|
||||
Reference in New Issue
Block a user