Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Take into account execution times of jobstores, executors and events … #754

Closed
wants to merge 4 commits into from

Conversation

kbasten
Copy link

@kbasten kbasten commented Jul 12, 2023

…when determining next wakeup time

Whenever a jobstore, executor or event takes a while to run, the next wakeup time is calculated incorrectly. This can lead to missed jobs, as in the example below:

12-07-2023 00:30:19 DEBUG Looking for jobs to run
12-07-2023 00:30:19 INFO Running job "job1 (trigger: interval[0:15:00], next run at: 2023-07-12 00:45:19 CEST)" (scheduled at 2023-07-12 00:30:19.283364+02:00)
12-07-2023 00:31:14 DEBUG Next wakeup is due at 2023-07-12 00:31:12.973193+02:00 (in 53.519473 seconds)
12-07-2023 00:31:14 INFO Job "job1 (trigger: interval[0:15:00], next run at: 2023-07-12 00:45:19 CEST)" executed successfully
12-07-2023 00:32:07 DEBUG Looking for jobs to run
12-07-2023 00:32:07 WARNING Run time of job "job2 (trigger: interval[0:05:00], next run at: 2023-07-12 00:36:12 CEST)" was missed by 0:00:54.633316

This is fixed by calculating the next wakeup time using the current datetime, not the datetime at the start of the execution.

@agronholm
Copy link
Owner

I'm willing to accommodate this change, but I would need at least an additional test that verifies that this fixes the problem.

@kbasten
Copy link
Author

kbasten commented Jul 12, 2023

Good, I will figure out how to write a test for this soon. Here is an example that misses jobs in the current version:

    def tick():
        print('Tick! The time is: %s' % datetime.now())


    def mk_slow_listener(execution_time_seconds):
        def slow_listener(event):
            print("Start slow event")
            time.sleep(execution_time_seconds)
            print("End slow event")

        return slow_listener


    job_interval = 10
    misfire_grace_time = 1

    logging.getLogger('apscheduler').setLevel(logging.DEBUG)
    scheduler = BackgroundScheduler()

    # add a listener that takes longer than the misfire grace time:
    scheduler.add_listener(mk_slow_listener(misfire_grace_time + 1), EVENT_JOB_SUBMITTED)

    scheduler.add_job(tick, 'interval', seconds=job_interval, misfire_grace_time=misfire_grace_time)
    scheduler.start()

    print('Press Ctrl+{0} to exit'.format('Break' if os.name == 'nt' else 'C'))

    try:
        # This is here to simulate application activity (which keeps the main thread alive).
        while True:
            input(">")
    except (KeyboardInterrupt, SystemExit):
        # Not strictly necessary if daemonic mode is enabled but should be done if possible
        scheduler.shutdown()

agronholm added a commit that referenced this pull request Aug 12, 2023
@agronholm
Copy link
Owner

I pushed a single commit with both this fix and a changelog entry where I give you credit. Thanks.

@agronholm agronholm closed this Aug 12, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants