David's Astronomy Pages
Notes - Session 1009 (2022-05-11)

 
Bullet Session Aims & Highlights
 - Observing Result
 - Night Summary Plot
 - Session Event Log
Bullet Operational Issues
  - Critical Issues (0),  Major Issues (1),  Minor Issues (2),  Small Defects (2),  Continuous Improvement (6)
 
Bullet Images from 2022-05-11 >>         [ Local Files >> ]    
2022-04-12
Bullet Investigation -  Dome didn't appear to move during telescope slew (01:56)

Session Aims & Highlights (2022-05-11)

Main aims

  1. Targets.  Acquire images of a selection of variable stars, nearby stars, comets & deep sky targets as allowed by time & conditions.
  2. Telescope re-sync. Update telescope pointing by resyncing scope on a new start field and running a short mapping job.
    (This followed a pointing accuracy issue for Near Zenith Focussing during previous S1008 session)

Equipment & Software

Highlights

Notes:

  Summary Plots & Logs

Observing Plan
Image
  
Observing Result
Image
   
  
Dome & Scope Slewing Performance
Image
  
Slew/Centering Performance
Image
  
Guiding Performance
Image
Image
 
  
Sky Conditions (Locate Frames)
Image
 
Night Sky Summary Plot
Top axis: Sky Brightness at Zenith (in ADU/s)
Lefthand axis: Local Time (hh LT). Righthand axis: Sun Altitude (degs)

Image   
  
Actual Weather vs Pre-Session Weather Forecast
Image
Image   
  
Session Event Log
Time     Event Detail
22:44:22 Program Hung AstroMain UI appears to have stopped responding at 22:44
22:44:36   Camera1 Connected SBIG Camera Connected (set point -15°C)
22:44:38 Session Created Live Session Created (2022-05-11 S01009, ImageSaveNum: 1009001)
22:44:40 Program Resumed AstroMain UI resumed again at 22:44 after 20s
22:50:29   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
22:51:53   Services Started Observatory Services started
22:57:56   Telescope Connected Telescope Connected (TheSky6)
22:58:17   Camera1 Connected SBIG Camera Connected (set point -15°C)
23:01:14   Dome Opened Dome opened (opening time 46s)
23:06:01 Telescope Running 'ResetScopePointing' under user supervision
23:07:20 Telescope Running 'ResetScopePointing' under user supervision
23:09:19   Automapping Started Automapping started (12 points planned)
23:20:54   Automapping Completed Automapping completed (7 points mapped out of 12 points)
23:21:54   Automapping Started Automapping started (12 points planned)
23:24:51   Automapping Aborted Automapping aborted (3 points mapped out of 12 points)
23:26:23   Telescope Parked Telescope parked (parking time 67s)
23:26:37   Telescope State Scope parked Turn scope off. (Handbox)
23:27:18   Telescope Switched Off Telescope Power has been switched off via UPB Switch.
23:28:20 Session Monitoring AutoStart monitoring for Live Session opportunity between 23:27 & 02:24
23:28:22 Observatory (AutoStart) Observatory placed in Auto-Start Mode
23:28:24 Session AutoStarting Session autostarting (23:28)
23:28:42   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
23:30:25   Services Started Observatory Services started
23:30:32 Observatory (Auto) Observatory placed in Fully-Automated Mode
23:30:37 Session Pending Session pending (2022-05-11)
23:30:39 Session Initiating Session initiating (2022-05-11)
23:30:41   Plan Requested Observing Plan requested from AstroPlan (1.30.5)
23:31:13   Plan Loaded Observing Plan loaded to queue (Plan ID: 768)
23:31:28   Camera1 Connected SBIG Camera Connected (set point -15°C)
23:31:33   Telescope Connected Telescope Connected (TheSky6)
23:31:57 Session Equilibration Session ready for dome & camera equilibration
23:32:37 Program Resumed AstroMain UI resumed again at 23:32 after 6s
23:32:43 Session Running Session running
23:32:45   Queue Started Observing Queue started (13 targets selected)
23:32:48     Target Started (NrZen) Target started (Focus Field 14, HIP 69068)
23:34:29       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:37:41       Focusing Completed Foc1 AutoFocus Completed (Profile No 1, wide)
23:39:38       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
23:39:40       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
23:41:50       Focusing Completed Foc2 AutoFocus Completed (Profile No 2, wide)
23:43:36       Focusing Completed Foc2 AutoFocus Completed (Profile No 2)
23:43:54     Target Completed Target completed (Focus Field 14, HIP 69068)
23:44:45     Target Started (1/13) Target started (1/13, GCVS BL Lac)
23:48:49       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:51:07       Focusing Completed Foc1 AutoFocus Completed (Profile No 3)
23:55:28     Target Completed Target completed (1/13, GCVS BL Lac)
23:55:32     Target Started (2/13) Target started (2/13, NGC 4545 w/SN2022fuc)
23:59:20       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:01:17       Focusing Completed Foc1 AutoFocus Completed (Profile No 4)
00:17:43     Target Completed Target completed (2/13, NGC 4545 w/SN2022fuc)
00:17:47     Target Started (3/13) Target started (3/13, AT2022jrp (CV))
00:21:01       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:23:14       Focusing Completed Foc1 AutoFocus Completed (Profile No 5)
00:29:23     Target Completed Target completed (3/13, AT2022jrp (CV))
00:29:27     Target Started (4/13) Target started (4/13, AT2022evu (CV))
00:32:13       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:35:00       Focusing Completed Foc1 AutoFocus Completed (Profile No 6)
00:40:57     Target Completed Target completed (4/13, AT2022evu (CV))
00:41:01     Target Started (5/13) Target started (5/13, AT2021agpw (CV))
00:44:04       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:46:29       Focusing Completed Foc1 AutoFocus Completed (Profile No 7)
00:52:27     Target Completed Target completed (5/13, AT2021agpw (CV))
00:52:51     Target Started (6/13) Target started (6/13, NGC 6061 w/AT2022fqs)
00:56:11       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:58:22       Focusing Completed Foc1 AutoFocus Completed (Profile No 8)
01:14:09     Target Completed Target completed (6/13, NGC 6061 w/AT2022fqs)
01:14:51     Target Started (7/13) Target started (7/13, UGC 3944 w/SN2022hkc)
01:18:33       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:21:01       Focusing Completed Foc1 AutoFocus Completed (Profile No 9)
01:36:46     Target Completed Target completed (7/13, UGC 3944 w/SN2022hkc)
01:36:50     Target Started (8/13) Target started (8/13, GCVS R CrB)
01:40:16       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:42:12       Focusing Completed Foc1 AutoFocus Completed (Profile No 10)
01:45:32     Target Completed Target completed (8/13, GCVS R CrB)
01:46:08     Target Started (9/13) Target started (9/13, GCVS SS Her)
01:49:08       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:51:21       Focusing Completed Foc1 AutoFocus Completed (Profile No 11)
01:55:08     Target Completed Target completed (9/13, GCVS SS Her)
01:55:40     Target Started (10/13) Target started (10/13, Mrk 506 w/AT2021agiv)
01:58:35       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
02:01:01       Focusing Completed Foc1 AutoFocus Completed (Profile No 12)
02:17:11     Target Completed Target completed (10/13, Mrk 506 w/AT2021agiv)
02:17:40     Target Started (11/13) Target started (11/13, KIC 8462852)
02:19:05   SoftSuspend Called Soft Suspend is called due to Deteriorating Conditions (too few stars)
02:22:14       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
02:26:31     Target Completed Target completed (11/13, KIC 8462852)
02:26:33   Queue Paused Queue paused for Session Suspension
02:26:36 Session Suspended Session suspended
02:27:26   Dome Closed Dome closed (closing time 50s)
02:43:42     Target Cancelled Target cancelled (12/13, GCVS SS Cyg) due to too few stars
03:12:57     Target Cancelled Target cancelled (13/13, AT2022iev) due to cloud
03:13:02   Queue Completed Job Queue completed
03:13:06 Session Closing Session closing
03:13:11   Dome Closed Dome already closed (closed at 02:27, closing time 50s)
03:13:28   Dome Parked Dome parked (parking time 9s), Az: 90.0 deg
03:14:44   Telescope Parked Telescope parked (parking time 71s)
03:14:59   Telescope State Scope parked Turn scope off. (Handbox)
03:15:21   Telescope Switched Off Telescope Power has been switched off via UPB Switch.
03:16:13   Services Stopped Night Services stopped
03:16:15 Session Housekeeping Housekeeping Started (Cleanup FITS, Create Fits Summary, Transfer Files)
03:16:27 Session Finished Session Finished
 
Session Alerts
Time     Alert Detail
01:56:14 Dome Dome didn't appear to move during the last telescope slew.
 

Back to Top


Operational Issues (2022-05-11, S1009)

[ Prev | Next ]

Critical Issues

Major Issues

Minor Issues

Small Defects

Continuous Improvement

[ Prev | Next ]

Back to Top


2022-05-12


Investigation -  Dome didn't appear to move during telescope slew (01:56)

Issue 
A "dome didn't appear to move during telescope slew" alert issued by AstroMain even though dome did move and in a manner consistent with slaved behaviour.

Description
Red Alert issued at 01:56:14 as the dome seemed to not move during telescope slew to Target 10/13 (Mrk 506 w/AT2021agiv).  

For the  telescope moving from AzAlt 171.1 / 39.7  to AzAlt 145.4 / 60.6, the slaved dome should moved from its initial position at Az 170.7, but it appears not to have moved according to slew monitoring

Report file shows Dome at Az: 170.7° after the slew with the alert '(ALERT. 25.3° difference from Scope Az)'.  There is then a follow up message 'Last Slew Alert - Dome didn't appear to move during the last telescope slew' / 'Dome Driver/Dome Slaving might be stalled' .

Analysis
Logs record that telescope was commanded to slew at 01:55:45, with first physical movement of the scope being recorded at  01:55:49. 

ObsPics show
- telescope starting to slew in picture at 01:55:47 (dome slaved but still stationary),
- dome at Az 148 in picture at 01:56:17 (dome still slewing),
- dome at Az 148 at 01:56:45 (dome stationary). 

After the Last Slew Alert message the Report file records ' Dome Position  Dome Az. 151.1° (vs. Scope Az. 145.4°, Delta Az. 5.7°).

So it seems that the Dome has operated ok. But why was the  Dome Alert generated ?  

The Pulsar ASCOM log file shows
- 01:56:04, Dome at Az 170.7°  (Slewing=False)
- 01:56:05, SlewToAzimuth (147.8°) command
- 01:56:06, Dome at Az 169.2°  (Slewing=True)
- 01:56:17, Dome at Az 147.8° (Slewing=False)
  (Note:  log slewing boolean is reported opposite to actual state , this is a known logging issue) 

This confirms that there was no any physical issue with the Dome or Dome driver, and that slew time (12s) was normal

The DeviceHub Dome log shows
- 01:56:09, Dome at Az 170° 42'  (Slewing=False),
- 01:56:12, Dome as Az 157° 48'  (Slewing=True)
- 01:56:17, Dome at Az 148° 00'  (Slewing=True)
- 01:56:19, Dome at Az 147° 48'  (Slewing=False). 

So again the physical dome slew and its communication seems completely normal.

Conclusion

The above analysis implies that there is some bug or design flaw in AstroMain's Scope/Dome Slew Monitoring loop, but we also find an apparent issue with DeviceHub-Pulsar communication ?

AstroMain's og file indicates that the slew monitoring loop  finished at 01:56:08 when the scope had reached its target, and didn't wait to see the movement of the Dome, which was only recorded to have started by DeviceHub at 01:56:12  (this is 5 secs after the monitoring loop exited,  7s after SlewToAzmiuth command from DH was received by Pulsar Dome, 27s after scope slew was originally requested (ie 27s since TimeStart) ) .   

So in this case it seems there was an unexplained delay of 20s before DH seemed to issue the SlewToAzimuth command to the Dome.   May be raise with Rick Burke (author of DeviceHub) ?   Did DH on this occasion wait until dome has reached its target before issuing command (was this actually a follow-up Slave Check action and the original command never reached the Pulsar driver for some reason. 

Regardless need to review/rework the design logic in AstroMain 's Scope.SlewTheSkyScope() routine to wait longer if the dome hasn't moved before closing the monitoring loop (at least in cases where a dome movement is fully expected but can evidenty be delayed).

Actions

Following actions identified and raised as ticket items (see Operational Issues section above for details)

Observation - Slaving Anomaly

Expectation.  
When the DH.Dome is slaved , I am supposing (expecting) that at the same time that a telescope slew request is received by DeviceHub and the the slew request is forwarded to the Telescope, a DH routine kicks-in and calculates the appropriate Dome azimuth that is best suited for the Telescope’s Target Az/Alt , and it then immediately or shortly after sends a SlewToAzimuth request to the Dome, so that both Scope and Dome head off to the target at more or less the same time (at least that’s the physical behaviour that I observe)

The above it what I suppose happens, rather than DH waiting for the Telescope to have moved by some distance or for it to reach the Target before it sends a command to slew the Dome (clearly through this, more reactionary behaviour, would occur if the scope was moved using its handbox controls since DH may not know what the target coords are in this situation)

My expectation of near-immediate dome slewing is what I normally experience, but it seemingly didn’t in one particular case encountered during my session last night.

Anomaly (Mrk 506 slew at 01:56)
Following the request to slew Telescope at 01:55:45 and its initial movement (not later than 01:55:48) , there is no 'immediate' command to slew the dome (at least the Pulsar Log shows no such commands being received). Instead the command to slew the dome appears not to be made until 01:56:05 which is 20s after the telescope was commanded to slew.

DH doesn't see any movement of the dome until 01:56:12 which is 4s after the telescope has arrived at the target.

Timeline.
The following combined timeline has been compiled from Pulsar Dome Ascom Logs, DeviceHub Dome & Scope Logs, Client Logs

01:55:43 Client looking up existing Scope/Dome positions (Scope Az= 171.1° Scope Alt=39.7°, Dome Az= 170.7°)
01:55:44 Setting Target RA/Dec (these are equivalent to Target Az 145.4°, Target Alt=60.6°)

01:55:45 Telescope commanded to slew to Target RA/Dec using TheSky6.Telescope.SlewToRaDec
                 (this is my normal method, it uses TheSky6 for it's TPoint functionality and it uses TheSky6>TeleAPI>DH.Telescope)
01:55:48 DH.Telescope starts moving (coordinates start changing, Slewing=True)

01:56:04 Pulsar Dome still at Az 170.7° (Dome.Slewing=False)
01:56:05 Pulsar Dome receives SlewToAzimuth (147.8°) command
01:56:06 Pulsar Dome moving at Az 169.2° (Dome.Slewing=True)
01:56:08 DeviceHub.Telescope arrives at Target (Scope.Slewing = False)

01:56:09 DH.Dome still stationary at Az 170° 42' (Dome Slewing=False)
01:56:12 DH Dome moving at Az 157° 48' (Slewing=True)
01:56:17 Pulsar Dome arrives at Target, Az 147.8° (Slewing=False)

01:56:17 DH Dome moving at Az 148° 00' (Slewing=True)
01:56:19 DH.Dome arrives at Target (Az 147° 48' (Dome.Slewing=False)

Analysis & Conjecture
The Pulsar log doesn't show receipt of any SlewToAzimuth command between 01:55:45 and the command that was recieved at 01:56:05.

It is possible that DH prepared an immediate Slew Dome command but didn't send it for some reason (exception ?)
or sent it but it wasn't received by the Pulsar Dome driver (but no other indication of any comms issue).

The Slew Dome command that was received was either the ‘immediate’ command but became somehow delayed on route or (more likely?) it is was a SlewToAzimuth command that was one sent by DH’s regular slaving checks and wasn't in direct response to the Slew Telescope command.

It is not throught that the observed anomaly is anything more than a one-off glitch. In particular there were no issues with either the proceeding slews or the two target slews that were made after this one particular slew.

Effect
The unexpected delay in dome movement caught-out my existing Slew Monitoring Loop and it issued a (false) alert that the ‘Dome hadn't appeared to have moved in response to Telescope Slew , is the DH slaving stalled ?’ . It hadn't stalled and the alert / issue didn't cause my observatory control program any material problem.

AstroMain client was modified today (2022-05-12) to allow for a delay of up to 30s before concluding and reporting that dome wasn't moving for some reason, so I shouldn’t get a similar false alert in future, and it will also ensure that loop sees the Dome movement and sees it finishing its slew, before I start taking images.

Note : I don’t use DH’s ‘Report Composite Slewing When Dome Is Slaved’ as it offers me better monitoring, such that I can separately spot/differentiate any scope slew , dome slew anomalies/issues.
.

Code Review/Rework:    Slew Monitoring Loop
Log files show that the monitoring loop was entered at 01:55:45.21, and exited 23s later at 01:56:08.00.

 It can be inferred that loop exit occurred upon the following condition state : 
  bScopeCompleted=True And bDomeCompleted=True
 (Other exit scenarios : JobAbort,  JobAbortTarget or loop taken > 4 mins can be discounted))

The current code shows that the bDomeCompleted flag is set to True in the following 4 situations

a) SecondsSince(StartTime) > 8 And bDomeSlewStopped And bDomeCompleted = False
b) bDomeSlewStarted = False And Dome.Slewing = False And SecondsSince(StartTime) > 10
c) bDomeCompleted = False And SecondsSince(StartTime) > 60 and DomeSlewAngle = 0.0
d) bSlaveDome = False

In the particular case of the Slew to Mrk 506 target at 01:56, the bScopeCompleted flag evidently became set to True by situation b).

Modifying the required condition for situation b) by increasing the minimum time to 30s (instead of just 10s) and including an additional condition that bScopeCompleted = True will have prevented the Mak 60 slew at 01:56 issue from occuring and prevent other foreseeable scenarios where there is a delay in commanding the dome to SlewToAzimuth.

Update 2022-04-14.  Observations on the anomalous slaving behaviour during Mk 506 slew at 01:56 emailed to Rick Burke (2022-12-13 am).  Reply indicated that DH code couldn't have given rise to a 20s delay, so issue is put down to a one-off glitch.   DH code could give rise to a delay of around 3s however and this will be fixed in the next version of DH.

Back to Top