David's Astronomy Pages
Notes - Session 979 (2022-02-28)

 
Bullet Session Aims & Highlights
 - Observing Result
 - Night Summary Plot
 - Session Event Log
Bullet Operational Issues
  - Critical Issues (0),  Major Issues (0),  Minor Issues (1),  Small Defects (0),  Continuous Improvement (1)
 
Bullet Images from 2022-02-28 >>         [ Local Files >> ]    
Bullet Investigation - Monitoring Graphs using incorrect MasterGraphStartTime

Session Aims & Highlights (2022-02-28)

Main aims

  1. Targets.  Acquire images of a selection of variable stars, nearby stars, comets & deep sky targets as allowed by time & conditions.
  2. AstroMain.  Check bug fixes and new improvements in AstroMain 3.50.6.

Equipment & Software

Highlights

Notes:

  Summary Plots & Logs

Observing Plan
Image
  
Observing Result
Image
   
  
Dome & Scope Slewing Performance
Image
  
Slew/Centering Performance
Image
  
Guiding Performance
Reasons for poor Dec guiding :
Black/Purple points (None) -
Red points (None) -
Orange targets (16,18) -
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:04:27 Session Monitoring AutoStart monitoring for Live Session opportunity between 22:04 & 04:58
22:04:29 Session AutoStarting Session autostarting (22:04)
22:04:58 Session Created Live Session Created (2022-02-28 S00979, ImageSaveNum: 979001)
22:05:00   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
22:06:43   Services Started Observatory Services started
22:06:50 Observatory (Auto) Observatory placed in Fully-Automated Mode
22:06:55 Session Pending Session pending (2022-02-28)
22:06:57 Session Initiating Session initiating (2022-02-28)
22:06:59   Plan Requested Observing Plan requested from AstroPlan (1.29.12)
22:07:30   Plan Loaded Observing Plan loaded to queue (Plan ID: 737)
22:07:55   Camera1 Connected SBIG Camera Connected (set point -25°C)
22:08:01   Telescope Connected Telescope Connected (TheSky6)
22:08:25 Session Equilibration Session ready for dome & camera equilibration
22:09:11   Dome Opened Dome opened (opening time 45s)
22:10:01 Session Running Session running
22:10:03   Queue Started Observing Queue started (25 targets selected)
22:10:06     Target Started (NrZen) Target started (Focus Field 9, HIP 44139)
22:11:51       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:15:24       Focusing Completed Foc1 AutoFocus Completed (Profile No 1, wide)
22:17:36       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
22:17:39       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
22:19:49       Focusing Completed Foc2 AutoFocus Completed (Profile No 2, wide)
22:21:38       Focusing Completed Foc2 AutoFocus Completed (Profile No 2)
22:21:56     Target Completed Target completed (Focus Field 9, HIP 44139)
22:22:01     Target Started (1/25) Target started (1/25, GCVS GK Per)
22:25:24       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:27:54       Focusing Completed Foc1 AutoFocus Completed (Profile No 3)
22:31:27     Target Completed Target completed (1/25, GCVS GK Per)
22:31:31     Target Started (2/25) Target started (2/25, 29P/Schwassmann-Wachmann)
22:34:24       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:36:43       Focusing Completed Foc1 AutoFocus Completed (Profile No 4)
22:42:54     Target Completed Target completed (2/25, 29P/Schwassmann-Wachmann)
22:42:58     Target Started (3/26) Target started (3/26, NGC 3626, ToO)
22:46:40       Focusing Skipped Foc1 focusing skipped - star is lost (TCF-S)
23:02:32     Target Completed Target completed (3/26, NGC 3626, ToO)
23:02:36     Target Started (4/27) Target started (4/27, NGC 5005, ToO)
23:05:26       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
23:21:55     Target Completed Target completed (4/27, NGC 5005, ToO)
23:21:59     Target Started (5/28) Target started (5/28, NGC 5248, ToO)
23:25:23       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:27:35       Focusing Completed Foc1 AutoFocus Completed (Profile No 5)
23:44:02     Target Completed Target completed (5/28, NGC 5248, ToO)
23:44:04     Target Missed (6/28) Target's time slot was missed (6/28, AT2022dcp)
23:44:06     Target Missed (7/28) Target's time slot was missed (7/28, C/2019 L3 (ATLAS))
23:44:08     Target Missed (8/28) Target's time slot was missed (8/28, UGC 3457 w/SN2022blm)
23:44:10     Target Started (9/28) Target started (9/28, 67P/Churyumov-Gerasimenko)
23:47:25       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:49:38       Focusing Completed Foc1 AutoFocus Completed (Profile No 6)
00:03:06     Target Completed Target completed (9/28, 67P/Churyumov-Gerasimenko)
00:03:10     Target Started (10/29) Target started (10/29, NGC 5248, ToO)
00:06:56       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:09:08       Focusing Completed Foc1 AutoFocus Completed (Profile No 7)
00:25:21     Target Completed Target completed (10/29, NGC 5248, ToO)
00:25:23     Target Missed (11/29) Target's time slot was missed (11/29, SN 2022bnf)
00:25:26     Target Started (12/29) Target started (12/29, NGC 2922 w/SN2022bdu)
00:28:23       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
00:44:50     Target Completed Target completed (12/29, NGC 2922 w/SN2022bdu)
00:44:54     Target Started (13/29) Target started (13/29, NGC 1233 w/SN2022bqi)
00:48:40       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
01:05:19     Target Completed Target completed (13/29, NGC 1233 w/SN2022bqi)
01:05:48     Target Started (14/29) Target started (14/29, NGC 4348 w/SN2022fw)
01:09:39       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
01:25:55     Target Completed Target completed (14/29, NGC 4348 w/SN2022fw)
01:27:48     Target Started (15/29) Target started (15/29, GCVS AM CVn)
01:30:36       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:32:34       Focusing Completed Foc1 AutoFocus Completed (Profile No 8)
01:35:37     Target Completed Target completed (15/29, GCVS AM CVn)
01:37:09     Target Started (16/29) Target started (16/29, NGC 5117 w/SN2022abq)
01:40:11       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
01:56:14     Target Completed Target completed (16/29, NGC 5117 w/SN2022abq)
01:59:09     Target Started (17/29) Target started (17/29, NGC 5273 w/AT2022csj)
02:01:52       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
02:17:43     Target Completed Target completed (17/29, NGC 5273 w/AT2022csj)
02:21:09     Target Started (18/29) Target started (18/29, AT2022cml)
02:24:10       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
02:40:07     Target Completed Target completed (18/29, AT2022cml)
02:43:09     Target Started (19/29) Target started (19/29, UGCA 258 w/SN2022mm)
02:47:12       Focusing Skipped Foc1 focusing skipped - star is lost (TCF-S)
03:03:25     Target Completed Target completed (19/29, UGCA 258 w/SN2022mm)
03:05:09     Target Started (20/29) Target started (20/29, C/2017 K2 (PANSTARRS))
03:08:28       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
03:10:53       Focusing Completed Foc1 AutoFocus Completed (Profile No 9)
03:19:32     Target Completed Target completed (20/29, C/2017 K2 (PANSTARRS))
03:19:36     Target Started (21/29) Target started (21/29, GCVS BL Lac)
03:23:04       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
03:25:19       Focusing Completed Foc1 AutoFocus Completed (Profile No 10)
03:29:09     Target Completed Target completed (21/29, GCVS BL Lac)
03:29:13     Target Started (22/29) Target started (22/29, GCVS SS Cyg)
03:32:17       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
03:34:28       Focusing Completed Foc1 AutoFocus Completed (Profile No 11)
03:40:35     Target Completed Target completed (22/29, GCVS SS Cyg)
03:45:23     Target Started (23/29) Target started (23/29, Nova Cas 2021)
03:48:46       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
03:50:56       Focusing Completed Foc1 AutoFocus Completed (Profile No 12)
03:59:06     Target Completed Target completed (23/29, Nova Cas 2021)
03:59:10     Target Started (24/29) Target started (24/29, IC 635 w/AT2022bqu)
04:02:05   UPB.Switch Restart UPB.Switch has been restarted.
04:02:46       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
04:19:01     Target Completed Target completed (24/29, IC 635 w/AT2022bqu)
04:21:08     Target Started (25/29) Target started (25/29, 61 Cyg)
04:24:43       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
04:26:39       Focusing Completed Foc1 AutoFocus Completed (Profile No 13)
04:29:34     Target Completed Target completed (25/29, 61 Cyg)
04:29:45     Target Started (26/29) Target started (26/29, UGC 9886 w/AT2022dmj)
04:33:08       Focusing Skipped Foc1 focusing skipped - star is too dim (TCF-S)
04:49:42     Target Completed Target completed (26/29, UGC 9886 w/AT2022dmj)
04:51:45     Target Started (27/29) Target started (27/29, GCVS SS Her)
04:54:44       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
04:56:54       Focusing Completed Foc1 AutoFocus Completed (Profile No 14)
05:00:43     Target Completed Target completed (27/29, GCVS SS Her)
05:01:17     Target Started (28/29) Target started (28/29, NGC 5732 w/SN2021agpf)
05:04:08       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
05:06:10       Focusing Completed Foc1 AutoFocus Completed (Profile No 15)
05:21:59     Target Completed Target completed (28/29, NGC 5732 w/SN2021agpf)
05:23:17     Target Started (29/29) Target started (29/29, GCVS R CrB)
05:26:03       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
05:27:57       Focusing Completed Foc1 AutoFocus Completed (Profile No 16)
05:31:32     Target Completed Target completed (29/29, GCVS R CrB)
05:31:35   Queue Completed Job Queue completed
05:31:36 Session Closing Session closing
05:32:32   Dome Closed Dome closed (closing time 50s)
05:33:24   Dome Parked Dome parked (parking time 45s), Az: 90.0 deg
05:34:32   Telescope Parked Telescope parked (parking time 64s)
05:34:42   Telescope State Scope parked Turn scope off. (Handbox)
05:35:04   Telescope Switched Off Telescope Power has been switched off via UPB Switch.
05:35:59   Services Stopped Night Services stopped
05:36:01 Session Housekeeping Housekeeping Started (Cleanup FITS, Create Fits Summary, Transfer Files)
05:36:22 Session Finished Session Finished
 
Session Alerts
Time     Alert Detail
04:02:05 UPB.Switch disconnected UPB.Switch has unexpectedly disconnected. Restart will be attempted
04:02:07 UPB.Switch UPB.Switch has been successfully restarted.
 

Back to Top


Operational Issues (2022-02-28, S979)

[ Prev | Next ]

Critical Issues

Major Issues

Minor Issues

Small Defects

Continuous Improvement

[ Prev | Next ]

Back to Top


Investigation - Monitoring Graphs using incorrect MasterGraphStartTime

Issue
Data Monitoring graphs from session S979 didn't use the intended MasterGraph starting time, had used an earlier setting which caused most of the night's data to be missed off the width limited plots.

Description
Data Monitoring graphs from session S979 used an inappropriate MasterGraph starting time (08:30), which caused various plots to not show much of the time based data from the session (22:04 onwards). Problem hit across all plots using a time (hour) based x axis. This including Best Focus, Zenith FWHM, Sky Quality CCD Temperature, Cam2 Temperature plots. 

Analysis
Plots seem to have a starting time (where shown) from 08:30 in the morning, even though session '2022-02-28 S00979' wasn't opened until 22:04.   The log file which was opened at 22:04:49 and shows some initial anomalies. After 'the 'Initialising Session Data' message  the 3 following messages are given  'Session data has been successfully read' , 'SkyConditionsTabNo set to 3' & 'Resuming Session Charts'.  For normal session startup these messages would have been 'Session Data has been written',  'SkyConditionsTabNo set to 1'. 

Shortly after this it would be expected to see the message  'Setting MasterGraphStartTime to 22:00'    and "Setting Graph StartTime to MasterGraphStartTime (22:00).    but instead of that there were messages like  'Setting Graph StartTime to MasterGraphStartTime (08:30)' .  Earlier the general session '2022-02-28' was automatically opened at 08:30 in morning which Set MasterGraphStartTime to 08:30. The AstroMain program was been restarted at 13:39 in order to upgrade to version 3.50.6.  Log file shows 'Reopening Session Charts'  and  'SkyConditionsTabNo set to 2' messages.  

It seem that upon opening the S979 session the Initialise Session Data routine, looked for existing an 'Session.dat' file, but might have looked in the session folder associated with the previous general session (and found one which then read-in) instead of looking for it in the newly created Session folder (where there would normally be one initially).   Since this has being working in all recent sessions and there have been no changes to code in this area, it would seem that there is a timing issue, with the InitialiseSessionData() routine (called from AssignObservatorySession, line 64906) running ahead of things and testing the existance of 'SessionDataFileName' before this file path variable had been set elsewhere with new session details.

SessionDataFileName is set in SetupFileNames() routine. This can be called from 6 code areas.  Only two are relevent in this case - from OpenBaseFiles() and OpenObservatoryFiles(). The former is called when program is initially loaded ,  the latter is called from AssignObservatorySession, line 64849.  This is before the call to InitialiseSessionData() so it seems impossible that theSessionDataFileName wasn't set. 

Session folders were created ok and report indicating that Session.SessionFolder and Session.Name were fully defined before call to OpenObservatoryFiles() & SetupFileNames(). Correct setup of live session filenames depends on Session.IsSelected being True.   If it had been false then all files references would have pointed to incorrect location and mutiple files would be incorrectly located/named and this evidently hasn't happened.  Since there is no explicit or implicit  indication of any exception occuring in SetupFileNames() before the code line setting SessionDataFileName.  

The only remaing hypothesis is that SessionDataFileName was set ok,  but between this point (22:04:49.73) and the call to InitialiseSessionData (at 22:04:49.85), i.e with a 120ms window,   there was an inappropriate call to WriteSessionDataFile() which would have created a session.dat file with MasterGraphStartTime set to the previous setting (08:30).    WriteSessionDataFile() is normally called every 60s or so from the OverseerLoop, so the probability of experiencing this issue was approximately 1 in 500.

Conclusion.  
The source of the issue is considered to be very probably due to a rare (1:500) timing scenario where OverseerLoop operation interferes with Session creation.

Although it is may be a long time before this issue will be seen again, the code should be modified to put a suitable block on the execution of WriteSessionDataFile() whilst a new session is being created in order to prevent this from this occuring.

Actions

Image Modify code to block execution of WriteSessionDataFile() whilst a new session is being created.       (Completed 2022-03-01)

Back to Top