Connection to mount lost - SGP, PHD2, or ASCOM?

Last night (five minutes after I went to sleep! dang!) the connection to the mount was lost, and SGP seems to have hung. When I found it this morning, though, the mount was still connected, and was still tracking, although of course pointing at the ground by this time. The SGP log, PHD2 debug and guide logs, and a mysterious .wer file found in a folder tellingly named AppCrash_ASCOM.Celestron are all here:

https://dl.dropboxusercontent.com/u/58468743/sg_logfile_20150519212523.zip

Everything went okay until 11:47:27, when PHD2 seemed to stop responding to SGP, and guiding stopped. SGP 2.4.1.3, PHD2.5. I know there’s some new PHD2 functionality in newer SGP betas so I’ll update, but I wondered if anyone knows if that was really the problem.

Kevin

I can’t be sure what happened except to say that something seems to have gone wrong when we queried your mount for the stuff we use in the FITS header. This is the last we hear from the sequencer:

[5/19/2015 11:46:23 PM] [DEBUG] [Sequence Thread] Collecting FITs headers...

And then, much later, this:

[5/20/2015 6:35:31 AM] [DEBUG] [CP Update Thread] ASCOM Telescope: Error in GetCurrentPos : The RPC server is unavailable. (Exception from HRESULT: 0x800706BA)

@Chris might have a better idea of what happened.

Things seem to have been running successfully for some time from about 10PM, the error isn’t until 6:35 the following morning. It couldn’t be something like a cable coming out?

What state was the mount and it’s HC in when you looked? Was it still running?

I don’t have any better idea, something went wrong but that’s all the log data reports.

I don’t know what the RPC server is, is this something internal to PHD2 or SGP? It’s not part of ASCOM (AFAIK).

None of the actual error messages from the driver seem to be reported. These might say what had happened from the driver’s perspective.
There is no log from the Celestron driver. This is essential because it will tell us what happened from the driver’s perspective.
Enable logging in the driver, run until the fault reappears, then send the driver log as well as the information here.

That’s all I can suggest.

Chris

From another look it seems as if things actually went wrong at 23:46:29, the PHD log shows:

23:46:29.879 00.000 5196 ScheduleExposure(1000,3,1) exposurePending=0
23:46:29.880 00.001 5196 Enqueuing Expose request

After that PHD and SGP seem to have at least partly stopped. All that’s going on are reports from SGP saying no response from PHD and PHD reporting what looks like messages from SGP.

Could this be an indication that the guide camera has problems?

Chris

Thanks for looking at this, Ken and Chris. Yes, the problem started about 23:46. When I saw it at 6:35 next morning, the mount and HC were both running properly. As soon as I clicked OK on the error message, PHD2 started taking images again. I’ll turn on logging next time. I’ve never seen this error before though.

I had just reinstalled the scope/mount in my obs, after having relubricated the dec axis. I had an NR 16 error on it when I tested it mid-day, but I think I had just plugged into the wrong socket. Re-plugged, and it connected without problem. So I don’t have any explanation for what went wrong. Maybe Andy will see something in the PHD debug log.

Kevin

The PHD2 worker thread hung at 23:46:29.858 in a call to get the Slewing property from the mount ASCOM driver. It stayed hung until 06:35:31.458 when it returned a COM error [800706ba] The RPC server is unavailable which likely means the ASCOM driver server process was terminated at that time.

No problem indicated with the guide camera. The worker thread that services both the camera and mount was hung in a call to the mount, so it never serviced the camera exposure request.

I guess the key to diagnosing this if it happens again will be to get the Mount ASCOM driver’s log as Chris said.

Andy

Yes, we definitely need a driver log. You don’t happen to have a screenshot of the error message? BTW this is a CPC mount isn’t it?

Andy, are you saying that an error message box reporting a problem was displayed at 23:46 but that the corresponding log message wasn’t written until 06:35, after the message box was cleared? If so could the log write be put before the message box show statement so the sequence of operations is preserved. It would also help if the exact error message that you get was reported. I try to make the messages meaningful - at least to me.

Nope, I wasn’t saying that. There was no error until 06:35. 23:46 was the time that the phd2 worker thread entered the get Slewing property ASCOM call. The call returned at 06:35 with an error which we logged (exactly) and then displayed a non-modal alert.

Andy

Thanks to all of you for taking a look at this. I’ll set the ASCOM log to record. I don’t remember seeing this before, but if it crops up again I’ll have it. I’m afraid I didn’t take a screen shot before clearing the error message. My brain isn’t working well enough at the crack of dawn when such things always seem to happen. But if it happens again, I’ll certainly get it.

Kevin

Kevin, that is not necessary. We have the error message in the log. Whenever we display an alert in PHD2 we log it. It would be too much to expect anyone to have to remember to take screenshots!
Andy

Hey, it just happened again! I have the SGP, PHD2, and ASCOM logs here, with a screen grab of the error message. Hopefully this will nail it down. I was in frame and focus mode, not paying much attention since it’s mostly cloudy and I’m just waiting and hoping for clearing. I doubt it was PHD2, because it was only looping, not guiding, but you never know.

Kevin

There’s no obvious problem with communication with the mount driver - at least from what I can see in the mount driver log. It’s difficult to tell what files are relevant though, or what time the error happened. I can’t find a PHD log, nor a screen grab of the error.

There are guide commands being sent successfully, the last one at 04:15:48.225, direction E duration 120.

Then at about 4:15:55 the mount is parked, the park completing at 04:16:31.799.

Various command are sent, with no problems, until the end of the log at 07:44:08.940

Chris

Chris

Hi Chris,
The error happened just before 11pm local time. I can’t access dropbox right now to doublecheck my files, but I’ll check in a few hours to make sure I uploaded the right files.

Kevin

There’s a gap in the Celestron log about that time:
22:46:25.804 Sidereal time From mount 16.0838012695313
22:59:08.395 Constructor Telescope constructor completed
No problems reported though.

Chris

Hi Chris,

I think you’re looking at the log file from my original post last month. The new log file is here:

https://dl.dropboxusercontent.com/u/58468743/sg_logfile_20150629223036.zip

You should find a screen grab of the error message, the SGP log, PHD2 logs, etc in that zip file.