Log opened at Fri, Sep 06 2019 00:56:58 UTC (actual time)
Current log level is Normal
ACP Expert Scheduler version 8.2.3
Full license: Arne Henden
2019-09-06 01:41:50.2: ++ Weather Safe ++
2019-09-06 01:41:51.2: ++ Observatory Startup ++
2019-09-06 01:41:51.2: Startup attempted, but no StartupObs script found
2019-09-06 01:41:51.3: Open the observatory dome/roof
2019-09-06 01:42:52.0: Observatory startup succeeded, and dome opened successfully
2019-09-06 02:20:36.9: ++ Auto Focus ++
2019-09-06 02:20:36.9: Doing initial autofocus.
2019-09-06 02:20:36.9: Start special ACP AutoFocus script for scheduler
2019-09-06 02:24:26.9: Next periodic autofocus ASAP after 3600sec. 06-Sep-2019 03:24:13 UTC
2019-09-06 02:24:27.2: Dispatcher cycle time: 0.3 sec.
2019-09-06 02:24:27.2: Acquire data for Observation SA109...
2019-09-06 02:24:27.2:   (belongs to Project Landolt fields, Plan SA109)
2019-09-06 02:24:27.2: Doing 3 sets
2019-09-06 02:24:27.3: Send Observation SA109 to ACP Sequencer
2019-09-06 02:31:10.1: Send Observation SA109 to ACP Sequencer
2019-09-06 02:33:53.6: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2019-09-06 02:34:05.7: ** ACP script "AcquireScheduler" failed:
2019-09-06 02:34:05.8: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 1440 column 13.

2019-09-06 02:34:05.8: RUN FAILED: Scheduler was stopped during run
2019-09-06 02:34:05.8: ACP data acquisition failed for Observation SA109.
2019-09-06 02:34:05.8:   (Observation SA109 interrupted by operator or system.)
2019-09-06 03:14:50.4: Start ACP AutoFlat script for Dusk flats
2019-09-06 03:15:10.4: ** ACP script "AutoFlat" failed:
2019-09-06 03:15:10.4: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 1855 column 13.

2019-09-06 03:20:43.7: ++ Observatory Startup ++
2019-09-06 03:20:43.7: Startup attempted, but no StartupObs script found
2019-09-06 03:20:43.7: Observatory startup succeeded
2019-09-06 03:20:43.7: ++ Auto Focus ++
2019-09-06 03:20:43.8: Doing initial autofocus.
2019-09-06 03:20:43.8: Start special ACP AutoFocus script for scheduler
2019-09-06 03:24:10.3: Next periodic autofocus ASAP after 3600sec. 06-Sep-2019 04:23:50 UTC
2019-09-06 03:24:10.5: Dispatcher cycle time: 0.2 sec.
2019-09-06 03:24:10.5: Acquire data for Observation SA112...
2019-09-06 03:24:10.5:   (belongs to Project Landolt fields, Plan SA112)
2019-09-06 03:24:10.5: Doing 3 sets
2019-09-06 03:24:10.5: Send Observation SA112 to ACP Sequencer
2019-09-06 03:32:07.9: Send Observation SA112 to ACP Sequencer
2019-09-06 03:37:52.1: Send Observation SA112 to ACP Sequencer
2019-09-06 10:56:12.3: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2019-09-06 10:56:28.0: ** ACP script "AcquireScheduler" failed:
2019-09-06 10:56:28.0: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 1440 column 13.

2019-09-06 10:56:28.0: RUN FAILED: Scheduler was stopped during run
2019-09-06 10:56:28.1: ACP data acquisition failed for Observation SA112.
2019-09-06 10:56:28.1:   (Observation SA112 interrupted by operator or system.)
2019-09-06 11:02:40.7: ++ Observatory Startup ++
2019-09-06 11:02:40.7: Startup attempted, but no StartupObs script found
2019-09-06 11:02:40.7: Observatory startup succeeded
2019-09-06 11:02:40.7: ++ Auto Focus ++
2019-09-06 11:02:40.7: Doing initial autofocus.
2019-09-06 11:02:40.7: Start special ACP AutoFocus script for scheduler
2019-09-06 11:05:44.3: ** Autofocus failed (n=1), will retry ASAP after 0 min.
2019-09-06 11:05:44.4: Dispatcher cycle time: 0.2 sec.
2019-09-06 11:05:44.5: Acquire data for Observation SA94...
2019-09-06 11:05:44.5:   (belongs to Project Landolt fields, Plan SA94)
2019-09-06 11:05:44.5: Doing 3 sets
2019-09-06 11:05:44.5: ++ Auto Focus ++
2019-09-06 11:05:44.5: Doing periodic autofocus.
2019-09-06 11:05:44.5: Start special ACP AutoFocus script for scheduler
2019-09-06 11:08:21.2: ** Autofocus failed (n=2), will retry ASAP after 5 min.
2019-09-06 11:08:21.2: Send Observation SA94 to ACP Sequencer
2019-09-06 11:15:53.9: Send Observation SA94 to ACP Sequencer
2019-09-06 11:21:42.0: Send Observation SA94 to ACP Sequencer
Log level changed from Normal to Debug
2019-09-06 11:27:32.1: Sequencer is no longer active
2019-09-06 11:27:32.1: Post-job status check done (stat=Completed)
2019-09-06 11:27:32.2: Acquisition time: 1150.9369885 sec.
2019-09-06 11:27:32.2: Data for Observation SA94 of Plan SA94 acquired successfully.
2019-09-06 11:27:32.2: Plan SA94 completed successfully.
2019-09-06 11:27:32.2: Image Efficiency: 62.5%
2019-09-06 11:27:32.2: Cycle Efficiency: 100.0%
2019-09-06 11:27:32.3: ++ Auto Focus ++
2019-09-06 11:27:32.3: Doing periodic autofocus.
2019-09-06 11:27:32.3: Start special ACP AutoFocus script for scheduler
2019-09-06 11:27:32.3: ACP.RunScript(AutoFocusScheduler, ):
2019-09-06 11:27:32.3:   Script AcquireScheduler is loaded, and
2019-09-06 11:27:32.3:   the console is idle.
2019-09-06 11:27:32.3:   In start loop, i = 0
2019-09-06 11:27:32.3:   Console is now idle
2019-09-06 11:27:32.3:   Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully
2019-09-06 11:27:32.3:   Script started successfully
2019-09-06 11:27:42.3: Sequencer is now active
2019-09-06 11:31:31.9: Sequencer is no longer active
2019-09-06 11:31:31.9: Next periodic autofocus ASAP after 3600sec. 06-Sep-2019 12:31:11 UTC
2019-09-06 11:31:32.0: SelectRunning: No running plans
2019-09-06 11:31:32.0: Plan KH15D would extend past daylight, deferred to next night
2019-09-06 11:31:32.0: No pending plans that can be started now.
2019-09-06 11:31:32.0: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:32:02.7: SelectRunning: No running plans
2019-09-06 11:32:02.7: No pending plans that can be started now.
2019-09-06 11:32:02.7: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:32:33.3: SelectRunning: No running plans
2019-09-06 11:32:33.3: No pending plans that can be started now.
2019-09-06 11:32:33.3: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:33:04.1: SelectRunning: No running plans
2019-09-06 11:33:04.1: Efficiency: Only one pending plan KH15D, it is the "best"
2019-09-06 11:33:04.2: Dispatcher cycle time: 0.1 sec.
2019-09-06 11:33:04.2: Acquire data for Observation KH15D...
2019-09-06 11:33:04.2:   (belongs to Project KH15D, Plan KH15D)
2019-09-06 11:33:04.2: Doing 2 sets
2019-09-06 11:33:04.2: Send Observation KH15D to ACP Sequencer
2019-09-06 11:33:04.2: ACP.RunScript(AcquireScheduler, ):
2019-09-06 11:33:04.2:   Script AutoFocusScheduler is loaded, and
2019-09-06 11:33:04.2:   the console is idle.
2019-09-06 11:33:04.2:   In start loop, i = 0
2019-09-06 11:33:04.2:   Console is now idle
2019-09-06 11:33:04.2:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2019-09-06 11:33:04.2:   Script started successfully
2019-09-06 11:33:14.2: Sequencer is now active
2019-09-06 11:40:09.9: Sequencer is no longer active
2019-09-06 11:40:09.9: Post-job status check done (stat=Completed)
2019-09-06 11:40:10.0: Observation's requested AF failed. Next periodic AF still 06-Sep-2019 12:31:11 UTC
2019-09-06 11:40:10.0: Send Observation KH15D to ACP Sequencer
2019-09-06 11:40:10.0: ACP.RunScript(AcquireScheduler, ):
2019-09-06 11:40:10.0:   Script AcquireScheduler is loaded, and
2019-09-06 11:40:10.0:   the console is idle.
2019-09-06 11:40:10.0:   In start loop, i = 0
2019-09-06 11:40:10.0:   Console is now idle
2019-09-06 11:40:10.0:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2019-09-06 11:40:10.0:   Script started successfully
2019-09-06 11:40:20.0: Sequencer is now active
2019-09-06 11:45:35.9: Sequencer is no longer active
2019-09-06 11:45:35.9: Post-job status check done (stat=Completed)
2019-09-06 11:45:35.9: Observation's requested AF failed. Next periodic AF still 06-Sep-2019 12:31:11 UTC
2019-09-06 11:45:35.9: Acquisition time: 751.7201887 sec.
2019-09-06 11:45:35.9: Data for Observation KH15D of Plan KH15D acquired successfully.
2019-09-06 11:45:36.0: Plan KH15D completed successfully.
2019-09-06 11:45:36.0: Image Efficiency: 23.9%
2019-09-06 11:45:36.0: Cycle Efficiency: 100.0%
2019-09-06 11:45:36.1: SelectRunning: No running plans
2019-09-06 11:45:36.1: No pending plans that can be started now.
2019-09-06 11:45:36.1: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:46:06.7: SelectRunning: No running plans
2019-09-06 11:46:06.7: No pending plans that can be started now.
2019-09-06 11:46:06.7: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:46:37.3: SelectRunning: No running plans
2019-09-06 11:46:37.3: No pending plans that can be started now.
2019-09-06 11:46:37.3: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:47:07.8: SelectRunning: No running plans
2019-09-06 11:47:07.8: No pending plans that can be started now.
2019-09-06 11:47:07.8: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:47:38.4: SelectRunning: No running plans
2019-09-06 11:47:38.4: No pending plans that can be started now.
2019-09-06 11:47:38.4: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:48:09.0: SelectRunning: No running plans
2019-09-06 11:48:09.0: No pending plans that can be started now.
2019-09-06 11:48:09.0: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:48:39.6: SelectRunning: No running plans
2019-09-06 11:48:39.6: No pending plans that can be started now.
2019-09-06 11:48:39.6: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:49:10.2: SelectRunning: No running plans
2019-09-06 11:49:10.2: No pending plans that can be started now.
2019-09-06 11:49:10.2: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:49:40.8: SelectRunning: No running plans
2019-09-06 11:49:40.8: No pending plans that can be started now.
2019-09-06 11:49:40.8: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:50:11.4: SelectRunning: No running plans
2019-09-06 11:50:11.4: No pending plans that can be started now.
2019-09-06 11:50:11.4: Dispatcher cycle time: 0.0 sec.
2019-09-06 11:50:42.0: SelectRunning: No running plans
2019-09-06 11:50:42.0: No pending plans that can be started now.
2019-09-06 11:50:42.0: Dispatcher cycle time: 0.0 sec.
2019-09-06 12:03:26.6: ++ Dawn Flats ++
2019-09-06 12:03:26.6: Start ACP AutoFlat script for Dawn flats
2019-09-06 12:03:26.6: ACP.RunScript(AutoFlat, C:\Users\admin\Documents\ACP Astronomy\Plans\SchedulerDawnFlats.txt):
2019-09-06 12:03:26.6:   Script AcquireScheduler is loaded, and
2019-09-06 12:03:26.6:   the console is idle.
2019-09-06 12:03:26.6:   In start loop, i = 0
2019-09-06 12:03:26.6:   Console is now idle
2019-09-06 12:03:26.6:   Loaded C:\Program Files (x86)\ACP Obs Control\Scripts\AutoFlat.vbs successfully
2019-09-06 12:03:26.6:   Set parameter "C:\Users\admin\Documents\ACP Astronomy\Plans\SchedulerDawnFlats.txt" successfully
2019-09-06 12:03:26.6:   Script started successfully
2019-09-06 12:03:36.7: Sequencer is now active
2019-09-06 12:25:12.6: Sequencer is no longer active
2019-09-06 12:25:43.2: -- Observatory Shutdown --
2019-09-06 12:25:43.2: Start ACP Sequencer's ShutdownObs script
2019-09-06 12:25:43.2: ACP.RunScript(ShutdownObs, ):
2019-09-06 12:25:43.2:   Script AutoFlat is loaded, and
2019-09-06 12:25:43.2:   the console is idle.
2019-09-06 12:25:43.2:   In start loop, i = 0
2019-09-06 12:25:43.2:   Console is now idle
2019-09-06 12:25:43.2:   Loaded C:\Users\Public\Documents\ACP Config\Scheduler\ShutdownObs.js successfully
2019-09-06 12:25:43.2:   Script started successfully
2019-09-06 12:25:53.3: Sequencer is now active
2019-09-06 12:26:46.7: Sequencer is no longer active
2019-09-06 12:55:19.0: -- Weather Unsafe --
2019-09-06 19:13:06.0: Run statistics:
2019-09-06 19:13:06.0:   Observations:   0
2019-09-06 19:13:06.0:   Considered:     0
2019-09-06 19:13:06.0:   Completed:      0
2019-09-06 19:13:06.0:   Skipped:        0
2019-09-06 19:13:06.0:   Never Eligible: 0
2019-09-06 19:13:06.0:   Failed:         0
Log closed at Fri, Sep 06 2019 19:13:06 UTC (actual time)