A possible clue to the focuser backlash comp issue?

I mentioned a couple weeks back that I am having trouble using focuser backlash compensation with versions of SGP newer than 2.3.5 with my Rigel Systems focus controller. I noticed something in some parts of my log (a relevant snippet of which is posted below - this is SGP 2.3.5) from last night that perhaps offers some insight. After an AF run, SGP calculated focus at 83721, then issued a backlash comp command to move to 84221 first. But after that it noted that the focuser was moving to 83717, not 83721. Why is that? The log shows that it did move successfully to 83721 after that.

This “miscalculation,” or whatever it is, happens in about 1/4 to 1/3 of the AF runs, and that’s exactly how often I’ve been having trouble with AF runs in the newer versions of SGP. Could this tie in to my problem? My issue is that the focuser often doesn’t move all the way in to the commanded position after a backlash comp move - it often falls a few steps short, and then won’t move further without user intervention.

[7/6/2014 3:35:12 AM] [DEBUG] [Camera Thread] Auto focus HFR calculated at: 191
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] New auto focus method calculated focus at:
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] Old auto focus method calculated focus at: 83721
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] Using old auto focus method for focuser position
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] New focus position is at 83721 (@16.00C).  Moving focuser…
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] Focuser moving to 83721
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] Focuser backlash active, modified move to 84221
[7/6/2014 3:35:13 AM] [DEBUG] [Camera Thread] Focuser move call complete
[7/6/2014 3:35:15 AM] [DEBUG] [Main Thread] Focuser running backlash compensation…
[7/6/2014 3:35:15 AM] [DEBUG] [Main Thread] Focuser backlash compensation needed. Steps: 500 Direction:IN
[7/6/2014 3:35:15 AM] [DEBUG] [Main Thread] Focuser moving to 83717
[7/6/2014 3:35:15 AM] [DEBUG] [Main Thread] Focuser move call complete
[7/6/2014 3:35:15 AM] [DEBUG] [Main Thread] Focuser backlash compensation complete
[7/6/2014 3:35:18 AM] [DEBUG] [Camera Thread] MoveFocuserAbsBlocking: Focuser position 83721 matches requested position 83721
[7/6/2014 3:35:18 AM] [DEBUG] [Camera Thread] Focuser successfully set to focus position (83721)

Please dropbox the entire log file and post a link instead of the code snippets. Ken/Jared often look for non-obvious things that we’re not looking for.

It would be nice if you found a clue :smile:

Okay, the log is here. Fingers crossed.

https://dl.dropboxusercontent.com/u/58468743/sg_logfile_20140705215340.txt

I’ll look at this a little more in depth this evening. But from the snippet you posted it seems like the focuser reported that the move was complete before it actually was (or that we thought it was complete).

Does your focuser allow for any logging? It would be nice to correlate the SGP log with your focuser log to see what’s going on there.

Thanks,
Jared

It does log, though it’s a bit awkward. It doesn’t write to a file, but it posts into a window that can be copied. I’m not sure how many minutes it will log, though. I’ll mess with it tonight and see if it will log a full AF run with backlash comp.

Here’s a snippet of the focuser log from tonight. As you can see, it only allows me to log about 30 seconds or so. So,
the focuser starts at 84672, and is instructed to move to 84592.  It gives one position report while moving - 84606 - and then reports that it is at 84596 with IsMoving: False.  The log shows several reports of it at that position, and then without another IsMoving: True reports that it is now at 84592, the commanded position.  The same thing happens on the next move in - the focuser is instructed to go to 84512, but stops at 84516 for a few reports before reporting that it is at 84512. That seems odd to me, but the SGP log shows nothing unusual at this point. I haven’t gone through the log in detail yet, however. The SGP log is in Dropbox:

https://dl.dropboxusercontent.com/u/58468743/sg_logfile_20140707224819.txt

11:34pm

Position: 84672
Position: 84672
Temperature: 26.5
Position: 84672
Position: 84672
Position: 84672
Move: 84592 IsMoving: False
Move: 84592
delta: -80
step=: 0 0 080absgoto=0 IsMoving: True IsMoving: True IsMoving: True IsMoving: True
Position: 84606
IsMoving: True IsMoving: True
Position: 84596
MaxStep: 99999
IsMoving: False
Position: 84596
Position: 84596
MaxStep: 99999
IsMoving: False
Position: 84596
IsMoving: False
Position: 84596
IsMoving: False
Position: 84592
IsMoving: False
Position: 84592
Position: 84592
MaxStep: 99999
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Position: 84592
Move: 84512
Move: 84512
delta: -80 IsMoving: True IsMoving: True
step=: 0 0 080absgoto=0 IsMoving: True IsMoving: True IsMoving: True IsMoving: True
Position: 84516
IsMoving: False
Position: 84516
Position: 84516
MaxStep: 99999
IsMoving: False
Position: 84516
Temperature: 26.5
IsMoving: False
Position: 84516
IsMoving: False
Position: 84516
IsMoving: False
Position: 84512
IsMoving: False
Position: 84512
Position: 84512
MaxStep: 99999
Position: 84512