Thanks. Well I'm glad I'm not missing anything. That's exactly where I thought the logs should be but they aren't there. I tried it on my Mac and the logs get saved there but the simulator CCD doesn't show any stars so I can't reproduce the hang-up.

I get the following message no matter where I slew the simulator....

"Got no stars, is gsc installed with appropriate environment variables set ??"

GSC is an additional package containing the Guide Star Catalog with stars down to magnitude 12 or even a bit fainter. You need to install that to be able to "take pictures" with the camera simulators.

Okay, finally got some logs. Below is the last capture right before auto-focus started. I ended the session after the 4th or 5th focus step. I also examined the focus fits saved and they are all the same exact image (the last focus image taken from the previous focus routine). I also, attached the entire log file.

[2020-04-13T15:41:08.704 CDT INFO ][ org.kde.kstars.ekos.capture] - "Received image 2 out of 4."
[2020-04-13T15:41:08.722 CDT INFO ][ org.kde.kstars.ekos.capture] - "Scheduled refocus starting after 129 seconds..."
[2020-04-13T15:41:08.736 CDT DEBG ][ org.kde.kstars.ekos.focus] - Check Focus requested with minimum required HFR 0.1
[2020-04-13T15:41:08.736 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:08.779 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.871557 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:13.746 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Uploading file. Ext: fits, Size: 662400, sendImage? Yes, saveImage? No "
[2020-04-13T15:41:13.749 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] BLOB transfer took 0.00257745 seconds "
[2020-04-13T15:41:13.750 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Upload complete "
[2020-04-13T15:41:13.752 CDT DEBG ][ org.kde.kstars.indi] - processBLOB() mode 1
[2020-04-13T15:41:13.753 CDT INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2020-04-13T15:41:13.767 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR 1.18882 Num stars 7
[2020-04-13T15:41:13.767 CDT DEBG ][ org.kde.kstars.ekos.focus] - Current HFR: 1.18882 is above required minimum HFR: 0.1 . Starting AutoFocus...
[2020-04-13T15:41:13.782 CDT DEBG ][ org.kde.kstars.ekos.focus] - Starting focus with box size: 64 Subframe: no Autostar: no Full frame: yes [ 0 %, 100 %] Step Size: 4000 Threshold: 150 Tolerance: 5 Frames: 1 Maximum Travel: 40000
[2020-04-13T15:41:13.782 CDT INFO ][ org.kde.kstars.ekos.focus] - "Please wait until image capture is complete..."
[2020-04-13T15:41:13.795 CDT DEBG ][ org.kde.kstars.ekos.focus] - State: "In Progress"
[2020-04-13T15:41:13.795 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: v3.2. 1st pass. Travel 40000 initStep 4000 pos 40849 min 0 max 100000 maxIters 30 tolerance 0.05 minlimit 849 maxlimit 80849"
[2020-04-13T15:41:13.795 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: initialPosition 60849 sized 4000"
[2020-04-13T15:41:13.796 CDT DEBG ][ org.kde.kstars.ekos.focus] - "LinearFocuser: extending outward movement by 20000"
[2020-04-13T15:41:13.796 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "outward" ( 40000 )
[2020-04-13T15:41:13.796 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing outward by 40000 steps..."
[2020-04-13T15:41:17.802 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:17.804 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 80849 "
[2020-04-13T15:41:17.804 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:17.804 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 80849"
[2020-04-13T15:41:17.804 CDT DEBG ][ org.kde.kstars.ekos.focus] - "LinearFocuser: un-doing extension. Moving back in by 20000"
[2020-04-13T15:41:17.804 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "inward" ( 20000 )
[2020-04-13T15:41:17.805 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing inward by 20000 steps..."
[2020-04-13T15:41:19.811 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:19.813 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 60849 "
[2020-04-13T15:41:19.813 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:19.813 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 60849"
[2020-04-13T15:41:19.847 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:19.876 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.871159 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:24.856 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Uploading file. Ext: fits, Size: 662400, sendImage? Yes, saveImage? No "
[2020-04-13T15:41:24.859 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] BLOB transfer took 0.00201632 seconds "
[2020-04-13T15:41:24.859 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Upload complete "
[2020-04-13T15:41:24.861 CDT DEBG ][ org.kde.kstars.indi] - processBLOB() mode 1
[2020-04-13T15:41:24.861 CDT INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2020-04-13T15:41:24.873 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR 1.18882 Num stars 7
[2020-04-13T15:41:24.880 CDT INFO ][ org.kde.kstars.fits] - Saved FITS file: "/Users/wesleycreech/Library/Application Support/kstars/autofocus/2020-04-13/autofocus_frame_15-41-23.fits"
[2020-04-13T15:41:24.883 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: step 1, newMeasurement(60849, 1.18882)"
[2020-04-13T15:41:24.884 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: requesting position 56849"
[2020-04-13T15:41:24.884 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "inward" ( 4000 )
[2020-04-13T15:41:24.884 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing inward by 4000 steps..."
[2020-04-13T15:41:25.287 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:25.288 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 56849 "
[2020-04-13T15:41:25.288 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:25.288 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 56849"
[2020-04-13T15:41:25.326 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:25.354 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.870932 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:30.360 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Uploading file. Ext: fits, Size: 662400, sendImage? Yes, saveImage? No "
[2020-04-13T15:41:30.360 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] BLOB transfer took 0.00249979 seconds "
[2020-04-13T15:41:30.361 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Upload complete "
[2020-04-13T15:41:30.362 CDT DEBG ][ org.kde.kstars.indi] - processBLOB() mode 1
[2020-04-13T15:41:30.363 CDT INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2020-04-13T15:41:30.384 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR 1.18882 Num stars 7
[2020-04-13T15:41:30.390 CDT INFO ][ org.kde.kstars.fits] - Saved FITS file: "/Users/wesleycreech/Library/Application Support/kstars/autofocus/2020-04-13/autofocus_frame_15-41-28.fits"
[2020-04-13T15:41:30.393 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: step 2, newMeasurement(56849, 1.18882)"
[2020-04-13T15:41:30.393 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: requesting position 52849"
[2020-04-13T15:41:30.393 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "inward" ( 4000 )
[2020-04-13T15:41:30.394 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing inward by 4000 steps..."
[2020-04-13T15:41:30.797 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:30.798 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 52849 "
[2020-04-13T15:41:30.799 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:30.799 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 52849"
[2020-04-13T15:41:30.828 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:30.861 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.870738 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:35.839 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Uploading file. Ext: fits, Size: 662400, sendImage? Yes, saveImage? No "
[2020-04-13T15:41:35.842 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] BLOB transfer took 0.00203293 seconds "
[2020-04-13T15:41:35.843 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Upload complete "
[2020-04-13T15:41:35.843 CDT DEBG ][ org.kde.kstars.indi] - processBLOB() mode 1
[2020-04-13T15:41:35.844 CDT INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2020-04-13T15:41:35.855 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR 1.18882 Num stars 7
[2020-04-13T15:41:35.861 CDT INFO ][ org.kde.kstars.fits] - Saved FITS file: "/Users/wesleycreech/Library/Application Support/kstars/autofocus/2020-04-13/autofocus_frame_15-41-34.fits"
[2020-04-13T15:41:35.865 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: step 3, newMeasurement(52849, 1.18882)"
[2020-04-13T15:41:35.865 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: requesting position 48849"
[2020-04-13T15:41:35.865 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "inward" ( 4000 )
[2020-04-13T15:41:35.866 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing inward by 4000 steps..."
[2020-04-13T15:41:36.269 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:36.270 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 48849 "
[2020-04-13T15:41:36.272 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:36.276 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 48849"
[2020-04-13T15:41:36.308 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:36.343 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.870502 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:41.319 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Uploading file. Ext: fits, Size: 662400, sendImage? Yes, saveImage? No "
[2020-04-13T15:41:41.322 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] BLOB transfer took 0.00204327 seconds "
[2020-04-13T15:41:41.322 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Upload complete "
[2020-04-13T15:41:41.323 CDT DEBG ][ org.kde.kstars.indi] - processBLOB() mode 1
[2020-04-13T15:41:41.324 CDT INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2020-04-13T15:41:41.336 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR 1.18882 Num stars 7
[2020-04-13T15:41:41.341 CDT INFO ][ org.kde.kstars.fits] - Saved FITS file: "/Users/wesleycreech/Library/Application Support/kstars/autofocus/2020-04-13/autofocus_frame_15-41-39.fits"
[2020-04-13T15:41:41.345 CDT WARN ][ org.kde.kstars.ekos.focus] - Focus GSL error: invalid argument supplied by user
[2020-04-13T15:41:41.348 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: step 4, newMeasurement(48849, 1.18882)"
[2020-04-13T15:41:41.349 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: requesting position 44849"
[2020-04-13T15:41:41.349 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "inward" ( 4000 )
[2020-04-13T15:41:41.349 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing inward by 4000 steps..."
[2020-04-13T15:41:41.776 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:41.777 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 44849 "
[2020-04-13T15:41:41.777 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:41.778 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 44849"
[2020-04-13T15:41:41.812 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:41.844 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.870304 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:46.833 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Uploading file. Ext: fits, Size: 662400, sendImage? Yes, saveImage? No "
[2020-04-13T15:41:46.833 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] BLOB transfer took 0.00246166 seconds "
[2020-04-13T15:41:46.834 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] Upload complete "
[2020-04-13T15:41:46.835 CDT DEBG ][ org.kde.kstars.indi] - processBLOB() mode 1
[2020-04-13T15:41:46.835 CDT INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2020-04-13T15:41:46.857 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus newFITS # 1 : Current HFR 1.18882 Num stars 7
[2020-04-13T15:41:46.863 CDT INFO ][ org.kde.kstars.fits] - Saved FITS file: "/Users/wesleycreech/Library/Application Support/kstars/autofocus/2020-04-13/autofocus_frame_15-41-45.fits"
[2020-04-13T15:41:46.873 CDT WARN ][ org.kde.kstars.ekos.focus] - Focus GSL error: invalid argument supplied by user
[2020-04-13T15:41:46.878 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: step 5, newMeasurement(44849, 1.18882)"
[2020-04-13T15:41:46.878 CDT WARN ][ org.kde.kstars.ekos.focus] - Focus GSL error: invalid argument supplied by user
[2020-04-13T15:41:46.878 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: ******** No poly min: Poly must be inverted"
[2020-04-13T15:41:46.878 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Linear: requesting position 40849"
[2020-04-13T15:41:46.878 CDT DEBG ][ org.kde.kstars.ekos.focus] - Focus "inward" ( 4000 )
[2020-04-13T15:41:46.878 CDT INFO ][ org.kde.kstars.ekos.focus] - "Focusing inward by 4000 steps..."
[2020-04-13T15:41:47.284 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber FWHM ERROR"
[2020-04-13T15:41:47.287 CDT INFO ][ org.kde.kstars.indi] - Focuser Simulator : "[INFO] Focuser moved to position 40849 "
[2020-04-13T15:41:47.287 CDT DEBG ][ org.kde.kstars.ekos.focus] - "processFocusNumber ABS_FOCUS_POSITION OK"
[2020-04-13T15:41:47.287 CDT DEBG ][ org.kde.kstars.ekos.focus] - "Abs Focuser position changed to 40849"
[2020-04-13T15:41:47.309 CDT INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2020-04-13T15:41:47.343 CDT DEBG ][ org.kde.kstars.indi] - CCD Simulator : "[DEBUG] GSC Command: gsc -c 179.870064 -89.887077 -r 19.2 -m 0 17.00 -n 3000 "
[2020-04-13T15:41:47.375 CDT DEBG ][ org.kde.kstars.ekos.focus] - AutoFocus result: false
[2020-04-13T15:41:47.376 CDT DEBG ][ org.kde.kstars.ekos.focus] - Stopping Focus
[2020-04-13T15:41:47.376 CDT DEBG ][ org.kde.kstars.ekos.focus] - State: "Aborted"
[2020-04-13T15:41:47.415 CDT DEBG ][ org.kde.kstars.ekos.focus] - State: "Failed"
[2020-04-13T15:41:47.415 CDT INFO ][ org.kde.kstars.ekos.capture] - "Autofocus failed. Aborting exposure..."
[2020-04-13T15:41:47.432 CDT INFO ][ org.kde.kstars.ekos.capture] - "CCD capture aborted"

Has anyone found any work around for this issue? Seems like a pretty large problem. This is a big reason I use Ekos, to be automated. Are we still waiting on a fix on the next stable release?

To my best of knowledge nobody knows what is causing this. The workaround (at least for now until somebody figures this out) is to either manually focus occasionally or schedule your jobs such that in between jobs the focuser runs.


Wouter

Any ways to reliably reproduce this? I cannot see it with any driver.

Wouter and/or Wes,

Just to clarify, my understanding is that this issue only comes up with the "focus every N minutes" checkbox checked.
For those using filters, a good workaround is to use the autofocus-on-filter-change strategy, where as far as I know, no-one has had this issue.
As Wouter mentioned, if that's not possible, and this is affecting you, another workaround is to have a series of short (e.g. 1-hour long) scheduler jobs with refocus at the start of the jobs.

FYI, I have also looked into this, when Wouter mentioned it to me privately, but unfortunately I haven't been unable to reproduce it either.

Hy

Yes, I can reproduce it every time with simulator drivers and with my devices. Let me know how I can help find the issue. I’ll do anything to try to help fix this.


Sent from my iPhone using Tapatalk

What exactly settings are you using? What steps to take? on what platform?

I first noticed it on 1.5.1 StellarMate OS when I updated to KStars 3.4.1 (stable release). but it happens on KStars 3.4.1 on my Mac OS as well. I start up KStars/Ekos, connect simulators/drivers, run auto-focus by manually pressing the AF button in the focus module (Linear/iterative or poly, doesn't matter which), set up 2 o 3 60 second exposures and set the sequence to re-focus every minute in order to save time but this interval doesn't seem to matter.

EDIT: I just tried to run the sequence while skipping the first "manual" auto-focus routine and it crashes KStars every time. Logs attached.

The issue that I am talking about is for when the "Refocus every ... minutes" option is enabled. I usually first execute an auto-focus manually before starting to image. When then during a sequence an auto-focus is triggered because of the "Refocus every ... minutes" option, it will always use the last image of the manual auto-focus run. Logs that show this were attached to this comment:

indilib.org/forum/ekos/6674-scheduled-re...s-failing.html#51358


Wouter