Load on a PandA doesn't seem to wait for it to take effect

[coretl]

@callumforrester and @olliesilvester have both seen cases where a load on PandA happens, then immediately after a different value is put, and the loaded value seems to take priority. This needs further investigation.

[olliesilvester]

This happened about 1% of the times where I used the yaml load on the panda, so it's likely a race condition. Also, I only noticed it happening with the sequencer table

[evalott100]

For documenting the error:

https://github.com/DiamondLightSource/hyperion/blob/73c4623a9e1806d24840541584ed9025b872c000/src/hyperion/device_setup_plans/setup_panda.py#L142-L149

This is the load save that's causing the issue.

[olliesilvester]

For documenting the error:

https://github.com/DiamondLightSource/hyperion/blob/73c4623a9e1806d24840541584ed9025b872c000/src/hyperion/device_setup_plans/setup_panda.py#L142-L149

This is the load save that's causing the issue.

From here, it's the yield from load_device(panda, config_yaml_path) followed by the yield from bps.abs_set(panda.seq[1].table, table, group="panda-config")

Where the sequencer table's values occasionally are overwritten by the load_device

[evalott100]

Reproduced with:

def load_plan():
    print("Starting plan")
    panda = get_panda()
    yield from ensure_connected(panda, timeout=DEFAULT_TIMEOUT)

    setter_infos = (
        SetterInfo(
            "flyscan2.yaml",
            {
                "outb1": np.array([0, 0, 0, 0, 0, 0], dtype=bool),
                "outd1": np.array([0, 0, 0, 0, 0, 0], dtype=bool),
            },
        ),
        SetterInfo(
            "flyscan1.yaml",
            {
                "outb1": np.array([1, 0, 1, 0, 0, 1], dtype=bool),
                "outd1": np.array([0, 0, 1, 0, 0, 1], dtype=bool),
            },
        ),
    )

    for try_number, setter_info in enumerate(cycle(setter_infos)):
        print(f"Setting up panda try number {try_number}")
        table_to_set: Dict = seq_table_from_arrays(
            **(yield from bps.rd(panda.seq[1].table))
        )
        table_to_set.update(setter_info.fields_to_set_after_table)
        yield from load_device(panda, setter_info.yaml_to_load)
        print(f"Loaded yaml file {setter_info.yaml_to_load} into panda")

        yield from bps.abs_set(panda.seq[1].table, table_to_set, group="panda-config")
        yield from bps.wait(group="panda-config", timeout=DEFAULT_TIMEOUT)

        set_table = yield from bps.rd(panda.seq[1].table)
        not_equal = {}
        for (key, set_table_value), table_to_set_value in zip(
            set_table.items(), table_to_set.values()
        ):
            if not np.array_equal(set_table_value, table_to_set_value):
                not_equal[key] = {
                    "set_value": set_table_value,
                    "table_to_set_value": table_to_set_value,
                }
        if not_equal:
            pprint(not_equal)
            return

Causing output

Starting plan
Setting up panda try number 0
Loaded yaml file flyscan2.yaml into panda
Setting up panda try number 1
Loaded yaml file flyscan1.yaml into panda
...
Setting up panda try number 147
Loaded yaml file flyscan1.yaml into panda
Setting up panda try number 148
Loaded yaml file flyscan2.yaml into panda
Setting up panda try number 149
Loaded yaml file flyscan1.yaml into panda
Setting up panda try number 150
Loaded yaml file flyscan2.yaml into panda
{'outb1': {'set_value': array([1, 0, 1, 0, 0, 1], dtype=uint8),
           'table_to_set_value': array([False, False, False, False, False, False])},
 'outc2': {'set_value': array([0, 1, 0, 0, 0, 0], dtype=uint8),
           'table_to_set_value': array([0, 0, 0, 0, 0, 0], dtype=uint8)},
 'outd1': {'set_value': array([0, 0, 1, 0, 0, 1], dtype=uint8),
           'table_to_set_value': array([False, False, False, False, False, False])},
 'oute1': {'set_value': array([1, 0, 0, 1, 0, 0], dtype=uint8),
           'table_to_set_value': array([0, 0, 0, 0, 0, 0], dtype=uint8)},
 'outf1': {'set_value': array([0, 1, 0, 0, 0, 0], dtype=uint8),
           'table_to_set_value': array([0, 0, 0, 0, 0, 0], dtype=uint8)}}

This implies that either:

• bps.wait is broken and for whatever reason is not adequately waiting for the PVs to be set
• Or... much more catastophically... pandablocks-ioc is momentarily setting values on the PVs then changing, allowing bps.wait to continue prematurely.

[evalott100]

It seems the second put is outright lost:

Starting plan
Setting up panda try number 0
    loaded yaml file flyscan2.yaml into panda
    checking table set
    table set successfully
==========================================================
Setting up panda try number 1
    loaded yaml file flyscan1.yaml into panda
    checking table set
    table set successfully
==========================================================
...
==========================================================
Setting up panda try number 156
    loaded yaml file flyscan2.yaml into panda
    checking table set
    table set successfully
==========================================================
Setting up panda try number 157
    loaded yaml file flyscan1.yaml into panda
    checking table set
    tables not equal trying again
{   'outb1': {   'set_value': array([0, 0, 0, 0, 0, 0], dtype=uint8),
                 'table_to_set_value': array([1, 0, 1, 0, 0, 1], dtype=int32)},
    'outd1': {   'set_value': array([0, 0, 0, 0, 0, 0], dtype=uint8),
                 'table_to_set_value': array([0, 0, 1, 0, 0, 1], dtype=int32)}}
        tables not equal after 1 retry
        tables not equal after 2 retry
        tables not equal after 3 retry
        tables not equal after 4 retry
        tables not equal after 5 retry
        tables not equal after 6 retry
...
        tables not equal after 978 retry

No errors to speak of on the pandablocks-ioc side. Waiting 0.1 seconds after load_device seems to prevent this issue.

[olliesilvester]

When I was looking into this, the ioc logs indicated that the sequencer table was being loaded twice, but the time resolution of those logs are high so both puts had the same timestamp

[evalott100]

I found a fix for this on the ioc side:

For posterity, here is the code I used to reproduce.

@dataclass
class SetterInfo:
    yaml_to_load: str
    seq_table_after_load: Dict
    fields_to_set_after_table: Dict

def verify_table_set(
    seq_table: SignalRW[SeqTable], table_to_set: Dict, try_number: int = 0
):
    seq_table_value = yield from bps.rd(seq_table)
    not_equal = {}
    for key in table_to_set:
        if not np.array_equal(seq_table_value[key], table_to_set[key]):
            not_equal[key] = {
                "set_value": seq_table_value[key],
                "table_to_set_value": table_to_set[key],
            }
    if not_equal:
        if try_number == 0:
            print("    tables not equal trying again")
            pprint(not_equal, indent=4)
            print()
        else:

            LINE_UP = '\033[1A'
            LINE_CLEAR = '\x1b[2K'
            print(LINE_UP, end=LINE_CLEAR)
            print(f"        tables not equal after {try_number} retry")
        if try_number == 100:
            raise RuntimeError("Tried 100 times to set table")
        yield from verify_table_set(
            seq_table, table_to_set, try_number=(try_number + 1)
        )
    else:
        if try_number == 0:
            print("    table set successfully")
        else:
            print(f"    table set successfully after {try_number} retries")

def load_plan():
    print("Starting plan")
    panda = get_panda()
    yield from ensure_connected(panda, timeout=DEFAULT_TIMEOUT)

    setter_infos = (
        SetterInfo(
            "flyscan2.yaml",
            {
                "outa1": np.array([0, 1, 0, 0, 1, 0], dtype=np.int32),
                "outb1": np.array([1, 0, 1, 0, 0, 1], dtype=np.int32),
                "outc1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outd1": np.array([0, 0, 1, 0, 0, 1], dtype=np.int32),
                "oute1": np.array([1, 0, 0, 1, 0, 0], dtype=np.int32),
                "outf1": np.array([0, 1, 0, 0, 0, 0], dtype=np.int32),
                "outa2": np.array([0, 1, 0, 0, 1, 0], dtype=np.int32),
                "outb2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outc2": np.array([0, 1, 0, 0, 0, 0], dtype=np.int32),
                "outd2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "oute2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outf2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "position": np.array([0, -65732, 52211, 111, 50267, -67732], dtype=np.int32),
                "repeats": np.array([1, 1, 1, 1, 1, 1], dtype=np.int32),
                "time1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "time2": np.array([1, 1, 1, 1, 1, 1], dtype=np.int32)
            },
            {
                "outb1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outd1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
            },
        ),
        SetterInfo(
            "flyscan1.yaml",
            {
                "outa1": np.array([0, 1, 0, 0, 1, 0], dtype=np.int32),
                "outb1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outc1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outd1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "oute1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outf1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outa2": np.array([0, 1, 0, 0, 1, 0], dtype=np.int32),
                "outb2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outc2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outd2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "oute2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "outf2": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "position": np.array([0, -65732, 52267, 0, 50267, -67732], dtype=np.int32),
                "repeats": np.array([1, 1, 1, 1, 1, 1], dtype=np.int32),
                "time1": np.array([0, 0, 0, 0, 0, 0], dtype=np.int32),
                "time2": np.array([1, 1, 1, 1, 1, 1], dtype=np.int32)
            },
            {
                "outb1": np.array([1, 0, 1, 0, 0, 1], dtype=np.int32),
                "outd1": np.array([0, 0, 1, 0, 0, 1], dtype=np.int32),
            },
        ),
    )

    for try_number, setter_info in enumerate(cycle(setter_infos)):
        print(f"Setting up panda try number {try_number}")
        table_to_set: Dict = seq_table_from_arrays(
            **(yield from bps.rd(panda.seq[1].table))
        )
        table_to_set.update(setter_info.fields_to_set_after_table)

        yield from load_device(panda, setter_info.yaml_to_load)
        print(
            f"    loaded yaml file {setter_info.yaml_to_load} into panda"
        )

        # THIS CHECK ALWAYS PASSED
        #print("    checking table after load")
        #yield from verify_table_set(panda.seq[1].table, setter_info.seq_table_after_load)

        yield from bps.abs_set(panda.seq[1].table, table_to_set, wait=True)
        print("    checking table set")
        yield from verify_table_set(panda.seq[1].table, table_to_set)
        print("==========================================================")