Log opened at Wed, Mar 11 2015 01:43:38 UTC (actual time)
Current log level is Verbose
Scheduler version 3.5.3
Multi-user license: Arne Henden
11-Mar-2015 01:43:38.9: Simulated clock initialized at 11-Mar-2015 01:43:38 UTC
11-Mar-2015 01:43:39.1: Loaded Constraint plugin AirMass
11-Mar-2015 01:43:39.1: Loaded Constraint plugin AirmassRange
11-Mar-2015 01:43:39.1: Loaded Constraint plugin Horizon
11-Mar-2015 01:43:39.1: Loaded Constraint plugin HourAngle
11-Mar-2015 01:43:39.1: Loaded Constraint plugin MoonAvoid
11-Mar-2015 01:43:39.1: Loaded Constraint plugin MoonDown
11-Mar-2015 01:43:39.1: Loaded Constraint plugin SkyCondition
11-Mar-2015 01:43:39.1: Loaded Constraint plugin TimeRange
11-Mar-2015 01:43:39.7: 77 plans are now pending.
11-Mar-2015 01:43:39.7: Attach ACP sequencer
11-Mar-2015 01:44:01.6: Weather successfully connected. Wait for valid data...
11-Mar-2015 01:44:41.9: Dispatcher started at 11-Mar-2015 01:44:41 UTC
11-Mar-2015 01:44:41.9:     Priority:          W[0]=1.00
11-Mar-2015 01:44:41.9:     Transit Altitude:  W[1]=0.70
11-Mar-2015 01:44:41.9:     Highest Altitude:  W[6]=0.00
11-Mar-2015 01:44:41.9:     Lateness:          W[5]=0.00
11-Mar-2015 01:44:41.9:     Slew Distance:     W[2]=0.30
11-Mar-2015 01:44:41.9:     Retry Count:       W[3]=0.20
11-Mar-2015 01:44:41.9:     Meridian Crossing: W[4]=0.30
11-Mar-2015 01:44:41.9:     Obs Conditions:    W[7]=0.40
11-Mar-2015 01:44:41.9:     Rising Plan Delay: disabled
11-Mar-2015 01:44:44.2: ++ Observatory Startup ++
11-Mar-2015 01:44:44.2: Start ACP Sequencer's StartupObs script
11-Mar-2015 01:45:09.6: Open the observatory dome/roof
11-Mar-2015 02:03:58.7: ++ Auto Focus ++
11-Mar-2015 02:03:58.7: Doing initial autofocus.
11-Mar-2015 02:03:58.7: Start special ACP AutoFocus script for scheduler
11-Mar-2015 02:08:31.9: Next periodic autofocus ASAP after 11-Mar-2015 04:07:54 UTC
11-Mar-2015 02:08:33.0: Plan KH_15D has Monitor Mode. Time to resubmit it.
11-Mar-2015 02:08:33.0: Plan V838_Mon has Monitor Mode. Time to resubmit it.
11-Mar-2015 02:08:34.3: Dispatcher cycle time: 2.3712042 sec.
11-Mar-2015 02:08:34.3: Acquire data for Observation KH_15D...
11-Mar-2015 02:08:34.3:   (belongs to Project Staels, Plan KH_15D)
11-Mar-2015 02:08:34.4: Send Observation KH_15D to ACP Sequencer
11-Mar-2015 02:22:45.6: Acquisition time: 851.2310951 sec.
11-Mar-2015 02:22:45.6: Data for Observation KH_15D acquired successfully.
11-Mar-2015 02:22:45.6: Image Efficiency: 75.0%
11-Mar-2015 02:22:45.6: Cycle Efficiency: 99.7%
11-Mar-2015 02:22:51.9: Dispatcher cycle time: 0.2652004 sec.
11-Mar-2015 02:22:51.9: Acquire data for Observation V838_Mon...
11-Mar-2015 02:22:51.9:   (belongs to Project AAVSO_Monitoring, Plan V838_Mon)
11-Mar-2015 02:22:51.9: Doing 15 sets
11-Mar-2015 02:22:51.9: Send Observation V838_Mon to ACP Sequencer
11-Mar-2015 02:37:02.9: Send Observation V838_Mon to ACP Sequencer
11-Mar-2015 02:40:56.0: ACP data acquisition failed for Observation V838_Mon.
11-Mar-2015 02:40:56.0:   (Observation V838_Mon interrupted by acquisition process failure.)
11-Mar-2015 02:40:56.5: Dispatcher cycle time: 0.2496004 sec.
11-Mar-2015 02:40:56.5: Acquire data for Observation SDSS073224...
11-Mar-2015 02:40:56.5:   (belongs to Project AGN, Plan SDSS073224)
11-Mar-2015 02:40:56.5: Send Observation SDSS073224 to ACP Sequencer
11-Mar-2015 03:38:09.4: Acquisition time: 3432.9264296 sec.
11-Mar-2015 03:38:09.4: Data for Observation SDSS073224 acquired successfully.
11-Mar-2015 03:38:09.4: Image Efficiency: 69.9%
11-Mar-2015 03:38:09.4: Cycle Efficiency: 100.0%
11-Mar-2015 03:38:20.3: Dispatcher cycle time: 0.6084011 sec.
11-Mar-2015 03:38:20.3: Acquire data for Observation NGC_2438...
11-Mar-2015 03:38:20.3:   (belongs to Project Staels, Plan NGC_2438)
11-Mar-2015 03:38:20.3: Send Observation NGC_2438 to ACP Sequencer
11-Mar-2015 03:43:52.1: Acquisition time: 331.7813827 sec.
11-Mar-2015 03:43:52.1: Data for Observation NGC_2438 acquired successfully.
11-Mar-2015 03:43:52.1: Image Efficiency: 54.2%
11-Mar-2015 03:43:52.1: Cycle Efficiency: 99.8%
11-Mar-2015 03:44:02.0: Dispatcher cycle time: 0.592801 sec.
11-Mar-2015 03:44:02.0: Acquire data for Observation MP_Gem...
11-Mar-2015 03:44:02.0:   (belongs to Project Staels, Plan MP_Gem)
11-Mar-2015 03:44:02.1: Send Observation MP_Gem to ACP Sequencer
11-Mar-2015 03:48:38.7: Acquisition time: 276.666486 sec.
11-Mar-2015 03:48:38.7: Data for Observation MP_Gem acquired successfully.
11-Mar-2015 03:48:38.7: Image Efficiency: 48.7%
11-Mar-2015 03:48:38.7: Cycle Efficiency: 99.8%
11-Mar-2015 03:48:44.8: Dispatcher cycle time: 0.2496004 sec.
11-Mar-2015 03:48:44.8: Acquire data for Observation T_CMi...
11-Mar-2015 03:48:44.8:   (belongs to Project Mogul_Mira, Plan T_CMi)
11-Mar-2015 03:48:44.8: Send Observation T_CMi to ACP Sequencer
11-Mar-2015 04:06:04.1: Acquisition time: 1039.2582254 sec.
11-Mar-2015 04:06:04.1: Data for Observation T_CMi acquired successfully.
11-Mar-2015 04:06:04.1: Image Efficiency: 48.1%
11-Mar-2015 04:06:04.1: Cycle Efficiency: 100.0%
11-Mar-2015 04:06:13.6: Dispatcher cycle time: 0.592801 sec.
11-Mar-2015 04:06:13.6: Acquire data for Observation TT_Mon...
11-Mar-2015 04:06:13.6:   (belongs to Project Mogul_Mira, Plan TT_Mon)
11-Mar-2015 04:06:13.6: Send Observation TT_Mon to ACP Sequencer
11-Mar-2015 04:27:54.2: Acquisition time: 1300.6210844 sec.
11-Mar-2015 04:27:54.2: Data for Observation TT_Mon acquired successfully.
11-Mar-2015 04:27:54.2: Image Efficiency: 57.6%
11-Mar-2015 04:27:54.2: Cycle Efficiency: 100.0%
11-Mar-2015 04:28:01.5: ++ Auto Focus ++
11-Mar-2015 04:28:01.6: Doing periodic autofocus.
11-Mar-2015 04:28:01.6: Start special ACP AutoFocus script for scheduler
11-Mar-2015 04:31:16.0: Next periodic autofocus ASAP after 11-Mar-2015 06:30:36 UTC
11-Mar-2015 04:31:18.1: Dispatcher cycle time: 0.2184004 sec.
11-Mar-2015 04:31:18.1: Acquire data for Observation NGC_2419...
11-Mar-2015 04:31:18.1:   (belongs to Project Welch_gc, Plan NGC_2419)
11-Mar-2015 04:31:18.4: Send Observation NGC_2419 to ACP Sequencer
11-Mar-2015 05:11:38.6: Acquisition time: 2420.5782515 sec.
11-Mar-2015 05:11:38.6: Data for Observation NGC_2419 acquired successfully.
11-Mar-2015 05:11:38.7: Image Efficiency: 82.6%
11-Mar-2015 05:11:38.7: Cycle Efficiency: 100.0%
11-Mar-2015 05:11:44.2: Dispatcher cycle time: 0.546001 sec.
11-Mar-2015 05:11:44.2: Acquire data for Observation S_Lyn...
11-Mar-2015 05:11:44.2:   (belongs to Project Mogul_Mira, Plan S_Lyn)
11-Mar-2015 05:11:44.2: Send Observation S_Lyn to ACP Sequencer
11-Mar-2015 05:31:51.7: Acquisition time: 1207.551321 sec.
11-Mar-2015 05:31:51.7: Data for Observation S_Lyn acquired successfully.
11-Mar-2015 05:31:51.8: Image Efficiency: 55.9%
11-Mar-2015 05:31:51.8: Cycle Efficiency: 100.0%
11-Mar-2015 05:31:57.0: Dispatcher cycle time: 0.2028003 sec.
11-Mar-2015 05:31:57.0: Acquire data for Observation RZ_Leo...
11-Mar-2015 05:31:57.0:   (belongs to Project Walker, Plan RZ_Leo)
11-Mar-2015 05:31:57.0: Send Observation RZ_Leo to ACP Sequencer
11-Mar-2015 05:33:10.8: ACP data acquisition failed for Observation RZ_Leo.
11-Mar-2015 05:33:10.8:   (Observation RZ_Leo interrupted by acquisition process failure.)
11-Mar-2015 05:33:15.0: Dispatcher cycle time: 0.1872004 sec.
11-Mar-2015 05:33:15.0: Acquire data for Observation Pal_3...
11-Mar-2015 05:33:15.0:   (belongs to Project Welch_gc, Plan Pal_3)
11-Mar-2015 05:33:15.0: Send Observation Pal_3 to ACP Sequencer
11-Mar-2015 11:21:18.8: Dispatcher stopped at 11-Mar-2015 11:21:18 UTC
11-Mar-2015 11:21:18.8: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
11-Mar-2015 11:23:18.4: ACP data acquisition failed for Observation Pal_3.
11-Mar-2015 11:23:18.4:   (Observation Pal_3 interrupted by acquisition process failure.)
11-Mar-2015 12:50:34.6: **EXCEPTION IN SCHEDULER:
11-Mar-2015 12:50:34.6: ConnectWeather() waited for over 5 seconds to read Weather.Available!
11-Mar-2015 12:50:34.6: Traceback:
   at DC3.Scheduler.ACPSequencer.ConnectWeather()
   at DC3.Scheduler.Engine.PollWeather()
   at DC3.Scheduler.Engine.Run()
11-Mar-2015 12:50:34.7: Run statistics:
11-Mar-2015 12:50:34.7:   Observations:   82
11-Mar-2015 12:50:34.7:   Considered:     30
11-Mar-2015 12:50:34.7:   Completed:      9
11-Mar-2015 12:50:34.7:   Skipped:        16
11-Mar-2015 12:50:34.7:   Never Eligible: 52
11-Mar-2015 12:50:34.7:   Failed:         5
11-Mar-2015 12:50:34.7: Shutter-Open efficiency: 23.65%
11-Mar-2015 12:50:34.7: Overall Efficiency: 99.90%
11-Mar-2015 12:50:34.7: Release ACP sequencer
11-Mar-2015 12:50:34.7: Failed to stop sequencer:
11-Mar-2015 12:50:34.7: The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)
Log closed at Wed, Mar 11 2015 12:50:36 UTC (actual time)