PVPositionerSoftDone gets stuck if target position is the same as current position

[gfabbris]

I ran into this problem with a couple of devices that use PVPositionerSoftDone. I think this is because if the position is the same as the current value in:

apstools/apstools/devices/positioner_soft_done.py

Line 191 in c52de89

self.setpoint.put(position, wait=True)

Then cb_setpoint is not called, and done is never switched to False.

[gfabbris]

Maybe we can remove this subscription:

apstools/apstools/devices/positioner_soft_done.py

Line 179 in c52de89

self.setpoint.subscribe(self.cb_setpoint)

But always call the cb_setpoint in _setup_move:

    def _setup_move(self, position):
        """Move and do not wait until motion is complete (asynchronous)"""
        self.log.debug("%s.setpoint = %s", self.name, position)
        if self.update_target:
            kwargs = {}
            if issubclass(self.target.__class__, EpicsSignalBase):
                kwargs["wait"] = True  # Signal.put() warns if kwargs are given
            self.target.put(position, **kwargs)
        self.setpoint.put(position, wait=True)
        if self.actuate is not None:
            self.log.debug("%s.actuate = %s", self.name, self.actuate_value)
            self.actuate.put(self.actuate_value, wait=False)
        self.cb_setpoint()  # Forces done to be false.
        self.cb_readback()  # This is needed to force the first check.

Or just switch done to false:

    def _setup_move(self, position):
        """Move and do not wait until motion is complete (asynchronous)"""
        self.log.debug("%s.setpoint = %s", self.name, position)
        if self.update_target:
            kwargs = {}
            if issubclass(self.target.__class__, EpicsSignalBase):
                kwargs["wait"] = True  # Signal.put() warns if kwargs are given
            self.target.put(position, **kwargs)
        self.setpoint.put(position, wait=True)
        if self.actuate is not None:
            self.log.debug("%s.actuate = %s", self.name, self.actuate_value)
            self.actuate.put(self.actuate_value, wait=False)
        self.done.put(not self.done_value)  # Forces done to be false.
        self.cb_readback()  # This is needed to force the first check.

[prjemian]

@gfabbris Thanks for reporting. I'll also add unit test(s) for this.

[prjemian]

Perhaps we see the same problem with this existing unit test code:

apstools/apstools/devices/tests/test_positioner_soft_done.py

Line 359 in d062549

confirm_in_position(calcpos)

It was succeeding locally but failing in GitHub Actions, so it was localized (test_move_calcpos[12] SKIPPED (need --run-local option to run)) using:

apstools/apstools/devices/tests/test_positioner_soft_done.py

Line 344 in d062549

@pytest.mark.local

[prjemian]

Now, local runs fail randomly. There's a problem lurking. Investigating...

[prjemian]

@gfabbris Here's my test code. It's not failing for me locally. Suggestions? Meanwhile, I'll start a PR so GHA will run the tests.

apstools/apstools/devices/tests/test_issue725.py

Lines 7 to 30 in e089f3f

	@pytest.mark.parametrize(
	# fmt: off
	"target", [-1.2345, -1, -1, -0.1, -0.1, 0, 0, 0, 0.1, 0.1, 1, 1, 1.2345]
	# fmt: on
	)
	def test_same_position_725(target, calcpos):
	# Before anything is changed.
	confirm_in_position(calcpos)
	if calcpos.position == target:
	# First, move away from the target.
	status = calcpos.move(-target or 0.1 *(1 + random.random()))
	assert status.elapsed > 0, str(status)
	confirm_in_position(calcpos)
	# Move to the target position.
	status = calcpos.move(target)
	assert status.elapsed > 0, str(status)
	confirm_in_position(calcpos)
	# Do it again (the reason for issue #725).
	status = calcpos.move(target)
	assert status.elapsed > 0, str(status)
	confirm_in_position(calcpos)

[prjemian]

GHA ran. This is the same error you saw @gfabbris ?

    def test_same_position_725(target, calcpos):
        # Before anything is changed.
        confirm_in_position(calcpos)
    
        # Confirm the initial position is as expected.
        if calcpos.position == target:
            # First, move away from the target.
            status = calcpos.move(-target or 0.1 * (1 + random.random()))
            assert status.done
            assert status.elapsed > 0, str(status)
>           confirm_in_position(calcpos)

/home/runner/work/apstools/apstools/apstools/devices/tests/test_positioner_soft_done.py:384: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

positioner = PVPositionerSoftDoneWithStop(prefix='', name='calcpos', settle_time=0.0, timeout=None, read_attrs=['readback', 'setpoint'], configuration_attrs=['done', 'tolerance', 'target'], limits=None, egu='')

    def confirm_in_position(positioner):
        """Apply the 'inposition' property code."""
        reading = positioner.read()
        p = reading[positioner.setpoint.name]["value"]
        r = reading[positioner.readback.name]["value"]
        t = positioner.actual_tolerance
>       assert abs(r - p) <= t, f"target={p}, readback={r}, tolerance={t}"
E       AssertionError: target=0.1548780125648433, readback=0.0, tolerance=1e-05
E       assert 0.1548780125648433 <= 1e-05
E        +  where 0.1548780125648433 = abs((0.0 - 0.1548780125648433))

/home/runner/work/apstools/apstools/apstools/devices/tests/test_positioner_soft_done.py:261: AssertionError
=============================== warnings summary ===============================

[gfabbris]

I think I understand this bug. The issue seems to be when the EpicsSignal uses a write_pv that is different from the "read" pv, as for instance in the Lakeshore 336:

apstools/apstools/devices/lakeshore_controllers.py

Lines 46 to 48 in fddc972

	setpoint = FormattedComponent(
	EpicsSignalWithRBV, "{prefix}OUT{loop_number}:SP", put_complete=True
	)

In [25]: lakeshore336.loop2.setpoint._write_pv
Out[25]: <PV '4idd:LS336:TC3:OUT2:SP', count=1, type=time_double, access=read/write>

In [26]: lakeshore336.loop2.setpoint._read_pv
Out[26]: <PV '4idd:LS336:TC3:OUT2:SP_RBV', count=1, type=time_double, access=read/write>

Then, the setpoint.put does not run the SUB_VALUE callback because this line doesn't run since self.pvname != self.setpoint_pvname.

[prjemian]

What would be the consequence if the lakeshore336.loop2.setpoint was changed to EpicsSignal("{prefix}OUT{loop_number}:SP", ...)? (Ignoring the read PV)

[gfabbris]

Yes, this solves the problem in the lakeshore. But it is a more general problem, I had another device that used PVPositionerSoftDone that had the same issue. My understanding is that the real bug is in EpicsSignal, because it should run the "sub_value" regardless of a separate write_pv being given or not.

For apstools, I would prefer to add a self.cb_setpoint() in the PVPositionerSoftDone._setup_move since that will fix the issue regardless of how the setpoint is configured.

[prjemian]

Can you add code proposing that?

[gfabbris]

Here it is: e91fa01.

Should we bring this up with the Bluesky team? We could double check this before, but I think this is not the expected behavior for EpicsSignal.

[prjemian]

Should we bring this up with the Bluesky team?

Yes