Log opened at Sun, Oct 13 2019 02:57:06 UTC (actual time)
Current log level is Debug
ACP Expert Scheduler version 8.2.3
Full license: Arne Henden
2019-10-13 02:57:06.6: ++ Observatory Startup ++
2019-10-13 02:57:06.6: Startup attempted, but no StartupObs script found
2019-10-13 02:57:06.6: Open the observatory dome/roof
2019-10-13 02:58:07.3: Observatory startup succeeded, and dome opened successfully
2019-10-13 02:58:07.3: ++ Auto Focus ++
2019-10-13 02:58:07.4: Doing initial autofocus.
2019-10-13 02:58:07.4: Start special ACP AutoFocus script for scheduler
2019-10-13 02:58:07.4: ACP.RunScript(AutoFocusScheduler, ):
2019-10-13 02:58:07.4:   Script ShutdownObs is loaded, and
2019-10-13 02:58:07.4:   the console is idle.
2019-10-13 02:58:07.4:   In start loop, i = 0
2019-10-13 02:58:07.4:   Console is now idle
2019-10-13 02:58:07.4:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2019-10-13 02:58:07.4:   Script started successfully
2019-10-13 02:58:17.4: Sequencer is now active
2019-10-13 03:03:27.9: Sequencer is no longer active
2019-10-13 03:03:27.9: Next periodic autofocus ASAP after 3600sec. 13-Oct-2019 04:03:13 UTC
2019-10-13 03:03:28.0: Plan KH15D has Monitor Mode. Time to resubmit it.
2019-10-13 03:03:28.0: Plan Test has Monitor Mode. Time to resubmit it.
2019-10-13 03:03:28.0: Plan KH15D-B has Monitor Mode. Time to resubmit it.
2019-10-13 03:03:28.3: SelectRunning: No running plans
2019-10-13 03:03:28.3: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2019-10-13 03:03:28.3:     AirMass estimates ready after 13-Oct-2019 08:19:45 UTC
2019-10-13 03:03:28.4: Obs KH15D-B in Plan KH15D-B was vetoed by AirMass constraint.
2019-10-13 03:03:28.4:     AirMass estimates ready after 13-Oct-2019 08:19:45 UTC
2019-10-13 03:03:28.4: Obs SA109 in Plan SA109 was vetoed by AirMass constraint.
2019-10-13 03:03:28.4:     AirMass estimates ready after 13-Oct-2019 19:50:04 UTC
2019-10-13 03:03:28.4: Efficiency: Only one pending plan Test, it is the "best"
2019-10-13 03:03:28.4: Dispatcher cycle time: 0.5 sec.
2019-10-13 03:03:28.4: Acquire data for Observation Test...
2019-10-13 03:03:28.4:   (belongs to Project KH15D, Plan Test)
2019-10-13 03:03:28.5: Send Observation Test to ACP Sequencer
2019-10-13 03:03:28.5: ACP.RunScript(AcquireScheduler, ):
2019-10-13 03:03:28.5:   Script AutoFocusScheduler is loaded, and
2019-10-13 03:03:28.5:   the console is idle.
2019-10-13 03:03:28.5:   In start loop, i = 0
2019-10-13 03:03:28.5:   Console is now idle
2019-10-13 03:03:28.5:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2019-10-13 03:03:28.5:   Script started successfully
2019-10-13 03:03:38.5: Sequencer is now active
2019-10-13 03:17:18.1: Sequencer is no longer active
2019-10-13 03:17:18.1: Post-job status check done (stat=Completed)
2019-10-13 03:17:18.1: Acquisition time: 829.6161919 sec.
2019-10-13 03:17:18.1: Data for Observation Test of Plan Test acquired successfully.
2019-10-13 03:17:18.1: Plan Test completed successfully.
2019-10-13 03:17:18.1: Image Efficiency: 72.3%
2019-10-13 03:17:18.1: Cycle Efficiency: 99.9%
2019-10-13 03:17:18.3: SelectRunning: No running plans
2019-10-13 03:17:18.3: No pending plans that can be started now.
2019-10-13 03:17:18.3: Dispatcher cycle time: 0.0 sec.
2019-10-13 03:17:48.8: SelectRunning: No running plans
2019-10-13 03:17:48.8: No pending plans that can be started now.
2019-10-13 03:17:48.8: Dispatcher cycle time: 0.0 sec.
2019-10-13 03:18:19.4: SelectRunning: No running plans
2019-10-13 03:18:19.4: No pending plans that can be started now.
2019-10-13 03:18:19.4: Dispatcher cycle time: 0.0 sec.
2019-10-13 03:18:51.9: **Dome closing when asked to open. Assuming weather closure.
2019-10-13 03:18:52.0: **EXCEPTION IN SCHEDULER:
2019-10-13 03:18:52.0: **Dome failed to open for reason other than hardware weather closure
2019-10-13 03:18:52.1: Traceback:
   at DC3.Scheduler.Engine.DoStartupIf(Boolean openDome)
   at DC3.Scheduler.Engine.Run()
2019-10-13 03:18:52.5: **Dome already closing when asked to close. Assuming weather closure.
2019-10-13 03:19:25.0: No operator intervention command tool specified
2019-10-13 03:19:25.2: Run statistics:
2019-10-13 03:19:25.2:   Observations:   3
2019-10-13 03:19:25.2:   Considered:     0
2019-10-13 03:19:25.2:   Completed:      0
2019-10-13 03:19:25.2:   Skipped:        0
2019-10-13 03:19:25.2:   Never Eligible: 3
2019-10-13 03:19:25.2:   Failed:         0
2019-10-13 03:19:25.2: Shutter-Open efficiency: 5.11%
2019-10-13 03:19:25.2: Overall Efficiency: 8.74%
2019-10-13 03:19:25.2: Release ACP sequencer
Log closed at Sun, Oct 13 2019 03:19:27 UTC (actual time)