test that positioner is in position #748

[prjemian]

• Certain tests still fail randomly in CI #748

[prjemian]

After refactors, one new test failed:

______________________ test_position_sequence_calcpos[13] ______________________

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

    @pytest.mark.parametrize("target", POSITION_SEQUENCE)
    def test_position_sequence_calcpos(target, calcpos):
        """
        Move both pos and calcpos to reference, then target position.
    
        Args:
            target (_type_): new position for the move
            calcpos (_type_): positioner based on swait record
        """
    
        def motion(p, goal, delay):
            status = p.move(goal)
            assert status.elapsed > 0, str(status)
    
            short_delay_for_EPICS_IOC_database_processing(delay)
            assert math.isclose(p.setpoint.get(use_monitor=False), goal, abs_tol=p.actual_tolerance)
            confirm_in_position(p)
            if not p.inposition:  # in case cb_readback needs one more call
                p.cb_readback()
            assert p.inposition
    
        known_position = -1
        delay = 0.125
    
>       motion(calcpos, known_position, delay)  # known starting position

/home/runner/work/apstools/apstools/apstools/devices/tests/test_positioner_soft_done.py:342: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
/home/runner/work/apstools/apstools/apstools/devices/tests/test_positioner_soft_done.py:334: in motion
    confirm_in_position(p)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

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

    def confirm_in_position(positioner):
        """Positioner readback is close enough to the target."""
>       assert math.isclose(
            positioner.readback.get(use_monitor=False),
            positioner.setpoint.get(use_monitor=False),
            abs_tol=positioner.actual_tolerance,
        )
E       AssertionError: assert False
E        +  where False = <built-in function isclose>(-0.99, -1.0, abs_tol=1e-05)
E        +    where <built-in function isclose> = math.isclose
E        +    and   -0.99 = <bound method EpicsSignalBase.get of EpicsSignalRO(read_pv='gp:userCalc10.VAL', name='calcpos', parent='calcpos', value=-0.99, timestamp=1674974456.072028, auto_monitor=True, string=False)>(use_monitor=False)
E        +      where <bound method EpicsSignalBase.get of EpicsSignalRO(read_pv='gp:userCalc10.VAL', name='calcpos', parent='calcpos', value=-0.99, timestamp=1674974456.072028, auto_monitor=True, string=False)> = EpicsSignalRO(read_pv='gp:userCalc10.VAL', name='calcpos', parent='calcpos', value=-0.99, timestamp=1674974456.072028, auto_monitor=True, string=False).get
E        +        where EpicsSignalRO(read_pv='gp:userCalc10.VAL', name='calcpos', parent='calcpos', value=-0.99, timestamp=1674974456.072028, auto_monitor=True, string=False) = MyUserCalcPositioner(prefix='', name='calcpos', settle_time=0.0, timeout=None, read_attrs=['readback', 'setpoint', 'actuate'], configuration_attrs=['done', 'tolerance', 'target'], limits=None, egu='').readback
E        +    and   -1.0 = <bound method EpicsSignalBase.get of EpicsSignal(read_pv='gp:userCalc10.B', name='calcpos_setpoint', parent='calcpos', value=-1.0, timestamp=1674974455.981381, tolerance=1e-05, auto_monitor=True, string=False, write_pv='gp:userCalc10.B', limits=False, put_complete=True)>(use_monitor=False)
E        +      where <bound method EpicsSignalBase.get of EpicsSignal(read_pv='gp:userCalc10.B', name='calcpos_setpoint', parent='calcpos', value=-1.0, timestamp=1674974455.981381, tolerance=1e-05, auto_monitor=True, string=False, write_pv='gp:userCalc10.B', limits=False, put_complete=True)> = EpicsSignal(read_pv='gp:userCalc10.B', name='calcpos_setpoint', parent='calcpos', value=-1.0, timestamp=1674974455.981381, tolerance=1e-05, auto_monitor=True, string=False, write_pv='gp:userCalc10.B', limits=False, put_complete=True).get
E        +        where EpicsSignal(read_pv='gp:userCalc10.B', name='calcpos_setpoint', parent='calcpos', value=-1.0, timestamp=1674974455.981381, tolerance=1e-05, auto_monitor=True, string=False, write_pv='gp:userCalc10.B', limits=False, put_complete=True) = MyUserCalcPositioner(prefix='', name='calcpos', settle_time=0.0, timeout=None, read_attrs=['readback', 'setpoint', 'actuate'], configuration_attrs=['done', 'tolerance', 'target'], limits=None, egu='').setpoint
E        +    and   1e-05 = MyUserCalcPositioner(prefix='', name='calcpos', settle_time=0.0, timeout=None, read_attrs=['readback', 'setpoint', 'actuate'], configuration_attrs=['done', 'tolerance', 'target'], limits=None, egu='').actual_tolerance

/home/runner/work/apstools/apstools/apstools/devices/tests/test_positioner_soft_done.py:97: AssertionError

[prjemian]

Disable jscpd (multi-language copy/paste detector) linter tests for now.

Add VALIDATE_JSCPD: false in this block:

apstools/.github/workflows/linter.yml

Lines 48 to 54 in 6dfa765

	env:
	VALIDATE_ALL_CODEBASE: false
	DEFAULT_BRANCH: master
	LINTER_RULES_PATH: /
	PYTHON_BLACK_CONFIG_FILE: pyproject.toml
	PYTHON_FLAKE8_CONFIG_FILE: setup.cfg
	PYTHON_ISORT_CONFIG_FILE: pyproject.toml

[prjemian]

Locally, the tests succeed when run for thousands of times. In CI, failures are seen with various Python versions. A common factor is that the readback value is zero when the target is non-zero, such as:

AssertionError: rb=0.0  sp=-0.9642   tol=1e-05
AssertionError: rb=0.0  sp=-1.0674   tol=1e-05

[prjemian]

Failed in different tests, still involving end of move detection:

    def test_move_and_stop_nonzero(rbv, pos):
        short_delay_for_EPICS_IOC_database_processing()
    
        # move to non-zero
        longer_delay = 2
        target = round(rand(2, 5), 2)
        delayed_complete(pos, rbv, delay=longer_delay)
        t0 = time.time()  # time it
        status = pos.move(target)  # readback set by delayed_complete()
        dt = time.time() - t0
        assert status.done
        assert status.success
>       assert status.elapsed >= longer_delay
E       assert 0.0017082691192626953 >= 2

and

    def test_move_and_stop_nonzero(rbv, pos):
        short_delay_for_EPICS_IOC_database_processing()
    
        # move to non-zero
        longer_delay = 2
        target = round(rand(2, 5), 2)
        delayed_complete(pos, rbv, delay=longer_delay)
        t0 = time.time()  # time it
        status = pos.move(target)  # readback set by delayed_complete()
        dt = time.time() - t0
        assert status.done
        assert status.success
>       assert status.elapsed >= longer_delay
E       assert 0.0017082691192626953 >= 2

[prjemian]

As the readback may change, regardless of a planned motion, the inposition() method is a less reliable basis for setting the done signal.

[prjemian]

and yet, still, the tests fail randomly

[prjemian]

This test result makes no sense!

        assert p.done.get() == p.done_value, diagnostics
>       assert math.isclose(rb, sp, abs_tol=tol), diagnostics
E       AssertionError: rb=-0.86292  sp=-0.95880   tol=1e-05  dt=0.0075s  p._sp_count=1  p._rb_count=1  p.done=Signal(name='calcpos_done', parent='calcpos', value=True, timestamp=1675147512.1780746)  p.done_value=True  time.time()=1675147512.1992
E       assert False

The first assert tests the move is complete, which was determined by |rb - sp| <= tol. Yet the second assert shows this expression was False. Things have changed within this test method.

[prjemian]

Testing on the GHA server is unreliable. Disable such failing tests until this is better understood.