Log opened at Sun, Dec 09 2012 02:51:10 UTC (actual time)
Current log level is Debug
Scheduler version 3.5.3
Multi-user license: Arne Henden
09-Dec-2012 02:51:10.3: Simulated clock initialized at 09-Dec-2012 02:51:10 UTC
09-Dec-2012 02:51:10.3: Loaded Constraint plugin AirMass
09-Dec-2012 02:51:10.3: Loaded Constraint plugin AirmassRange
09-Dec-2012 02:51:10.3: Loaded Constraint plugin Horizon
09-Dec-2012 02:51:10.3: Loaded Constraint plugin HourAngle
09-Dec-2012 02:51:10.3: Loaded Constraint plugin MoonAvoid
09-Dec-2012 02:51:10.3: Loaded Constraint plugin MoonDown
09-Dec-2012 02:51:10.3: Loaded Constraint plugin SkyCondition
09-Dec-2012 02:51:10.3: Loaded Constraint plugin TimeRange
09-Dec-2012 02:51:10.9: 3 plans are now pending.
09-Dec-2012 02:51:10.9: Attach ACP sequencer
09-Dec-2012 02:51:18.6: Dispatcher started at 09-Dec-2012 02:51:18 UTC
09-Dec-2012 02:51:18.6:     Priority:          W[0]=1.00
09-Dec-2012 02:51:18.6:     Transit Altitude:  W[1]=0.00
09-Dec-2012 02:51:18.6:     Highest Altitude:  W[6]=0.00
09-Dec-2012 02:51:18.6:     Lateness:          W[5]=0.70
09-Dec-2012 02:51:18.6:     Slew Distance:     W[2]=0.30
09-Dec-2012 02:51:18.6:     Retry Count:       W[3]=0.20
09-Dec-2012 02:51:18.6:     Meridian Crossing: W[4]=0.30
09-Dec-2012 02:51:18.6:     Obs Conditions:    W[7]=0.40
09-Dec-2012 02:51:18.6:     Rising Plan Delay: disabled
09-Dec-2012 02:51:19.3: ++ Observatory Startup ++
09-Dec-2012 02:51:19.3: Start ACP Sequencer's StartupObs script
09-Dec-2012 02:51:29.3: Sequencer is now active
09-Dec-2012 02:51:34.9: Sequencer is no longer active
09-Dec-2012 02:51:35.0: SelectRunning: No running plans
09-Dec-2012 02:51:35.0: Obs V1108_Her in Plan V1108_Her was vetoed by AirMass constraint.
09-Dec-2012 02:51:35.0:     AirMass estimates ready after 09-Dec-2012 15:52:11 UTC
09-Dec-2012 02:51:35.0: Efficiency: Selecting from 2 pending plans:
09-Dec-2012 02:51:35.0:   Selected Plan HS_2214+2845 (TotEff=1.63)
09-Dec-2012 02:51:35.1: Dispatcher cycle time: 0.1560003 sec.
09-Dec-2012 02:51:35.1: Acquire data for Observation HS_2214+2845...
09-Dec-2012 02:51:35.1:   (belongs to Project x2, Plan HS_2214+2845)
09-Dec-2012 02:51:35.1: Send Observation HS_2214+2845 to ACP Sequencer
09-Dec-2012 02:51:45.1: Sequencer is now active
09-Dec-2012 03:07:40.9: Sequencer is no longer active
09-Dec-2012 03:07:40.9: ** Sequencer script "AcquireScheduler" failed:
09-Dec-2012 03:07:40.9: **Script Error (Tracking has been stopped)**
Source:  ACP Plate Solver
Message: **Too many failures to plate solve. The scope appears to be lost. Aborted. at line 1526 column 13.
Script Context:
    1523:         If Not SUP.ExternalGuider Then                          ' Update pointing if internal guider
    1524:             Console.PrintLine "  (internal guider - attempt pointing update before guider restart)"
    1525:             isPointing = True                                       ' For ACP web UI (typ)
=>  1526:             SUP.UpdatePointing OBS.Name, OBS.RA, OBS.Dec, OBS.PA
                      ^
    1527:             isPointing = False
    1528:         End If
    1529:     End If
-- end --

09-Dec-2012 03:07:44.0: Post-job status check done (stat=Running)
09-Dec-2012 03:07:44.0: ACP ERROR: Run failed due to script error (see ACP run log)
09-Dec-2012 03:07:44.0: ACP data acquisition failed for Observation HS_2214+2845.
09-Dec-2012 03:07:44.0:   (Observation HS_2214+2845 interrupted by acquisition process failure.)
09-Dec-2012 03:07:44.1: SelectRunning: No running plans
09-Dec-2012 03:07:44.1: Efficiency: Only one pending plan V405_Peg, it is the "best"
09-Dec-2012 03:07:44.2: Dispatcher cycle time: 0.0312 sec.
09-Dec-2012 03:07:44.2: Acquire data for Observation V405_Peg...
09-Dec-2012 03:07:44.2:   (belongs to Project yy, Plan V405_Peg)
09-Dec-2012 03:07:44.2: Send Observation V405_Peg to ACP Sequencer
09-Dec-2012 03:07:54.2: Sequencer is now active
09-Dec-2012 03:09:19.2: Dispatcher stopped at 09-Dec-2012 03:09:19 UTC
09-Dec-2012 03:09:19.2: **DISPATCHER INTERRUPT LEVEL 1 RECEIVED**
09-Dec-2012 03:09:33.0: Sequencer is no longer active
09-Dec-2012 03:09:33.3: ** Sequencer script "AcquireScheduler" failed:
09-Dec-2012 03:09:33.3: **Script Error**
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 --

09-Dec-2012 03:09:36.4: Post-job status check done (stat=Running)
09-Dec-2012 03:09:36.4: RUN FAILED: Scheduler was stopped during run
09-Dec-2012 03:09:36.4: ACP data acquisition failed for Observation V405_Peg.
09-Dec-2012 03:09:36.4:   (Observation V405_Peg interrupted by operator or system.)
09-Dec-2012 03:13:38.4: Dispatcher started at 09-Dec-2012 03:13:38 UTC
09-Dec-2012 03:13:38.4:     Priority:          W[0]=1.00
09-Dec-2012 03:13:38.4:     Transit Altitude:  W[1]=0.00
09-Dec-2012 03:13:38.4:     Highest Altitude:  W[6]=0.00
09-Dec-2012 03:13:38.4:     Lateness:          W[5]=0.70
09-Dec-2012 03:13:38.4:     Slew Distance:     W[2]=0.30
09-Dec-2012 03:13:38.4:     Retry Count:       W[3]=0.20
09-Dec-2012 03:13:38.4:     Meridian Crossing: W[4]=0.30
09-Dec-2012 03:13:38.4:     Obs Conditions:    W[7]=0.40
09-Dec-2012 03:13:38.4:     Rising Plan Delay: disabled
09-Dec-2012 03:13:39.7: ++ Observatory Startup ++
09-Dec-2012 03:13:39.7: Start ACP Sequencer's StartupObs script
09-Dec-2012 03:13:49.7: Sequencer is now active
09-Dec-2012 03:13:54.9: Sequencer is no longer active
09-Dec-2012 03:13:55.0: SelectRunning: No running plans
09-Dec-2012 03:13:55.0: Obs CW_Mon in Plan CW_Mon was vetoed by AirMass constraint.
09-Dec-2012 03:13:55.0:     AirMass estimates ready after 09-Dec-2012 04:54:36 UTC
09-Dec-2012 03:13:55.0: Obs SDSS_J075507 in Plan SDSS_J075507 was vetoed by AirMass constraint.
09-Dec-2012 03:13:55.0:     AirMass estimates ready after 09-Dec-2012 05:33:55 UTC
09-Dec-2012 03:13:55.0: Efficiency: Selecting from 5 pending plans:
09-Dec-2012 03:13:55.1:   Selected Plan HS_2214+2845 (TotEff=2.02)
09-Dec-2012 03:13:55.1: Dispatcher cycle time: 0.1872003 sec.
09-Dec-2012 03:13:55.1: Acquire data for Observation HS_2214+2845...
09-Dec-2012 03:13:55.1:   (belongs to Project x2, Plan HS_2214+2845)
09-Dec-2012 03:13:55.1: Send Observation HS_2214+2845 to ACP Sequencer
09-Dec-2012 03:14:05.1: Sequencer is now active
09-Dec-2012 03:15:51.2: Sequencer is no longer active
09-Dec-2012 03:15:51.2: Post-job status check done (stat=Failed)
09-Dec-2012 03:15:51.2: ACP data acquisition failed for Observation HS_2214+2845.
09-Dec-2012 03:15:51.2:   (Observation HS_2214+2845 interrupted by acquisition process failure.)
09-Dec-2012 03:15:51.3: SelectRunning: No running plans
09-Dec-2012 03:15:51.3: Efficiency: Selecting from 4 pending plans:
09-Dec-2012 03:15:51.3:   Selected Plan V405_Peg (TotEff=1.96)
09-Dec-2012 03:15:51.4: Dispatcher cycle time: 0.0780002 sec.
09-Dec-2012 03:15:51.4: Acquire data for Observation V405_Peg...
09-Dec-2012 03:15:51.4:   (belongs to Project yy, Plan V405_Peg)
09-Dec-2012 03:15:51.4: Send Observation V405_Peg to ACP Sequencer
09-Dec-2012 03:16:01.4: Sequencer is now active
09-Dec-2012 03:29:52.0: Sequencer is no longer active
09-Dec-2012 03:29:52.0: Post-job status check done (stat=Failed)
09-Dec-2012 03:29:52.0: ACP data acquisition failed for Observation V405_Peg.
09-Dec-2012 03:29:52.0:   (Observation V405_Peg interrupted by acquisition process failure.)
09-Dec-2012 03:29:52.2: SelectRunning: No running plans
09-Dec-2012 03:29:52.2: Efficiency: Selecting from 3 pending plans:
09-Dec-2012 03:29:52.2:   Selected Plan HS_0218+3229 (TotEff=1.32)
09-Dec-2012 03:29:52.2: Dispatcher cycle time: 0.0624001 sec.
09-Dec-2012 03:29:52.2: Acquire data for Observation HS_0218+3229...
09-Dec-2012 03:29:52.2:   (belongs to Project xx, Plan HS_0218+3229)
09-Dec-2012 03:29:52.2: Send Observation HS_0218+3229 to ACP Sequencer
09-Dec-2012 03:30:02.2: Sequencer is now active
09-Dec-2012 03:48:19.0: Sequencer is no longer active
09-Dec-2012 03:48:19.0: Post-job status check done (stat=Completed)
09-Dec-2012 03:48:19.0: Acquisition time: 1106.7283439 sec.
09-Dec-2012 03:48:19.0: Data for Observation HS_0218+3229 acquired successfully.
09-Dec-2012 03:48:19.0: Image Efficiency: 32.5%
09-Dec-2012 03:48:19.0: Cycle Efficiency: 100.0%
09-Dec-2012 03:48:19.1: **EXCEPTION IN SCHEDULER:
09-Dec-2012 03:48:19.1: DOME FAILURE: Dome reports shutter error status
09-Dec-2012 03:48:19.1: Traceback:
   at DC3.Scheduler.ACPSequencer.get_DomeOpen()
   at DC3.Scheduler.Engine.DoStartupIf(Boolean openDome)
   at DC3.Scheduler.Engine.Run()
09-Dec-2012 03:48:19.1: Run statistics:
09-Dec-2012 03:48:19.1:   Observations:   8
09-Dec-2012 03:48:19.1:   Considered:     5
09-Dec-2012 03:48:19.1:   Completed:      1
09-Dec-2012 03:48:19.1:   Skipped:        2
09-Dec-2012 03:48:19.1:   Never Eligible: 3
09-Dec-2012 03:48:19.1:   Failed:         2
09-Dec-2012 03:48:19.1: Shutter-Open efficiency: 11.45%
09-Dec-2012 03:48:19.1: Overall Efficiency: 99.90%
09-Dec-2012 03:48:19.1: Release ACP sequencer
Log closed at Sun, Dec 09 2012 03:48:20 UTC (actual time)