Log opened at Wed, Sep 05 2018 02:15:03 UTC (actual time)
Current log level is Verbose
ACP Expert Scheduler version 8.1.1
Full license: Arne Henden
2018-09-05 02:15:03.9: Internal clock initialized at 05-Sep-2018 02:15:03 UTC
2018-09-05 02:15:04.0: Loaded Constraint plugin AirMass
2018-09-05 02:15:04.0: Loaded Constraint plugin AirmassRange
2018-09-05 02:15:04.0: Loaded Constraint plugin Horizon
2018-09-05 02:15:04.0: Loaded Constraint plugin HourAngle
2018-09-05 02:15:04.0: Loaded Constraint plugin MoonAvoid
2018-09-05 02:15:04.0: Loaded Constraint plugin MoonDown
2018-09-05 02:15:04.0: Loaded Constraint plugin SkyCondition
2018-09-05 02:15:04.0: Loaded Constraint plugin TimeRange
2018-09-05 02:15:04.9: 34 plans are now pending.
2018-09-05 02:15:04.9: Attach ACP sequencer
2018-09-05 02:15:11.3: There is no controllable dome or roof.
2018-09-05 02:15:12.9: Sequencer does sky flats
2018-09-05 02:15:28.2: Weather successfully connected. Wait for valid data...
2018-09-05 02:29:35.3: Dispatcher started at 05-Sep-2018 02:29:35 UTC
2018-09-05 04:45:29.9: ++ Weather Safe ++
2018-09-05 04:45:30.9: ++ Observatory Startup ++
2018-09-05 04:45:30.9: Start ACP Sequencer's StartupObs script
2018-09-05 04:46:00.6: Open the observatory dome/roof
2018-09-05 04:46:56.7: Observatory startup succeeded, and dome opened successfully
2018-09-05 04:46:56.9: ++ Auto Focus ++
2018-09-05 04:46:56.9: Doing initial autofocus.
2018-09-05 04:46:56.9: Start special ACP AutoFocus script for scheduler
2018-09-05 04:51:09.4: Next periodic autofocus ASAP after 05-Sep-2018 07:50:53 UTC
2018-09-05 04:51:12.5: Plan GSC_3649-0825 has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan V0809_Cep has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan V0965_Per has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan V1722_Aql has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan SDSS073224 has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan NGC_7790 has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan U_Aqr has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan V339_Del_TMO61 has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan Mkn_501 has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.5: Plan AF_And has Monitor Mode. Time to resubmit it.
2018-09-05 04:51:12.6: Rising plan delay enabled for Plan AF_And:
2018-09-05 04:51:12.6:     547 min. remaining to meet strict constraints.
2018-09-05 04:51:12.6:     419 min. remaining for the plan to fit before dawn.
2018-09-05 04:51:12.6:     but only 241 min till mid-Plan transit.
2018-09-05 04:51:12.6:     deferred (rising) for 241 min, until 05-Sep-2018 08:52:52 UTC
2018-09-05 04:51:12.6: Rising plan delay enabled for Plan GSC_3649-0825:
2018-09-05 04:51:12.6:     182 min. remaining to meet strict constraints.
2018-09-05 04:51:12.6:     419 min. remaining for the plan to fit before dawn.
2018-09-05 04:51:12.6:     but only 165 min till mid-Plan transit.
2018-09-05 04:51:12.6:     deferred (rising) for 165 min, until 05-Sep-2018 07:36:34 UTC
2018-09-05 04:51:12.7: Rising plan delay enabled for Plan NGC_7790:
2018-09-05 04:51:12.7:     182 min. remaining to meet strict constraints.
2018-09-05 04:51:12.7:     419 min. remaining for the plan to fit before dawn.
2018-09-05 04:51:12.7:     deferred (rising) for 182 min, until 05-Sep-2018 07:53:21 UTC
2018-09-05 04:51:12.8: Rising plan delay enabled for Plan U_Aqr:
2018-09-05 04:51:12.8:     182 min. remaining to meet strict constraints.
2018-09-05 04:51:12.8:     419 min. remaining for the plan to fit before dawn.
2018-09-05 04:51:12.8:     but only 81 min till mid-Plan transit.
2018-09-05 04:51:12.8:     deferred (rising) for 81 min, until 05-Sep-2018 06:13:05 UTC
2018-09-05 04:51:12.8: Rising plan delay enabled for Plan V0809_Cep:
2018-09-05 04:51:12.8:     182 min. remaining to meet strict constraints.
2018-09-05 04:51:12.8:     419 min. remaining for the plan to fit before dawn.
2018-09-05 04:51:12.8:     but only 146 min till mid-Plan transit.
2018-09-05 04:51:12.8:     deferred (rising) for 146 min, until 05-Sep-2018 07:17:39 UTC
2018-09-05 04:51:12.9: Rising plan delay enabled for Plan V2481_Cyg:
2018-09-05 04:51:12.9:     182 min. remaining to meet strict constraints.
2018-09-05 04:51:12.9:     402 min. remaining for the plan to fit before dawn.
2018-09-05 04:51:12.9:     but only 14 min till mid-Plan transit.
2018-09-05 04:51:12.9:     deferred (rising) for 12 min, until 05-Sep-2018 05:03:58 UTC
2018-09-05 04:51:13.0: Dispatcher cycle time: 1.9 sec.
2018-09-05 04:51:13.0: Acquire data for Observation Mkn_501...
2018-09-05 04:51:13.0:   (belongs to Project AAVSO_SXAC_Mkn_501, Plan Mkn_501)
2018-09-05 04:51:13.0: Doing 3 sets
2018-09-05 04:51:16.8: Send Observation Mkn_501 to ACP Sequencer
2018-09-05 05:00:46.6: Send Observation Mkn_501 to ACP Sequencer
2018-09-05 05:08:18.2: Send Observation Mkn_501 to ACP Sequencer
2018-09-05 05:15:49.9: Acquisition time: 1473.0949874 sec.
2018-09-05 05:15:49.9: Data for Observation Mkn_501 of Plan Mkn_501 acquired successfully.
2018-09-05 05:15:49.9: Plan Mkn_501 completed successfully.
2018-09-05 05:15:49.9: Image Efficiency: 61.0%
2018-09-05 05:15:49.9: Cycle Efficiency: 99.9%
2018-09-05 05:15:57.9: Dispatcher cycle time: 0.6 sec.
2018-09-05 05:15:57.9: Acquire data for Observation V339_Del_TMO61...
2018-09-05 05:15:57.9:   (belongs to Project AAVSO_Monitoring, Plan V339_Del_TMO61)
2018-09-05 05:15:57.9: Doing 3 sets
2018-09-05 05:16:06.4: Send Observation V339_Del_TMO61 to ACP Sequencer
2018-09-05 05:22:36.5: Send Observation V339_Del_TMO61 to ACP Sequencer
2018-09-05 05:27:26.8: Send Observation V339_Del_TMO61 to ACP Sequencer
2018-09-05 05:32:24.1: Acquisition time: 977.6849172 sec.
2018-09-05 05:32:24.1: Data for Observation V339_Del_TMO61 of Plan V339_Del_TMO61 acquired successfully.
2018-09-05 05:32:24.1: Plan V339_Del_TMO61 completed successfully.
2018-09-05 05:32:24.1: Image Efficiency: 27.6%
2018-09-05 05:32:24.1: Cycle Efficiency: 99.9%
2018-09-05 05:32:28.5: Dispatcher cycle time: 0.2 sec.
2018-09-05 05:32:28.5: Acquire data for Observation V1722_Aql...
2018-09-05 05:32:28.5:   (belongs to Project Nova_Monitoring, Plan V1722_Aql)
2018-09-05 05:32:28.6: Send Observation V1722_Aql to ACP Sequencer
2018-09-05 06:06:24.1: Acquisition time: 2035.4915752 sec.
2018-09-05 06:06:24.1: Data for Observation V1722_Aql of Plan V1722_Aql acquired successfully.
2018-09-05 06:06:24.1: Plan V1722_Aql completed successfully.
2018-09-05 06:06:24.1: Image Efficiency: 73.7%
2018-09-05 06:06:24.1: Cycle Efficiency: 100.0%
2018-09-05 06:06:32.2: Rising plan delay enabled for Plan FU_Cam:
2018-09-05 06:06:32.2:     106 min. remaining to meet strict constraints.
2018-09-05 06:06:32.2:     326 min. remaining for the plan to fit before dawn.
2018-09-05 06:06:32.2:     deferred (rising) for 105 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 06:06:32.3: Rising plan delay enabled for Plan FW_Cam:
2018-09-05 06:06:32.3:     106 min. remaining to meet strict constraints.
2018-09-05 06:06:32.3:     326 min. remaining for the plan to fit before dawn.
2018-09-05 06:06:32.3:     deferred (rising) for 105 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 06:06:32.3: Rising plan delay enabled for Plan FY_Cam:
2018-09-05 06:06:32.3:     106 min. remaining to meet strict constraints.
2018-09-05 06:06:32.3:     326 min. remaining for the plan to fit before dawn.
2018-09-05 06:06:32.3:     deferred (rising) for 105 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 06:06:32.8: Dispatcher cycle time: 0.5 sec.
2018-09-05 06:06:32.8: Acquire data for Observation V1721_Aql...
2018-09-05 06:06:32.8:   (belongs to Project Nova_Monitoring, Plan V1721_Aql)
2018-09-05 06:06:36.1: Send Observation V1721_Aql to ACP Sequencer
2018-09-05 06:38:55.6: Acquisition time: 1939.4578065 sec.
2018-09-05 06:38:55.6: Data for Observation V1721_Aql of Plan V1721_Aql acquired successfully.
2018-09-05 06:38:55.6: Plan V1721_Aql completed successfully.
2018-09-05 06:38:55.6: Image Efficiency: 77.3%
2018-09-05 06:38:55.6: Cycle Efficiency: 100.0%
2018-09-05 06:39:02.6: Rising plan delay enabled for Plan V0603_Per:
2018-09-05 06:39:02.6:     74 min. remaining to meet strict constraints.
2018-09-05 06:39:02.6:     294 min. remaining for the plan to fit before dawn.
2018-09-05 06:39:02.6:     deferred (rising) for 72 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 06:39:02.6: Rising plan delay enabled for Plan V0965_Per:
2018-09-05 06:39:02.6:     74 min. remaining to meet strict constraints.
2018-09-05 06:39:02.6:     311 min. remaining for the plan to fit before dawn.
2018-09-05 06:39:02.6:     deferred (rising) for 74 min, until 05-Sep-2018 07:53:21 UTC
2018-09-05 06:39:02.7: Dispatcher cycle time: 0.2 sec.
2018-09-05 06:39:02.7: Acquire data for Observation V2481_Cyg...
2018-09-05 06:39:02.7:   (belongs to Project AAVSO_HGUA_Miras_Manual_ver167, Plan V2481_Cyg)
2018-09-05 06:39:11.1: Send Observation V2481_Cyg to ACP Sequencer
2018-09-05 06:55:48.9: Acquisition time: 997.7153524 sec.
2018-09-05 06:55:48.9: Data for Observation V2481_Cyg of Plan V2481_Cyg acquired successfully.
2018-09-05 06:55:48.9: Plan V2481_Cyg completed successfully.
2018-09-05 06:55:48.9: Image Efficiency: 39.1%
2018-09-05 06:55:48.9: Cycle Efficiency: 100.0%
2018-09-05 06:55:53.3: Rising plan delay enabled for Plan WZ_Per:
2018-09-05 06:55:53.3:     57 min. remaining to meet strict constraints.
2018-09-05 06:55:53.3:     277 min. remaining for the plan to fit before dawn.
2018-09-05 06:55:53.3:     deferred (rising) for 55 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 06:55:53.3: Dispatcher cycle time: 0.2 sec.
2018-09-05 06:55:53.3: Acquire data for Observation U_Aqr...
2018-09-05 06:55:53.3:   (belongs to Project AAVSO_Monitoring, Plan U_Aqr)
2018-09-05 06:55:53.4: Send Observation U_Aqr to ACP Sequencer
2018-09-05 07:06:16.6: ACP ERROR: Run failed for unknown reason (see ACP run log)
2018-09-05 07:06:16.6: ACP data acquisition failed for Observation U_Aqr.
2018-09-05 07:06:16.6:   (Observation U_Aqr interrupted by acquisition process failure.)
2018-09-05 07:06:20.5: -- Weather Unsafe --
2018-09-05 07:36:29.2: ++ Weather Safe ++
2018-09-05 07:36:30.3: ++ Observatory Startup ++
2018-09-05 07:36:30.3: Start ACP Sequencer's StartupObs script
2018-09-05 07:36:46.1: Open the observatory dome/roof
2018-09-05 07:37:46.0: Observatory startup succeeded, and dome opened successfully
2018-09-05 07:37:46.0: ++ Auto Focus ++
2018-09-05 07:37:46.0: Doing initial autofocus.
2018-09-05 07:37:46.0: Start special ACP AutoFocus script for scheduler
2018-09-05 07:42:22.9: Next periodic autofocus ASAP after 05-Sep-2018 10:41:56 UTC
2018-09-05 07:42:25.7: Rising plan delay enabled for Plan HI_Cam:
2018-09-05 07:42:25.7:     10 min. remaining to meet strict constraints.
2018-09-05 07:42:25.7:     231 min. remaining for the plan to fit before dawn.
2018-09-05 07:42:25.7:     deferred (rising) for 9 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 07:42:25.9: Dispatcher cycle time: 0.3 sec.
2018-09-05 07:42:25.9: Acquire data for Observation GSC_3649-0825...
2018-09-05 07:42:25.9:   (belongs to Project Staels, Plan GSC_3649-0825)
2018-09-05 07:42:26.2: Send Observation GSC_3649-0825 to ACP Sequencer
2018-09-05 07:47:38.9: Acquisition time: 312.7025492 sec.
2018-09-05 07:47:38.9: Data for Observation GSC_3649-0825 of Plan GSC_3649-0825 acquired successfully.
2018-09-05 07:47:39.0: Plan GSC_3649-0825 completed successfully.
2018-09-05 07:47:39.0: Image Efficiency: 43.1%
2018-09-05 07:47:39.0: Cycle Efficiency: 99.9%
2018-09-05 07:47:41.3: Rising plan delay enabled for Plan HO_Cam:
2018-09-05 07:47:41.3:     5 min. remaining to meet strict constraints.
2018-09-05 07:47:41.3:     225 min. remaining for the plan to fit before dawn.
2018-09-05 07:47:41.3:     deferred (rising) for 3 min, until 05-Sep-2018 07:51:39 UTC
2018-09-05 07:47:41.4: Dispatcher cycle time: 0.1 sec.
2018-09-05 07:47:41.4: Acquire data for Observation V0809_Cep...
2018-09-05 07:47:41.4:   (belongs to Project Nova_Monitoring, Plan V0809_Cep)
2018-09-05 07:47:45.8: Send Observation V0809_Cep to ACP Sequencer
2018-09-05 08:19:05.2: Acquisition time: 1879.428901 sec.
2018-09-05 08:19:05.2: Data for Observation V0809_Cep of Plan V0809_Cep acquired successfully.
2018-09-05 08:19:05.2: Plan V0809_Cep completed successfully.
2018-09-05 08:19:05.2: Image Efficiency: 74.5%
2018-09-05 08:19:05.2: Cycle Efficiency: 100.0%
2018-09-05 08:19:09.3: Rising plan delay enabled for Plan FU_Cam:
2018-09-05 08:19:09.3:     543 min. remaining to meet strict constraints.
2018-09-05 08:19:09.3:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.3:     but only 185 min till mid-Plan transit.
2018-09-05 08:19:09.3:     deferred (rising) for 183 min, until 05-Sep-2018 11:22:29 UTC
2018-09-05 08:19:09.3: Rising plan delay enabled for Plan FW_Cam:
2018-09-05 08:19:09.3:     555 min. remaining to meet strict constraints.
2018-09-05 08:19:09.3:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.3:     but only 191 min till mid-Plan transit.
2018-09-05 08:19:09.3:     deferred (rising) for 190 min, until 05-Sep-2018 11:29:18 UTC
2018-09-05 08:19:09.3: Rising plan delay enabled for Plan FY_Cam:
2018-09-05 08:19:09.3:     548 min. remaining to meet strict constraints.
2018-09-05 08:19:09.3:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.3:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.3: Rising plan delay enabled for Plan HI_Cam:
2018-09-05 08:19:09.3:     611 min. remaining to meet strict constraints.
2018-09-05 08:19:09.3:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.3:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.3: Rising plan delay enabled for Plan HO_Cam:
2018-09-05 08:19:09.3:     640 min. remaining to meet strict constraints.
2018-09-05 08:19:09.3:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.3:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.3: Rising plan delay enabled for Plan HQ_Aur:
2018-09-05 08:19:09.3:     643 min. remaining to meet strict constraints.
2018-09-05 08:19:09.3:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.3:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.4: Rising plan delay enabled for Plan HX_Aur:
2018-09-05 08:19:09.4:     610 min. remaining to meet strict constraints.
2018-09-05 08:19:09.4:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.4:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.4: Rising plan delay enabled for Plan V0603_Per:
2018-09-05 08:19:09.4:     540 min. remaining to meet strict constraints.
2018-09-05 08:19:09.4:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.4:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.4: Rising plan delay enabled for Plan V0965_Per:
2018-09-05 08:19:09.4:     479 min. remaining to meet strict constraints.
2018-09-05 08:19:09.4:     211 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.4:     but only 181 min till mid-Plan transit.
2018-09-05 08:19:09.4:     deferred (rising) for 181 min, until 05-Sep-2018 11:20:11 UTC
2018-09-05 08:19:09.4: Rising plan delay enabled for Plan WZ_Per:
2018-09-05 08:19:09.4:     519 min. remaining to meet strict constraints.
2018-09-05 08:19:09.4:     194 min. remaining for the plan to fit before dawn.
2018-09-05 08:19:09.4:     deferred (rising) for 192 min, until 05-Sep-2018 11:31:45 UTC
2018-09-05 08:19:09.4: Dispatcher cycle time: 0.2 sec.
2018-09-05 08:19:09.4: Acquire data for Observation NGC_7790...
2018-09-05 08:19:09.5:   (belongs to Project AAVSO_Monitoring, Plan NGC_7790)
2018-09-05 08:19:15.1: Send Observation NGC_7790 to ACP Sequencer
2018-09-05 08:36:45.5: Acquisition time: 1050.427845 sec.
2018-09-05 08:36:45.5: Data for Observation NGC_7790 of Plan NGC_7790 acquired successfully.
2018-09-05 08:36:45.6: Plan NGC_7790 completed successfully.
2018-09-05 08:36:45.6: Image Efficiency: 44.3%
2018-09-05 08:36:45.6: Cycle Efficiency: 100.0%
2018-09-05 08:36:52.0: Dispatcher cycle time: 0.0 sec.
2018-09-05 08:36:52.0: Acquire data for Observation RX_J0524+42...
2018-09-05 08:36:52.0:   (belongs to Project Walker, Plan RX_J0524+42)
2018-09-05 08:36:52.0: Doing 30 sets
2018-09-05 08:36:58.4: Send Observation RX_J0524+42 to ACP Sequencer
2018-09-05 09:08:26.3: Send Observation RX_J0524+42 to ACP Sequencer
2018-09-05 09:36:00.2: Send Observation RX_J0524+42 to ACP Sequencer
2018-09-05 10:03:28.3: Send Observation RX_J0524+42 to ACP Sequencer
2018-09-05 10:31:06.2: Send Observation RX_J0524+42 to ACP Sequencer
2018-09-05 10:58:36.3: Send Observation RX_J0524+42 to ACP Sequencer
2018-09-05 11:26:20.7: ***Running Plan RX_J0524+42 (best efforts) completed early:
2018-09-05 11:26:20.7:    Obs RX_J0524+42 would extend past dawn
2018-09-05 11:26:20.7: Acquisition time: 10162.2478491 sec.
2018-09-05 11:26:20.7: Data for Observation RX_J0524+42 of Plan RX_J0524+42 acquired successfully.
2018-09-05 11:26:20.8: Plan RX_J0524+42 completed successfully.
2018-09-05 11:26:20.8: Image Efficiency: 70.8%
2018-09-05 11:26:20.8: Cycle Efficiency: 100.0%
2018-09-05 11:26:28.0: ++ Auto Focus ++
2018-09-05 11:26:28.0: Doing periodic autofocus.
2018-09-05 11:26:28.0: Start special ACP AutoFocus script for scheduler
2018-09-05 11:27:59.1: ** ACP script "AutoFocusScheduler" failed:
2018-09-05 11:27:59.1: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 78 column 9.

2018-09-05 11:27:59.1: ** Autofocus failed (n=1), will retry ASAP after 0 min.
2018-09-05 11:28:01.4: -- Weather Unsafe --
2018-09-05 12:01:18.8: ++ Weather Safe ++
2018-09-05 12:05:32.4: ++ Observatory Startup ++
2018-09-05 12:05:32.4: Start ACP Sequencer's StartupObs script
2018-09-05 12:05:49.1: Open the observatory dome/roof
2018-09-05 12:06:43.4: Observatory startup succeeded, and dome opened successfully
2018-09-05 12:06:43.4: ++ Dawn Flats ++
2018-09-05 12:06:43.4: Start ACP AutoFlat script for Dawn flats
2018-09-05 12:22:44.7: ** ACP script "AutoFlat" failed:
2018-09-05 12:22:44.7: **Script Error**
Source:   ACP
Message:  The script was aborted.
Location: line 1548 column 25.

2018-09-05 12:22:46.4: -- Weather Unsafe --
2018-09-05 12:23:25.0: -- Observatory Shutdown --
2018-09-05 12:23:25.4: Start ACP Sequencer's ShutdownObs script
2018-09-05 12:23:26.3: WARNING: Request sent while Weather Safety Script is running
2018-09-05 19:08:07.3: Run statistics:
2018-09-05 19:08:07.3:   Observations:   54
2018-09-05 19:08:07.3:   Considered:     27
2018-09-05 19:08:07.3:   Completed:      15
2018-09-05 19:08:07.3:   Skipped:        8
2018-09-05 19:08:07.3:   Never Eligible: 27
2018-09-05 19:08:07.3:   Failed:         4
Log closed at Wed, Sep 05 2018 19:08:07 UTC (actual time)