David's Astronomy Pages
 Notes - Session 825 (2020-10-30)

 Previous Notes
Notes
(S824)		   Notes
Notes
Main		   Home
Home
Page		   Next Notes
Notes
(S826)		  
 
Bullet Session Aims & Highlights
 - Observing Result
 - Night Summary Plot
 - Session Event Log
 
Bullet Operational Issues
  - Critical Issues (0),  Major Issues (1),  Minor Issues (3),  Continuous Improvement (9)
Bullet Images from 2020-10-30 >>
Bullet Investigation - Obs.Manager hanging whilst loading plan
 

Session Aims & Highlights (2020-10-30)

Main aims -

  1. Cam1 Guiding. Test routines and settings for guiding using LX200/ST10 (main scope, north down images) whilst imaging with TS80/178MC (secondary scope)
  2. Targets.  Acquire images of a selection of deep sky targets
  3. Bug fixes.  Check that bugs discovered in last session in AstroMain 3.31.2 have been fixed, and that recent new features are working ok

Equipment & Software

Highlights

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 a clear spell in middle of evening (cloud cover 0-23%) but clouding at 22:00 to 02:00 (cloud cover 54-78%) ,
becoming totally overcast from 02:00 onwards.  Minimum temperature 6 degC.
Wind becoming strong onwards dawn with potential rain (heavy rain forecast from 08:00 onwards)

In the event there was a clear spell from 18:00 to 20:10 but transparency and seeing were fairly poor, and sky
was bright due to moonlight and cloud reflection. Cloud thickened at 21:45 and session suspended.  
User intervention made to finish session at 23:30 due to  cloud and rain risk.
Image
Image   
  
Session Event Log
Time     Event Detail
17:49:26 Session Monitoring AutoStart monitoring for Live Session opportunity starting between 17:49 & 05:21
17:49:28 Session AutoStarting Session autostarting (17:49)
17:49:59 Session Created Live Session Created (2020-10-30 S00825, ImageSaveNum: 825001)
17:50:01   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
17:51:40   Services Started Observatory Services started
17:51:48 Observatory (Auto) Observatory placed in Fully-Automated Mode
17:51:50 Session Pending Session pending (2020-10-30)
17:51:52 Session Initiating Session initiating (2020-10-30)
17:51:54   Plan Requested Observing Plan requested from AstroPlan (1.16.9)
18:19:59 Session Resumed Live Session Resumed (2020-10-30 S00825, ImageSaveNum: 825001)
18:20:27   Obs.Manager Started Obs.Manager started
18:20:29   Obs.Overseer Started Obs.Overseer started
18:20:33   Services Started Observatory Services started
18:20:41   Camera1 Connected SBIG Camera Connected (set point -20°C)
18:20:57   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
18:22:38   Services Started Observatory Services started
18:23:00   Telescope Connected Telescope Connected (TheSky6)
18:23:58   Dome Opened Dome opened (opening time 47s)
18:25:28 Observatory (Auto) Observatory placed in Fully-Automated Mode
18:25:33 Session Pending Session pending (2020-10-30)
18:25:35 Session Initiating Session initiating (2020-10-30)
18:25:37   Plan Loaded Observing Plan loaded to queue (2020-10-30 V1 BEST PLAN, Plan ID: 560)
18:25:38   Camera1 Connected SBIG Camera Connected (set point -20°C)
18:25:46   Telescope Connected Telescope Connected (TheSky6)
18:25:58 Session Equilibration Session ready for dome & camera equilibration
18:26:00 Session Running Session running
18:26:02   Queue Started Observing Queue started (51 targets selected)
18:27:08       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
18:32:03       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
18:34:41       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
18:34:43       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
18:35:00     Target Missed (1/51) Target's time slot was missed (1/51, GCVS R CrB)
18:35:02     Target Missed (2/51) Target's time slot was missed (2/51, C/2019 K7 (Smith))
18:35:04     Target Started (3/51) Target started (3/51, GCVS U Her)
18:37:50       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
18:40:29       Focusing Completed Foc1 AutoFocus Completed (Profile No 2)
18:48:10     Target Completed Target completed (3/51, GCVS U Her)
18:48:12     Target Started (4/51) Target started (4/51, HIP 87937)
18:50:22       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
18:53:13       Focusing Completed Foc1 AutoFocus Completed (Profile No 3)
18:55:42     Target Completed Target completed (4/51, HIP 87937)
18:55:44     Target Started (5/51) Target started (5/51, GCVS BL Lac)
18:58:13       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:01:04       Focusing Completed Foc1 AutoFocus Completed (Profile No 4)
19:04:39     Target Completed Target completed (5/51, GCVS BL Lac)
19:04:41     Target Started (6/51) Target started (6/51, GCVS Z And)
19:07:07       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:09:57       Focusing Completed Foc1 AutoFocus Completed (Profile No 5)
19:13:43     Target Completed Target completed (6/51, GCVS Z And)
19:13:45     Target Started (7/51) Target started (7/51, GCVS CI Cyg)
19:16:42       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:19:32       Focusing Completed Foc1 AutoFocus Completed (Profile No 6)
19:23:14     Target Completed Target completed (7/51, GCVS CI Cyg)
19:23:16     Target Started (8/51) Target started (8/51, M31_AT2020vak)
19:24:34     Target Aborted (8/51) Target aborted (8/51, M31_AT2020vak) due to Priority 1 ToO Target
19:24:37     Target Started (9/53) Target started (9/53, 184P/Lovas, ToO)
19:27:37       Focusing Failed Foc1 Focusing Failed - star is lost (TCF-S)
19:37:54     Target Completed Target completed (9/53, 184P/Lovas, ToO)
19:37:57     Target Started (10/53) Target started (10/53, C/2019 K7 (Smith), ToO)
19:38:54   SoftSuspend Called Soft Suspend is called due to Deteriorating Conditions (too few stars)
19:38:59   SoftSuspend Cancelled Soft Suspend is cancelled due to Improved Conditions
19:40:12       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:42:59       Focusing Completed Foc1 AutoFocus Completed (Profile No 7)
19:51:33     Target Completed Target completed (10/53, C/2019 K7 (Smith), ToO)
19:51:35     Target Started (11/54) Target started (11/54, NGC 514, ToO)
19:54:28       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:57:29       Focusing Completed Foc1 AutoFocus Completed (Profile No 8)
20:08:41     Target Completed Target completed (11/54, NGC 514, ToO)
20:08:43     Target Missed (12/54) Target's time slot was missed (12/54, GSC 1224:29)
20:08:45     Target Started (13/54) Target started (13/54, NGC 772)
20:09:47   SoftSuspend Called Soft Suspend is called due to Deteriorating Conditions (too few stars)
20:12:03     Target Failed Target failed due to cloud (13/54, NGC 772)
20:12:05   Queue Paused Queue paused for SoftSuspend
20:12:08 Session Suspended Session suspended
20:12:53   Dome Closed Dome closed (closing time 45s)
20:31:51     Target Cancelled Target cancelled (14/54, NGC 772) due to cloud
20:50:21     Target Cancelled Target cancelled (15/54, C/2018 N2 (ASASSN)) due to cloud
20:59:31     Target Cancelled Target cancelled (16/54, GCVS RX And) due to cloud
21:03:17 Session Resuming Session resuming
21:04:02   Dome Opened Dome opened (opening time 45s)
21:04:04 Session Running Session running
21:04:06   Queue Resumed Observing Queue resumed
21:04:56       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
21:07:34       Focusing Failed Foc1 Focusing Failed - failed QC check (Ambiguous)
21:07:37       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
21:07:50     Target Started (17/54) Target started (17/54, GCVS U And)
21:14:28   SoftSuspend Called Soft Suspend is called due to Deteriorating Conditions (too few stars)
21:16:13   SoftSuspend Cancelled Soft Suspend is cancelled due to Improved Conditions
21:18:37     Target Completed Target partially completed (17/54, GCVS U And)
21:18:40     Target Started (18/54) Target started (18/54, GSC 1224:29)
21:28:51     Target Completed Target completed (18/54, GSC 1224:29)
21:28:53     Target Started (19/54) Target started (19/54, NGC 772)
21:32:35       Focusing Failed Foc1 Focusing Failed - unable to find a star (TCF-S)
21:32:45   SoftSuspend Called Soft Suspend is called due to Deteriorating Conditions (too few stars)
21:50:04     Target Completed Target completed (19/54, NGC 772)
21:50:06   Queue Paused Queue paused for SoftSuspend
21:50:09 Session Suspended Session suspended
21:50:52   Dome Closed Dome closed (closing time 45s)
21:59:40     Target Cancelled Target cancelled (20/54, GCVS S Cyg) due to cloud
22:16:37     Target Cancelled Target cancelled (21/54, GCVS SS Cyg) due to cloud
22:25:02     Target Cancelled Target cancelled (22/54, GCVS HH And) due to cloud
22:37:03     Target Cancelled Target cancelled (23/54, C/2019 L3 (ATLAS)) due to cloud
22:47:06     Target Cancelled Target cancelled (24/54, GCVS CY Lyr) due to cloud
22:58:02     Target Cancelled Target cancelled (25/54, GCVS AM Her) due to cloud
23:05:49     Target Cancelled Target cancelled (26/54, 61 Cyg) due to cloud
23:14:01     Target Cancelled Target cancelled (27/54, WDS GRB 34) due to cloud
23:29:28     Target Cancelled Target cancelled (28/54, NGC 514) due to cloud
23:31:41 User Intervention User request to close and finish session
23:31:43   Queue Aborted Job Queue aborted
23:31:46 Session Closing Session closing
23:31:51   Dome Closed Dome already closed (closed at 21:50, closing time 45s)
23:32:29   Dome Parked Dome parked (parking time 30s), Az: 90.0 deg
23:33:14   Telescope Parked Telescope parked (parking time 40s)
23:33:44   Telescope Switched Off Telescope Power has been switched off via UPB Powerbox.
23:34:32   Services Stopped Night Services stopped
23:34:34 Session Housekeeping Housekeeping Started (Cleanup FITS, Create Fits Summary, Transfer Files)
23:34:36 Session Finished Session Finished
 
Session Alerts
Time     Alert Detail
-- No Alerts                --                              

Back to Top

Operational Issues (2020-10-30 S825)

[ Prev | Next ]

Critical Issues

Major Issues

Minor Issues

Continuous Improvement

[ Prev | Next ]

Back to Top

Investigation - Obs.Manager hanging whilst loading plan

Issue:
Obs.Manager/AstroMain hung whilst retrieving targets for the night's observing plan

Description: 
During Session Initiation the Obs.Manger requests from AstroPlan Schedule Builder (if one is required) and fetches the new observing plan from AstroPlan/Database.  On this occasion the process of Retrieving Targets from the Plan into AstroMain's job queue stalled for some reason and caused Obs.Manager/AstroMain itself to hang.  

The same issue also occurred in session S689  (2019-09-03) and in session S856 Attempt (2021-01-30).

In-Session Fix:
To regain control the scope was parked using DeviceHub, before killing AstroMain, and stopping/killing observatory software and then restarted everything again. There was no problem importing the plan on the second attempt. 

Investigation:
Examining log file shows  Loading Latest Plan: 2020-10-30 V1 BEST PLAN'  at 17:52:44.  Obs.Monitor is Pending (4s) at 17:52:49.  Obs.Manager is Frozen at 17:52:59  (given after 10s since last Obs.Manager cycle).   Later on when Observatory placed in Manual Mode, there was an exception (database is locked) whilst attempting to Insert Session Event. Last message in Report File was  "Retrieving Targets..." from RetrievePlan() routine.  Since a final "Ok"  or "Fail" message wasn't written to Report File and there no exception message from the routine, it seems probable that stall happened somewhere in the RetrievePlan() routine.  

Conclusion:
There is not enough information to indicate exactly what had caused the problem on this occasion and it is therefore not possible to fix the underlying issue, if there is a specific one. It is possible that the underlying issue might be in AstroPlan rather than in AstroMain since AstroPlan was noted to be sluggish after AstroMain's Obs Manager froze and had to be killed.  Whatever the cause the code for calling Import Plan should be modified in such a way that Obs.Manager doesn't become frozen and can continue to manage safe operation of the observatory (shutter closed on this and most occasions when importing plan, but it isn't necessarily so.   AstroGuard and Dome.Relay would have still provided backup protection as they independant of any freeze in AstroMain. Code shows that LoadNightPlan() / LoadLatestPlan(), call LoadPlanFromDB() directly and the load plan from database  is performed on the Obs.Manager Main Loop thread. Extra lines have been added to trap & report exceptions in case that is helpful in the future.  It isn't possible to quickly bundle the call to a thread without further analysis and review.

Action Required :
A fix is required to stop the program from hanging whatever might have caused the underlying problem (database access ?).  Place LoadLatestPlan() into a thread so that any failure/hang can't cause Obs.Manager to stall. Details of Major Issue given above.  Code analysis needs to be conducted to understand how this can be done safely, how to track any failure in the thread and what action to take.  Need to check for similarities with program freeze when retrieving plan from database in session S689  (2019-09-03)

Update (2021-01-30):
Issue occured again in session attempt on 2021-01-30.  Examining log file on this new occasion didn't show up any tracing messages that were added after similar issue in S825.   Logs show that ObsMonitor and ObsManager both frooze at the point that Importing Observing Plan was initiated. Last message was that 'Latest Plan: 2021-01-30 V1 ACTIVE PLAN S856'.  Report File showed that plan had been selected.  Last report line was the message "Retrieving Targets..." The expected continuation  'Ok       51 Targets.'   was not written, showing that execution froze within the ObservingDB.RetrievePlan() routine. That the correct plan was selected ok just beforehand shows that database was active & seeminingly not universally locked.  Extra trace lines have been added to AstroMain 3.36 (2021-02-10) to help to constrain the position where execution freezes if the issue occurs again

Update (2021-02-10) :
A partial solution has been implemented 2021-02-10 (AstroMain 3.36),  involving an overhaul of the PlanStatus tracking process and the making Plan Loading a threaded operation, so that the Obs.Manager can continue running in the event of an issue with Plan Loading.

Back to Top

This Web Page: Notes - Session 825 (2020-10-30)
Last Updated : 2024-09-30
Site Owner : David Richards
Home Page : David's Astronomy Web Site