Possible for EVENT_JOB_EXECUTED to fire before EVENT_JOB_SUBMITTED

[invokermain]

Seems to affect Cron trigger occasionally. The ordering of job events is not guaranteed.

Expected Behavior

The SUBMITTED event for a job should always fire before its corresponding EXECUTED event.

Current Behavior

A job's EXECUTED event can fire before the SUBMITTED event leading to unexpected behaviour.

Steps to Reproduce

https://repl.it/repls/CultivatedOrneryVideogames

from apscheduler.events import (
    EVENT_JOB_EXECUTED,
    EVENT_JOB_SUBMITTED,
)
from apscheduler.schedulers.blocking import BlockingScheduler
from time import sleep
import datetime as dt

def my_job():
  print(f"my job: {dt.datetime.now()}")
  return


def executed_listener(event):
  print(f"job executed: {dt.datetime.now()}")

def submitted_listener(event):
  print(f"job submitted: {dt.datetime.now()}")


if __name__ == "__main__":
  print("starting")
  scheduler = BlockingScheduler()

  scheduler.add_job(
    func=my_job,
    id="my_job",
    trigger="cron",
    second="*/10"
  )

  scheduler.add_listener(executed_listener, EVENT_JOB_EXECUTED)
  scheduler.add_listener(submitted_listener, EVENT_JOB_SUBMITTED)

  scheduler.start()

  while True:
    sleep(60)

Context (Environment)

Attempting to audit job run's to a SQL database means sometimes it is audited incorrectly. (e.g. Doing Insert row on SUBMITTED, update row on EXECUTED would lead to missed events as the row does not exist when the EXECUTED callback fires).

[agronholm]

Since the SUBMITTED event is only sent after submitting the job, and the executor itself fires the EXECUTED event, it's possible that the latter arrives before the former.

[ylcoder]

I am using the similar feature to log history. I was trying to work around it but it is cumbersome at least and maybe impossible. Do you think this is fixable?

[agronholm]

It could be fixable by acquiring a lock for these events while dispatching jobs. I am currently occupied with another project so this will have to wait.

[ylcoder]

Makes sense. I have a workaround for now. I will update once you have the fix, Thanks a lot Alex.

[invokermain]

in case it's useful to anyone you can solve this simply by delaying job run:

def job_delay_wrapper(func: Callable) -> Callable:
    """
    This fixes an issue with APScheduler: https://github.com/agronholm/apscheduler/issues/445
    """

    def delayed_job(*args, **kwargs):
        time.sleep(0.1)
        func(*args, **kwargs)

    return delayed_job

[HanSooloo]

in case it's useful to anyone you can solve this simply by delaying job run:

def job_delay_wrapper(func: Callable) -> Callable:
    """
    This fixes an issue with APScheduler: https://github.com/agronholm/apscheduler/issues/445
    """

    def delayed_job(*args, **kwargs):
        time.sleep(0.1)
        func(*args, **kwargs)

    return delayed_job

Was running into the same issue. @invokermain do you use the wrapper as a decorator to the job function? e.g.,

@job_delay_wrapper
def my_function(some_argument, some_other_argument):
  print(f'Doing stuff with: {some_argument}')
  print(f'Doing some other stuff with: {some_other_argument}')
  ret = f'Awesome return value'
  return ret

[jatinwatts]

EVENT_JOB_EXECUTED.retval is returning None, in spite of executing a job? what can be the reason, tired finding but was not able to get a concrete solution