Log opened at Thu, Nov 08 2012 04:27:58 UTC (actual time) Current log level is Debug Scheduler version 3.5.3 Multi-user license: Arne Henden 08-Nov-2012 04:27:58.5: Simulated clock initialized at 08-Nov-2012 04:27:58 UTC 08-Nov-2012 04:27:58.6: Loaded Constraint plugin AirMass 08-Nov-2012 04:27:58.6: Loaded Constraint plugin AirmassRange 08-Nov-2012 04:27:58.6: Loaded Constraint plugin Horizon 08-Nov-2012 04:27:58.6: Loaded Constraint plugin HourAngle 08-Nov-2012 04:27:58.6: Loaded Constraint plugin MoonAvoid 08-Nov-2012 04:27:58.6: Loaded Constraint plugin MoonDown 08-Nov-2012 04:27:58.6: Loaded Constraint plugin SkyCondition 08-Nov-2012 04:27:58.6: Loaded Constraint plugin TimeRange 08-Nov-2012 04:27:59.1: 0 plans are now pending. 08-Nov-2012 04:27:59.1: Attach ACP sequencer 08-Nov-2012 04:28:07.3: Dispatcher started at 08-Nov-2012 04:28:07 UTC 08-Nov-2012 04:28:07.3: Priority: W[0]=1.00 08-Nov-2012 04:28:07.3: Transit Altitude: W[1]=0.70 08-Nov-2012 04:28:07.3: Highest Altitude: W[6]=0.00 08-Nov-2012 04:28:07.3: Lateness: W[5]=0.00 08-Nov-2012 04:28:07.3: Slew Distance: W[2]=0.30 08-Nov-2012 04:28:07.3: Retry Count: W[3]=0.20 08-Nov-2012 04:28:07.3: Meridian Crossing: W[4]=0.30 08-Nov-2012 04:28:07.3: Obs Conditions: W[7]=0.40 08-Nov-2012 04:28:07.3: Rising Plan Delay: disabled 08-Nov-2012 04:28:07.8: ++ Observatory Startup ++ 08-Nov-2012 04:28:07.8: Start ACP Sequencer's StartupObs script 08-Nov-2012 04:28:17.8: Sequencer is now active 08-Nov-2012 04:28:23.0: Sequencer is no longer active 08-Nov-2012 04:28:23.0: SelectRunning: No running plans 08-Nov-2012 04:28:23.0: No pending plans that can be started now. 08-Nov-2012 04:28:23.0: Dispatcher cycle time: 0.0156 sec. 08-Nov-2012 04:28:53.6: SelectRunning: No running plans 08-Nov-2012 04:28:53.6: No pending plans that can be started now. 08-Nov-2012 04:28:53.6: Dispatcher cycle time: 0 sec. 08-Nov-2012 04:29:24.2: SelectRunning: No running plans 08-Nov-2012 04:29:24.2: Obs CW_Mon in Plan CW_Mon was vetoed by AirMass constraint. 08-Nov-2012 04:29:24.2: AirMass estimates ready after 08-Nov-2012 06:56:29 UTC 08-Nov-2012 04:29:24.2: Obs SDSS_J075507 in Plan SDSS_J075507 was vetoed by AirMass constraint. 08-Nov-2012 04:29:24.2: AirMass estimates ready after 08-Nov-2012 07:35:48 UTC 08-Nov-2012 04:29:24.3: Obs V1108_Her in Plan V1108_Her was vetoed by AirMass constraint. 08-Nov-2012 04:29:24.3: AirMass estimates ready after 08-Nov-2012 17:54:04 UTC 08-Nov-2012 04:29:24.3: Efficiency: Selecting from 3 pending plans: 08-Nov-2012 04:29:24.3: Selected Plan V405_Peg (TotEff=1.90) 08-Nov-2012 04:29:24.3: Dispatcher cycle time: 0.2496004 sec. 08-Nov-2012 04:29:24.3: Acquire data for Observation V405_Peg... 08-Nov-2012 04:29:24.3: (belongs to Project yy, Plan V405_Peg) 08-Nov-2012 04:29:24.3: Send Observation V405_Peg to ACP Sequencer 08-Nov-2012 04:29:34.4: Sequencer is now active 08-Nov-2012 04:31:08.5: Dispatcher stopped at 08-Nov-2012 04:31:08 UTC 08-Nov-2012 04:31:08.5: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED** 08-Nov-2012 04:31:17.0: Sequencer is no longer active 08-Nov-2012 04:31:17.0: ** Sequencer script "AcquireScheduler" failed: 08-Nov-2012 04:31:17.0: **Script Error (Tracking has been stopped)** Source: ACP Message: The script was aborted. at line 1531 column 5. Script Context: 1528: End If 1529: End If 1530: => 1531: If Not SUP.AutoGuide(True) Then ^ 1532: If Not IMG Is Nothing Then 1533: If IMG.ExposureInterval > Prefs.AutoGuiding.MaxUnguidedExposureInterval Then 1534: If STRICT_AUTOGUIDING And Not PLN.BestEfforts Then -- end -- 08-Nov-2012 04:31:20.1: Post-job status check done (stat=Running) 08-Nov-2012 04:31:20.1: RUN FAILED: Scheduler was stopped during run 08-Nov-2012 04:31:20.1: ACP data acquisition failed for Observation V405_Peg. 08-Nov-2012 04:31:20.1: (Observation V405_Peg interrupted by operator or system.) 08-Nov-2012 04:42:36.0: Dispatcher started at 08-Nov-2012 04:42:36 UTC 08-Nov-2012 04:42:36.0: Priority: W[0]=1.00 08-Nov-2012 04:42:36.0: Transit Altitude: W[1]=0.70 08-Nov-2012 04:42:36.0: Highest Altitude: W[6]=0.00 08-Nov-2012 04:42:36.0: Lateness: W[5]=0.00 08-Nov-2012 04:42:36.0: Slew Distance: W[2]=0.30 08-Nov-2012 04:42:36.0: Retry Count: W[3]=0.20 08-Nov-2012 04:42:36.0: Meridian Crossing: W[4]=0.30 08-Nov-2012 04:42:36.0: Obs Conditions: W[7]=0.40 08-Nov-2012 04:42:36.0: Rising Plan Delay: disabled 08-Nov-2012 04:42:36.5: ++ Observatory Startup ++ 08-Nov-2012 04:42:36.5: Start ACP Sequencer's StartupObs script 08-Nov-2012 04:42:46.6: Sequencer is now active 08-Nov-2012 04:42:51.9: Sequencer is no longer active 08-Nov-2012 04:42:51.9: SelectRunning: No running plans 08-Nov-2012 04:42:52.0: Efficiency: Selecting from 3 pending plans: 08-Nov-2012 04:42:52.0: Selected Plan V405_Peg (TotEff=1.88) 08-Nov-2012 04:42:52.0: Dispatcher cycle time: 0.0936001 sec. 08-Nov-2012 04:42:52.0: Acquire data for Observation V405_Peg... 08-Nov-2012 04:42:52.0: (belongs to Project yy, Plan V405_Peg) 08-Nov-2012 04:42:52.0: Send Observation V405_Peg to ACP Sequencer 08-Nov-2012 04:43:02.1: Sequencer is now active 08-Nov-2012 04:46:31.5: Dispatcher stopped at 08-Nov-2012 04:46:31 UTC 08-Nov-2012 04:46:31.5: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED** 08-Nov-2012 04:46:38.0: Sequencer is no longer active 08-Nov-2012 04:46:41.1: Post-job status check done (stat=Running) 08-Nov-2012 04:46:41.1: RUN FAILED: Scheduler was stopped during run 08-Nov-2012 04:46:41.1: ACP data acquisition failed for Observation V405_Peg. 08-Nov-2012 04:46:41.1: (Observation V405_Peg interrupted by operator or system.) 08-Nov-2012 04:47:14.4: Dispatcher started at 08-Nov-2012 04:47:14 UTC 08-Nov-2012 04:47:14.4: Priority: W[0]=1.00 08-Nov-2012 04:47:14.4: Transit Altitude: W[1]=0.70 08-Nov-2012 04:47:14.4: Highest Altitude: W[6]=0.00 08-Nov-2012 04:47:14.4: Lateness: W[5]=0.00 08-Nov-2012 04:47:14.4: Slew Distance: W[2]=0.30 08-Nov-2012 04:47:14.4: Retry Count: W[3]=0.20 08-Nov-2012 04:47:14.4: Meridian Crossing: W[4]=0.30 08-Nov-2012 04:47:14.4: Obs Conditions: W[7]=0.40 08-Nov-2012 04:47:14.4: Rising Plan Delay: disabled 08-Nov-2012 04:47:14.9: ++ Observatory Startup ++ 08-Nov-2012 04:47:14.9: Start ACP Sequencer's StartupObs script 08-Nov-2012 04:47:24.9: Sequencer is now active 08-Nov-2012 04:47:30.1: Sequencer is no longer active 08-Nov-2012 04:47:30.2: SelectRunning: No running plans 08-Nov-2012 04:47:30.2: Efficiency: Selecting from 3 pending plans: 08-Nov-2012 04:47:30.2: Selected Plan V405_Peg (TotEff=1.87) 08-Nov-2012 04:47:30.2: Dispatcher cycle time: 0.0780001 sec. 08-Nov-2012 04:47:30.2: Acquire data for Observation V405_Peg... 08-Nov-2012 04:47:30.2: (belongs to Project yy, Plan V405_Peg) 08-Nov-2012 04:47:30.2: Send Observation V405_Peg to ACP Sequencer 08-Nov-2012 04:47:40.2: Sequencer is now active 08-Nov-2012 04:48:45.9: Sequencer is no longer active 08-Nov-2012 04:48:45.9: Post-job status check done (stat=Failed) 08-Nov-2012 04:48:45.9: ACP data acquisition failed for Observation V405_Peg. 08-Nov-2012 04:48:45.9: (Observation V405_Peg interrupted by acquisition process failure.) 08-Nov-2012 04:48:46.0: SelectRunning: No running plans 08-Nov-2012 04:48:46.0: Efficiency: Selecting from 2 pending plans: 08-Nov-2012 04:48:46.1: Selected Plan HS_2214+2845 (TotEff=1.75) 08-Nov-2012 04:48:46.1: Dispatcher cycle time: 0.0624001 sec. 08-Nov-2012 04:48:46.1: Acquire data for Observation HS_2214+2845... 08-Nov-2012 04:48:46.1: (belongs to Project x2, Plan HS_2214+2845) 08-Nov-2012 04:48:46.1: Send Observation HS_2214+2845 to ACP Sequencer 08-Nov-2012 04:48:56.1: Sequencer is now active 08-Nov-2012 04:50:29.2: Dispatcher stopped at 08-Nov-2012 04:50:29 UTC 08-Nov-2012 04:50:29.2: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED** 08-Nov-2012 04:50:36.0: Sequencer is no longer active 08-Nov-2012 04:50:36.0: ** Sequencer script "AcquireScheduler" failed: 08-Nov-2012 04:50:36.0: **Script Error (Tracking has been stopped)** Source: ACP Message: The script was aborted. at line 1531 column 5. Script Context: 1528: End If 1529: End If 1530: => 1531: If Not SUP.AutoGuide(True) Then ^ 1532: If Not IMG Is Nothing Then 1533: If IMG.ExposureInterval > Prefs.AutoGuiding.MaxUnguidedExposureInterval Then 1534: If STRICT_AUTOGUIDING And Not PLN.BestEfforts Then -- end -- 08-Nov-2012 04:50:39.1: Post-job status check done (stat=Running) 08-Nov-2012 04:50:39.1: RUN FAILED: Scheduler was stopped during run 08-Nov-2012 04:50:39.1: ACP data acquisition failed for Observation HS_2214+2845. 08-Nov-2012 04:50:39.1: (Observation HS_2214+2845 interrupted by operator or system.) 08-Nov-2012 04:55:07.4: Dispatcher started at 08-Nov-2012 04:55:07 UTC 08-Nov-2012 04:55:07.4: Priority: W[0]=1.00 08-Nov-2012 04:55:07.4: Transit Altitude: W[1]=0.70 08-Nov-2012 04:55:07.4: Highest Altitude: W[6]=0.00 08-Nov-2012 04:55:07.4: Lateness: W[5]=0.00 08-Nov-2012 04:55:07.4: Slew Distance: W[2]=0.30 08-Nov-2012 04:55:07.4: Retry Count: W[3]=0.20 08-Nov-2012 04:55:07.4: Meridian Crossing: W[4]=0.30 08-Nov-2012 04:55:07.4: Obs Conditions: W[7]=0.40 08-Nov-2012 04:55:07.4: Rising Plan Delay: disabled 08-Nov-2012 04:55:07.5: ++ Observatory Startup ++ 08-Nov-2012 04:55:07.5: Start ACP Sequencer's StartupObs script 08-Nov-2012 04:55:17.5: Sequencer is now active 08-Nov-2012 04:55:23.1: Sequencer is no longer active 08-Nov-2012 04:55:23.1: SelectRunning: No running plans 08-Nov-2012 04:55:23.1: Efficiency: Selecting from 3 pending plans: 08-Nov-2012 04:55:23.1: Selected Plan V405_Peg (TotEff=1.86) 08-Nov-2012 04:55:23.2: Dispatcher cycle time: 0.1092002 sec. 08-Nov-2012 04:55:23.2: Acquire data for Observation V405_Peg... 08-Nov-2012 04:55:23.2: (belongs to Project yy, Plan V405_Peg) 08-Nov-2012 04:55:23.2: Send Observation V405_Peg to ACP Sequencer 08-Nov-2012 04:55:33.2: Sequencer is now active 08-Nov-2012 05:04:43.2: Sequencer is no longer active 08-Nov-2012 05:04:43.2: Post-job status check done (stat=Completed) 08-Nov-2012 05:04:43.2: Acquisition time: 560.0721837 sec. 08-Nov-2012 05:04:43.2: Data for Observation V405_Peg acquired successfully. 08-Nov-2012 05:04:43.3: Image Efficiency: 64.3% 08-Nov-2012 05:04:43.3: Cycle Efficiency: 100.0% 08-Nov-2012 05:04:43.4: SelectRunning: No running plans 08-Nov-2012 05:04:43.4: Efficiency: Selecting from 2 pending plans: 08-Nov-2012 05:04:43.4: Selected Plan HS_2214+2845 (TotEff=1.72) 08-Nov-2012 05:04:43.4: Dispatcher cycle time: 0.0624001 sec. 08-Nov-2012 05:04:43.4: Acquire data for Observation HS_2214+2845... 08-Nov-2012 05:04:43.4: (belongs to Project x2, Plan HS_2214+2845) 08-Nov-2012 05:04:43.4: Send Observation HS_2214+2845 to ACP Sequencer 08-Nov-2012 05:04:53.4: Sequencer is now active 08-Nov-2012 05:06:59.5: Sequencer is no longer active 08-Nov-2012 05:06:59.5: Post-job status check done (stat=Failed) 08-Nov-2012 05:06:59.5: ACP data acquisition failed for Observation HS_2214+2845. 08-Nov-2012 05:06:59.5: (Observation HS_2214+2845 interrupted by acquisition process failure.) 08-Nov-2012 05:06:59.6: SelectRunning: No running plans 08-Nov-2012 05:06:59.6: Efficiency: Only one pending plan HS_0218+3229, it is the "best" 08-Nov-2012 05:06:59.6: Dispatcher cycle time: 0.0312001 sec. 08-Nov-2012 05:06:59.6: Acquire data for Observation HS_0218+3229... 08-Nov-2012 05:06:59.6: (belongs to Project xx, Plan HS_0218+3229) 08-Nov-2012 05:06:59.6: Send Observation HS_0218+3229 to ACP Sequencer 08-Nov-2012 05:07:09.6: Sequencer is now active 08-Nov-2012 05:17:06.0: Sequencer is no longer active 08-Nov-2012 05:17:06.0: Post-job status check done (stat=Completed) 08-Nov-2012 05:17:06.0: Acquisition time: 606.3886651 sec. 08-Nov-2012 05:17:06.0: Data for Observation HS_0218+3229 acquired successfully. 08-Nov-2012 05:17:06.0: Image Efficiency: 59.4% 08-Nov-2012 05:17:06.0: Cycle Efficiency: 100.0% 08-Nov-2012 05:17:06.2: SelectRunning: No running plans 08-Nov-2012 05:17:06.2: Efficiency: Only one pending plan HS_2214+2845, it is the "best" 08-Nov-2012 05:17:06.2: Dispatcher cycle time: 0.0624001 sec. 08-Nov-2012 05:17:06.2: Acquire data for Observation HS_2214+2845... 08-Nov-2012 05:17:06.2: (belongs to Project x2, Plan HS_2214+2845) 08-Nov-2012 05:17:06.2: Send Observation HS_2214+2845 to ACP Sequencer 08-Nov-2012 05:17:16.2: Sequencer is now active 08-Nov-2012 05:28:36.0: Sequencer is no longer active 08-Nov-2012 05:28:36.0: Post-job status check done (stat=Completed) 08-Nov-2012 05:28:36.0: Acquisition time: 689.7552115 sec. 08-Nov-2012 05:28:36.0: Data for Observation HS_2214+2845 acquired successfully. 08-Nov-2012 05:28:36.0: Image Efficiency: 52.2% 08-Nov-2012 05:28:36.0: Cycle Efficiency: 100.0% 08-Nov-2012 05:28:36.1: **EXCEPTION IN SCHEDULER: 08-Nov-2012 05:28:36.1: DOME FAILURE: Dome reports shutter error status 08-Nov-2012 05:28:36.1: Traceback: at DC3.Scheduler.ACPSequencer.get_DomeOpen() at DC3.Scheduler.Engine.DoStartupIf(Boolean openDome) at DC3.Scheduler.Engine.Run() 08-Nov-2012 05:28:36.1: Run statistics: 08-Nov-2012 05:28:36.1: Observations: 6 08-Nov-2012 05:28:36.1: Considered: 3 08-Nov-2012 05:28:36.1: Completed: 3 08-Nov-2012 05:28:36.1: Skipped: 0 08-Nov-2012 05:28:36.1: Never Eligible: 3 08-Nov-2012 05:28:36.1: Failed: 0 08-Nov-2012 05:28:36.1: Shutter-Open efficiency: 41.74% 08-Nov-2012 05:28:36.1: Overall Efficiency: 97.61% 08-Nov-2012 05:28:36.1: Release ACP sequencer Log closed at Thu, Nov 08 2012 05:28:37 UTC (actual time)