Log opened at Wed, Oct 09 2019 10:18:15 UTC (actual time) Current log level is Debug ACP Expert Scheduler version 8.2.3 Full license: Arne Henden 2019-10-09 10:18:15.6: ++ Observatory Startup ++ 2019-10-09 10:18:15.6: Startup attempted, but no StartupObs script found 2019-10-09 10:18:15.6: Open the observatory dome/roof 2019-10-09 10:19:31.4: Observatory startup succeeded, and dome opened successfully 2019-10-09 10:19:31.4: ++ Auto Focus ++ 2019-10-09 10:19:31.4: Doing initial autofocus. 2019-10-09 10:19:31.4: Start special ACP AutoFocus script for scheduler 2019-10-09 10:19:31.4: ACP.RunScript(AutoFocusScheduler, ): 2019-10-09 10:19:31.4: No script is loaded. ACP is definitely idle 2019-10-09 10:19:31.4: In start loop, i = 0 2019-10-09 10:19:31.4: Console is now idle 2019-10-09 10:19:31.6: Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully 2019-10-09 10:19:31.6: Script started successfully 2019-10-09 10:19:41.6: Sequencer is now active 2019-10-09 10:24:50.1: Sequencer is no longer active 2019-10-09 10:24:50.1: Next periodic autofocus ASAP after 3600sec. 09-Oct-2019 11:24:31 UTC 2019-10-09 10:24:50.3: SelectRunning: No running plans 2019-10-09 10:24:50.4: Obs SA109 in Plan SA109 was vetoed by AirMass constraint. 2019-10-09 10:24:50.4: AirMass estimates ready after 09-Oct-2019 20:05:47 UTC 2019-10-09 10:24:50.4: Obs Test in Plan Test vetoed for sequencer hard limit. 2019-10-09 10:24:50.4: (deferred for 55 min, until 09-Oct-2019 11:19:50 UTC 2019-10-09 10:24:50.4: Efficiency: Only one pending plan KH15D, it is the "best" 2019-10-09 10:24:50.4: Dispatcher cycle time: 0.3 sec. 2019-10-09 10:24:50.4: Acquire data for Observation KH15D... 2019-10-09 10:24:50.5: (belongs to Project KH15D, Plan KH15D) 2019-10-09 10:24:50.5: Send Observation KH15D to ACP Sequencer 2019-10-09 10:24:50.5: ACP.RunScript(AcquireScheduler, ): 2019-10-09 10:24:50.5: Script AutoFocusScheduler is loaded, and 2019-10-09 10:24:50.5: the console is idle. 2019-10-09 10:24:50.5: In start loop, i = 0 2019-10-09 10:24:50.5: Console is now idle 2019-10-09 10:24:50.5: Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully 2019-10-09 10:24:50.5: Script started successfully 2019-10-09 10:25:00.6: Sequencer is now active 2019-10-09 10:29:50.5: Sequencer is no longer active 2019-10-09 10:29:50.5: Post-job status check done (stat=Failed) 2019-10-09 10:29:50.5: ACP data acquisition failed for Observation KH15D. 2019-10-09 10:29:50.5: (Observation KH15D interrupted by acquisition process failure.) 2019-10-09 10:29:50.7: SelectRunning: No running plans 2019-10-09 10:29:50.7: No pending plans that can be started now. 2019-10-09 10:29:50.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 10:30:21.6: SelectRunning: No running plans 2019-10-09 10:30:21.6: No pending plans that can be started now. 2019-10-09 10:30:21.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 10:30:52.2: SelectRunning: No running plans 2019-10-09 10:30:52.2: Efficiency: Only one pending plan KH15D, it is the "best" 2019-10-09 10:30:52.2: Dispatcher cycle time: 0.1 sec. 2019-10-09 10:30:52.2: Acquire data for Observation KH15D... 2019-10-09 10:30:52.2: (belongs to Project KH15D, Plan KH15D) 2019-10-09 10:30:52.3: Send Observation KH15D to ACP Sequencer 2019-10-09 10:30:52.3: ACP.RunScript(AcquireScheduler, ): 2019-10-09 10:30:52.3: Script AcquireScheduler is loaded, and 2019-10-09 10:30:52.3: the console is idle. 2019-10-09 10:30:52.3: In start loop, i = 0 2019-10-09 10:30:52.3: Console is now idle 2019-10-09 10:30:52.3: Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully 2019-10-09 10:30:52.3: Script started successfully 2019-10-09 10:31:02.3: Sequencer is now active 2019-10-09 11:36:52.1: Sequencer is no longer active 2019-10-09 11:36:52.1: Post-job status check done (stat=Completed) 2019-10-09 11:36:52.1: Acquisition time: 3959.8074406 sec. 2019-10-09 11:36:52.1: Data for Observation KH15D of Plan KH15D acquired successfully. 2019-10-09 11:36:52.1: Plan KH15D completed successfully. 2019-10-09 11:36:52.1: Image Efficiency: 90.9% 2019-10-09 11:36:52.1: Cycle Efficiency: 100.0% 2019-10-09 11:36:52.3: ++ Auto Focus ++ 2019-10-09 11:36:52.3: Doing periodic autofocus. 2019-10-09 11:36:52.3: Start special ACP AutoFocus script for scheduler 2019-10-09 11:36:52.3: ACP.RunScript(AutoFocusScheduler, ): 2019-10-09 11:36:52.3: Script AcquireScheduler is loaded, and 2019-10-09 11:36:52.3: the console is idle. 2019-10-09 11:36:52.3: In start loop, i = 0 2019-10-09 11:36:52.3: Console is now idle 2019-10-09 11:36:52.3: Loaded C:\Program Files (x86)\ACP Scheduler\AutoFocusScheduler.vbs successfully 2019-10-09 11:36:52.3: Script started successfully 2019-10-09 11:37:02.3: Sequencer is now active 2019-10-09 11:41:18.6: Sequencer is no longer active 2019-10-09 11:41:18.6: Next periodic autofocus ASAP after 3600sec. 09-Oct-2019 12:40:59 UTC 2019-10-09 11:41:18.6: SelectRunning: No running plans 2019-10-09 11:41:18.6: Obs Test in Plan Test vetoed for sequencer hard limit. 2019-10-09 11:41:18.6: (deferred for 48 min, until 09-Oct-2019 12:29:18 UTC 2019-10-09 11:41:18.6: No pending plans that can be started now. 2019-10-09 11:41:18.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:41:49.2: SelectRunning: No running plans 2019-10-09 11:41:49.2: No pending plans that can be started now. 2019-10-09 11:41:49.2: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:42:19.8: SelectRunning: No running plans 2019-10-09 11:42:19.8: No pending plans that can be started now. 2019-10-09 11:42:19.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:42:50.4: SelectRunning: No running plans 2019-10-09 11:42:50.4: No pending plans that can be started now. 2019-10-09 11:42:50.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:43:21.0: SelectRunning: No running plans 2019-10-09 11:43:21.0: No pending plans that can be started now. 2019-10-09 11:43:21.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:43:51.5: SelectRunning: No running plans 2019-10-09 11:43:51.5: No pending plans that can be started now. 2019-10-09 11:43:51.5: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:44:22.1: SelectRunning: No running plans 2019-10-09 11:44:22.1: No pending plans that can be started now. 2019-10-09 11:44:22.1: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:44:52.7: SelectRunning: No running plans 2019-10-09 11:44:52.7: No pending plans that can be started now. 2019-10-09 11:44:52.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:45:23.6: SelectRunning: No running plans 2019-10-09 11:45:23.6: No pending plans that can be started now. 2019-10-09 11:45:23.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:45:54.2: SelectRunning: No running plans 2019-10-09 11:45:54.2: No pending plans that can be started now. 2019-10-09 11:45:54.2: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:46:24.8: SelectRunning: No running plans 2019-10-09 11:46:24.8: No pending plans that can be started now. 2019-10-09 11:46:24.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:46:55.4: SelectRunning: No running plans 2019-10-09 11:46:55.4: No pending plans that can be started now. 2019-10-09 11:46:55.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:47:26.0: SelectRunning: No running plans 2019-10-09 11:47:26.0: No pending plans that can be started now. 2019-10-09 11:47:26.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:47:56.6: SelectRunning: No running plans 2019-10-09 11:47:56.6: No pending plans that can be started now. 2019-10-09 11:47:56.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:48:27.1: SelectRunning: No running plans 2019-10-09 11:48:27.1: No pending plans that can be started now. 2019-10-09 11:48:27.1: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:48:57.7: SelectRunning: No running plans 2019-10-09 11:48:57.7: No pending plans that can be started now. 2019-10-09 11:48:57.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:49:28.3: SelectRunning: No running plans 2019-10-09 11:49:28.3: No pending plans that can be started now. 2019-10-09 11:49:28.3: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:49:58.9: SelectRunning: No running plans 2019-10-09 11:49:58.9: No pending plans that can be started now. 2019-10-09 11:49:58.9: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:50:29.5: SelectRunning: No running plans 2019-10-09 11:50:29.5: No pending plans that can be started now. 2019-10-09 11:50:29.5: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:51:00.1: SelectRunning: No running plans 2019-10-09 11:51:00.1: No pending plans that can be started now. 2019-10-09 11:51:00.1: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:51:30.7: SelectRunning: No running plans 2019-10-09 11:51:30.7: No pending plans that can be started now. 2019-10-09 11:51:30.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:52:01.3: SelectRunning: No running plans 2019-10-09 11:52:01.3: No pending plans that can be started now. 2019-10-09 11:52:01.3: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:52:32.0: SelectRunning: No running plans 2019-10-09 11:52:32.0: No pending plans that can be started now. 2019-10-09 11:52:32.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:53:02.6: SelectRunning: No running plans 2019-10-09 11:53:02.6: No pending plans that can be started now. 2019-10-09 11:53:02.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:53:33.2: SelectRunning: No running plans 2019-10-09 11:53:33.2: No pending plans that can be started now. 2019-10-09 11:53:33.2: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:54:04.1: SelectRunning: No running plans 2019-10-09 11:54:04.1: No pending plans that can be started now. 2019-10-09 11:54:04.1: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:54:34.7: SelectRunning: No running plans 2019-10-09 11:54:34.7: No pending plans that can be started now. 2019-10-09 11:54:34.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:55:05.3: SelectRunning: No running plans 2019-10-09 11:55:05.3: No pending plans that can be started now. 2019-10-09 11:55:05.3: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:55:36.2: SelectRunning: No running plans 2019-10-09 11:55:36.2: No pending plans that can be started now. 2019-10-09 11:55:36.2: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:56:06.8: SelectRunning: No running plans 2019-10-09 11:56:06.8: No pending plans that can be started now. 2019-10-09 11:56:06.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:56:37.4: SelectRunning: No running plans 2019-10-09 11:56:37.4: No pending plans that can be started now. 2019-10-09 11:56:37.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:57:08.3: SelectRunning: No running plans 2019-10-09 11:57:08.4: No pending plans that can be started now. 2019-10-09 11:57:08.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:57:38.9: SelectRunning: No running plans 2019-10-09 11:57:39.0: No pending plans that can be started now. 2019-10-09 11:57:39.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:58:09.5: SelectRunning: No running plans 2019-10-09 11:58:09.5: No pending plans that can be started now. 2019-10-09 11:58:09.5: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:58:40.4: SelectRunning: No running plans 2019-10-09 11:58:40.5: No pending plans that can be started now. 2019-10-09 11:58:40.5: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:59:11.0: SelectRunning: No running plans 2019-10-09 11:59:11.1: No pending plans that can be started now. 2019-10-09 11:59:11.1: Dispatcher cycle time: 0.0 sec. 2019-10-09 11:59:41.6: SelectRunning: No running plans 2019-10-09 11:59:41.6: No pending plans that can be started now. 2019-10-09 11:59:41.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:00:12.6: SelectRunning: No running plans 2019-10-09 12:00:12.6: No pending plans that can be started now. 2019-10-09 12:00:12.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:00:43.2: SelectRunning: No running plans 2019-10-09 12:00:43.2: No pending plans that can be started now. 2019-10-09 12:00:43.2: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:01:13.7: SelectRunning: No running plans 2019-10-09 12:01:13.8: No pending plans that can be started now. 2019-10-09 12:01:13.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:01:44.7: SelectRunning: No running plans 2019-10-09 12:01:44.7: No pending plans that can be started now. 2019-10-09 12:01:44.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:02:15.3: SelectRunning: No running plans 2019-10-09 12:02:15.3: No pending plans that can be started now. 2019-10-09 12:02:15.3: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:02:45.9: SelectRunning: No running plans 2019-10-09 12:02:45.9: No pending plans that can be started now. 2019-10-09 12:02:45.9: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:03:16.8: SelectRunning: No running plans 2019-10-09 12:03:16.8: No pending plans that can be started now. 2019-10-09 12:03:16.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:03:47.4: SelectRunning: No running plans 2019-10-09 12:03:47.4: No pending plans that can be started now. 2019-10-09 12:03:47.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:04:18.0: SelectRunning: No running plans 2019-10-09 12:04:18.0: No pending plans that can be started now. 2019-10-09 12:04:18.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:04:48.9: SelectRunning: No running plans 2019-10-09 12:04:48.9: No pending plans that can be started now. 2019-10-09 12:04:48.9: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:05:19.5: SelectRunning: No running plans 2019-10-09 12:05:19.5: No pending plans that can be started now. 2019-10-09 12:05:19.5: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:05:50.1: SelectRunning: No running plans 2019-10-09 12:05:50.1: No pending plans that can be started now. 2019-10-09 12:05:50.1: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:06:20.7: SelectRunning: No running plans 2019-10-09 12:06:20.7: No pending plans that can be started now. 2019-10-09 12:06:20.7: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:06:51.3: SelectRunning: No running plans 2019-10-09 12:06:51.3: No pending plans that can be started now. 2019-10-09 12:06:51.3: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:07:21.9: SelectRunning: No running plans 2019-10-09 12:07:21.9: No pending plans that can be started now. 2019-10-09 12:07:21.9: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:07:52.4: SelectRunning: No running plans 2019-10-09 12:07:52.5: No pending plans that can be started now. 2019-10-09 12:07:52.5: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:08:23.0: SelectRunning: No running plans 2019-10-09 12:08:23.0: No pending plans that can be started now. 2019-10-09 12:08:23.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:08:53.6: SelectRunning: No running plans 2019-10-09 12:08:53.6: No pending plans that can be started now. 2019-10-09 12:08:53.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:09:24.2: SelectRunning: No running plans 2019-10-09 12:09:24.2: No pending plans that can be started now. 2019-10-09 12:09:24.2: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:09:54.8: SelectRunning: No running plans 2019-10-09 12:09:54.8: No pending plans that can be started now. 2019-10-09 12:09:54.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:10:25.4: SelectRunning: No running plans 2019-10-09 12:10:25.4: No pending plans that can be started now. 2019-10-09 12:10:25.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:10:56.0: SelectRunning: No running plans 2019-10-09 12:10:56.0: No pending plans that can be started now. 2019-10-09 12:10:56.0: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:11:26.6: SelectRunning: No running plans 2019-10-09 12:11:26.6: No pending plans that can be started now. 2019-10-09 12:11:26.6: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:11:57.3: SelectRunning: No running plans 2019-10-09 12:11:57.3: No pending plans that can be started now. 2019-10-09 12:11:57.3: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:12:27.8: SelectRunning: No running plans 2019-10-09 12:12:27.8: No pending plans that can be started now. 2019-10-09 12:12:27.8: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:12:58.4: SelectRunning: No running plans 2019-10-09 12:12:58.4: No pending plans that can be started now. 2019-10-09 12:12:58.4: Dispatcher cycle time: 0.0 sec. 2019-10-09 12:25:13.0: ++ Dawn Flats ++ 2019-10-09 12:25:13.0: Start ACP AutoFlat script for Dawn flats 2019-10-09 12:25:13.0: ACP.RunScript(AutoFlat, C:\Users\admin\Documents\ACP Astronomy\Plans\SchedulerDawnFlats.txt): 2019-10-09 12:25:13.0: Script AutoFocusScheduler is loaded, and 2019-10-09 12:25:13.0: the console is idle. 2019-10-09 12:25:13.0: In start loop, i = 0 2019-10-09 12:25:13.0: Console is now idle 2019-10-09 12:25:13.1: Loaded C:\Program Files (x86)\ACP Obs Control\Scripts\AutoFlat.vbs successfully 2019-10-09 12:25:13.2: Set parameter "C:\Users\admin\Documents\ACP Astronomy\Plans\SchedulerDawnFlats.txt" successfully 2019-10-09 12:25:13.2: Script started successfully 2019-10-09 12:25:23.3: Sequencer is now active 2019-10-09 12:43:52.2: Sequencer is no longer active 2019-10-09 12:44:22.7: -- Observatory Shutdown -- 2019-10-09 12:44:22.7: Start ACP Sequencer's ShutdownObs script 2019-10-09 12:44:22.7: ACP.RunScript(ShutdownObs, ): 2019-10-09 12:44:22.7: Script AutoFlat is loaded, and 2019-10-09 12:44:22.7: the console is idle. 2019-10-09 12:44:22.7: In start loop, i = 0 2019-10-09 12:44:22.7: Console is now idle 2019-10-09 12:44:22.8: Loaded C:\Users\Public\Documents\ACP Config\Scheduler\ShutdownObs.js successfully 2019-10-09 12:44:22.8: Script started successfully 2019-10-09 12:44:32.8: Sequencer is now active 2019-10-09 12:45:37.7: Sequencer is no longer active 2019-10-09 12:45:37.7: -- Weather Unsafe -- 2019-10-09 13:50:00.0: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED** 2019-10-09 14:13:01.7: Requested shutdown of scheduler 2019-10-09 14:13:01.7: Run statistics: 2019-10-09 14:13:01.7: Observations: 2 2019-10-09 14:13:01.7: Considered: 0 2019-10-09 14:13:01.7: Completed: 0 2019-10-09 14:13:01.7: Skipped: 0 2019-10-09 14:13:01.7: Never Eligible: 2 2019-10-09 14:13:01.7: Failed: 0 2019-10-09 14:13:01.7: Shutter-Open efficiency: 57.68% 2019-10-09 14:13:01.7: Overall Efficiency: 68.25% 2019-10-09 14:13:01.7: Release ACP sequencer Log closed at Wed, Oct 09 2019 14:13:03 UTC (actual time)