Hi, last night I ran into a weird situation that I don't fully understand. I left a scheduler job running all night long, that involved refocusing each 50 minutes; also, the target crossed the meridian near 4:00 AM. But after the flip, the job didn't capture any images.
In the kstars (3.5.4) log file (see below), it seems that the refocus and the meridian flip overlapped (things start to mess at 03:54:34): focus module was on its first outward movement when the flip started. It also seems to try to resume guiding during the flip a few times, of course failing. Also, the flip was flagged as failed, but then immediately marked as completed. After the flip, the refocus is not retried; it only started a guiding calibration (that didn't complete?). Nothing more until dawn, when shutdown was executed normally.
Should I open a bug?
Thanks in advance!
Sergio
KStars 3.5.4, INDI 1.9.1 (from PPA)
<code>...
[2021-07-15T03:49:07.973 CEST INFO ][ org.kde.kstars.ekos.capture] - "Capturing 300,000-second O3G image..."
[2021-07-15T03:54:23.334 CEST INFO ][ org.kde.kstars.indi] - MI G2-8300 : "[INFO] Exposure done, downloading image... "
[2021-07-15T03:54:23.650 CEST INFO ][ org.kde.kstars.indi] - MI G2-8300 : "[INFO] Download complete. "
[2021-07-15T03:54:23.657 CEST INFO ][ org.kde.kstars.indi] - "FITS" file saved to "/home/aristarco/datos/NorAmPel_SHO/NorAmPel_SHO/Light/O3G/NorAmPel_SHO_Light_O3G_300_secs_151.fits"
[2021-07-15T03:54:24.296 CEST INFO ][ org.kde.kstars.ekos.capture] - "Download Time: 0.65 s, New Download Time Estimate: 0.84 s."
[2021-07-15T03:54:24.298 CEST INFO ][ org.kde.kstars.ekos.capture] - "Received image 151 out of 200."
[2021-07-15T03:54:24.395 CEST INFO ][ org.kde.kstars.ekos.capture] - Dithering...
[2021-07-15T03:54:24.395 CEST INFO ][ org.kde.kstars.ekos.capture] - "Dithering..."
[2021-07-15T03:54:24.488 CEST INFO ][ org.kde.kstars.ekos.guide] - "Dithering in progress."
[2021-07-15T03:54:24.620 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' 200x300\" O3G sees 151 captures in output folder '/home/aristarco/datos/NorAmPel_SHO/NorAmPel_SHO/Light/O3G'."
[2021-07-15T03:54:24.620 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' 200x300\" O3G requires a dither procedure."
[2021-07-15T03:54:24.622 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' estimated to take 04h 21m 03s to complete."
[2021-07-15T03:54:31.421 CEST INFO ][ org.kde.kstars.ekos.capture] - Dithering succeeded, capture state "Dithering"
[2021-07-15T03:54:31.421 CEST INFO ][ org.kde.kstars.ekos.capture] - "Dithering succeeded."
[2021-07-15T03:54:31.423 CEST INFO ][ org.kde.kstars.ekos.capture] - "Dither complete. Resuming in 3 seconds..."
[2021-07-15T03:54:31.425 CEST INFO ][ org.kde.kstars.ekos.guide] - "Dithering completed successfully."
[2021-07-15T03:54:31.525 CEST INFO ][ org.kde.kstars.ekos.guide] - "Guiding resumed."
[2021-07-15T03:54:34.556 CEST INFO ][ org.kde.kstars.ekos.capture] - "Scheduled refocus starting after 3.285 seconds..."
[2021-07-15T03:54:34.559 CEST INFO ][ org.kde.kstars.ekos.focus] - "Capturing to check HFR..."
[2021-07-15T03:54:34.564 CEST INFO ][ org.kde.kstars.ekos.focus] - "Capturing image..."
[2021-07-15T03:54:42.883 CEST INFO ][ org.kde.kstars.ekos.focus] - "Image received."
[2021-07-15T03:54:42.886 CEST INFO ][ org.kde.kstars.ekos.focus] - "Detecting sources..."
[2021-07-15T03:54:43.018 CEST INFO ][ org.kde.kstars.ekos.focus] - "Detection complete."
[2021-07-15T03:54:43.117 CEST INFO ][ org.kde.kstars.ekos.guide] - "Guiding suspended."
[2021-07-15T03:54:43.119 CEST INFO ][ org.kde.kstars.ekos.focus] - "Focusing outward by 100 steps..."
[2021-07-15T03:54:43.164 CEST INFO ][ org.kde.kstars.indi] - MoonLite : "[INFO] Focuser is moving to position 560 "
[2021-07-15T03:54:52.025 CEST INFO ][ org.kde.kstars.ekos.mount] - "Meridian flip waiting."
[2021-07-15T03:54:52.927 CEST INFO ][ org.kde.kstars.ekos.mount] - Meridian flip: slewing to RA= "20h 55m 40s" DEC= " 43° 55' 20\"" Hour Angle "00h 00m 31s"
[2021-07-15T03:54:52.927 CEST INFO ][ org.kde.kstars.ekos.mount] - "Meridian flip started."
[2021-07-15T03:54:53.122 CEST INFO ][ org.kde.kstars.ekos.guide] - "Guiding resumed."
[2021-07-15T03:54:53.125 CEST INFO ][ org.kde.kstars.ekos.capture] - "Autofocus failed. Aborting exposure..."
[2021-07-15T03:54:53.127 CEST INFO ][ org.kde.kstars.ekos.capture] - "CCD capture aborted"
[2021-07-15T03:54:53.138 CEST INFO ][ org.kde.kstars.ekos.focus] - "Autofocus aborted."
[2021-07-15T03:54:53.236 CEST INFO ][ org.kde.kstars.ekos.guide] - "Mount is moving. Resetting calibration..."
[2021-07-15T03:54:53.238 CEST INFO ][ org.kde.kstars.ekos.guide] - "Calibration is cleared."
[2021-07-15T03:54:53.240 CEST INFO ][ org.kde.kstars.ekos.guide] - "Mount is slewing. Aborting guide..."
[2021-07-15T03:54:53.336 CEST INFO ][ org.kde.kstars.ekos.guide] - "Autoguiding aborted."
[2021-07-15T03:54:53.338 CEST INFO ][ org.kde.kstars.ekos.mount] - "Meridian flip slew started..."
[2021-07-15T03:54:53.341 CEST INFO ][ org.kde.kstars.indi] - MI G2-8300 : "[INFO] Exposure aborted. "
[2021-07-15T03:54:53.435 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Warning: job 'NorAmPel_SHO' failed to capture target."
[2021-07-15T03:54:53.437 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' is capturing, is restarting its guiding procedure (attempt #1 of 5)."
[2021-07-15T03:54:53.440 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Starting guiding procedure for NorAmPel_SHO ..."
[2021-07-15T03:54:53.442 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Starting Goto RA=20.9279 DE=43.9223 (current RA=20.894 DE=42.9016) "
[2021-07-15T03:54:53.442 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] GOTO ALign Nearest: delta RA = -0.030205, delta DEC = -0.969358 "
[2021-07-15T03:54:53.443 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Aligned Eqmod Goto RA=20.8977 DE=42.9529 (target RA=20.9279 DE=43.9223) "
[2021-07-15T03:54:53.443 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Setting Eqmod Goto RA=20.8977 DE=42.9529 (target RA=20.9279 DE=43.9223) "
[2021-07-15T03:54:53.444 CEST INFO ][ org.kde.kstars.indi] - MI G2-8300 : "[INFO] Exposure aborted. "
[2021-07-15T03:54:53.445 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Warning: job 'NorAmPel_SHO' guiding failed."
[2021-07-15T03:54:53.446 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' is guiding, guiding procedure will be restarted in 5 seconds."
[2021-07-15T03:54:53.448 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Slewing mount: RA increment = -4609364, DE increment = 2410125 "
[2021-07-15T03:54:53.573 CEST INFO ][ org.kde.kstars.ekos.guide] - "Calibration is cleared."
[2021-07-15T03:54:53.576 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Slewing to RA: 20:55:40 - DEC: 43:55:20 "
[2021-07-15T03:54:55.718 CEST INFO ][ org.kde.kstars.ekos.guide] - "Auto star selected."
[2021-07-15T03:54:55.842 CEST INFO ][ org.kde.kstars.ekos.guide] - "Calibration started."
[2021-07-15T03:54:55.844 CEST INFO ][ org.kde.kstars.ekos.guide] - "RA drifting forward..."
[2021-07-15T03:54:55.849 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Start Tracking (Sidereal). "
[2021-07-15T03:54:55.849 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[WARNING] Warning: Invalid parameter -> Can not change rate while motor is running (speedmode differs). "
[2021-07-15T03:54:57.124 CEST WARN ][ org.kde.kstars.ekos.mount] - Meridian flip failed, pier side not changed
[2021-07-15T03:54:57.124 CEST INFO ][ org.kde.kstars.ekos.mount] - "meridian flip failed, retrying in 4 minutes"
[2021-07-15T03:54:57.126 CEST INFO ][ org.kde.kstars.ekos.mount] - "Meridian flip completed."
[2021-07-15T03:54:57.222 CEST INFO ][ org.kde.kstars.ekos.capture] - "Telescope completed the meridian flip."
[2021-07-15T03:54:57.512 CEST INFO ][ org.kde.kstars.indi] - MoonLite : "[INFO] Focuser reached requested position. "
[2021-07-15T03:54:58.522 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Starting guiding procedure for NorAmPel_SHO ..."
[2021-07-15T03:54:58.525 CEST INFO ][ org.kde.kstars.ekos.guide] - "Calibration is cleared."
[2021-07-15T03:55:00.417 CEST INFO ][ org.kde.kstars.ekos.guide] - "Auto star selected."
[2021-07-15T03:55:00.502 CEST INFO ][ org.kde.kstars.ekos.guide] - "RA drifting reverse..."
[2021-07-15T03:55:39.038 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Iterative Goto (1): RA diff = 45.32 arcsecs DE diff = 0.00 arcsecs "
[2021-07-15T03:55:39.039 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Iterative goto (1): slew mount to RA increment = 4845, DE increment = 0 "
[2021-07-15T03:55:40.282 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Iterative Goto (2): RA diff = 1.14 arcsecs DE diff = 0.00 arcsecs "
[2021-07-15T03:55:40.410 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Telescope slew is complete. Tracking TRACK_SIDEREAL... "
[2021-07-15T05:25:13.426 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' is now approaching astronomical twilight rise limit at jue. jul. 15 05:25:11 2021 (0 minutes safety margin), marking idle."
[2021-07-15T05:25:13.479 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' is stopping guiding..."
[2021-07-15T05:25:13.479 CEST INFO ][ org.kde.kstars.ekos.guide] - "Autoguiding aborted."
[2021-07-15T05:25:14.461 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' 200x300\" O3G sees 151 captures in output folder '/home/aristarco/datos/NorAmPel_SHO/NorAmPel_SHO/Light/O3G'."
[2021-07-15T05:25:14.461 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' 200x300\" O3G requires a dither procedure."
[2021-07-15T05:25:14.463 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' estimated to take 04h 21m 03s to complete."
[2021-07-15T05:25:14.464 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Option to sort jobs based on priority and altitude is false
[2021-07-15T05:25:14.522 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' has a total score of -1000 at 15/07 05:25."
[2021-07-15T05:25:14.524 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' has a total score of -1000 at 15/07 05:25."
[2021-07-15T05:25:15.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'NorAmPel_SHO' scheduled for execution at 15/07 23:21. Observatory scheduled for shutdown until next job is ready."
[2021-07-15T05:25:15.431 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Starting shutdown process...
[2021-07-15T05:25:15.431 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Warming up CCD..."
[2021-07-15T05:25:15.440 CEST INFO ][ org.kde.kstars.ekos.capture] - "Cooler is off"
[2021-07-15T05:25:16.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - "Parking mount in progress..."
[2021-07-15T05:25:16.596 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Parking mount: RA increment = 1662613, DE increment = -1204405 "
[2021-07-15T05:25:16.884 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Mount park in progress... "
[2021-07-15T05:25:17.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:18.063 CEST INFO ][ org.kde.kstars.ekos.guide] - "Mount is moving. Resetting calibration..."
[2021-07-15T05:25:18.065 CEST INFO ][ org.kde.kstars.ekos.guide] - "Calibration is cleared."
[2021-07-15T05:25:18.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:19.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:20.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:21.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:22.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:23.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:24.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:25.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:26.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:27.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:28.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:29.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:30.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:31.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:32.428 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:33.427 CEST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2021-07-15T05:25:34.029 CEST INFO ][ org.kde.kstars.indi] - EQMod Mount : "[INFO] Mount is parked. "</code>