Log opened at Sun, Apr 26 2020 03:13:23 UTC (actual time)
Current log level is Debug
ACP Expert Scheduler version 8.2.3
Full license: Arne Henden
2020-04-26 03:13:23.5: ++ Observatory Startup ++
2020-04-26 03:13:23.6: Start ACP Sequencer's StartupObs script
2020-04-26 03:13:23.6: Starting with open dome, unsafe weather will cause operator intervention error
2020-04-26 03:13:23.6: ACP.RunScript(StartupObs, ):
2020-04-26 03:13:23.6:   Script StartupObs is loaded, and
2020-04-26 03:13:23.6:   the console is idle.
2020-04-26 03:13:23.6:   In start loop, i = 0
2020-04-26 03:13:23.6:   Console is now idle
2020-04-26 03:13:23.6:   Loaded C:\Users\Public\Documents\ACP Config\Scheduler\StartupObs.js successfully
2020-04-26 03:13:23.6:   Script started successfully
2020-04-26 03:13:33.7: Sequencer is now active
2020-04-26 03:13:38.7: Sequencer is no longer active
2020-04-26 03:13:38.7: Observatory startup succeeded
2020-04-26 03:13:38.7: ++ Auto Focus ++
2020-04-26 03:13:38.7: Doing initial autofocus.
2020-04-26 03:13:38.7: Start special ACP AutoFocus script for scheduler
2020-04-26 03:13:38.7: ACP.RunScript(AutoFocusScheduler, ):
2020-04-26 03:13:38.7:   Script StartupObs is loaded, and
2020-04-26 03:13:38.7:   the console is idle.
2020-04-26 03:13:38.7:   In start loop, i = 0
2020-04-26 03:13:38.7:   Console is now idle
2020-04-26 03:13:38.8:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2020-04-26 03:13:38.8:   Script started successfully
2020-04-26 03:13:48.8: Sequencer is now active
2020-04-26 03:16:17.6: Sequencer is no longer active
2020-04-26 03:16:17.6: ** Autofocus failed (n=1), will retry ASAP after 0 min.
2020-04-26 03:16:17.8: SelectRunning: No running plans
2020-04-26 03:16:17.8: STRICT VETO:
2020-04-26 03:16:17.8: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2020-04-26 03:16:17.8:     AirMass estimates ready after 26-Apr-2020 19:25:12 UTC
2020-04-26 03:16:17.8: STRICT VETO:
2020-04-26 03:16:17.8: Obs KH15D-B in Plan KH15D-B was vetoed by AirMass constraint.
2020-04-26 03:16:17.8:     AirMass estimates ready after 26-Apr-2020 19:25:12 UTC
2020-04-26 03:16:17.9: Obs Test in Plan Test vetoed for sequencer hard limit.
2020-04-26 03:16:17.9:  (deferred for 40 min, until 26-Apr-2020 03:56:17 UTC
2020-04-26 03:16:17.9: No pending plans that can be started now.
2020-04-26 03:16:17.9: Dispatcher cycle time: 0.2 sec.
2020-04-26 03:16:48.4: ++ Auto Focus ++
2020-04-26 03:16:48.5: Doing periodic autofocus.
2020-04-26 03:16:48.5: Start special ACP AutoFocus script for scheduler
2020-04-26 03:16:48.5: ACP.RunScript(AutoFocusScheduler, ):
2020-04-26 03:16:48.5:   Script AutoFocusScheduler is loaded, and
2020-04-26 03:16:48.5:   the console is idle.
2020-04-26 03:16:48.5:   In start loop, i = 0
2020-04-26 03:16:48.5:   Console is now idle
2020-04-26 03:16:48.5:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2020-04-26 03:16:48.5:   Script started successfully
2020-04-26 03:16:58.5: Sequencer is now active
2020-04-26 03:18:37.2: Sequencer is no longer active
2020-04-26 03:18:37.2: ** Autofocus failed (n=2), will retry ASAP after 5 min.
2020-04-26 03:18:37.2: SelectRunning: No running plans
2020-04-26 03:18:37.2: No pending plans that can be started now.
2020-04-26 03:18:37.2: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:19:07.8: SelectRunning: No running plans
2020-04-26 03:19:07.8: No pending plans that can be started now.
2020-04-26 03:19:07.8: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:19:38.4: SelectRunning: No running plans
2020-04-26 03:19:38.4: No pending plans that can be started now.
2020-04-26 03:19:38.4: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:20:07.4: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2020-04-26 03:28:51.5: ++ Observatory Startup ++
2020-04-26 03:28:51.5: Start ACP Sequencer's StartupObs script
2020-04-26 03:28:51.5: Starting with open dome, unsafe weather will cause operator intervention error
2020-04-26 03:28:51.5: ACP.RunScript(StartupObs, ):
2020-04-26 03:28:51.5:   Script AutoFocusScheduler is loaded, and
2020-04-26 03:28:51.5:   the console is idle.
2020-04-26 03:28:51.5:   In start loop, i = 0
2020-04-26 03:28:51.5:   Console is now idle
2020-04-26 03:28:51.5:   Loaded C:\Users\Public\Documents\ACP Config\Scheduler\StartupObs.js successfully
2020-04-26 03:28:51.5:   Script started successfully
2020-04-26 03:29:01.6: Sequencer is now active
2020-04-26 03:29:06.6: Sequencer is no longer active
2020-04-26 03:29:06.6: Observatory startup succeeded
2020-04-26 03:29:06.6: ++ Auto Focus ++
2020-04-26 03:29:06.6: Doing initial autofocus.
2020-04-26 03:29:06.6: Start special ACP AutoFocus script for scheduler
2020-04-26 03:29:06.6: ACP.RunScript(AutoFocusScheduler, ):
2020-04-26 03:29:06.6:   Script StartupObs is loaded, and
2020-04-26 03:29:06.6:   the console is idle.
2020-04-26 03:29:06.6:   In start loop, i = 0
2020-04-26 03:29:06.6:   Console is now idle
2020-04-26 03:29:06.7:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2020-04-26 03:29:06.7:   Script started successfully
2020-04-26 03:29:16.7: Sequencer is now active
2020-04-26 03:32:11.4: Sequencer is no longer active
2020-04-26 03:32:11.4: Next periodic autofocus ASAP after 3600sec. 26-Apr-2020 04:31:56 UTC
2020-04-26 03:32:11.5: SelectRunning: No running plans
2020-04-26 03:32:11.5: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2020-04-26 03:32:11.5:     AirMass estimates ready after 26-Apr-2020 19:25:12 UTC
2020-04-26 03:32:11.5: Obs KH15D-B in Plan KH15D-B was vetoed by AirMass constraint.
2020-04-26 03:32:11.5:     AirMass estimates ready after 26-Apr-2020 19:25:12 UTC
2020-04-26 03:32:11.5: Obs Test in Plan Test vetoed for sequencer hard limit.
2020-04-26 03:32:11.5:  (deferred for 57 min, until 26-Apr-2020 04:29:11 UTC
2020-04-26 03:32:11.5: No pending plans that can be started now.
2020-04-26 03:32:11.5: Dispatcher cycle time: 0.1 sec.
2020-04-26 03:32:42.1: SelectRunning: No running plans
2020-04-26 03:32:42.1: No pending plans that can be started now.
2020-04-26 03:32:42.1: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:33:12.7: SelectRunning: No running plans
2020-04-26 03:33:12.7: No pending plans that can be started now.
2020-04-26 03:33:12.7: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:33:43.3: SelectRunning: No running plans
2020-04-26 03:33:43.3: No pending plans that can be started now.
2020-04-26 03:33:43.3: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:34:13.9: **Plan test failed:
2020-04-26 03:34:13.9: **Linked Observation OBJ 2 (#2) time from previous is too small.
2020-04-26 03:34:13.9:   Previous obs requires 2263 sec, yet time spacing is only 600 sec.
2020-04-26 03:34:13.9: SelectRunning: No running plans
2020-04-26 03:34:13.9: No pending plans that can be started now.
2020-04-26 03:34:13.9: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:34:44.5: SelectRunning: No running plans
2020-04-26 03:34:44.5: No pending plans that can be started now.
2020-04-26 03:34:44.5: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:35:15.0: SelectRunning: No running plans
2020-04-26 03:35:15.0: No pending plans that can be started now.
2020-04-26 03:35:15.0: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:35:45.6: SelectRunning: No running plans
2020-04-26 03:35:45.6: No pending plans that can be started now.
2020-04-26 03:35:45.6: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:36:16.1: SelectRunning: No running plans
2020-04-26 03:36:16.2: No pending plans that can be started now.
2020-04-26 03:36:16.2: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:36:46.7: SelectRunning: No running plans
2020-04-26 03:36:46.7: No pending plans that can be started now.
2020-04-26 03:36:46.7: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:37:17.7: SelectRunning: No running plans
2020-04-26 03:37:17.7: No pending plans that can be started now.
2020-04-26 03:37:17.7: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:37:48.3: SelectRunning: No running plans
2020-04-26 03:37:48.3: Efficiency: Only one pending plan test, it is the "best"
2020-04-26 03:37:48.3: Dispatcher cycle time: 0.1 sec.
2020-04-26 03:37:48.3: Acquire data for Observation OBJ 1...
2020-04-26 03:37:48.3:   (belongs to Project JHU, Plan test)
2020-04-26 03:37:48.4: Send Observation OBJ 1 to ACP Sequencer
2020-04-26 03:37:48.4: ACP.RunScript(AcquireScheduler, ):
2020-04-26 03:37:48.4:   Script AutoFocusScheduler is loaded, and
2020-04-26 03:37:48.4:   the console is idle.
2020-04-26 03:37:48.4:   In start loop, i = 0
2020-04-26 03:37:48.4:   Console is now idle
2020-04-26 03:37:48.4:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2020-04-26 03:37:48.4:   Script started successfully
2020-04-26 03:37:58.5: Sequencer is now active
2020-04-26 03:38:29.0: Sequencer is no longer active
2020-04-26 03:38:29.0: ** ACP script "AcquireScheduler" failed:
2020-04-26 03:38:29.0: **Script Error**
Source:   ACP
Message:  The telescope is not connected.
Location: line 1054 column 9.

2020-04-26 03:38:29.0: ACP ERROR: Run failed due to script error (see ACP run log)
2020-04-26 03:38:29.1: ACP data acquisition failed for Observation OBJ 1.
2020-04-26 03:38:29.1:   (Observation OBJ 1 interrupted by acquisition process failure.)
2020-04-26 03:38:29.2: SelectRunning: No running plans
2020-04-26 03:38:29.2: No pending plans that can be started now.
2020-04-26 03:38:29.2: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:38:59.8: SelectRunning: No running plans
2020-04-26 03:38:59.8: No pending plans that can be started now.
2020-04-26 03:38:59.8: Dispatcher cycle time: 0.0 sec.
2020-04-26 03:39:30.4: SelectRunning: No running plans
2020-04-26 03:39:30.4: Efficiency: Only one pending plan OBJ 2, it is the "best"
2020-04-26 03:39:30.5: Dispatcher cycle time: 0.1 sec.
2020-04-26 03:39:30.5: Acquire data for Observation R...
2020-04-26 03:39:30.5:   (belongs to Project JHU, Plan OBJ 2)
2020-04-26 03:39:30.6: **EXCEPTION IN SCHEDULER:
2020-04-26 03:39:30.6: The telescope is not connected.
2020-04-26 03:39:30.6: Traceback:
   at ACP.TelescopeClass.get_SlewSettleTime()
   at DC3.Scheduler.ACPSequencer.AcquireData(Observation Obs)
   at DC3.Scheduler.Engine.DoSchedulePass()
   at DC3.Scheduler.Engine.Run()
2020-04-26 03:39:30.7: No operator intervention command tool specified
2020-04-26 03:39:30.7: Run statistics:
2020-04-26 03:39:30.7:   Observations:   5
2020-04-26 03:39:30.7:   Considered:     1
2020-04-26 03:39:30.7:   Completed:      0
2020-04-26 03:39:30.7:   Skipped:        0
2020-04-26 03:39:30.7:   Never Eligible: 4
2020-04-26 03:39:30.7:   Failed:         1
2020-04-26 03:39:30.7: Shutter-Open efficiency: 0.00%
2020-04-26 03:39:30.7: Overall Efficiency: 7.29%
2020-04-26 03:39:30.7: Release ACP sequencer
Log closed at Sun, Apr 26 2020 03:39:32 UTC (actual time)