×

INDI Library v2.0.6 is Released (02 Feb 2024)

Bi-monthly release with minor bug fixes and improvements

Ekos Scheduler On At Bug Marking aborted

Stable was updated, please check now.
5 years 2 months ago #33480

Please Log in or Create an account to join the conversation.

  • Posts: 19
  • Thank you received: 3
Too late...i’m now with the 3.1 ;)
Great job and thanks for this fix !
The scheduler is a great function of ekos.

Frank
5 years 2 months ago #33481

Please Log in or Create an account to join the conversation.

  • Posts: 1957
  • Thank you received: 420

I tried to update KStars (and all of Ubuntu 18.04) on my Odroid-XU4 (armv7l) and mini-PC (x86_64) but neither get an updated KStars. I am on stable, not nightly. Have I misunderstood something? KStars 3.1 hasn’t been released yet, has it?
5 years 2 months ago #33491

Please Log in or Create an account to join the conversation.

  • Posts: 19
  • Thank you received: 3
exact wvreeven, the stable is 3.0 but nightly is 3.1
works great on my config
top !

Frank
5 years 2 months ago #33495

Please Log in or Create an account to join the conversation.

  • Posts: 3
  • Thank you received: 1
It looks like the original bug is still there, but being exposed later in the schedule chain. For the last 2 nights, with the last 2 nightlies (30.0.0.40.5 and prior), I have loaded in schedules and let them run. Instead of aborting all jobs at the start, it now aborts the jobs when the scheduler gets to the start time of the job and then calls it invalid and aborts. I assume that this is related to the original bug?
8RC - iOptron CEM60 - ZWO ASI1600MM-C
INDI on RPi 3B
KStars on x86_64 with PHD2
The following user(s) said Thank You: Eric
5 years 2 months ago #34088

Please Log in or Create an account to join the conversation.

  • Posts: 1029
  • Thank you received: 301
@ISEE It would be interesting to have logs in that case. I tried to reproduce the issue with the simulators, to no avail for now.
But I think it has to do with a drift in the planning. Something you could check is whether your jobs end progressively closer to the startup of their next siblings. In that case, increase the lead time in the Ekos options so that there is more room for accessory tasks such as slewing, aligning and focusing.
Scheduler will able to learn how long those tasks take by monitoring their duration over sessions, but for now it's pretty dumb (and undocumented) on that subject.
-Eric

EDIT: This said, I reproduced the "proceeding directly to capture" issue, so I'll continue trying yours.
Last edit: 5 years 2 months ago by Eric.
5 years 2 months ago #34099

Please Log in or Create an account to join the conversation.

  • Posts: 3
  • Thank you received: 1
There was only a single job when it failed, but the night before I had other jobs fail (marked invalid) because they where only a few seconds apart even though the lead time setting was set to 0.00s. There shouldn't have been any overlap but the scheduler still invalidated them.
Two nights ago a loaded several jobs from XML, most were marked as invalid due to time (correctly), 1 was marked invalid due to time overlap (incorrectly), and the final jobs actually ran correctly, so this bug doesn't seem to happen everytime, but Im not sure why.

Here is the relevant part of the log:
[2019-01-24T22:02:26.304 PST INFO ][ org.kde.kstars.ekos.scheduler] - Ekos finished evaluating jobs, no job selection required.
[2019-01-24T22:02:26.304 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Scheduler started.
[2019-01-24T22:02:27.255 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking Park Wait State...
[2019-01-24T22:02:27.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Frame map summary:
[2019-01-24T22:02:27.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Blue/2x2_-10C_Light_Blue_60_secs" : 0
[2019-01-24T22:02:27.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Green/2x2_-10C_Light_Green_60_secs" : 0
[2019-01-24T22:02:27.258 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Lum/2x2_-10C_Light_Lum_30_secs" : 0
[2019-01-24T22:02:27.258 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Red/2x2_-10C_Light_Red_60_secs" : 0
[2019-01-24T22:02:27.276 PST INFO ][ org.kde.kstars.ekos.scheduler] - Option to sort jobs based on priority and altitude is true
[2019-01-24T22:02:27.277 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Schedule attempt #1 for 13500-second job 'M 42_2019-01-24' on row #1 starting at 24/01/19 23:45, completing at 25/01/19 03:30."
[2019-01-24T22:02:27.277 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' altitude score is +20 at 24/01/19 22:02"
[2019-01-24T22:02:27.278 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' Moon separation score is +0 at 24/01/19 22:02"
[2019-01-24T22:02:27.278 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' has a total score of +20 at 24/01/19 22:02."
[2019-01-24T22:02:27.280 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' is scheduled to start at 24/01/19 23:45, in compliance with fixed startup time requirement."
[2019-01-24T22:02:27.280 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' is selected for next observation with priority #10 and score 20."
[2019-01-24T22:02:28.247 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' scheduled for execution at 24/01/19 23:45. Observatory scheduled for shutdown until next job is ready."
[2019-01-24T22:02:28.250 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:28.250 PST INFO ][ org.kde.kstars.ekos.scheduler] - Starting shutdown process...
[2019-01-24T22:02:28.250 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Warming up CCD..."
[2019-01-24T22:02:28.285 PST INFO ][ org.kde.kstars.ekos.capture] - "Cooler is off"
[2019-01-24T22:02:29.247 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:29.247 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Parking mount in progress..."
[2019-01-24T22:02:29.672 PST INFO ][ org.kde.kstars.indi] - iEQ : "[INFO] Telescope parking in progress to RA: 10:28:50 DEC: 90:00:00 "
[2019-01-24T22:02:30.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:30.247 PST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2019-01-24T22:02:31.253 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
...
[2019-01-24T22:02:50.247 PST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2019-01-24T22:02:51.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:51.246 PST INFO ][ org.kde.kstars.ekos.scheduler] - Parking mount in progress...
[2019-01-24T22:02:51.577 PST INFO ][ org.kde.kstars.indi] - iEQ : "[INFO] Mount is parked. "
[2019-01-24T22:02:52.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:52.246 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Mount parked."
[2019-01-24T22:02:53.247 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:54.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T22:02:55.246 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Shutdown complete."
[2019-01-24T22:02:55.248 PST INFO ][ org.kde.kstars.ekos.scheduler] - Scheduler is stopping...
[2019-01-24T23:45:01.247 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Scheduler is awake."
[2019-01-24T23:45:01.249 PST INFO ][ org.kde.kstars.ekos.scheduler] - Scheduler is starting...
[2019-01-24T23:45:01.256 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum', files '2x2_-10C_Light_Lum_30_secs*' for prefix '2x2_-10C_Light_Lum_30_secs'..."
[2019-01-24T23:45:01.256 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Red', files '2x2_-10C_Light_Red_60_secs*' for prefix '2x2_-10C_Light_Red_60_secs'..."
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Green', files '2x2_-10C_Light_Green_60_secs*' for prefix '2x2_-10C_Light_Green_60_secs'..."
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Blue', files '2x2_-10C_Light_Blue_60_secs*' for prefix '2x2_-10C_Light_Blue_60_secs'..."
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Frame map summary:
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Blue/2x2_-10C_Light_Blue_60_secs" : 0
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Green/2x2_-10C_Light_Green_60_secs" : 0
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Lum/2x2_-10C_Light_Lum_30_secs" : 0
[2019-01-24T23:45:01.257 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Red/2x2_-10C_Light_Red_60_secs" : 0
[2019-01-24T23:45:01.259 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum', files '2x2_-10C_Light_Lum_30_secs*' for prefix '2x2_-10C_Light_Lum_30_secs'..."
[2019-01-24T23:45:01.259 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Red', files '2x2_-10C_Light_Red_60_secs*' for prefix '2x2_-10C_Light_Red_60_secs'..."
[2019-01-24T23:45:01.259 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Green', files '2x2_-10C_Light_Green_60_secs*' for prefix '2x2_-10C_Light_Green_60_secs'..."
[2019-01-24T23:45:01.259 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/var/mas/astro/FITS/M42_2019-01-24/Light/Blue', files '2x2_-10C_Light_Blue_60_secs*' for prefix '2x2_-10C_Light_Blue_60_secs'..."
[2019-01-24T23:45:01.259 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Frame map summary:
[2019-01-24T23:45:01.260 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Blue/2x2_-10C_Light_Blue_60_secs" : 0
[2019-01-24T23:45:01.260 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Green/2x2_-10C_Light_Green_60_secs" : 0
[2019-01-24T23:45:01.260 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Lum/2x2_-10C_Light_Lum_30_secs" : 0
[2019-01-24T23:45:01.260 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Red/2x2_-10C_Light_Red_60_secs" : 0
[2019-01-24T23:45:01.278 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x30\" sees 0 captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum'."
[2019-01-24T23:45:01.278 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x30\" has completed 0/30 of its required captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum'."
[2019-01-24T23:45:01.278 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x30\" sees 0 captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum'."
[2019-01-24T23:45:01.278 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x30\" has completed 0/30 of its required captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x30\" sees 0 captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x30\" has completed 0/30 of its required captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Lum'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x60\" sees 0 captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Red'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x60\" has completed 0/30 of its required captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Red'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x60\" sees 0 captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Green'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x60\" has completed 0/30 of its required captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Green'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x60\" sees 0 captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Blue'."
[2019-01-24T23:45:01.279 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' 1x60\" has completed 0/30 of its required captures in output folder '/var/mas/astro/FITS/M42_2019-01-24/Light/Blue'."
[2019-01-24T23:45:01.281 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'M 42_2019-01-24' estimated to take 03h 45m 00s to complete."
[2019-01-24T23:45:01.282 PST INFO ][ org.kde.kstars.ekos.scheduler] - Option to sort jobs based on priority and altitude is true
[2019-01-24T23:45:01.282 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "Schedule attempt #1 for 13500-second job 'M 42_2019-01-24' on row #1 starting at 24/01/19 23:45, completing at 25/01/19 03:30."
[2019-01-24T23:45:01.285 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Warning: job 'M 42_2019-01-24' has fixed startup time 24/01/19 23:45 set in the past, marking invalid."
[2019-01-24T23:45:01.285 PST INFO ][ org.kde.kstars.ekos.scheduler] - Ekos finished evaluating jobs, no job selection required.
[2019-01-24T23:45:01.286 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Scheduler started.
[2019-01-24T23:45:02.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking Park Wait State...
[2019-01-24T23:45:02.248 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Frame map summary:
[2019-01-24T23:45:02.248 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Blue/2x2_-10C_Light_Blue_60_secs" : 0
[2019-01-24T23:45:02.248 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Green/2x2_-10C_Light_Green_60_secs" : 0
[2019-01-24T23:45:02.248 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Lum/2x2_-10C_Light_Lum_30_secs" : 0
[2019-01-24T23:45:02.248 PST DEBG ][ org.kde.kstars.ekos.scheduler] - "/var/mas/astro/FITS/M42_2019-01-24/Light/Red/2x2_-10C_Light_Red_60_secs" : 0
[2019-01-24T23:45:02.264 PST INFO ][ org.kde.kstars.ekos.scheduler] - "No jobs left in the scheduler queue."
[2019-01-24T23:45:02.267 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T23:45:02.267 PST INFO ][ org.kde.kstars.ekos.scheduler] - Starting shutdown process...
[2019-01-24T23:45:02.267 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Warming up CCD..."
[2019-01-24T23:45:02.286 PST INFO ][ org.kde.kstars.ekos.capture] - "Cooler is off"
[2019-01-24T23:45:03.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T23:45:03.246 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Mount already parked."
[2019-01-24T23:45:04.246 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T23:45:05.247 PST DEBG ][ org.kde.kstars.ekos.scheduler] - Checking shutdown state...
[2019-01-24T23:45:06.246 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Shutdown complete."
[2019-01-24T23:45:06.248 PST INFO ][ org.kde.kstars.ekos.scheduler] - Scheduler is stopping...
[2019-01-25T10:06:22.624 PST INFO ][ org.kde.kstars.ekos.guide] - "PHD2: Disconnecting Equipment. . ."
[2019-01-25T10:06:22.627 PST INFO ][ org.kde.kstars.ekos.guide] - "External guider disconnected."
8RC - iOptron CEM60 - ZWO ASI1600MM-C
INDI on RPi 3B
KStars on x86_64 with PHD2
5 years 2 months ago #34103

Please Log in or Create an account to join the conversation.

  • Posts: 1029
  • Thank you received: 301
@Isee From what I see in the log, the day at which the job should start is Jan 19, but the current date is Jan 24.

[2019-01-24T23:45:01.285 PST INFO ][ org.kde.kstars.ekos.scheduler] - "Warning: job 'M 42_2019-01-24' has fixed startup time 24/01/19 23:45 set in the past, marking invalid."

I agree that part is not user-friendly. At all. The reminder for this should either be clearer in the plan, or there should be an option to disregard the date and keep only the time.
I'll see what I can do, thanks for reporting this.

-Eric

EDIT: Now that was a ridiculous attempt at finding an issue at all costs. That's what I get for going through things too fast. @wvreeven Thanks!!
Last edit: 5 years 2 months ago by Eric.
5 years 2 months ago #34122

Please Log in or Create an account to join the conversation.

  • Posts: 1957
  • Thank you received: 420
I could be wrong but doesn’t 24/01/19 mean January 24, 2019?


Wouter
The following user(s) said Thank You: Eric
5 years 2 months ago #34124

Please Log in or Create an account to join the conversation.

  • Posts: 1029
  • Thank you received: 301
@Isee I had a look (quietly this time) at the code responsible for the log and the action marking the job invalid. Basically, the code does "if ( StartupTime + LeadTime < now ) then markJobInvalid".
So here's the problem. When the considered job is the first of the list, it will start one second after its startup time. Thus will immediately be marked invalid if the lead time is less than one second.
You should be able to work around the issue by relaxing the lead time, but this is assuredly a bug, which I'll push an update for.

-Eric
5 years 2 months ago #34126

Please Log in or Create an account to join the conversation.

Time to create page: 0.774 seconds