Log opened at Tue, Sep 03 2019 19:28:57 UTC (actual time)
Current log level is Normal
ACP Expert Scheduler version 8.2.3
Full license: Arne Henden
2019-09-03 19:45:27.8: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2019-09-03 19:45:34.5: Start ACP AutoFlat script for Dawn flats
2019-09-03 19:45:49.6: ** ACP script "AutoFlat" failed:
2019-09-03 19:45:49.6: **Script Error (Tracking has been stopped)**
Source:   ACP.AcquireSupport
Message:  **The weather is unsafe. Cannot continue.
Location: line 710 column 9.

2019-09-03 19:45:49.9: Start ACP AutoFlat script for Dawn flats
2019-09-03 19:46:05.0: ** ACP script "AutoFlat" failed:
2019-09-03 19:46:05.0: **Script Error (Tracking has been stopped)**
Source:   ACP.AcquireSupport
Message:  **The weather is unsafe. Cannot continue.
Location: line 710 column 9.

2019-09-04 01:42:12.7: ++ Weather Safe ++
2019-09-04 02:19:33.9: ++ Observatory Startup ++
2019-09-04 02:19:33.9: Startup attempted, but no StartupObs script found
2019-09-04 02:19:33.9: Open the observatory dome/roof
2019-09-04 02:20:34.6: Observatory startup succeeded, and dome opened successfully
2019-09-04 02:23:38.5: Plan KH15D has Monitor Mode. Time to resubmit it.
Log level changed from Normal to Debug
2019-09-04 02:30:46.9: SelectRunning: No running plans
2019-09-04 02:30:46.9: No pending plans that can be started now.
2019-09-04 02:30:46.9: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:31:17.6: SelectRunning: No running plans
2019-09-04 02:31:17.6: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2019-09-04 02:31:17.6:     AirMass estimates ready after 04-Sep-2019 10:22:28 UTC
2019-09-04 02:31:17.6: No pending plans that can be started now.
2019-09-04 02:31:17.6: Dispatcher cycle time: 0.1 sec.
2019-09-04 02:31:48.5: SelectRunning: No running plans
2019-09-04 02:31:48.5: No pending plans that can be started now.
2019-09-04 02:31:48.5: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:31:50.7: Efficiency weights are set to:
2019-09-04 02:31:50.7:     Priority:          W[0]=0.00
2019-09-04 02:31:50.7:     Transit Altitude:  W[1]=0.00
2019-09-04 02:31:50.7:     Highest Altitude:  W[6]=0.00
2019-09-04 02:31:50.7:     Lateness:          W[5]=0.00
2019-09-04 02:31:50.7:     Slew Distance:     W[2]=0.00
2019-09-04 02:31:50.7:     Retry Count:       W[3]=0.00
2019-09-04 02:31:50.7:     Meridian Crossing: W[4]=0.00
2019-09-04 02:31:50.7:     Obs Conditions:    W[7]=0.00
2019-09-04 02:31:50.7:     Proj Completion:   W[8]=0.00
2019-09-04 02:31:50.7:     Rising Plan Delay: disabled
2019-09-04 02:32:19.1: SelectRunning: No running plans
2019-09-04 02:32:19.1: No pending plans that can be started now.
2019-09-04 02:32:19.1: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:32:49.7: SelectRunning: No running plans
2019-09-04 02:32:49.7: No pending plans that can be started now.
2019-09-04 02:32:49.7: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:33:20.3: SelectRunning: No running plans
2019-09-04 02:33:20.3: No pending plans that can be started now.
2019-09-04 02:33:20.3: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:33:50.9: SelectRunning: No running plans
2019-09-04 02:33:50.9: No pending plans that can be started now.
2019-09-04 02:33:50.9: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:34:21.5: SelectRunning: No running plans
2019-09-04 02:34:21.5: No pending plans that can be started now.
2019-09-04 02:34:21.5: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:34:39.0: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2019-09-04 02:34:42.9: ++ Observatory Startup ++
2019-09-04 02:34:42.9: Startup attempted, but no StartupObs script found
2019-09-04 02:34:42.9: Observatory startup succeeded
2019-09-04 02:34:42.9: SelectRunning: No running plans
2019-09-04 02:34:42.9: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2019-09-04 02:34:42.9:     AirMass estimates ready after 04-Sep-2019 10:22:28 UTC
2019-09-04 02:34:42.9: No pending plans that can be started now.
2019-09-04 02:34:42.9: Dispatcher cycle time: 0.1 sec.
Log level changed from Debug to Extreme
2019-09-04 02:35:13.5: SelectRunning: No running plans
2019-09-04 02:35:13.5: No pending plans that can be started now.
2019-09-04 02:35:13.5: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:35:44.1: SelectRunning: No running plans
2019-09-04 02:35:44.1: No pending plans that can be started now.
2019-09-04 02:35:44.1: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:36:14.7: SelectRunning: No running plans
2019-09-04 02:36:14.7: No pending plans that can be started now.
2019-09-04 02:36:14.7: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:36:45.3: SelectRunning: No running plans
2019-09-04 02:36:45.3: No pending plans that can be started now.
2019-09-04 02:36:45.3: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:37:15.9: SelectRunning: No running plans
2019-09-04 02:37:15.9: No pending plans that can be started now.
2019-09-04 02:37:15.9: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:37:46.6: SelectRunning: No running plans
2019-09-04 02:37:46.6: No pending plans that can be started now.
2019-09-04 02:37:46.6: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:38:17.2: SelectRunning: No running plans
2019-09-04 02:38:17.2: No pending plans that can be started now.
2019-09-04 02:38:17.2: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:38:47.8: SelectRunning: No running plans
2019-09-04 02:38:47.9: No pending plans that can be started now.
2019-09-04 02:38:47.9: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:39:18.9: SelectRunning: No running plans
2019-09-04 02:39:18.9: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2019-09-04 02:39:18.9:     AirMass estimates ready after 04-Sep-2019 10:22:28 UTC
2019-09-04 02:39:18.9: Obs SA112 in Plan SA112 was vetoed by SkyCondition constraint.
2019-09-04 02:39:18.9:     SkyCondition estimates ready after 04-Sep-2019 02:54:18 UTC
2019-09-04 02:39:18.9: Obs SA114 in Plan SA114 was vetoed by AirMass constraint.
2019-09-04 02:39:18.9:     AirMass estimates ready after 04-Sep-2019 03:17:41 UTC
2019-09-04 02:39:18.9: Obs SA94 in Plan SA94 was vetoed by AirMass constraint.
2019-09-04 02:39:18.9:     AirMass estimates ready after 04-Sep-2019 07:33:31 UTC
2019-09-04 02:39:18.9: No pending plans that can be started now.
2019-09-04 02:39:18.9: Dispatcher cycle time: 0.2 sec.
2019-09-04 02:39:49.5: SelectRunning: No running plans
2019-09-04 02:39:49.5: No pending plans that can be started now.
2019-09-04 02:39:49.5: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:40:20.1: SelectRunning: No running plans
2019-09-04 02:40:20.1: No pending plans that can be started now.
2019-09-04 02:40:20.1: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:40:51.0: SelectRunning: No running plans
2019-09-04 02:40:51.0: No pending plans that can be started now.
2019-09-04 02:40:51.0: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:41:21.6: SelectRunning: No running plans
2019-09-04 02:41:21.6: No pending plans that can be started now.
2019-09-04 02:41:21.6: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:41:52.2: SelectRunning: No running plans
2019-09-04 02:41:52.2: No pending plans that can be started now.
2019-09-04 02:41:52.2: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:42:22.8: SelectRunning: No running plans
2019-09-04 02:42:22.8: No pending plans that can be started now.
2019-09-04 02:42:22.8: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:42:53.4: SelectRunning: No running plans
2019-09-04 02:42:53.4: No pending plans that can be started now.
2019-09-04 02:42:53.4: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:43:24.0: SelectRunning: No running plans
2019-09-04 02:43:24.0: No pending plans that can be started now.
2019-09-04 02:43:24.0: Dispatcher cycle time: 0.0 sec.
2019-09-04 02:43:38.4: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2019-09-04 02:43:44.6: ++ Observatory Startup ++
2019-09-04 02:43:44.6: Startup attempted, but no StartupObs script found
2019-09-04 02:43:44.6: Observatory startup succeeded
2019-09-04 02:43:44.7: SelectRunning: No running plans
2019-09-04 02:43:44.7: Obs KH15D in Plan KH15D was vetoed by AirMass constraint.
2019-09-04 02:43:44.7:     AirMass estimates ready after 04-Sep-2019 10:22:28 UTC
2019-09-04 02:43:44.7: Obs SA114 in Plan SA114 was vetoed by AirMass constraint.
2019-09-04 02:43:44.7:     AirMass estimates ready after 04-Sep-2019 03:17:41 UTC
2019-09-04 02:43:44.8: Obs SA94 in Plan SA94 was vetoed by AirMass constraint.
2019-09-04 02:43:44.8:     AirMass estimates ready after 04-Sep-2019 07:33:31 UTC
2019-09-04 02:43:44.8: Efficiency: Only one pending plan SA112, it is the "best"
2019-09-04 02:43:44.8: Dispatcher cycle time: 0.2 sec.
2019-09-04 02:43:44.8: Acquire data for Observation SA112...
2019-09-04 02:43:44.8:   (belongs to Project Landolt fields, Plan SA112)
2019-09-04 02:43:44.8: Doing 3 sets
2019-09-04 02:43:44.8: ACP Last AF Time 27-Aug-2019 03:28:55 UTC
2019-09-04 02:43:44.8: Send Observation SA112 to ACP Sequencer
2019-09-04 02:43:44.8: ACP.RunScript(AcquireScheduler, ):
2019-09-04 02:43:44.8:   Script AutoFlat is loaded, and
2019-09-04 02:43:44.8:   the console is idle.
2019-09-04 02:43:44.8:   In start loop, i = 0
2019-09-04 02:43:44.8:   Console is now idle
2019-09-04 02:43:44.9:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2019-09-04 02:43:44.9:   Script started successfully
2019-09-04 02:43:54.9: Sequencer is now active
2019-09-04 02:47:24.3: Sequencer is no longer active
2019-09-04 02:47:24.3: Post-job status check done (stat=Completed)
2019-09-04 02:47:24.3: ACP Last AF Time 27-Aug-2019 03:28:55 UTC
2019-09-04 02:47:24.3: Send Observation SA112 to ACP Sequencer
2019-09-04 02:47:24.3: ACP.RunScript(AcquireScheduler, ):
2019-09-04 02:47:24.3:   Script AcquireScheduler is loaded, and
2019-09-04 02:47:24.3:   the console is idle.
2019-09-04 02:47:24.3:   In start loop, i = 0
2019-09-04 02:47:24.3:   Console is now idle
2019-09-04 02:47:24.3:   Loaded C:\Program Files (x86)\ACP Scheduler\AcquireScheduler.vbs successfully
2019-09-04 02:47:24.3:   Script started successfully
2019-09-04 02:47:34.4: Sequencer is now active
Log level changed from Extreme to Normal
2019-09-04 02:49:35.4: Send Observation SA112 to ACP Sequencer
2019-09-04 02:51:47.9: Acquisition time: 483.0351156 sec.
2019-09-04 02:51:47.9: Data for Observation SA112 of Plan SA112 acquired successfully.
2019-09-04 02:51:47.9: Plan SA112 completed successfully.
2019-09-04 02:51:48.0: Image Efficiency: 24.8%
2019-09-04 02:51:48.0: Cycle Efficiency: 99.9%
2019-09-04 02:51:48.1: ++ Auto Focus ++
2019-09-04 02:51:48.1: Doing initial autofocus.
2019-09-04 02:51:48.1: Start special ACP AutoFocus script for scheduler
2019-09-04 02:56:26.3: Next periodic autofocus ASAP after 3600sec. 04-Sep-2019 03:56:08 UTC
2019-09-04 02:56:57.0: Dispatcher cycle time: 0.1 sec.
2019-09-04 02:56:57.0: Acquire data for Observation SA109...
2019-09-04 02:56:57.0:   (belongs to Project Landolt fields, Plan SA109)
2019-09-04 02:56:57.0: Doing 3 sets
2019-09-04 02:56:57.0: Send Observation SA109 to ACP Sequencer
2019-09-04 03:00:05.4: Send Observation SA109 to ACP Sequencer
2019-09-04 03:00:20.3: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2019-09-04 03:00:56.6: RUN FAILED: Scheduler was stopped during run
2019-09-04 03:00:56.6: ACP data acquisition failed for Observation SA109.
2019-09-04 03:00:56.6:   (Observation SA109 interrupted by operator or system.)
2019-09-04 03:15:18.1: ++ Observatory Startup ++
2019-09-04 03:15:18.1: Startup attempted, but no StartupObs script found
2019-09-04 03:15:18.1: Observatory startup succeeded
2019-09-04 03:15:18.1: ++ Auto Focus ++
2019-09-04 03:15:18.1: Doing initial autofocus.
2019-09-04 03:15:18.1: Start special ACP AutoFocus script for scheduler
2019-09-04 03:18:50.2: Next periodic autofocus ASAP after 3600sec. 04-Sep-2019 04:18:35 UTC
2019-09-04 03:18:50.4: Dispatcher cycle time: 0.3 sec.
2019-09-04 03:18:50.4: Acquire data for Observation SA114...
2019-09-04 03:18:50.4:   (belongs to Project Landolt fields, Plan SA114)
2019-09-04 03:18:50.4: Doing 3 sets
2019-09-04 03:18:50.4: Send Observation SA114 to ACP Sequencer
2019-09-04 03:24:10.5: Send Observation SA114 to ACP Sequencer
2019-09-04 03:26:35.4: Send Observation SA114 to ACP Sequencer
2019-09-04 03:28:59.1: Acquisition time: 608.6344687 sec.
2019-09-04 03:28:59.1: Data for Observation SA114 of Plan SA114 acquired successfully.
2019-09-04 03:28:59.2: Plan SA114 completed successfully.
2019-09-04 03:28:59.2: Image Efficiency: 19.7%
2019-09-04 03:28:59.2: Cycle Efficiency: 99.9%
2019-09-04 03:28:59.3: Dispatcher cycle time: 0.0 sec.
2019-09-04 03:28:59.3: Acquire data for Observation SA112...
2019-09-04 03:28:59.4:   (belongs to Project Landolt fields, Plan SA112)
2019-09-04 03:28:59.4: Doing 3 sets
2019-09-04 03:28:59.4: Send Observation SA112 to ACP Sequencer
2019-09-04 03:33:16.5: Send Observation SA112 to ACP Sequencer
2019-09-04 03:35:40.8: Send Observation SA112 to ACP Sequencer
2019-09-04 03:38:03.4: Acquisition time: 543.9961879 sec.
2019-09-04 03:38:03.4: Data for Observation SA112 of Plan SA112 acquired successfully.
2019-09-04 03:38:03.5: Plan SA112 completed successfully.
2019-09-04 03:38:03.5: Image Efficiency: 22.1%
2019-09-04 03:38:03.5: Cycle Efficiency: 100.0%
2019-09-04 04:18:51.3: ++ Auto Focus ++
2019-09-04 04:18:51.3: Doing periodic autofocus.
2019-09-04 04:18:51.3: Start special ACP AutoFocus script for scheduler
2019-09-04 04:23:36.4: Next periodic autofocus ASAP after 3600sec. 04-Sep-2019 05:23:21 UTC
2019-09-04 05:23:47.3: ++ Auto Focus ++
2019-09-04 05:23:47.3: Doing periodic autofocus.
2019-09-04 05:23:47.3: Start special ACP AutoFocus script for scheduler
2019-09-04 05:27:03.8: Next periodic autofocus ASAP after 3600sec. 04-Sep-2019 06:26:48 UTC
2019-09-04 06:11:26.9: -- Weather Unsafe --
2019-09-04 08:47:00.1: ++ Weather Safe ++
2019-09-04 08:47:01.1: ++ Observatory Startup ++
2019-09-04 08:47:01.1: Startup attempted, but no StartupObs script found
2019-09-04 08:47:01.1: Open the observatory dome/roof
2019-09-04 08:47:31.8: **EXCEPTION IN SCHEDULER:
2019-09-04 08:47:31.8: DOME FAILURE: Dome reports shutter error status while opening
2019-09-04 08:47:32.1: Traceback:
   at DC3.Scheduler.ACPSequencer.OpenDome()
   at DC3.Scheduler.Engine.DoStartupIf(Boolean openDome)
   at DC3.Scheduler.Engine.Run()
2019-09-04 08:47:32.1: DOME/ROOF FAILURE: In addition, attempting to close your dome/roof this error occurred:
2019-09-04 08:47:32.1: DOME FAILURE: Dome reports shutter error status when asked to close.
2019-09-04 08:47:32.1: No operator intervention command tool specified
2019-09-04 08:47:32.2: Run statistics:
2019-09-04 08:47:32.2:   Observations:   3
2019-09-04 08:47:32.2:   Considered:     1
2019-09-04 08:47:32.2:   Completed:      0
2019-09-04 08:47:32.2:   Skipped:        0
2019-09-04 08:47:32.2:   Never Eligible: 2
2019-09-04 08:47:32.2:   Failed:         1
2019-09-04 08:47:32.2: Shutter-Open efficiency: 3.39%
2019-09-04 08:47:32.2: Overall Efficiency: 34.60%
2019-09-04 08:47:32.2: Release ACP sequencer
Log closed at Wed, Sep 04 2019 08:47:33 UTC (actual time)