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

Notes (S824)

Notes Main

Home Page

Notes (S826)

	Session Aims & Highlights
	- Observing Result  - Night Summary Plot  - Session Event Log
	Operational Issues
	- Critical Issues (0),  Major Issues (1),  Minor Issues (3),  Continuous Improvement (9)
	Images from 2020-10-30 >>
	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

• 12" LX200 and ST-10XME
• 80mm APO and ZWO ASI 178MC
• CCDApp2, TheSky6, CCDSoft5, PHD2,  DeviceHub 4.5.0.1, UPB 1.5 
• Pegasus UPB & Motor Focus, TCF-S
• SharpCap 3.2, PHD2  2.6.9
   
• AstroMain 3.31.6,  AstroGuard 1.4.6,   AstroPlan 1.16.9  AstroShCap 1.3.1, AstroVOE 1.4.4, AstroProtect 1.4.1
  (AstroWeather 1.10.13, AstroAllSky 3.6)

Highlights

•   Dome Parking.  Data was collected about a issue that has affected the last two session  whereby false alerts are being generated by the observatory control program (AstroMain) during observatory shutdown saying that Dome Parking had failed when the dome had in fact successfuly moved to its park position, allowing a fix to be made to Dome.SlewToAzimuth (90) routine.   Fix to be tested over the course of next few sessions to make sure that it resolved the issue.

Lowlights

•   Cloud. Conditons deteriorated very shortly after starting the session and session suspended itself until dawn due to cloud.
  Cloud prevented testing routines and settings associated with Cam1 guiding (guiding using LX200/ST10 (main scope, north down images) whilst imaging with TS80/178MC (secondary scope)

Summary Plots & Logs

Observing Plan

Observing Result

Dome & Scope Slewing Performance

Slew/Centering Performance

Guiding Performance

Sky Conditions (Locate Frames)

Night Sky Summary Plot Top axis: Sky Brightness at Zenith (in ADU/s) Lefthand axis: Local Time (hh LT). Righthand axis: Sun Altitude (degs)

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.

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)

• Critical Issues (0)
• Major Issues (1)
• Minor Issues (3)
• Continuous Improvement (9)

[ Prev | Next ]

Critical Issues

•  None

Major Issues

• 'Obs.Manager/AstroMain hung whilst retrieving targets from the Night's Observing Plan.    Resolved in session by Parking Scope using DeviceHub, killing AstroMain, and stopping/killing observatory software and restarted everything again. There was no problem importing the Plan on second attempt, and  successfully executed.  Same issue occurred in session S689  (2019-09-03) and in session S856 Attempt (2021-01-30).  An investigation was carrried out (see Investigation - Obs.Manager hanging whilst loading plan). A solution to prevent the issue from locking up the program was implemented on 2021-02-10 (AstroMain 3.36).   This mitigates the main problem caused by the issue but does not fix the underlying cause that leads to target retrieval to stall. .
  Solution implemented 2021-02-10 (AstroMain 3.36)

Minor Issues

•  'Latest Data' & Time (hh:mm) are shown twice in legend area of new Cam2Temperature Chart. The two versions partially overpost each other.
  Fixed 2020-10-30 (AstroMain 3.31.7)
   
• Create Fits Summary & Analyse Reduced Folder are not working.   Problem affected Reduction of images from S824 & S825.   Problem was due to a bug in new routine 'FitFileExists()'  (didn't allow for '. dot returned by Path.GetExtension() ) and bug in ReduceFolder (result of FitFileExists(Path)  tested against False instead of True)
  Fixed 2020-10-31 (AstroMain 3.31.7)
   
• Guide Reference and Guide Frame Pictures not being created/uploaded.   Problem affected Guide Picture from S824 & S825.   Problem was due to a bug in new routine 'FitFileExists()'  (didn't allow for '. dot returned by Path.GetExtension() )
  Fixed 2020-10-31 (AstroMain 3.31.7)

Continuous Improvement

• Create a web page to host the latest session log file.  The latest session log file is at present displayed from a link direct to the log file.  Safari (on IPAD display the files with wrapped text which is highly inconvenient way of displaying/reading the log data. Embedding the log file in a web page allows better control on page width..
  Done 2020-10-30 (Website).
   
• Pass GRB Position Error radius to AstroMain for plotting on Fast-React images captured in response to a GRB Alert.   This involves adding a new column to 'targets' table in the Target Database, editing AstroVOE to save the position error radius in the database when creating a GRB target , editing AstroPlan to display/edit the Position Error Radius  (value 0 used for n/a ), and editing AstroMain to retrieve Position Error Radius when importing a Plan Target or ToO.  (Note :Display of circle representing the position error is subject of a separate improvement item)
  Done 2020-11-01 (AstroVOE 1.5,  AstroPlan 1.17, AstroMain 3.32).
   
• Rationalise Job Queue holding loops when going into Suspension. Whilst the conditions and responses to bHardSuspend and bSoftSuspend are somewhat diffferent there should be opportunity to rationalise the hold loops within the Job Executor. Work done to rationalise holding loops.
  Considered closed Nov 2020 (AstroMain).
   
• Display Position Error Circle on Fast-React pictures taken in response to a GRB alert.  Improvement depends on prior improvement work to save Position Error Radius from GRB alerts and import them as part of the ToO import into AstroMain.  Plotting of circle will be performed by ImageMagicK by extending the existing ConvertFitsToJPG routine.  Iinitial implementation had a bug which coause the error circle to be drawn with an incorrect radius.  This was fixed in a subsequent version (AstroMain 3.32.14, 2020-12-04).
  Done 2020-12-04 (AstroMain 3.32.14)
   
• Add ShCap Logging of AstroMain communications to/from ShCap Server. New log file (shcap).log added to AstroMain, based on similar logging communications to/from for PHD2 server
  Done 2020-11-03 (AstroMain 3.32.1)
   
• Make a number of corrections and improvement to SetCameraProperties in the ShCap Server.
  Done 2020-11-03 (AstroShCap 1.3.3)
   
• Remove code/controls relating to use of POTH hub. DeviceHub is bedding in as the ASCOM replacement for POTH Hub and has been used for the last 6 months or so. There is opportunity to streamline code and UI by removing references to POTH Hub.   This will of course mean that POTH can not be used as a backup should DeviceHUb stop functioning for any reason.  Several programs would need to be changed, but not necessarily at same time. It is suggested that change is not made until the 'stalled dome' issue has been resolved.   FInally done in Feb 2021 after successfully using DeviceHub for several months and proving stability and benefits over POTH.Hub.
  Done 2021-02-07  (AstroMain 3.36, AstroGuard 1.5, AstroProtect 1.5).
   
• Make improvements to messages written to Log File.  Improvements include better consistency / naming of existing messages, clearer information, addition of new messages corresponding with key messages written to Report File for better tracing. .
  Largely Done (AstroMain).
   
• Improve the messages reported when AutoStart is unable to start at the beginning of the AutoStart Window.  When Clarity is ok, but there are simply  insufficient number of stars the message should be "Unable to begin AutoStart at 17:15 due to too few stars'  rather than '... due to cloud'.  Implemented in AstroMain 3.39.13, AstroPlan 1.22.1
  Done  2021-05-14  (AstroMain 3.39.13, AstroPlan 1.22.1)

[ 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