sheila.dwyer@LIGO.ORG - posted 01:31, Tuesday 23 August 2016 - last comment - 10:28, Tuesday 23 August 2016(29238)
strange lockloss
Jenne, Sheila
We had an unusual lockloss a few minutes ago, related to 28255
I happened around 8:11 August 23rd UTC, the DRMI gaurdian seemed to think that the lock was lost although it was not.
There are two locklosses around that time, so Ill play detective for both.
1.) 8:09:33 UTC (1155974990)
Looking at the Guardian log:
2016-08-23_08:09:30.786330Z ISC_DRMI [ENGAGE_DRMI_ASC.run] ezca: H1:ASC-MICH_P_SW1 => 16
2016-08-23_08:09:31.037960Z ISC_DRMI [ENGAGE_DRMI_ASC.run] ezca: H1:ASC-MICH_P => OFF: FM1
2016-08-23_08:09:31.042700Z ISC_DRMI [ENGAGE_DRMI_ASC.run] ezca: H1:ASC-MICH_Y_SW1 => 16
2016-08-23_08:09:31.290770Z ISC_DRMI [ENGAGE_DRMI_ASC.run] ezca: H1:ASC-MICH_Y => OFF: FM1
2016-08-23_08:09:33.911750Z ISC_DRMI new request: DRMI_WFS_CENTERING
2016-08-23_08:09:33.911930Z ISC_DRMI calculating path: ENGAGE_DRMI_ASC->DRMI_WFS_CENTERING
2016-08-23_08:09:33.912540Z ISC_DRMI new target: DOWN
2016-08-23_08:09:33.912620Z ISC_DRMI GOTO REDIRECT
2016-08-23_08:09:33.912900Z ISC_DRMI REDIRECT requested, timeout in 1.000 seconds
Seems as though there was a request for a state that is behind its current position, so it had to go through DOWN to get there. This request came from ISC_LOCK:
2016-08-23_08:09:33.546800Z ISC_LOCK [LOCK_DRMI_3F.run] DRMI TRIGGERED NOT LOCKED:
2016-08-23_08:09:33.546920Z ISC_LOCK [LOCK_DRMI_3F.run] LSC-MICH_TRIG_MON = 0.0
2016-08-23_08:09:33.547020Z ISC_LOCK [LOCK_DRMI_3F.run] LSC-PRCL_TRIG_MON = 1.0
2016-08-23_08:09:33.547110Z ISC_LOCK [LOCK_DRMI_3F.run] LSC-SRCL_TRIG_MON = 0.0
2016-08-23_08:09:33.547210Z ISC_LOCK [LOCK_DRMI_3F.run] DRMI lost lock
2016-08-23_08:09:33.602500Z ISC_LOCK state returned jump target: LOCKLOSS_DRMI
2016-08-23_08:09:33.602710Z ISC_LOCK [LOCK_DRMI_3F.exit]
2016-08-23_08:09:33.666340Z ISC_LOCK JUMP: LOCK_DRMI_3F->LOCKLOSS_DRMI
2016-08-23_08:09:33.667220Z ISC_LOCK calculating path: LOCKLOSS_DRMI->LOCK_DRMI_3F
2016-08-23_08:09:33.667760Z ISC_LOCK new target: LOCK_DRMI_1F
2016-08-23_08:09:33.668520Z ISC_LOCK executing state: LOCKLOSS_DRMI (3)
2016-08-23_08:09:33.668750Z ISC_LOCK [LOCKLOSS_DRMI.enter]
2016-08-23_08:09:33.854350Z ISC_LOCK EDGE: LOCKLOSS_DRMI->LOCK_DRMI_1F
2016-08-23_08:09:33.855110Z ISC_LOCK calculating path: LOCK_DRMI_1F->LOCK_DRMI_3F
2016-08-23_08:09:33.855670Z ISC_LOCK new target: ENGAGE_DRMI_ASC
2016-08-23_08:09:33.856260Z ISC_LOCK executing state: LOCK_DRMI_1F (101)
2016-08-23_08:09:33.856410Z ISC_LOCK [LOCK_DRMI_1F.enter]
2016-08-23_08:09:33.868100Z ISC_LOCK [LOCK_DRMI_1F.main] USERMSG 0: node TCS_ITMY_CO2_PWR: NOTIFICATION
2016-08-23_08:09:33.868130Z ISC_LOCK [LOCK_DRMI_1F.main] USERMSG 1: node SEI_BS: NOTIFICATION
2016-08-23_08:09:33.893890Z ISC_LOCK [LOCK_DRMI_1F.main] ezca: H1:GRD-ISC_DRMI_REQUEST => DRMI_WFS_CENTERING
and
2.) 08:13:12 UTC (1155975209)
Doesnt seem to be any funny business here. The DRMI_locked() function looks at the channels in the log below and then will return to DRMI_1F, and at this point it seems like the MC lost lock (see plots).
2016-08-23_08:13:17.613090Z ISC_DRMI [DRMI_WFS_CENTERING.run] DRMI TRIGGERED NOT LOCKED:
2016-08-23_08:13:17.613160Z ISC_DRMI [DRMI_WFS_CENTERING.run] LSC-MICH_TRIG_MON = 0.0
2016-08-23_08:13:17.613230Z ISC_DRMI [DRMI_WFS_CENTERING.run] LSC-PRCL_TRIG_MON = 1.0
2016-08-23_08:13:17.613300Z ISC_DRMI [DRMI_WFS_CENTERING.run] LSC-SRCL_TRIG_MON = 0.0
2016-08-23_08:13:17.613500Z ISC_DRMI [DRMI_WFS_CENTERING.run] la la
2016-08-23_08:13:17.670880Z ISC_DRMI state returned jump target: LOCK_DRMI_1F
2016-08-23_08:13:17.671070Z ISC_DRMI [DRMI_WFS_CENTERING.exit]
2016-08-23_08:13:17.671520Z ISC_DRMI STALLED
2016-08-23_08:13:17.734330Z ISC_DRMI JUMP: DRMI_WFS_CENTERING->LOCK_DRMI_1F
2016-08-23_08:13:17.741520Z ISC_DRMI calculating path: LOCK_DRMI_1F->DRMI_WFS_CENTERING
2016-08-23_08:13:17.742080Z ISC_DRMI new target: DRMI_LOCK_WAIT
2016-08-23_08:13:17.742750Z ISC_DRMI executing state: LOCK_DRMI_1F (30)
2016-08-23_08:13:17.742920Z ISC_DRMI [LOCK_DRMI_1F.enter]
2016-08-23_08:13:17.744030Z ISC_DRMI [LOCK_DRMI_1F.main] MC not Locked
2016-08-23_08:13:17.795150Z ISC_DRMI state returned jump target: DOWN
2016-08-23_08:13:17.795290Z ISC_DRMI [LOCK_DRMI_1F.exit]
Here are the functions that are used as decorators in DRMI_WFS_CENTERING
def MC_locked():
trans_pd_lock_threshold = 50
return ezca['IMC-MC2_TRANS_SUM_OUTPUT']/ezca['IMC-PWR_IN_OUTPUT'] >= trans_pd_lock_threshold
def DRMI_locked():
MichMon = ezca['LSC-MICH_TRIG_MON']
PrclMon = ezca['LSC-PRCL_TRIG_MON']
SrclMon = ezca['LSC-SRCL_TRIG_MON']
if (MichMon > 0.5) and (PrclMon > 0.5) and (SrclMon > 0.5):
# We're still locked and triggered, so return True
return True
else:
# Eeep! Not locked. Log some stuff
log('DRMI TRIGGERED NOT LOCKED:')
log('LSC-MICH_TRIG_MON = %s' % MichMon)
log('LSC-PRCL_TRIG_MON = %s' % PrclMon)
log('LSC-SRCL_TRIG_MON = %s' % SrclMon)
return False
Something I also should have mentioned is that ISC_LOCK was brought into Manual and then requested LOCK_DRMI_3F right before the logs seen above. Seems as though it wasnt quite ready to be there yet so it jumped back down to LOCK_DRMI_1F, reran the state where it requested DRMI_WFS_CENTERING from the ISC_DRMI guardian.