Autofocus before centering failed

Sequence Generator
1

sg_logfile_20191111195101.zip (73.5 KB)
Not sure if the autofocus problem is with SGP or somewhere else, but in my opinion is wasn’t handled well by SGP because after this it just sat there waiting for over 1 hour at the auto centering window, i had to kill SGP from the task manager.

[11/11/19 21:58:19.214][DEBUG] [Camera Thread] ASCOM Focuser: Timeout! Focuser trying to get to 97286, reports it is at 100878. Focuser move complete reports: True
[11/11/19 21:58:19.214][DEBUG] [Camera Thread] MoveFocuserAbs: End, move complete, at 100878…
[11/11/19 21:58:19.214][DEBUG] [Camera Thread] Auto focus failed! Error in auto focus! Focuser failed to move to the auto focus position (97286). Focuser reports it is at 88478. : Error in auto focus! Focuser failed to move to the auto focus position (97286). Focuser reports it is at 88478.
at p3.a(AutoFocusData A_0, sa& A_1)
[11/11/19 21:58:19.214][DEBUG] [Main Thread] Adding sequence level notification: Auto focus failed! Error in auto focus! Focuser failed to move to the auto focus position (97286). Focuser reports it is at 88478.
[11/11/19 21:58:19.238][DEBUG] [Camera Thread] Sending Notification: Error - Auto focus failed! Error in auto focus! Focuser failed to move to the auto focus position (97286). Focuser reports it is at 88478.
[11/11/19 21:58:19.238][DEBUG] [Camera Thread] MoveFocuserAbs: Start, move to 94678…
[11/11/19 21:58:19.238][DEBUG] [Camera Thread] ASCOM Focuser: MoveSync - start…
[11/11/19 21:58:19.238][DEBUG] [Camera Thread] Focuser moving to 94678
[11/11/19 21:58:19.302][DEBUG] [Camera Thread] Focuser move call complete
[11/11/19 21:58:26.363][DEBUG] [Camera Thread] ASCOM Focuser: MoveSync - Focuser reports it is done moving, continuing…
[11/11/19 21:58:26.363][DEBUG] [Camera Thread] MoveFocuserAbs: End, move complete, at 94678…
[11/11/19 21:58:26.363][DEBUG] [Camera Thread] Auto focus (finally): closing dialog…
[11/11/19 21:58:37.277][DEBUG] [Camera Thread] Set temp comp baseline marker -> Temp: 12.1 …
[11/11/19 21:58:37.277][DEBUG] [Camera Thread] Auto focus complete…
[11/11/19 21:58:37.282][DEBUG] [Camera Thread] SGM_FOCUSER_AUTO_FOCUS complete…
[11/11/19 21:58:37.312][DEBUG] [Sequence Thread] AF is complete, continuing sequence…
[11/11/19 21:58:37.312][DEBUG] [Sequence Thread] DoEventGroupChange: Centering on target
[11/11/19 21:58:37.318][DEBUG] [Main Thread] Adding sequence level notification: Centering on target “NGC7380”…
[11/11/19 21:58:37.321][DEBUG] [Sequence Thread] Sending Notification: Status - Centering on target “NGC7380”…
[11/11/19 21:58:54.667][DEBUG] [PHD2 Listener Thread] PHD2 - No messages received from PHD2 for 1 minute, checking socket with status…
[11/11/19 21:58:54.667][DEBUG] [PHD2 Listener Thread] Checking PHD2 state…
[11/11/19 21:58:54.667][DEBUG] [PHD2 Listener Thread] PHD2 GetPhdStatus - Pre-Wait : Stopped
[11/11/19 21:58:54.667][DEBUG] [PHD2 Listener Thread] Sending to PHD2:
{“method”: “get_app_state”, “id”: 1001}

[11/11/19 21:58:54.667][DEBUG] [PHD2 Listener Thread] PHD2 GetPhdStatus - Post-Wait: Stopped
[11/11/19 21:59:54.775][DEBUG] [PHD2 Listener Thread] PHD2 - No messages received from PHD2 for 1 minute, checking socket with status…
[11/11/19 21:59:54.775][DEBUG] [PHD2 Listener Thread] Checking PHD2 state…
[11/11/19 21:59:54.775][DEBUG] [PHD2 Listener Thread] PHD2 GetPhdStatus - Pre-Wait : Stopped
[11/11/19 21:59:54.775][DEBUG] [PHD2 Listener Thread] Sending to PHD2:
{“method”: “get_app_state”, “id”: 1001}

[11/11/19 21:59:54.775][DEBUG] [PHD2 Listener Thread] PHD2 GetPhdStatus - Post-Wait: Stopped
[11/11/19 22:00:36.751][DEBUG] [Main Thread] Adding sequence level notification: (AG) Failure during sequence startup. Sequence has not started in alloted time period.

2

Ya… that looks nasty. A quick inspection does not reveal what SGPro is waiting for, but it does show that auto focus exited properly with an error. I will need to spend some more time here.

There is seemingly a big problem with your focuser in that last run… seems to not want to move.

3

I’m looking into this. As Ken mentioned there’s not a lot of information about what happened. Something just seemed to stop. I’m guessing since you had to kill SGP that closing Auto Center wasn’t working?

Jared

4

Seems more like the focuser position is reported wrong because the log says it reports both 100878 and 88478 at the exact same time.

I forgot to take a screenshot of the auto centering, but if i remember correctly it had not even started doing anything and all buttons to cancel were greyed out.

I wonder if the problems are related to the startup after “unsafe”? I’ve never been able to use this option before because “unsafe” would run end of sequence and that would mean SGP could not power up the gear by itself.

5

Yes, I actually just found that issue where we destroy the focuser move on backlash. I have that fixed. Still unsure about why centering hung…

6

Great that you found and fixed a bug with backlash.
I have upgraded to 362 and will report back if the centering hangs again.

7

Same problem happened again…i see i can actually click “done”
Letting it sit waiting there for a while before i force shutdown.

Screenshot_14
Screenshot_14.png1929×1212 955 KB

8

It did actually close the centering window after a while, but there’s still no explanation for why it just sits there waiting for step 1 of centering.
sg_logfile_20191113193421.zip (84.2 KB)

9

Alright, I found a few issues where “restart on safe” would fight with “Capture cal frames on sequence fail” and where the sequence thread would get ahead of threads that run auto focus and centering routines. I am not 100% certain these are related to this issue, but it’s pretty likely that at least one of them is.