issue with MR prevent duplicate focus execution

Sun Dec 13 10:49:12 GMT 2020

https://invent.kde.org/education/kstars/-/issues/53

Feel free to discuss! 

eric.dejouhanet at gmail.com - https://astronomy.dejouha.net

	  Message original  	

De: eric.dejouhanet at gmail.com
Envoyé: 11 décembre 2020 09:22
À: hy at murveit.com
Cc: hy at murveit.com; kstars-devel at kde.org
Objet: Re: issue with MR prevent duplicate focus execution

Hello Hy,

I had a look at the source tree, and I agree this case went through
the testFocusFailure unitary/UI test.

In the situation you describe, flag "resetFocus" is used to require a
restart, and counter resetFocusIteration is used as a (hardcoded)
boundary.
The current algorithm is scattering those two flags in the code, and
only works for the absolute focuser.
I suggest building upon my intent with MR141 and MR144, and manage the
success/failure states in the unique function
"completeFocusProcedure".
If the procedure has to be restarted from a retry mechanism, then it
should happen in the singleShot timer lambda after settling, and
before restarting guiding or notifying result.
The least start() calls in the code, the better position we will be in
to manage edge cases.

In terms of development, I strongly suggest someone improve
testFocusFailure to observe the failure in that specific situation.
When this test situation is observed consistently, the fix should be
relatively easy and safe to write.

For reference, MR141 and MR144 prevent the critical situation where
two focus procedures happen to run in parallel.

-Eric

Le jeu. 10 déc. 2020 à 21:58, Hy Murveit <murveit at gmail.com> a écrit :
>
> Eric,
>
> I am running with MR144. In fact it was running through commit 79ff9655db804db1ac87df23023164172ba84605
> so, MR144 didn't fix that.
>
> Please check out the log or snippets or let me know if it's unclear.
>
> Hy
>
> On Thu, Dec 10, 2020 at 12:37 PM Eric Dejouhanet <eric.dejouhanet at gmail.com> wrote:
>>
>> Thanks for noticing that Hy!
>>
>> I was under the impression that this case was covered by the tests I added in test_ekos_focus. I do verify that an autofocus that fails does not prevent a subsequent autofocus from succeeding.
>>
>> Ah you are looking at the preliminary MR. Since then, we merged MR144 that fixed that situation. It is very unfortunate that v3.5.0 got out in-between.
>>
>> eric.dejouhanet at gmail.com - https://astronomy.dejouha.net
>>
>> De: murveit at gmail.com
>> Envoyé: 10 décembre 2020 21:15
>> À: eric.dejouhanet at gmail.com; kstars-devel at kde.org
>> Répondre à: hy at murveit.com
>> Objet: issue with MR prevent duplicate focus execution
>>
>> Eric,
>>
>> I stumbled on this issue with your recent MR. "prevent duplicate focus execution"
>> https://invent.kde.org/education/kstars/-/merge_requests/141
>>
>> Basically, focus fails (no stars detected for reasons unimportant here), goes back to its initial position,  and decides to restart,
>> but when it restarts it says it can't restart because autofocus is already running!
>>
>> I guess when it decides to restart itself, it probably needs to deal with the inAutoFocus variable somehow
>> Perhaps it's as simple as just setting inAutoFocus to false before the call to start() on lines 2651, 2688, 2726, 2748,
>>
>> However, since you've looked at this logic recently, I think you're in a better position
>> to make this change (or just tell me that my suggestion looks OK and I can send in that MR).
>>
>> Hy
>>
>> Log:  https://drive.google.com/file/d/1CF89JedlhJ3e5BHkebZHbALDiS_Unm2S/view?usp=sharing
>>
>> Snippets from the above log:
>>
>> [2020-12-10T03:31:17.161 PST DEBG ][     org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR  -1  Num stars  0
>> [2020-12-10T03:31:17.288 PST INFO ][     org.kde.kstars.ekos.focus] - "Failed to detect any stars. Reset frame and try again."
>> [2020-12-10T03:31:17.289 PST INFO ][     org.kde.kstars.ekos.focus] - "Focus procedure completed after 8 iterations."
>> [2020-12-10T03:31:17.289 PST DEBG ][     org.kde.kstars.ekos.focus] - Stopping Focus
>>
>> [2020-12-10T03:31:17.289 PST DEBG ][     org.kde.kstars.ekos.focus] - Stopping Focus
>> [2020-12-10T03:31:17.318 PST DEBG ][   org.kde.kstars.ekos.capture] - Guiding state changed from "Suspended" to "Guiding"
>> [2020-12-10T03:31:17.319 PST INFO ][     org.kde.kstars.ekos.guide] - "Guiding resumed."
>> [2020-12-10T03:31:17.319 PST DEBG ][     org.kde.kstars.ekos.guide] - Capturing frame...
>> [2020-12-10T03:31:17.319 PST DEBG ][     org.kde.kstars.ekos.focus] - State: "Aborted"
>> [2020-12-10T03:31:17.320 PST DEBG ][   org.kde.kstars.ekos.capture] - setFocusStatus:  3
>> [2020-12-10T03:31:17.321 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Guide State "Guiding"
>> [2020-12-10T03:31:17.323 PST DEBG ][     org.kde.kstars.ekos.focus] - AutoFocus result: false
>> [2020-12-10T03:31:17.324 PST INFO ][     org.kde.kstars.ekos.focus] - "Autofocus failed, moving back to initial focus position 11592."
>> [2020-12-10T03:31:17.324 PST DEBG ][     org.kde.kstars.ekos.focus] - Frame is reset. X: 0 Y: 0 W: 4656 H: 3520 binX: 1 binY: 1
>> [2020-12-10T03:31:17.349 PST DEBG ][     org.kde.kstars.ekos.focus] - Settled. State: "Failed"
>> [2020-12-10T03:31:17.350 PST DEBG ][     org.kde.kstars.ekos.focus] - Check Focus requested with minimum required HFR 0.01
>> [2020-12-10T03:31:17.350 PST DEBG ][   org.kde.kstars.ekos.capture] - setFocusStatus:  5
>>
>> [2020-12-10T03:31:17.669 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  12327  (state =  2 )
>> [2020-12-10T03:31:18.213 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  12199  (state =  2 )
>> [2020-12-10T03:31:18.759 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  12071  (state =  2 )
>> [2020-12-10T03:31:19.317 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  11940  (state =  2 )
>> [2020-12-10T03:31:19.865 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  11812  (state =  2 )
>> [2020-12-10T03:31:20.405 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  11684  (state =  2 )
>> [2020-12-10T03:31:20.948 PST DEBG ][     org.kde.kstars.ekos.focus] - Abs Focuser position changed to  11592  (state =  2 )
>> [2020-12-10T03:31:20.981 PST INFO ][     org.kde.kstars.ekos.focus] - "Restarting autofocus process..."
>> [2020-12-10T03:31:20.987 PST DEBG ][     org.kde.kstars.ekos.focus] - Starting focus with box size:  64  Subframe:  no  Autostar:  no  Full frame:  yes  [ 25 %, 75 %]  Step Size:  25  Threshold:  150  Gaussian Sigma:  1.5  Gaussian Kernel size:  5  Multi row average:  3  Tolerance:  10  Frames:  1  Maximum Travel:  10000
>>
>>
>> [2020-12-10T03:31:25.388 PST DEBG ][     org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR  1.70595  Num stars  5
>> [2020-12-10T03:31:25.508 PST DEBG ][     org.kde.kstars.ekos.focus] - Current HFR: 1.70595 is above required minimum HFR: 0.01 . Starting AutoFocus...
>> [2020-12-10T03:31:25.508 PST INFO ][     org.kde.kstars.ekos.focus] - "Autofocus is already running, discarding start request."
>> [2020-12-10T03:31:25.508 PST INFO ][     org.kde.kstars.ekos.focus] - "Detection complete."
>>
>>

--
-- eric.dejouhanet at gmail.com - https://astronomy.dejouha.net