APScheduler Job not running after restart

Question

I trying the MongoJobStore example of APS. The example code is:

import logging
import os
import sys
from datetime import datetime, timedelta

from apscheduler.schedulers.blocking import BlockingScheduler

logging.basicConfig()


def alarm(time):
    print('Alarm! This alarm was scheduled at %s.' % time)


if __name__ == '__main__':
    scheduler = BlockingScheduler()
    scheduler.add_jobstore('mongodb', collection='example_jobs', host='192.168.0.108', port=27017)

    if len(sys.argv) > 1 and sys.argv[1] == '--clear':
        scheduler.remove_all_jobs()

    alarm_time = datetime.now() + timedelta(seconds=10)
    # scheduler.add_job(alarm, 'date', run_date=alarm_time, args=[datetime.now()], id="la")
    print('To clear the alarms, run this example with the --clear argument.')
    print('Press Ctrl+{0} to exit'.format('Break' if os.name == 'nt' else 'C'))

    scheduler.start()

First to test I ran the code and the output of the alarm method got printed on the console. Then to test the use of mongo I did the following:

1. Ran the example and stopped it before executing the job.

2. This created a following entry in the db

   > db.example_jobs.find().pretty()
   {
       "_id" : "la",
       "next_run_time" : 1456771825.792437,
       "job_state" : BinData(0,"gAJ9cQEoVQRhcmdzcQJjZGF0ZXRpbWUKZGF0ZXRpbWUKcQNVCgfgAwEAFA8MF4SFUnEEhXEFVQhleGVjdXRvcnEGVQdkZWZhdWx0cQdVDW1heF9pbnN0YW5jZXNxCEsBVQRmdW5jcQlVDl9fbWFpbl9fOmFsYXJtcQpVAmlkcQtVAmxhcQxVDW5leHRfcnVuX3RpbWVxDWgDVQoH4AMBABQZDBd1Y3B5dHoKX3AKcQ4oVQxBc2lhL0tvbGthdGFxD01YTUsAVQNJU1RxEHRScRGGUnESVQRuYW1lcRNVBWFsYXJtcRRVEm1pc2ZpcmVfZ3JhY2VfdGltZXEVSwFVB3RyaWdnZXJxFmNhcHNjaGVkdWxlci50cmlnZ2Vycy5kYXRlCkRhdGVUcmlnZ2VyCnEXKYFxGH1xGX1xGlUIcnVuX2RhdGVxG2gSc4ZiVQhjb2FsZXNjZXEciFUHdmVyc2lvbnEdSwFVBmt3YXJnc3EefXEfdS4=")
   }
   

3. Then I commented the line which was adding the job: # scheduler.add_job(alarm, 'date', run_date=alarm_time, args=[datetime.now()], id="la")

4. Then I ran the script again and got following output:

   To clear the alarms, run this example with the --clear argument.
   Press Ctrl+C to exit
   WARNING:apscheduler.executors.default:Run time of job "alarm (trigger: date[2016-03-01 00:35:27 IST], next run at: 2016-03-01 00:35:27 IST)" was missed by 0:00:19.290825
   

5. The output of the alarm function is not printed and the record is deleted from the db.

I tried debugging the second run, the code is reading the job from the db and then submitting it to the threadpool. But no output is printed.

Why this could be happening?

Answer 1

The issue was misfire_grace_time (doc). I didn't set it. It was actually not set even in the example itself.

Working code:

import logging
import os
import sys
from datetime import datetime, timedelta

from apscheduler.schedulers.blocking import BlockingScheduler

logging.basicConfig()


def alarm(time):
    print('Alarm! This alarm was scheduled at %s.' % time)


if __name__ == '__main__':
    scheduler = BlockingScheduler()
    scheduler.add_jobstore('mongodb', collection='example_jobs', host='192.168.0.108', port=27017)

    if len(sys.argv) > 1 and sys.argv[1] == '--clear':
        scheduler.remove_all_jobs()

    alarm_time = datetime.now() + timedelta(seconds=10)
    scheduler.add_job(alarm, 'date', run_date=alarm_time, args=[datetime.now()], id="la", misfire_grace_time=1000)
    print('To clear the alarms, run this example with the --clear argument.')
    print('Press Ctrl+{0} to exit'.format('Break' if os.name == 'nt' else 'C'))

    scheduler.start()

I got this answer from APS's IRC channel #apscheduler. @agronholm helped me.