David's Astronomy Pages
Notes - Session 808 (2020-09-13)

 
2020-09-13 (Session 808)
Bullet Session Aims & Highlights
 - Observing Result
 - Night Summary Plot
 - Session Event Log
 
Bullet Operational Issues
  - Critical Issues (0),  Major Issues (2),  Minor Issues (14),  Continuous Improvement (3)
 
Bullet Images from 2020-09-13 >>
2020-09-14
Bullet Investigation - Dome appears non-responsive or stuck (S808)
 

Session Aims & Highlights (2020-09-13)

Main aims

  1. Dome.ShutterStatusFromDome. Test modified routine that should access Shutter Status, Azimuth, slewing state  directly from the Pulsar ASCOM trace file, which contains Volatile records sent from the Dome Drive Unit that provides information about the status of the dome that is independant of DeviceHub.Dome where a bug occasionally appears whereby dome information stops updating,  causing uncertainty to open/closing of shutter and preventing slaved movements of dome according to the telescope position
  2. Targets. Acquire images of a number of targets if conditions allow.

Equipment & Software

Highlights

Lowlights

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   
  
Pre-Session Weather Forecast (API data from darksky.net)
Pre-Session Weather forecast showed dry conditons for the night with minimum temperature of 15°C,  with clear conditions for middle of night, but with cloud developing from 02:00 onwards reaching 97-100% cloud cover.  Wind was forecast to be moderate (16-18 mph). It was expected that conditions might  be suitable for an observing session, but the quality of images would be limited by seeing and potential effects on the telescope due to wind

In the event conditions were slightly less windy that expected and conditions were clear from dusk until 00:45 when cloud began to develop.  
Cloud Cover reached 100% at 02:00, but there was no rain.  Minimum outside temperature was 15.5°C during the observing period ending ~. 01:30
but dropped to 14°C in the latter part of the night
Image   
  
Session Event Log
Time     Event Detail
20:43:47 Session Created Live Session Created (2020-09-13 S00808, ImageSaveNum: 808001)
20:43:50   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
20:45:41   Services Started Observatory Services started
20:45:49 Observatory (Auto) Observatory placed in Fully-Automated Mode
20:45:51 Session Monitoring AutoStart monitoring for Live Session opportunity starting between 20:28 & 04:40
20:45:53   AutoStart Waiting AutoStart waiting till earliest start time at 20:28
20:45:55   AutoStart Delayed Session delayed due to cloud
20:45:57 Session AutoStarting Session autostarting (20:43)
20:45:59 Session Pending Session pending (2020-09-13)
20:46:01 Session Initiating Session initiating (2020-09-13)
20:46:03   Plan Requested Observing Plan requested from AstroPlan (1.16)
20:46:08 Program Closed Program closed by User
20:46:11   Services Stopped Observatory Services stopped
20:46:13 Program Closed Program closed by User
20:48:28 Session Resumed Live Session Resumed (2020-09-13 S00808, ImageSaveNum: 808001)
20:48:48   Obs.Manager Started Obs.Manager started
20:48:50   Obs.Overseer Started Obs.Overseer started
20:48:54   Services Started Observatory Services started
20:48:59 Session Monitoring AutoStart monitoring for Live Session opportunity starting between 20:48 & 04:40
20:49:01 Observatory (AutoStart) Observatory placed in Auto-Start Mode
20:49:03 Session AutoStarting Session autostarting (20:49)
20:49:52   Services Started Observatory Services started
20:50:01 Observatory (Auto) Observatory placed in Fully-Automated Mode
20:50:03 Session Monitoring AutoStart monitoring for Live Session opportunity starting between 20:48 & 04:40
20:50:05 Session AutoStarting Session autostarting (20:49)
20:50:07 Session Pending Session pending (2020-09-13)
20:50:09 Session Initiating Session initiating (2020-09-13)
20:50:11   Plan Loaded Observing Plan loaded to queue (2020-09-13 V1 BEST PLAN, Plan ID: 542)
20:50:13   Camera1 Connected SBIG Camera Connected (set point -5°C)
20:50:15   Telescope Connected Telescope Connected (TheSky6)
20:50:23 Session Equilibration Session ready for dome & camera equilibration
20:51:08   Dome Opened Dome opened (opening time 45s)
20:51:11   Equilibration Started Dome Equilibration started
20:51:13   Equilibration Ended Dome Equilibration ended (0.0 mins total)
20:51:15 Session Running Session running
20:51:17   Queue Started Observing Queue started (30 targets selected)
20:52:24       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
20:57:00       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
21:00:30       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
21:00:32     Target Started (1/30) Target started (1/30, UGC 6930)
21:02:51       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
21:14:36     Target Completed Target partially completed (1/30, UGC 6930)
21:14:39     Target Started (2/30) Target started (2/30, NGC 7722)
21:18:51       Focusing Failed Foc1 Focusing Failed - star is too dim (TCF-S)
21:30:47     Target Completed Target completed (2/30, NGC 7722)
21:30:49     Target Started (3/30) Target started (3/30, GCVS AM Her)
21:32:12       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
21:35:15       Focusing Completed Foc2 AutoFocus Completed (Profile No 2, wide)
21:37:17       Focusing Completed Foc2 AutoFocus Completed (Profile No 2)
21:37:37       Focusing Checked Foc2 Focusing Check Succeeded
21:38:29       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
21:41:23       Focusing Completed Foc1 AutoFocus Completed (Profile No 3)
21:43:30     Target Completed Target partially completed (3/30, GCVS AM Her)
21:43:32     Target Started (4/30) Target started (4/30, B110)
21:45:11       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
21:48:14       Focusing Failed Foc1 Focusing Failed - failed QC check (Ambiguous)
22:12:32     Target Completed Target partially completed (4/30, B110)
22:12:34     Target Started (5/30) Target started (5/30, HIP 87937)
22:14:39       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:17:22       Focusing Completed Foc1 AutoFocus Completed (Profile No 5)
22:19:46     Target Completed Target completed (5/30, HIP 87937)
22:19:48     Target Started (6/30) Target started (6/30, B107). Using SharpCap
22:38:07     Target Completed Target partially completed (6/30, B107)
22:38:09     Target Started (7/30) Target started (7/30, GCVS SS Cyg)
22:41:06       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:43:47       Focusing Completed Foc1 AutoFocus Completed (Profile No 6)
22:47:29     Target Completed Target completed (7/30, GCVS SS Cyg)
22:48:31     Target Started (8/30) Target started (8/30, 61 Cyg)
22:50:30       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:53:12       Focusing Completed Foc1 AutoFocus Completed (Profile No 7)
22:54:31     Target Completed Target completed (8/30, 61 Cyg)
22:55:35     Target Started (9/30) Target started (9/30, UGC 11893)
22:57:42       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:00:36       Focusing Completed Foc1 AutoFocus Completed (Profile No 8)
23:16:51     Target Completed Target completed (9/30, UGC 11893)
23:17:57     Target Started (10/30) Target started (10/30, UGC 12430)
23:20:09       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:23:15       Focusing Completed Foc1 AutoFocus Completed (Profile No 9)
23:39:10     Target Completed Target completed (10/30, UGC 12430)
23:40:19     Target Started (11/30) Target started (11/30, NGC 7592)
23:43:25       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:44:13       Focusing Failed Foc1 Focusing Failed - star lost
00:00:56     Target Completed Target completed (11/30, NGC 7592)
00:02:42     Target Started (12/30) Target started (12/30, SHK 362)
00:04:37       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:07:33       Focusing Completed Foc1 AutoFocus Completed (Profile No 11)
00:23:13     Target Completed Target completed (12/30, SHK 362)
00:23:16     Target Started (13/31) Target started (13/31, C/2019 L3 (ATLAS), ToO)
00:25:35       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:28:28       Focusing Completed Foc1 AutoFocus Completed (Profile No 12)
00:35:00     Target Completed Target completed (13/31, C/2019 L3 (ATLAS), ToO)
00:35:02     Target Missed (14/31) Target's time slot was missed (14/31, GCVS FG Sge)
00:35:04     Target Started (15/31) Target started (15/31, GCVS V Sge)
00:40:01       Focusing Failed Foc1 Focusing Failed - unable to find a star (TCF-S)
00:49:57     Target Completed Target partially completed (15/31, GCVS V Sge)
00:49:59     Target Started (16/31) Target started (16/31, GCVS BL Lac)
00:53:12       Focusing Failed Foc1 Focusing Failed - star is too dim (TCF-S)
00:58:23     Target Completed Target completed (16/31, GCVS BL Lac)
00:58:25     Target Started (17/31) Target started (17/31, GCVS Z And)
01:00:37       Focusing Failed Foc1 Focusing Failed - star is lost (TCF-S)
01:04:20   SoftSuspend Called Soft Suspend is called due to Deteriorating Conditions (too few stars)
01:04:25 Critical Cloud Alert Critical Cloud Alert (Obs.Manager will close the Shutter)
01:04:27   HardSuspend Called Hard Suspend is called due to Critical Conditions (cloud)
01:04:30     Target Aborted (17/31) Target aborted (17/31, GCVS Z And) due to cloud
01:04:32   Queue Paused Queue paused for SoftSuspend
01:04:34 Session Suspended Session suspended
01:04:36   Queue Paused Queue pausing for HardSuspend
01:16:06 Session Resuming Session resuming
01:17:36   Dome Opening Dome opening hasn't finished after 90s
01:17:47 Session Suspended Session suspended
01:19:51 Session Resuming Session resuming
01:21:22   Dome Opening Dome opening hasn't finished after 90s
01:21:32 Session Suspended Session suspended
01:23:37 Session Resuming Session resuming
01:25:07   Dome Opening Dome opening hasn't finished after 90s
01:25:18 Session Suspended Session suspended
01:48:09 Session Resuming Session resuming
01:49:39   Dome Opening Dome opening hasn't finished after 90s
01:49:50 Session Suspended Session suspended
01:52:29 Session Resuming Session resuming
01:54:00   Dome Opening Dome opening hasn't finished after 90s
01:54:10 Session Suspended Session suspended
02:04:11   Camera1 SetPoint SBIG Camera Set Point Temperature Updated (new set point -10°C)
05:34:33 Session Resumed Live Session Resumed (2020-09-13 S00808, ImageSaveNum: 808145)
05:34:58   Obs.Manager Started Obs.Manager started
05:35:00   Obs.Overseer Started Obs.Overseer started
05:35:04   Services Started Observatory Services started
05:36:04 User Intervention User request to close and finish session
05:36:06 Session Closing Session closing
05:36:08   Dome Closed Dome already closed (closure time is unknown)
05:36:10   Dome Parked Dome already parked (parking time is unknown)
05:36:38   Telescope Switched Off Telescope Power has been switched off via UPB Powerbox.
05:37:24   Services Stopped Night Services stopped
05:37:26 Session Housekeeping Housekeeping Started (Cleanup FITS, Create Fits Summary, Transfer Files)
05:37:44 Session Finished Session Finished
   
Session Alerts
Time     Alert Detail
-- No Alerts                --                              

Back to Top


Operational Issues (2020-09-13, S808)

[ Prev | Next ]

Critical Issues

Major Issues

Minor Issues

Continuous Improvement

[ Prev | Next ]

Back to Top


2020-09-14


Investigation - Dome appears non-responsive or stuck (S808)

An brief investigation was carried out today (2020-09-14) as a follow-up to a sequence of Dome Problems during session S808.
The problem appear very similar to the problems that affect Session S805 which were investigated on 2020-09-07 (see Investigation - Dome appears non-responsive or stuck (S805) )

Issue:
Problem Closing Dome (01:04). Dome appears non-responsive or stuck in 'Shutter Closing' state.

Description
Sky conditions deteriorated at 01:04 (Clarity dropped to 23.9) and hard suspend was called.   During Suspend operations   'Closing Dome' was reported.    However there was no corresponding message line or event to report that dome closure had been completed.   AstroGuard observed that Dome was closing at 01:04 but noted that shutter had taken > 68s to close.  

Obs.Overseer reported that Job Queue appears to be frozen (01:15) and took action by calling to MakeObservatorySafe() routine that attempted to Close Dome, Park Dome and Turn Off Scope Tracking.   Close Dome aborted or overtaken by an Open Command.   Slew Dome to 90 Az / Park was aborted after 3 minutes as dome didnt appear to move from Az 155.9 deg (Dome did in fact respond to request to move to Az 90, but change was reflected back in DeviceManager).  Due to a conflicting logic Obs.Manager was trying request to resume the session around this time, and to Open the Shutter.  This attempt appeared to fail with message "Dome opening hasn't finished after 90s".  AstroGuard observed that Dome was opening at 01:16 but noted that shutter had taken > 68s to open.  

 There were further calls to MakeObservatorySafe at 01:26,  01:38, 01:49, 02:01, 02:12, 02:24, 02:35 , 02:47, 02:58, 03:10, 03:21, 03:33, 03:34, 03:56, 04:07, 04:19
, 04:30, 04:42 , 04:54, 05:05, 05:17.  ObsPics trough this time show the Dome information apparently 'stuck' on Slewing=True, ShutterState="Closing", Az : 155.9

There were further attempts to open shutter at 01:19, 01:23,  01:48 &  01:52 when Clarity reached 25-26 and AllSkyStars reached 25-26.   There were further attempts to close shutter at 01:21, 01:25 , 01:49 & 01:54

Observatory Status was checked at 05:15 and the finding the dome to be slewing and closing when it should have been parked and closed, and the Close Down observatory seemingly stalled, the Observatory state was checked by flashlight to check precise situation.  Dome was found to be physically closed and parked (Az 90) WNW (Az. 280 degs). ObsPics showed the scope was pointing at to S-SSW sky at 81 deg inclination with Tracking Off. 

Telescope was parked via Device Hub at 05:30.  Dome was parked via AstroGuard at 05:34.  

  Dome Service restarted in AstroMain at 05:33.

Analysis
Looking back at the set of saved ObsPics shows the Dome going  to Az. 155 a 22:38 for Target xx (SS Cyg) and slaved tracking to Az 156 at 22:40 but not moving when scope went on to Target 9/32 (61 Cyg) at 22:49.   Although Dome remained stationary  UGC 11893 (Az 157 deg), NGC 7592 (Az 160 deg), SHK_362 (Az 156 deg))  had azimith positions that were fortunately close enough to the dome's shutter azimuth that they could be successfully imaged without impact, but other targets such C/2019 L3 (Atlas)  were affected by the stationary dome

Examining the Dome's ASCOM Trace Log shows the regular sequence of requests every 5s ( 'Connected Get' ,  'ShutterStatus' etc) stops being logged  after the request at 22:40:19 which corresponds with the time that ObsPic show the Dome not responding.   Volatile message line continue every 1s suggesting that Pulsar Dome Driver is still getting information from the Dome Drive Unit. 

The Trace Log shows a Close Shutter request at 01:04:31  and the shutter moves to state 3 (closing) at 01:04:32, and to state 1 (closed) at 01:05:15 (i.e. a normal closing time of 44s).  Other client requests to Open / Close Shutter are actioned ok.

A SlewToAzimuth request was made at 01:16:06 (from Az 155.9), which is completed at 01:16:35 (Az 90.0 degs).

Beside relying entirely on the DeviceHub, it is possible to monitor / read the Pulsar Dome Ascom log to identify / resolve discrepencies between what the Dome is saying and what Device Hub is saying.

Conclusion
As per conclusion fof S805 session it seems that DeviceHub is passing client requests to Open/Shut the Dome through to the Dome Driver, but has stopped getting updates from Pulsar Dome Driver.  It would appear that the relevant thread in DeviceHub for doing this has 'frozen' or otherwise stopped working or can't return new results. The DeviceHub thread that monitors the Telescope position and automatically moves the Slaved Dome when Scope moves also appears to have stopped working.

The fact that both AstroMain and AstroGuard clients aren't getting correct information about the status of the Dome from 22:40 onwards would indicate a problem in the DeviceHub (the Server) rather than a problem coincidentally happening in both Clients at the same time. 
(Its impossible to rule out a problem in Pulsar Dome Driver, but there are no indications of this from examing the ASCOM trace log and doesn't seem to happen when running POTH.Hub).


Work Required
Problem needs to be spotted by the Obs.Manager and an appropriate Alert generated for first new occurance of the problem. The dome should probably be disconnected by both AstroMain and AstroGuard before reconnecting the dome and reappraising the situation. If this doesn't resolve the problem the Telescope might also need to be disconnected (by AstroMain, AstroGuard & PHD2) and Device Hub closed / restarted.

Problem should be reported to DeviceHub's author (Rick).

Close Session Routine needs to prevent itself getting stuck in an endless cycle waiting for Dome to Close and have a timeout facility to allow Dome Shutdown to conclude, with appropriate error reporting & alerts on Dome Closure & Dome Parking.

Back to Top