Log opened at Sun, Apr 26 2020 02:09:53 UTC (actual time)
Current log level is Debug
ACP Expert Scheduler version 8.2.3
Full license: Arne Henden
2020-04-26 02:28:45.0: ++ Weather Safe ++
2020-04-26 02:28:46.1: ++ Observatory Startup ++
2020-04-26 02:28:46.1: Start ACP Sequencer's StartupObs script
2020-04-26 02:28:46.4: ACP.RunScript(StartupObs, ):
2020-04-26 02:28:46.4:   Script ShutdownObs is loaded, and
2020-04-26 02:28:46.4:   the console is idle.
2020-04-26 02:28:46.4:   In start loop, i = 0
2020-04-26 02:28:46.4:   Console is now idle
2020-04-26 02:28:46.8:   Loaded C:\Users\Public\Documents\ACP Config\Scheduler\StartupObs.js successfully
2020-04-26 02:28:46.8:   Script started successfully
2020-04-26 02:28:56.8: Sequencer is now active
2020-04-26 02:29:01.9: Sequencer is no longer active
2020-04-26 02:29:02.2: Open the observatory dome/roof
2020-04-26 02:29:48.6: Observatory startup succeeded, and dome opened successfully
2020-04-26 02:41:09.0: ++ Auto Focus ++
2020-04-26 02:41:09.0: Doing initial autofocus.
2020-04-26 02:41:09.0: Start special ACP AutoFocus script for scheduler
2020-04-26 02:41:09.0: ACP.RunScript(AutoFocusScheduler, ):
2020-04-26 02:41:09.0:   Script StartupObs is loaded, and
2020-04-26 02:41:09.0:   the console is idle.
2020-04-26 02:41:09.0:   In start loop, i = 0
2020-04-26 02:41:09.0:   Console is now idle
2020-04-26 02:41:09.3:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2020-04-26 02:41:09.3:   Script started successfully
2020-04-26 02:41:19.3: Sequencer is now active
2020-04-26 02:41:24.4: Sequencer is no longer active
2020-04-26 02:41:24.4: ** Autofocus failed (n=1), will retry ASAP after 0 min.
2020-04-26 02:41:24.4: Plan KH15D has Monitor Mode. Time to resubmit it.
2020-04-26 02:41:24.4: Plan KH15D-B has Monitor Mode. Time to resubmit it.
2020-04-26 02:41:24.4: SelectRunning: No running plans
2020-04-26 02:41:24.5: Obs Test in Plan Test vetoed for sequencer hard limit.
2020-04-26 02:41:24.5:  (deferred for 51 min, until 26-Apr-2020 03:32:24 UTC
2020-04-26 02:41:24.5: Efficiency: Selecting from 2 pending plans:
2020-04-26 02:41:24.5:   Selected Plan KH15D-B (TotEff=1.56)
2020-04-26 02:41:24.6: Dispatcher cycle time: 0.2 sec.
2020-04-26 02:41:24.6: Acquire data for Observation KH15D-B...
2020-04-26 02:41:24.6:   (belongs to Project KH15D, Plan KH15D-B)
2020-04-26 02:41:25.0: ++ Auto Focus ++
2020-04-26 02:41:25.0: Doing periodic autofocus.
2020-04-26 02:41:25.0: Start special ACP AutoFocus script for scheduler
2020-04-26 02:41:25.0: ACP.RunScript(AutoFocusScheduler, ):
2020-04-26 02:41:25.0:   Script AutoFocusScheduler is loaded, and
2020-04-26 02:41:25.0:   the console is idle.
2020-04-26 02:41:25.0:   In start loop, i = 0
2020-04-26 02:41:25.0:   Console is now idle
2020-04-26 02:41:25.0:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2020-04-26 02:41:25.0:   Script started successfully
2020-04-26 02:41:35.1: Sequencer is now active
2020-04-26 02:41:40.1: Sequencer is no longer active
2020-04-26 02:41:40.1: ** Autofocus failed (n=2), will retry ASAP after 5 min.
2020-04-26 02:41:40.1: Send Observation KH15D-B to ACP Sequencer
2020-04-26 02:41:40.1: ACP.RunScript(AcquireScheduler, ):
2020-04-26 02:41:40.1:   Script AutoFocusScheduler is loaded, and
2020-04-26 02:41:40.1:   the console is idle.
2020-04-26 02:41:40.1:   In start loop, i = 0
2020-04-26 02:41:40.1:   Console is now idle
2020-04-26 02:41:40.7:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2020-04-26 02:41:40.7:   Script started successfully
2020-04-26 02:41:50.7: Sequencer is now active
2020-04-26 02:41:55.8: Sequencer is no longer active
2020-04-26 02:42:26.2: Post-job status check done (stat=Running)
2020-04-26 02:42:26.3: ASSERT: ACP script exited with AcquireNow still True
2020-04-26 02:42:26.3: ACP ERROR: Run failed for unknown reason (see ACP run log)
2020-04-26 02:42:26.3: Observation's requested AF failed. Next periodic AF still 26-Apr-2020 02:46:40 UTC
2020-04-26 02:42:26.3: ACP data acquisition failed for Observation KH15D-B.
2020-04-26 02:42:26.3:   (Observation KH15D-B interrupted by acquisition process failure.)
2020-04-26 02:42:26.8: SelectRunning: No running plans
2020-04-26 02:42:26.8: Efficiency: Only one pending plan KH15D, it is the "best"
2020-04-26 02:42:26.8: Dispatcher cycle time: 0.1 sec.
2020-04-26 02:42:26.8: Acquire data for Observation KH15D...
2020-04-26 02:42:26.9:   (belongs to Project KH15D, Plan KH15D)
2020-04-26 02:42:26.9: Send Observation KH15D to ACP Sequencer
2020-04-26 02:42:26.9: ACP.RunScript(AcquireScheduler, ):
2020-04-26 02:42:26.9:   Script AcquireScheduler is loaded, and
2020-04-26 02:42:26.9:   the console is idle.
2020-04-26 02:42:26.9:   In start loop, i = 0
2020-04-26 02:42:26.9:   Console is now idle
2020-04-26 02:42:26.9:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2020-04-26 02:42:26.9:   Script started successfully
2020-04-26 02:42:36.9: Sequencer is now active
2020-04-26 02:42:42.0: Sequencer is no longer active
2020-04-26 02:43:12.5: Post-job status check done (stat=Running)
2020-04-26 02:43:12.5: ASSERT: ACP script exited with AcquireNow still True
2020-04-26 02:43:12.5: ACP ERROR: Run failed for unknown reason (see ACP run log)
2020-04-26 02:43:12.5: ACP data acquisition failed for Observation KH15D.
2020-04-26 02:43:12.5:   (Observation KH15D interrupted by acquisition process failure.)
2020-04-26 02:43:13.0: SelectRunning: No running plans
2020-04-26 02:43:13.0: No pending plans that can be started now.
2020-04-26 02:43:13.0: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:43:44.0: SelectRunning: No running plans
2020-04-26 02:43:44.0: No pending plans that can be started now.
2020-04-26 02:43:44.0: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:44:14.9: SelectRunning: No running plans
2020-04-26 02:44:14.9: No pending plans that can be started now.
2020-04-26 02:44:14.9: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:44:45.8: SelectRunning: No running plans
2020-04-26 02:44:45.8: No pending plans that can be started now.
2020-04-26 02:44:45.8: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:45:16.7: SelectRunning: No running plans
2020-04-26 02:45:16.7: No pending plans that can be started now.
2020-04-26 02:45:16.7: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:45:47.7: SelectRunning: No running plans
2020-04-26 02:45:47.7: No pending plans that can be started now.
2020-04-26 02:45:47.7: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:46:18.6: SelectRunning: No running plans
2020-04-26 02:46:18.6: No pending plans that can be started now.
2020-04-26 02:46:18.6: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:46:49.5: ++ Auto Focus ++
2020-04-26 02:46:49.6: Doing periodic autofocus.
2020-04-26 02:46:49.6: Start special ACP AutoFocus script for scheduler
2020-04-26 02:46:49.6: ACP.RunScript(AutoFocusScheduler, ):
2020-04-26 02:46:49.6:   Script AcquireScheduler is loaded, and
2020-04-26 02:46:49.6:   the console is idle.
2020-04-26 02:46:49.6:   In start loop, i = 0
2020-04-26 02:46:49.6:   Console is now idle
2020-04-26 02:46:49.6:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2020-04-26 02:46:49.6:   Script started successfully
2020-04-26 02:46:59.6: Sequencer is now active
2020-04-26 02:47:04.7: Sequencer is no longer active
2020-04-26 02:47:04.7: ** Autofocus failed (n=3), will retry ASAP after 10 min.
2020-04-26 02:47:04.7: SelectRunning: No running plans
2020-04-26 02:47:04.7: No pending plans that can be started now.
2020-04-26 02:47:04.7: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:47:35.6: SelectRunning: No running plans
2020-04-26 02:47:35.6: No pending plans that can be started now.
2020-04-26 02:47:35.6: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:48:06.5: SelectRunning: No running plans
2020-04-26 02:48:06.5: No pending plans that can be started now.
2020-04-26 02:48:06.5: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:48:37.5: SelectRunning: No running plans
2020-04-26 02:48:37.5: No pending plans that can be started now.
2020-04-26 02:48:37.5: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:49:08.4: SelectRunning: No running plans
2020-04-26 02:49:08.4: No pending plans that can be started now.
2020-04-26 02:49:08.4: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:49:39.3: SelectRunning: No running plans
2020-04-26 02:49:39.3: No pending plans that can be started now.
2020-04-26 02:49:39.3: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:50:10.1: SelectRunning: No running plans
2020-04-26 02:50:10.1: No pending plans that can be started now.
2020-04-26 02:50:10.1: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:50:40.9: SelectRunning: No running plans
2020-04-26 02:50:40.9: No pending plans that can be started now.
2020-04-26 02:50:40.9: Dispatcher cycle time: 0.0 sec.
2020-04-26 02:50:51.1: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2020-04-26 03:07:57.7: ++ Observatory Startup ++
2020-04-26 03:07:57.7: Start ACP Sequencer's StartupObs script
2020-04-26 03:07:57.7: Starting with open dome, unsafe weather will cause operator intervention error
2020-04-26 03:07:57.7: ACP.RunScript(StartupObs, ):
2020-04-26 03:07:57.7:   Script AutoFocusScheduler is loaded, and
2020-04-26 03:07:57.7:   the console is idle.
2020-04-26 03:07:57.7:   In start loop, i = 0
2020-04-26 03:07:57.7:   Console is now idle
2020-04-26 03:07:57.8:   Loaded C:\Users\Public\Documents\ACP Config\Scheduler\StartupObs.js successfully
2020-04-26 03:07:57.8:   Script started successfully
2020-04-26 03:08:07.8: Sequencer is now active
2020-04-26 03:08:13.0: Sequencer is no longer active
2020-04-26 03:08:13.0: ** ACP script "StartupObs" failed:
2020-04-26 03:08:13.0: **Script Error (Tracking has been stopped)**
Source:   Microsoft JScript runtime error
Message:  The remote server machine does not exist or is unavailable
Location: line 164 column 5.

2020-04-26 03:08:13.0: **EXCEPTION IN SCHEDULER:
2020-04-26 03:08:13.0: Observatory startup failed, cannot continue.
2020-04-26 03:08:13.4: Traceback:
   at DC3.Scheduler.Engine.DoStartupIf(Boolean openDome)
   at DC3.Scheduler.Engine.Run()
2020-04-26 03:08:13.4: Close the observatory dome/roof.
2020-04-26 03:08:44.1: No operator intervention command tool specified
2020-04-26 03:08:44.2: Run statistics:
2020-04-26 03:08:44.2:   Observations:   3
2020-04-26 03:08:44.2:   Considered:     1
2020-04-26 03:08:44.2:   Completed:      0
2020-04-26 03:08:44.2:   Skipped:        0
2020-04-26 03:08:44.2:   Never Eligible: 2
2020-04-26 03:08:44.2:   Failed:         1
2020-04-26 03:08:44.2: Shutter-Open efficiency: 0.00%
2020-04-26 03:08:44.2: Overall Efficiency: 0.62%
2020-04-26 03:08:44.2: Release ACP sequencer
Log closed at Sun, Apr 26 2020 03:08:46 UTC (actual time)