David's Astronomy Pages
Notes - Session 942 (2021-12-16)

 
Bullet Session Aims & Highlights
 - Observing Result
 - Night Summary Plot
 - Session Event Log
 
Bullet Operational Issues
  - Critical Issues (0),  Major Issues (2),  Minor Issues (6),  Small Defects (2),  Continuous Improvement (3)
 
Bullet Images from 2021-12-16 >>         [ Local Files >> ]
Bullet MeadeGeneric 1.3.3.373
   
2021-12-17
Bullet Investigation - PHD2 application failed during guiding (unhandled and unknown exception)

Session Aims & Highlights (2021-12-16)

Main aims

  1. Centering / JogUsingPulseGuide. Test out new JogUsingPulseGuide method for performing fine target centering (ie for jogs < 2 arc min)
  2. JPG Pictures: Test fix for JPG Picture which were being generated in S940 and S941).
  3. Observatory Computer.  Continue ironing out issues with new Observatory Computer (installed 2021-12-10)
  4. Targets.  Acquire images of a selection of variable stars, nearby stars, comets & deep sky targets as allowed by time & conditions.

Equipment & Software

Highlights

Notes:

  Summary Plots & Logs

Observing Plan
Image
  
Observing Result
Image
   
  
Dome & Scope Slewing Performance
Image
  
Slew/Centering Performance
Good centering performance - using new JogUsingPulseGuide for movements < 2'
Image
  
Guiding Performance
Reasons for poor Dec guiding :
Black point (10,13)  
Mauve points (?)   -
Red point (11,14)   -
Orange point (?, 15)   - .
Yellow points ()   -
Green points  ()   -

Image
Image
  
Sky Conditions (Locate Frames)
Sky Brightness measurements are invalid due to a SBIG camera bias level issue (eventually fixed 2022-01-02)
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
18:54:34 Session Monitoring AutoStart monitoring for Live Session opportunity between 18:54 & 06:23
18:54:36 Session AutoStarting Session autostarting (18:54)
18:55:04 Session Created Live Session Created (2021-12-16 S00942, ImageSaveNum: 942001)
18:55:06   Scope Switched On Telescope Power has been switched on via UPB Powerbox.
18:56:47   Services Started Observatory Services started
18:56:54 Observatory (Auto) Observatory placed in Fully-Automated Mode
18:56:56 Session Pending Session pending (2021-12-16)
18:56:58 Session Initiating Session initiating (2021-12-16)
18:57:00   Plan Requested Observing Plan requested from AstroPlan (1.29.1)
18:57:44   Plan Loaded Observing Plan loaded to queue (, Plan ID: 695)
18:58:06   Camera1 Connected SBIG Camera Connected (set point -20°C)
18:58:13   Telescope Connected Telescope Connected (TheSky6)
18:58:37 Session Equilibration Session ready for dome & camera equilibration
18:59:22   Dome Opened Dome opened (opening time 45s)
19:00:02 Session Running Session running
19:00:05   Queue Started Observing Queue started (43 targets selected)
19:00:07     Target Started (NrZen) Target started (Focus Field 1, HIP 4911)
19:01:31       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:04:30       Focusing Completed Foc1 AutoFocus Completed (Profile No 1, wide)
19:06:43       Focusing Completed Foc1 AutoFocus Completed (Profile No 1)
19:06:46       Focusing Started-Foc2 Foc2 Focusing Started (Secondary Scope, using ShCap)
19:08:57       Focusing Completed Foc2 AutoFocus Completed (Profile No 2, wide)
19:10:44       Focusing Completed Foc2 AutoFocus Completed (Profile No 2)
19:11:02     Target Completed Target completed (Focus Field 1, HIP 4911)
19:12:04     Target Started (1/43) Target started (1/43, 132P/Helin-Roman-Alu)
19:15:24       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:17:48       Focusing Completed Foc1 AutoFocus Completed (Profile No 3)
19:27:35     Target Completed Target completed (1/43, 132P/Helin-Roman-Alu)
19:27:39     Target Started (2/43) Target started (2/43, NGC 7446 w/SN2021agdd)
19:30:17       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:32:19       Focusing Completed Foc1 AutoFocus Completed (Profile No 4)
19:49:07     Target Completed Target completed (2/43, NGC 7446 w/SN2021agdd)
19:49:11     Target Started (3/43) Target started (3/43, GCVS HH And)
19:51:19       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
19:53:33       Focusing Completed Foc1 AutoFocus Completed (Profile No 5)
19:55:42     Target Completed Target completed (3/43, GCVS HH And)
19:56:37     Target Started (4/43) Target started (4/43, GCVS U And)
20:00:10       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
20:02:14       Focusing Completed Foc1 AutoFocus Completed (Profile No 6)
20:14:46     Target Completed Target completed (4/43, GCVS U And)
20:14:50     Target Started (5/43) Target started (5/43, GCVS SS Cyg)
20:17:21       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
20:19:33       Focusing Completed Foc1 AutoFocus Completed (Profile No 7)
20:24:30     Target Completed Target completed (5/43, GCVS SS Cyg)
20:25:55     Target Started (6/43) Target started (6/43, GCVS BL Lac)
20:28:09       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
20:30:23       Focusing Completed Foc1 AutoFocus Completed (Profile No 8)
20:34:25     Target Completed Target completed (6/43, GCVS BL Lac)
20:36:13     Target Started (7/43) Target started (7/43, Nova Cas 2021)
20:39:22       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
20:41:10       Focusing Completed Foc1 AutoFocus Completed (Profile No 9)
20:48:37     Target Completed Target completed (7/43, Nova Cas 2021)
20:48:57     Target Started (8/43) Target started (8/43, GCVS Z And)
20:51:27       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
20:53:40       Focusing Completed Foc1 AutoFocus Completed (Profile No 10)
20:58:41     Target Completed Target completed (8/43, GCVS Z And)
20:58:45     Target Started (9/43) Target started (9/43, M31 w/AT2021aaxp)
21:01:20       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
21:03:08       Focusing Completed Foc1 AutoFocus Completed (Profile No 11)
21:09:56     Target Completed Target completed (9/43, M31 w/AT2021aaxp)
21:10:00     Target Started (10/43) Target started (10/43, GCVS DY Per)
21:12:34       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
21:14:50       Focusing Completed Foc1 AutoFocus Completed (Profile No 12)
21:20:03     Target Completed Target completed (10/43, GCVS DY Per)
21:20:07     Target Started (11/43) Target started (11/43, NGC 1400 w/AT2021hcz)
21:25:20       Focusing Skipped Foc1 focusing skipped - star is lost (TCF-S)
21:43:57     Target Completed Target completed (11/43, NGC 1400 w/AT2021hcz)
21:44:01     Target Started (12/43) Target started (12/43, UGC 2528 w/SN2020adnx)
21:46:30       Focusing Skipped Foc1 focusing skipped - star is lost (TCF-S)
22:03:35     Target Completed Target completed (12/43, UGC 2528 w/SN2020adnx)
22:04:00     Target Started (13/43) Target started (13/43, 10P/Tempel)
22:07:14       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:09:34       Focusing Completed Foc1 AutoFocus Completed (Profile No 13)
22:21:10     Target Completed Target completed (13/43, 10P/Tempel)
22:21:14     Target Started (14/43) Target started (14/43, AT2021xbh)
22:24:09       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:26:15       Focusing Completed Foc1 AutoFocus Completed (Profile No 14)
22:43:06     Target Completed Target completed (14/43, AT2021xbh)
22:43:10     Target Started (15/43) Target started (15/43, GCVS RR Tau)
22:45:53       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
22:48:05       Focusing Completed Foc1 AutoFocus Completed (Profile No 15)
22:56:24     Target Completed Target completed (15/43, GCVS RR Tau)
22:56:28     Target Started (16/43) Target started (16/43, GCVS NV Ori)
23:00:21       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:02:31       Focusing Completed Foc1 AutoFocus Completed (Profile No 16)
23:07:17     Target Completed Target completed (16/43, GCVS NV Ori)
23:07:21     Target Started (17/43) Target started (17/43, GCVS FU Ori)
23:09:39       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:12:15       Focusing Completed Foc1 AutoFocus Completed (Profile No 17)
23:15:05     Target Completed Target partially completed (17/43, GCVS FU Ori)
23:15:09     Target Started (18/43) Target started (18/43, GSC 1224:29)
23:17:48       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:20:17       Focusing Failed Foc1 focusing failed - star lost
23:25:40     Target Completed Target partially completed (18/43, GSC 1224:29)
23:25:44     Target Started (19/43) Target started (19/43, Nova Per 2020)
23:28:01       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:29:48       Focusing Completed Foc1 AutoFocus Completed (Profile No 19)
23:38:50     Target Completed Target completed (19/43, Nova Per 2020)
23:38:54     Target Started (20/43) Target started (20/43, UGC 4671 w/SN2021afsj)
23:42:02       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
23:43:49       Focusing Completed Foc1 AutoFocus Completed (Profile No 20)
00:00:54     Target Completed Target completed (20/43, UGC 4671 w/SN2021afsj)
00:00:59     Target Started (21/43) Target started (21/43, SN 2021wcu)
00:03:20       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:05:31       Focusing Completed Foc1 AutoFocus Completed (Profile No 21)
00:22:03     Target Completed Target completed (21/43, SN 2021wcu)
00:22:07     Target Started (22/43) Target started (22/43, AT2021kkh)
00:25:11       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:27:10       Focusing Completed Foc1 AutoFocus Completed (Profile No 22)
00:43:41     Target Completed Target completed (22/43, AT2021kkh)
00:43:45     Target Started (23/43) Target started (23/43, C/2019 L3 (ATLAS))
00:45:58       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
00:47:56       Focusing Completed Foc1 AutoFocus Completed (Profile No 23)
00:56:52     Target Completed Target completed (23/43, C/2019 L3 (ATLAS))
00:56:56     Target Started (24/43) Target started (24/43, 67P/Churyumov-Gerasimenko)
00:59:06       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:01:16       Focusing Completed Foc1 AutoFocus Completed (Profile No 24)
01:15:03     Target Completed Target completed (24/43, 67P/Churyumov-Gerasimenko)
01:15:07     Target Started (25/43) Target started (25/43, NGC 2955 w/AT2021jtt)
01:17:41       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:19:51       Focusing Completed Foc1 AutoFocus Completed (Profile No 25)
01:36:40     Target Completed Target completed (25/43, NGC 2955 w/AT2021jtt)
01:36:44     Target Started (26/43) Target started (26/43, AT2021agdv (CV))
01:40:01       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:41:48       Focusing Completed Foc1 AutoFocus Completed (Profile No 26)
01:49:06     Target Completed Target completed (26/43, AT2021agdv (CV))
01:49:10     Target Started (27/43) Target started (27/43, Scholz's Star)
01:52:12       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
01:54:12       Focusing Completed Foc1 AutoFocus Completed (Profile No 27)
02:09:53     Target Completed Target completed (27/43, Scholz's Star)
02:09:57     Target Started (28/43) Target started (28/43, GCVS FO Ori)
02:12:21       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
02:14:51       Focusing Completed Foc1 AutoFocus Completed (Profile No 28)
02:20:03     Target Completed Target completed (28/43, GCVS FO Ori)
02:20:07     Target Started (29/43) Target started (29/43, UGC 4002 w/SN2021wvy)
02:22:36       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
02:24:41       Focusing Completed Foc1 AutoFocus Completed (Profile No 29)
02:41:14     Target Completed Target completed (29/43, UGC 4002 w/SN2021wvy)
02:41:18     Target Started (30/43) Target started (30/43, GCVS RZ LMi)
02:43:57       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
02:45:44       Focusing Completed Foc1 AutoFocus Completed (Profile No 30)
02:51:34     Target Completed Target completed (30/43, GCVS RZ LMi)
02:52:18     Target Started (31/43) Target started (31/43, AT2021rl)
02:55:48       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
02:58:29       Focusing Completed Foc1 AutoFocus Completed (Profile No 31)
03:15:17     Target Completed Target completed (31/43, AT2021rl)
03:15:21     Target Started (32/43) Target started (32/43, UGC 5829 w/LBV2021blu)
03:18:11       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
03:20:40       Focusing Completed Foc1 AutoFocus Completed (Profile No 32)
03:38:00     Target Completed Target completed (32/43, UGC 5829 w/LBV2021blu)
03:38:04     Target Started (33/43) Target started (33/43, NGC 4227 w/SN2021biz)
03:40:31       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
03:42:30       Focusing Completed Foc1 AutoFocus Completed (Profile No 33)
03:59:26     Target Completed Target completed (33/43, NGC 4227 w/SN2021biz)
03:59:30     Target Started (34/43) Target started (34/43, UGC 3855 w/SN2021agco)
04:04:25       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
04:06:24       Focusing Completed Foc1 AutoFocus Completed (Profile No 34)
04:22:58     Target Completed Target completed (34/43, UGC 3855 w/SN2021agco)
04:23:02     Target Started (35/43) Target started (35/43, NGC 3310 w/SN2021gmj)
04:26:09       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
04:28:26       Focusing Completed Foc1 AutoFocus Completed (Profile No 35)
04:44:57     Target Completed Target completed (35/43, NGC 3310 w/SN2021gmj)
04:45:01     Target Started (36/43) Target started (36/43, GCVS CN Leo)
04:47:38       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
04:49:25       Focusing Completed Foc1 AutoFocus Completed (Profile No 36)
04:57:28     Target Completed Target completed (36/43, GCVS CN Leo)
04:57:32     Target Started (37/43) Target started (37/43, IC 719 w/SN2021kos)
04:59:54       Focusing Skipped Foc1 focusing skipped - star is lost (TCF-S)
05:16:11     Target Completed Target completed (37/43, IC 719 w/SN2021kos)
05:17:12     Target Started (38/43) Target started (38/43, NGC 3836 w/SN2021aefs)
05:20:29       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
05:22:28       Focusing Completed Foc1 AutoFocus Completed (Profile No 37)
05:38:59     Target Completed Target completed (38/43, NGC 3836 w/SN2021aefs)
05:39:03     Target Started (39/43) Target started (39/43, SBS 0951+534 w/SN2021hmc)
05:41:46       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
05:44:14       Focusing Completed Foc1 AutoFocus Completed (Profile No 38)
06:00:51     Target Completed Target completed (39/43, SBS 0951+534 w/SN2021hmc)
06:00:55     Target Started (40/43) Target started (40/43, AT2021aena (CV))
06:04:36       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
06:06:47       Focusing Completed Foc1 AutoFocus Completed (Profile No 39)
06:13:18     Target Completed Target completed (40/43, AT2021aena (CV))
06:13:22     Target Started (41/43) Target started (41/43, IC 992 w/SN2021dwg)
06:16:34       Focusing Skipped Foc1 focusing skipped - star is lost (TCF-S)
06:32:36     Target Completed Target completed (41/43, IC 992 w/SN2021dwg)
06:34:40     Target Started (42/43) Target started (42/43, GCVS R CrB)
06:37:06       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
06:38:41       Focusing Completed Foc1 AutoFocus Completed (Profile No 40)
06:42:49     Target Completed Target completed (42/43, GCVS R CrB)
06:43:21     Target Started (43/43) Target started (43/43, C/2017 K2 (PANSTARRS))
06:45:55       Focusing Started-Foc1 Foc1 Focusing Started (TCF-S)
06:47:54       Focusing Completed Foc1 AutoFocus Completed (Profile No 41)
06:56:35     Target Completed Target completed (43/43, C/2017 K2 (PANSTARRS))
06:56:38   Queue Completed Job Queue completed
06:56:39 Session Closing Session closing
06:57:34   Dome Closed Dome closed (closing time 50s)
07:00:43   Dome Parked Dome parked (parking time 181s), Az: 90.0 deg
07:01:57   Telescope Parked Telescope parked (parking time 69s)
07:02:11   Telescope State Scope parked Turn scope off. (Handbox)
07:02:32   Telescope Switched Off Telescope Power has been switched off via UPB Switch.
07:03:27   Services Stopped Night Services stopped
07:03:29 Session Housekeeping Housekeeping Started (Cleanup FITS, Create Fits Summary, Transfer Files)
07:04:05 Session Finished Session Finished
 
Session Alerts
Time     Alert Detail
-- No Alerts                --                              

Back to Top


Operational Issues (2021-12-16, S942)

[ Prev | Next ]

Critical Issues

Major Issues

Minor Issues

Small Defects

Continuous Improvement

[ Prev | Next ]

Back to Top


MeadeGeneric 1.3.3.373

A new development version of MeadeGeneric driver was installed on the observatory computer today (2021-12-16).  This contains a fix for issue when TrackingRate returns driveLunar (normally 57.9z) for actual scope tracking rate of 60.0Hz  which is actually the tracking rate for driveSolar.

Results
MeadeGeneric 1.3.3.373 was successfully used in session S942 (2021-12-16).

>> MeadeGeneric Releases : https://bitbucket.org/cjdskunkworks/meadeautostar497/wiki/Release%20History


2021-12-17


Investigation - PHD2 application failed during guiding (unhandled and unknown exception)

Issue:  PHD2 Guiding Run suddenly ended when a key thread in PHD2 crashed due to a fatal exception and prevented autoguiding for the remainder of the automated session.

Description.   Checking in with observing session in morning showed although the session had completed normally the targets from second part of night hadn't been auto-guided. Guide Charts had been created with normal header data, but the graphs were devoid of any guide data and GuideSummary Plots and Table only show data for Guide Run 1 to 16,  whilst Guide Run 17 to 43 were devoid of data.  Report Log indicates problem capturing Focus Reference image.

Checking the PHD2 application showed an error dialog with the message "*** Caught, unhandled, unknown exception; terminating".
The Image in PHD2 show a region of sky including M42 consistent with the target NV Ori (guide run 16) and guiding history plot was normal.

Image


The error dialog was dismissed with click on its Ok button whereupon the PHD2 GUI was found to be non-responsive and had to be killed.

Data in AstroMain indicates that the PHD2 server was responsive throughout,  for example the temperature of the camera connected to PHD2 was able to be monitored and its graphs show normal data throughout.   General data from PHD2 (Profile Name, Connected Camera / Mount etc) was also recoverable with no problem

AstroMain Report files shows 'Failed to capture frame'  (ie 10s Reference Frame from PHD2) at 23:08 during attempted Guide Run 17 for FU Ori.
Guiding data seems to stops coming through at or just before the the start of Image Group 2 at 23:04:30 during Guide Run 16 for NV Ori.

PHD2 Debug Log shows output that consistent with active Guiding up until 23:03:45. After this there are just mainly "evsrv: cli ... " messages associated with PHD2 server requests and responses.  At 23:08:46 there is a "request: {"method":"guide".... " from AstroMain to begin guiding for the next target (NV Ori).  PHD2 then outs as series of "PhdController::Guide begins . sequence consistent with request from AstroMain

 << Normal sequence of Guiding Related activity
23:03:44.573 00.003 12516 UpdateImageDisplay: Size=(3096,2080) min=283, max=65531, med=900, FiltMin=489, FiltMax=65531, Gamma=0.300
23:03:44.875 00.302 12516 UpdateGuideState exits: m=1217784 SNR=435.5
23:03:44.875 00.000 12516 OnExposeComplete: CaptureActive=1 m_continueCapturing=1
23:03:44.875 00.000 12516 ScheduleExposure(1500,3,1) exposurePending=0
23:03:44.883 00.008 12516 Enqueuing Expose request
23:03:44.887 00.004 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1321}
23:03:44.890 00.003 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":12.2},"id":1321}
23:03:45.288 00.398 11812 IsGuiding returns 0
23:03:45.288 00.000 11812 Move returns status 0, amount 91
23:03:45.288 00.000 11812 MoveAxis(N, 66, ABG)
23:03:45.288 00.000 11812 duration set to 0 by GuideMode
23:03:45.288 00.000 11812 Move returns status 0, amount 0
23:03:45.288 00.000 11812 move complete, result=0
23:03:45.288 00.000 11812 worker thread done servicing request
23:03:45.288 00.000 12516 GuideStep: 0.8 px 91 ms WEST, -1.4 px 0 ms NORTH
23:03:45.288 00.000 11812 Worker thread wakes up
23:03:45.288 00.000 11812 worker thread servicing REQUEST_EXPOSE 1500
23:03:45.288 00.000 11812 Handling exposure in thread, d=1500 o=3 r=(1958,1796,41,41)

 << Guiding Related activity suddenly and unexpectedly stops here (no errors or unusual messages)
23:04:05.058 19.770 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1322}
23:04:05.062 00.004 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":12.2},"id":1322}
23:04:25.495 20.433 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1323}
23:04:25.504 00.009 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":12.1},"id":1323}

 << PHD2 Server requests and responses (4 mins of data not shown)
23:08:45.649 00.003 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"id":1,"name":"TS80/178MC"},"id":1370}
23:08:46.060 00.411 12516 evsrv: cli 0CDA5F30 request: {"method":"get_search_region","id":1371}
23:08:46.064 00.004 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":20,"id":1371}
23:08:46.176 00.112 12516 evsrv: cli 0CDA5F30 request: {"method":"get_camera_frame_size","id":1372}
23:08:46.180 00.004 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":[3096,2080],"id":1372}

 << Request to Start Guiding
23:08:46.293 00.113 12516 evsrv: cli 0CDA5F30 request: {"method":"guide","params":[{"pixels":2,"time":10,"timeout":15},false,[341,229,2415,1622]],"id":1373}

 << Phd2 Controller seems to still be active
23:08:46.296 00.003 12516 PhdController::Guide begins
23:08:46.299 00.003 12516 PhdController: newstate STATE_SETUP
23:08:46.301 00.002 12516 PhdController: setup
23:08:46.302 00.001 12516 PhdController: newstate STATE_ATTEMPT_START
23:08:46.302 00.000 12516 PhdController: guider state = 6
23:08:46.307 00.005 12516 PhdController: newstate STATE_SETTLE_BEGIN
23:08:46.312 00.005 12516 PhdController: newstate STATE_SETTLE_WAIT
23:08:46.316 00.004 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":0,"id":1373}
23:08:47.188 00.872 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1374}
23:08:47.191 00.003 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":11.7},"id":1374}
23:09:07.789 20.598 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1375}
23:09:07.791 00.002 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":11.7},"id":1375}
23:09:16.188 08.397 12516 evsrv: cli 0CDA5F30 request: {"method":"save_image","id":1376}
23:09:16.194 00.006 12516 GetString("/profile/1/name", "") returns "TS80/178MC"

 << SideOfPier Not Implemented Exception Occurs (red-herring)
23:09:16.197 00.003 12516 invoke: [80020009] Exception occurred.
23:09:16.198 00.001 12516 Error thrown from C:\cygwin\home\agalasso\projects\phd2\scope_ascom.cpp:1119->ASCOM Scope: SideOfPier failed: (ASCOM.DeviceHub.Telescope) Property read ASCOM.MeadeGeneric.Telescope SideOfPier is not implemented in this driver.
23:09:16.198 00.000 12516 ScopeASCOM::SideOfPier() returns -1
23:09:16.207 00.009 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"filename":"C:\\Users\\David\\AppData\\Local\\phd2\\savD7FB.tmp"},"id":1376}
23:09:30.237 14.030 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1377}
23:09:30.240 00.003 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":11.7},"id":1377}

 << PHD2 Server requests and responses (18 mins not shown here)
23:27:03.390 00.000 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"id":1,"name":"TS80/178MC"},"id":1501}
23:27:03.803 00.413 12516 evsrv: cli 0CDA5F30 request: {"method":"get_search_region","id":1502}
23:27:03.806 00.003 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":20,"id":1502}
23:27:03.904 00.098 12516 evsrv: cli 0CDA5F30 request: {"method":"get_camera_frame_size","id":1503}
23:27:03.907 00.003 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":[3096,2080],"id":1503}

 << Next Request to Start Guiding
23:16:50.249 00.113 12516 evsrv: cli 0CDA5F30 request: {"method":"guide","params":[{"pixels":2,"time":10,"timeout":15},false,[341,229,2415,1622]],"id":1436}

 << Phd2 Controller seems to less active
23:16:50.252 00.003 12516 PhdController::Guide reentrancy state = 9 op = 1
23:16:50.252 00.000 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","error":{"code":1,"message":"Cannot initiate guide while guide is in progress"},"id":1436}
23:17:09.454 19.202 12516 evsrv: cli 0CDA5F30 request: {"method":"get_ccd_temperature","id":1437}
23:17:09.455 00.001 12516 evsrv: cli 0CDA5F30 response: {"jsonrpc":"2.0","result":{"temperature":11.6},"id":1437}
23:17:20.132 10.677 12516 evsrv: cli 0CDA5F30 request: {"method":"save_image","id":1438}
23:17:20.138 00.006 12516 GetString("/profile/1/name", "") returns "TS80/178MC"

PHD2 Guide Log shows the last recorded guide sequence  starting at around 22:59  ('Guiding Begins at 2021-12-16 22:59:43 , whilst debug log shows 22:59:31for PhdController::Guide begins) . Once guiding gets underways Guidesteps are reported until 242s after start of guiding . This would equate with 23:03:45 and is thus consistent with the end of guiding activity in the debug log.

The following sofware versions where being used :
  - ASCOM 6.5 SP1
  - AstroMain 3.48.4
  - MeadeGeneric 1.3.3.373
  - DeviceHub 6.5.1.9
  - PHD2 Guiding 2.6.10

Analysis

Conclusion
PHD2 failed due to an unhandled, unknown exception.  There is no information to diagnose the cause of the exception any further.   It may be a glitch that will never be seen again or it might be something that occurs from time to time .  The problem is not related to recent SideOfPier/Calibration Flipping Issue.

Actions:
 
Image Pass details of the case to PHD2 Forum/Support

Image Add code to AstroMain to monitor the PHD2 application and kill/restart PHD2 if it has stalled. Add code to Obs.Monitor/Obs.Manager  to monitor the apparent level of activity in PHD2  and if it seems to have stalled  then call a new routine to Close PHD2 Server connection and then kill PHD2 process before restarting it and reconnecting.

Update 2022-07-29

Code added to AstroMain 3.53.1 that will check PHD2 functioning following a request to Guide, and if PHD2 appears stalled it will kill and restarted PHD2 & restart PHD2 service.

It is noticed that following the exception in PHD2 and its failure to guide from 23:04 , PHD2 responded to requests (like 'get_current_equipment') but in response to 'guide' request there wasn't the usual sequence of Events that would be sent out by PHD2.   Apart from 'GuideParamChange'  and 'ConfigurationChange' events associated with 'set_dec_guide_mode' requests the only guiding related event seen is a single 'SettleBegin' event associated with 'guide' request at 23:08:46.  The usual events 'LoopingExposures', 'LockPositionSet', 'StarSelected', 'StartGuiding' , 'Settling', 'GuideStep' are all missing.

The absence of these normal guiding events following 'guide' request will be used to indicate a probably problem with the PHD2 program.  Specifically the absence of 'LoopingExposures' events will be used to diagnose an issue.


The correct functioning of PHD2 will be identified presence of LoopingExposures events following request to 'Guide', and incrementing the variable nLoopingExposureEvents

Back to Top