Log opened at Wed, Jan 04 2023 21:27:22 UTC (actual time)
Current log level is Normal
ACP Expert Scheduler Engine Version 9.0.4
Part of ACP Expert 9.0 Release
Full license: Arne Henden
2023-01-04 21:27:22.5: REAL TIME internal clock initialized at 04-Jan-2023 21:27:22 UTC
2023-01-04 21:27:22.5: Dispatcher started at 04-Jan-2023 21:27:22 UTC
2023-01-04 21:27:22.6: Loaded Constraint plugin AirMass
2023-01-04 21:27:22.6: Loaded Constraint plugin AirmassRange
2023-01-04 21:27:22.6: Loaded Constraint plugin Horizon
2023-01-04 21:27:22.7: Loaded Constraint plugin HourAngle
2023-01-04 21:27:22.7: Loaded Constraint plugin MoonAvoid
2023-01-04 21:27:22.7: Loaded Constraint plugin MoonDown
2023-01-04 21:27:22.7: Loaded Constraint plugin SkyCondition
2023-01-04 21:27:22.7: Loaded Constraint plugin TimeRange
2023-01-04 21:27:23.7: 179 plans are now pending.
2023-01-04 21:27:23.7: Attach ACP sequencer
2023-01-04 21:27:30.5: Weather successfully connected. Wait for valid data...
2023-01-04 21:27:32.4: ==== Dispatcher is running in NORMAL (NIGHT) mode ====
2023-01-04 21:27:32.4: Sequencer does sky flats
2023-01-04 21:27:35.5: ++ Weather Safe ++
2023-01-05 02:21:45.1: ++ Observatory Startup ++
2023-01-05 02:21:45.1: Weather safety is now disabled
2023-01-05 02:21:45.1: Start ACP Sequencer's StartupObs script
2023-01-05 02:22:47.0: Weather safety is re-enabled
2023-01-05 02:22:47.0: Weather safety is now disabled
2023-01-05 02:22:47.0: Open the observatory dome/roof
2023-01-05 02:23:47.8: Weather safety is re-enabled
2023-01-05 02:23:47.8: Observatory startup succeeded, and dome opened successfully
2023-01-05 02:23:47.8: Periodic AF schedule reset. Interval is now 1.0 hours
2023-01-05 02:23:47.8: Last AutoFocus was completed at 27-Dec-2022 12:13:26 UTC
2023-01-05 02:23:47.8: Autofocus will be done ASAP.
2023-01-05 02:23:47.8: ++ Auto Focus ++
2023-01-05 02:23:47.8: Doing periodic autofocus.
2023-01-05 02:23:47.8: Start special ACP AutoFocus script for scheduler
2023-01-05 02:37:56.8: ** Autofocus failed (n=1), will retry ASAP after 0 min.
2023-01-05 02:37:58.8: Plan V370_And has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan OI_158 has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan KP_Cyg has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan KU_Cyg has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan GZ_Cnc has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan V630_Cas has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan AE_And has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:58.8: Plan NSV-6690 has Monitor Mode. Time to resubmit it.
2023-01-05 02:37:59.3: Rising plan delay enabled for Plan GR_Ori:
2023-01-05 02:37:59.3:     391 min. remaining to meet strict constraints.
2023-01-05 02:37:59.3:     626 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.3:     but only 168 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.3:     deferred (rising) for 168 min, until 05-Jan-2023 05:26:07 UTC
2023-01-05 02:37:59.3: Rising plan delay enabled for Plan GR_Ori:
2023-01-05 02:37:59.3:     391 min. remaining to meet strict constraints.
2023-01-05 02:37:59.3:     626 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.3:     but only 168 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.3:     deferred (rising) for 168 min, until 05-Jan-2023 05:26:07 UTC
2023-01-05 02:37:59.4: Rising plan delay enabled for Plan J072816:
2023-01-05 02:37:59.4:     677 min. remaining to meet strict constraints.
2023-01-05 02:37:59.4:     606 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.4:     but only 285 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.4:     deferred (rising) for 282 min, until 05-Jan-2023 07:20:41 UTC
2023-01-05 02:37:59.4: Rising plan delay enabled for Plan J072816:
2023-01-05 02:37:59.4:     677 min. remaining to meet strict constraints.
2023-01-05 02:37:59.4:     606 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.4:     but only 285 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.4:     deferred (rising) for 282 min, until 05-Jan-2023 07:20:41 UTC
2023-01-05 02:37:59.4: Rising plan delay enabled for Plan KN_Lyn:
2023-01-05 02:37:59.4:     705 min. remaining to meet strict constraints.
2023-01-05 02:37:59.4:     596 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.4:     but only 328 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.4:     deferred (rising) for 324 min, until 05-Jan-2023 08:02:27 UTC
2023-01-05 02:37:59.5: Rising plan delay enabled for Plan MP_Gem:
2023-01-05 02:37:59.5:     524 min. remaining to meet strict constraints.
2023-01-05 02:37:59.5:     576 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.5:     but only 230 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.5:     deferred (rising) for 224 min, until 05-Jan-2023 06:22:50 UTC
2023-01-05 02:37:59.5: Rising plan delay enabled for Plan MP_Gem:
2023-01-05 02:37:59.5:     524 min. remaining to meet strict constraints.
2023-01-05 02:37:59.5:     600 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.5:     but only 242 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.5:     deferred (rising) for 239 min, until 05-Jan-2023 06:37:35 UTC
2023-01-05 02:37:59.6: Rising plan delay enabled for Plan NSVS_0421121:
2023-01-05 02:37:59.6:     370 min. remaining to meet strict constraints.
2023-01-05 02:37:59.6:     616 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.6:     but only 103 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.6:     deferred (rising) for 102 min, until 05-Jan-2023 04:20:08 UTC
2023-01-05 02:37:59.6: Rising plan delay enabled for Plan NSVS_0421121:
2023-01-05 02:37:59.6:     370 min. remaining to meet strict constraints.
2023-01-05 02:37:59.6:     616 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.6:     but only 103 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.6:     deferred (rising) for 102 min, until 05-Jan-2023 04:20:08 UTC
2023-01-05 02:37:59.7: Rising plan delay enabled for Plan S_Ori:
2023-01-05 02:37:59.7:     379 min. remaining to meet strict constraints.
2023-01-05 02:37:59.7:     613 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.7:     but only 169 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.7:     deferred (rising) for 167 min, until 05-Jan-2023 05:25:52 UTC
2023-01-05 02:37:59.7: Rising plan delay enabled for Plan S5_0716+714:
2023-01-05 02:37:59.7:     657 min. remaining to meet strict constraints.
2023-01-05 02:37:59.7:     629 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.7:     but only 290 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.7:     deferred (rising) for 289 min, until 05-Jan-2023 07:27:50 UTC
2023-01-05 02:37:59.7: [AirmassRange] Target will never be below the maximum air mass
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan SU_Lyn:
2023-01-05 02:37:59.8:     584 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     626 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 249 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 249 min, until 05-Jan-2023 06:47:13 UTC
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan SU_Lyn:
2023-01-05 02:37:59.8:     584 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     627 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 250 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 249 min, until 05-Jan-2023 06:47:45 UTC
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan TIC35022727:
2023-01-05 02:37:59.8:     352 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     447 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only -47 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     ending rising plan delay. Plan is now eligible.
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan TIC35022727:
2023-01-05 02:37:59.8:     352 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     355 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only -94 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     ending rising plan delay. Plan is now eligible.
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan TV_Cam:
2023-01-05 02:37:59.8:     438 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     619 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 91 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 90 min, until 05-Jan-2023 04:08:04 UTC
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan TV_Cam:
2023-01-05 02:37:59.8:     438 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     619 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 91 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 90 min, until 05-Jan-2023 04:08:04 UTC
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan TV_Cam:
2023-01-05 02:37:59.8:     438 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     619 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 91 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 90 min, until 05-Jan-2023 04:08:04 UTC
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan V1112_Per:
2023-01-05 02:37:59.8:     431 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     617 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 112 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 110 min, until 05-Jan-2023 04:28:28 UTC
2023-01-05 02:37:59.8: Rising plan delay enabled for Plan V1261_Ori:
2023-01-05 02:37:59.8:     357 min. remaining to meet strict constraints.
2023-01-05 02:37:59.8:     629 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.8:     but only 171 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.8:     deferred (rising) for 170 min, until 05-Jan-2023 05:28:43 UTC
2023-01-05 02:37:59.9: Rising plan delay enabled for Plan V1647_Ori:
2023-01-05 02:37:59.9:     411 min. remaining to meet strict constraints.
2023-01-05 02:37:59.9:     618 min. remaining for the plan to fit before dawn.
2023-01-05 02:37:59.9:     but only 189 min till start so Plan transits mid-way in its time span.
2023-01-05 02:37:59.9:     deferred (rising) for 187 min, until 05-Jan-2023 05:45:55 UTC
2023-01-05 02:37:59.9: [AirmassRange] Target will never be below the maximum air mass
2023-01-05 02:37:59.9: [AirmassRange] Target will never be below the maximum air mass
2023-01-05 02:38:00.2: Dispatcher cycle time: 3.5 sec.
2023-01-05 02:38:00.2: Acquire data for Observation V407_Cas...
2023-01-05 02:38:00.2:   (belongs to Project AAVSO_survey_HQ_AUTO_ver3391, Plan V407_Cas)
2023-01-05 02:38:00.2: Weather safety is now disabled
2023-01-05 02:38:00.2: Open the observatory dome/roof
2023-01-05 02:39:00.9: Weather safety is re-enabled
2023-01-05 02:39:00.9: Periodic AF schedule reset. Interval is now 1.0 hours
2023-01-05 02:39:00.9: Last AutoFocus was completed at 27-Dec-2022 12:13:26 UTC
2023-01-05 02:39:00.9: Autofocus will be done ASAP.
2023-01-05 02:39:00.9: ++ Auto Focus ++
2023-01-05 02:39:01.0: Doing periodic autofocus.
2023-01-05 02:39:01.0: Start special ACP AutoFocus script for scheduler
2023-01-05 02:52:32.7: ** Autofocus failed (n=2), will retry ASAP after 5 min.
2023-01-05 02:52:32.7: Send Observation V407_Cas to ACP Sequencer
2023-01-05 03:04:44.4: ** ACP script "AcquireScheduler" failed:
2023-01-05 03:04:44.4: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 1168 column 17.

2023-01-05 03:04:44.4: ACP OPERATOR ABORT: The operator killed the run
2023-01-05 03:04:44.4: ACP data acquisition failed for Observation V407_Cas.
2023-01-05 03:04:44.4:   (Observation V407_Cas interrupted by acquisition process failure.)
2023-01-05 03:04:44.5: Weather safety is now disabled
2023-01-05 03:04:44.5: Open the observatory dome/roof
2023-01-05 03:05:35.3: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
2023-01-05 03:06:00.6: Weather safety is re-enabled
2023-01-05 03:06:00.6: Periodic AF schedule reset. Interval is now 1.0 hours
2023-01-05 03:06:00.6: Last AutoFocus was completed at 27-Dec-2022 12:13:26 UTC
2023-01-05 03:06:00.6: Autofocus will be done ASAP.
2023-01-05 03:06:00.6: ++ Auto Focus ++
2023-01-05 03:06:00.6: Doing periodic autofocus.
2023-01-05 03:06:00.6: Start special ACP AutoFocus script for scheduler
2023-01-05 03:06:19.8: ** ACP script "AutoFocusScheduler" failed:
2023-01-05 03:06:19.8: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 80 column 9.

2023-01-05 03:06:19.8: ** Autofocus failed (n=3), will retry ASAP after 10 min.
2023-01-05 03:17:50.5: Weather successfully connected. Wait for valid data...
2023-01-05 03:18:46.2: Weather successfully connected. Wait for valid data...
2023-01-05 03:18:46.2: ACPSequencer: Failed to get ACP's DispatcherEnabled property. ACP is compromised.
2023-01-05 03:18:46.2:               The object invoked has disconnected from its clients. (Exception from HRESULT: 0x80010108 (RPC_E_DISCONNECTED))
2023-01-05 03:18:51.2: **ACP HAS BECOME COMPROMISED:
2023-01-05 03:18:51.2:   Scheduler depends on ACP and yet ACP is frozen, dead, or otherwise compromised.
2023-01-05 03:18:51.2:   If this happens again, please look at ACP. Is it running? Is a fatal error box visible? Is it frozen?
2023-01-05 03:18:51.2:   Usually this is a result of a device or USB failure or lock-up.
2023-01-05 03:18:51.2: No operator intervention command tool specified
2023-01-05 03:18:51.4: Run statistics:
2023-01-05 03:18:51.4:   Observations:   302
2023-01-05 03:18:51.4:   Considered:     2
2023-01-05 03:18:51.4:   Completed:      0
2023-01-05 03:18:51.4:   Skipped:        0
2023-01-05 03:18:51.4:   Never Eligible: 300
2023-01-05 03:18:51.4:   Failed:         2
2023-01-05 03:18:51.4: Shutter-Open efficiency: 0.00%
2023-01-05 03:18:51.4: Overall Efficiency: 45.51%
Log closed at Thu, Jan 05 2023 03:18:55 UTC (actual time)