pass1 Autosave is Broken

[ZLLentz]

And I think pytmc is the right place to fix it. Nobody has been able to prove this issue to me, so I did some tests today.

I created a PLC program with the following pragmas:

    // Floating point setting, default autosave
    {attribute 'pytmc' := '
        pv: PLC:TST:PASS0
    '}
    fAutoPass0: LREAL;

    // Floating point setting, pass1 autosave
    {attribute 'pytmc' := '
        pv: PLC:TST:PASS1
        autosave_pass1: VAL
    '}
    fAutoPass1: LREAL;

Then I did some caputs to get to this state:

pass0 = 3.1415
pass1 = 42

Wait a bit (I did some laundry), restart the PLC to zero them out, restart the IOC to activate the autosave load:

pass0 = 0
pass1 = 0

... "What?" I thought. So there's an actual issue. I see the successful loading messages in the ioc shell but the values aren't here in the PLC. I expected the pass1 to make it through and the pass0 to fail to get into the PLC, but both have failed.

For a prospective fix, I decided to set PINI=1 by manually editing the db files. I did this on both the pass0 and the pass1 PVs. Then, I put 21 to each of the values on the PLC side so I could be sure if "something" was happening (in retrospect this step did not need to be done).

I restarted the IOC with the PINI=1 hotfix on my IOC and found:

pass0=21
pass1=42

... so without the PINI set, the record never gets processed, even if it is in pass1. And with the PINI set, the pass0 autosave does not get applied to the PLC.

My proposed solution options:

• Set PINI=1 in all records
• OR, more conservatively, set PINI=1 in all records with VAL autosaved at pass1

Thoughts?

[ZLLentz]

This is where PINI is currently stripped in output records, presumably to prevent accidental writes at startup: https://github.com/slaclab/pytmc/blob/62fd04d723885c3da264a11dcc9e87e90c4aae5e/pytmc/record.py#L477

[klauer]

Hmm, the behavior here goes against what I thought I knew (but that's nothing new with EPICS!).

One thing that was on the back of my mind, is: what if the autosaved pass0 and pass1 values being identical are causing it not to process after iocInit? Since you have it setup already, would you mind giving this a try, @ZLLentz? It should be pretty easy to confirm even without tweaking the pragmas: you could just delete the pass0 save file, reboot the PLC, and restart the IOC, I think.

I have no other ideas, and would be happy at least to implement the conservative option for starters.

[ZLLentz]

@klauer, you're saying that the successful load of a pass0 may be preventing the corresponding pass1 load/apply? Definitely worth a check, I'll stop/delete/restart as suggested

[ZLLentz]

I gave it a go, it didn't seem to work. Before calling this I'm going to make sure that PINI=1 with no previous saved values doesn't automatically slap a 0 into the PLC, which could be dangerous.

[klauer]

Yes, as autosave docs say:

At run time (after iocInit has completed), autosave reads and writes using channel-access. 
Restoring at run time can produce a different result than restoring at boot time, because 
record processing may occur.

(That is to say, it's effectively a caput .VAL pass1_value)

This seems to be consistent with what I thought regarding pass1. I don't understand what's going on here.

[ZLLentz]

My double-checking suggests that this should be safe. I didn't get zero values pulled into my PLC.

My understanding of pass1 is exactly the same as yours. Perhaps there's something else going on that my solution is stepping over?

[klauer]

There could be something else going on - some initialization race or something? I don't want to suggest too crazy of things to waste your time testing, but maybe testing 1000 PVs with PINI off/on, or an epicsThreadSleep(1.0) in spots in the st.cmd may produce different results. Mike may be able to shed some light as he knows the ads internals better.

[ZLLentz]

An initialization race seems possible, but I'm not sure what kind of race it would be. Record fields at pass1 definitely load (but do not process), and if it was loading too early surely it would simply fail? (as a caput would)

[klauer]

Fair points - I'm grasping at straws here.

[ZLLentz]

I'll make an issue in ads-ioc to investigate the behavior, and self-assign this issue to do the conservative version of the bandaid fix.

[klauer]

I was incorrect here - in recollection and/or understanding. This appears to be the expected behavior based on all that I can find.

I now believe your proposed fix isn't a bandaid at all: it's the cure.

I've verified 3/4 of the reported bulletpoints in https://github.com/pcdshub/ads-ioc/issues/65, confirming with ads-async that the server (or actual PLC) will not see a write on startup with PINI=NO under any circumstances (the .VAL field is populated, but the record is not processed, contrary to what I had thought, leaving it in an undefined state).

The only discrepancy I noted was with pass 0 + PINI=YES.

``` $ ./configure_test.sh ** PINI=YES ** ** PASS 0 ** PLC:Test.VAL 15123 ** PASS 1 ** $ ./st.cmd |grep -i process # Initialize the IOC and start processing records _main_: dbProcess of 'PLC:Test' _main_: dbProcess of 'PLC:Test_RBV' cbLow: dbProcess of Active 'PLC:Test_RBV' with RPRO=0 ``` Server sees: ``` [D 11:41:04.597 protocol: 441] 127.0.0.1:52218 0.0.0.0:48898 {13} Handling AdsCommandId.WRITE [W 11:41:04.597 symbols: 141] Symbol write (0.0,) (b'\x00\x00\x00\x00\x00\x00\x00\x00') [D 11:41:04.597 protocol: 304] 127.0.0.1:52218 0.0.0.0:48898 Writing symbol old value: c_double(0.0) new value: c_double(0.0) ``` Or in short, a write of the value 0.0. Writing when PINI is YES makes logical sense to me, but this value doesn't. This is clearly undesirable behavior. This further points to the proposed fix being the correct one. It's possible a real PLC would behave differently, but I'd tend to trust this result, as the library is mostly protocol-compliant.