This was a result of an unintentional implicit assumption than when the PD shutter opening is requested 1 metatron cycle after the vbias, the shuter opens 1 second later. Clearly this is not always the case, figure 1 shows an example when it takes 2 second after vbias enabled to have the shutter open. This fools DET_MAIN that doesn't see any power on the PDs, so think the slow shutter is closed, and one second later realizes the error.
Today around 10:20 UTC change the waiting logic to be 2 metatron cycles after the vbias dropped below -10V in the data read back by metatron.
There was a mistake in that change which made the situation worse. And around 11:00 UTC DET_MAIN went into a loop at two occasion. Fixed the issue around 12:00 UTC.
These loop highlighted a more high level issue (see log below), when MICH unlocks while in recombined before the slow shutter has the time to close, then the ITF doesn't go through the DOWN state, so the request to DET_MAIN is still to go to the SHUTTER_CLOSED state, but DET_MAIN can close the shutter only if the MICH flashes are not present, can MICH can't be locked because DET_MAIN closes the fast shutter at each cycle.
A solution would be for ITF_LOCK to check that DET_MAIN is in ENABLE_B1p or SHUTTER_CLOSED at all the steps between DOWN and LOCKED_RECOMBINED (instead of just DOWN like right now).
In addition, for other issues that we have stumbled upon yet, an auto relock like feature needs to be added to DET_MAIN, so that if it cycles through the DOWN state several times without reaching its target, then it stops trying.
2018-10-19-11h04m59-UTC>WARNING-[LOCKED_RECOMBINED.run] USERMSG 0: Waiting for SDB1 slow shutter to close
2018-10-19-11h05m02-UTC>INFO...-Unstalling MICH_LOCK
2018-10-19-11h05m02-UTC>WARNING-MICH unlocked! Relocking MICH...
2018-10-19-11h05m03-UTC>INFO...-Unstalling CARM_DARM_LOCK
2018-10-19-11h05m03-UTC>WARNING-in LOCKING_RECOMBINED main
2018-10-19-11h05m03-UTC>INFO...-cm_send('LSC_Acl', 'AcConstChSet', 'B4_DC_CALI', 15.0, 1.0, 'apply')
2018-10-19-11h05m04-UTC>WARNING-One arm unlocked! Relocking arms...
2018-10-19-11h05m05-UTC>WARNING-in LOCKING_ARMS main
2018-10-19-11h05m05-UTC>INFO...-cm_send('LSC_Acl', 'AcRelayChTranSet', 'ENABLE', 1)
2018-10-19-11h05m05-UTC>INFO...-cm_send('ASC_Acl', 'AcConstChSet', 'ASC_ENABLE', 1.0)
2018-10-19-11h05m05-UTC>WARNING-[LOCKING_ARMS.main] ezca: V1:GRD-MICH_LOCK_REQUEST => DOWN
2018-10-19-11h05m09-UTC>INFO...-Unstalling DET_MAIN
