agronholm / agronholm/apscheduler
Missed jobs run at next fire time instead of immediately
- Lenguaje dominante
- Python
- Estrellas
- 7.6k
- Forks
- 783
- Merge medio
- 4 d 8 h
- PR fusionados (30 d)
- 5
Descripción
### Things to check first
- [x] I have checked that my issue does not already have a solution in the [FAQ](https://apscheduler.readthedocs.io/en/master/faq.html)
- [x] I have searched the existing issues and didn't find my bug already reported there
- [x] I have checked that my bug is still present in the latest release
### Version
3.11.1
### What happened?
I'm not sure if this is intended behavior, so I don't know whether to call this a bug or a feature request, you tell me...
When a job runs past the next fire time, it doesn't run again immediately after the previous run finishes. Instead the next fire time gets reset, even with `misfire_grace_time=None`, and the job runs on it's original schedule regardless of whether or not a run was missed
Here's a minimal example with AsyncIOScheduler. The task takes 3 seconds, but the trigger interval is 2 seconds.
```python
from apscheduler.schedulers.asyncio import AsyncIOScheduler
import asyncio
# setup logging
import logging
logger = logging.getLogger()
handler = logging.StreamHandler()
handler.setFormatter(logging.Formatter('%(asctime)s %(name)s/%(levelname)s: %(message)s'))
logger.addHandler(handler)
logger.setLevel(logging.NOTSET)
async def job():
logger.info('job start')
await asyncio.sleep(3)
logger.info('job end')
with asyncio.Runner() as runner:
loop = runner.get_loop()
scheduler = AsyncIOScheduler(event_loop=loop)
scheduler.add_job(job, 'interval', seconds=2, misfire_grace_time=None, coalesce=True)
scheduler.start()
logger.info('scheduler start')
loop.run_forever()
```
And here's the log output
```
2025-12-24 00:17:12,219 asyncio/DEBUG: Using proactor: IocpProactor
2025-12-24 00:17:12,221 tzlocal/DEBUG: Looking up time zone info from registry
2025-12-24 00:17:12,222 apscheduler.scheduler/INFO: Adding job tentatively -- it will be properly scheduled when the scheduler starts
2025-12-24 00:17:12,223 apscheduler.scheduler/INFO: Added job "job" to job store "default"
2025-12-24 00:17:12,223 apscheduler.scheduler/INFO: Scheduler started
2025-12-24 00:17:12,223 root/INFO: scheduler start
2025-12-24 00:17:12,224 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:12,224 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:14.222133-05:00 (in 1.997824 seconds)
2025-12-24 00:17:14,231 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:14,232 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:16.222133-05:00 (in 1.989867 seconds)
2025-12-24 00:17:14,232 apscheduler.executors.default/INFO: Running job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:16 EST)" (scheduled at 2025-12-24 00:17:14.222133-05:00)
2025-12-24 00:17:14,232 root/INFO: job start
2025-12-24 00:17:16,234 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:16,235 apscheduler.scheduler/WARNING: Execution of job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:16 EST)" skipped: maximum number of running instances reached (1)
2025-12-24 00:17:16,235 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:18.222133-05:00 (in 1.986747 seconds)
2025-12-24 00:17:17,237 root/INFO: job end
2025-12-24 00:17:17,237 apscheduler.executors.default/INFO: Job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:18 EST)" executed successfully
2025-12-24 00:17:18,236 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:18,237 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:20.222133-05:00 (in 1.984534 seconds)
2025-12-24 00:17:18,238 apscheduler.executors.default/INFO: Running job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:20 EST)" (scheduled at 2025-12-24 00:17:18.222133-05:00)
2025-12-24 00:17:18,239 root/INFO: job start
2025-12-24 00:17:20,229 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:20,230 apscheduler.scheduler/WARNING: Execution of job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:20 EST)" skipped: maximum number of running instances reached (1)
2025-12-24 00:17:20,231 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:22.222133-05:00 (in 1.990791 seconds)
2025-12-24 00:17:21,255 root/INFO: job end
2025-12-24 00:17:21,255 apscheduler.executors.default/INFO: Job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:22 EST)" executed successfully
2025-12-24 00:17:22,236 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:22,236 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:24.222133-05:00 (in 1.985206 seconds)
2025-12-24 00:17:22,237 apscheduler.executors.default/INFO: Running job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:24 EST)" (scheduled at 2025-12-24 00:17:22.222133-05:00)
2025-12-24 00:17:22,237 root/INFO: job start
2025-12-24 00:17:24,223 apscheduler.scheduler/DEBUG: Looking for jobs to run
2025-12-24 00:17:24,224 apscheduler.scheduler/WARNING: Execution of job "job (trigger: interval[0:00:02], next run at: 2025-12-24 00:17:24 EST)" skipped: maximum number of running instances reached (1)
2025-12-24 00:17:24,225 apscheduler.scheduler/DEBUG: Next wakeup is due at 2025-12-24 00:17:26.222133-05:00 (in 1.996511 seconds)
2025-12-24 00:17:25,241 root/INFO: job end
```
With `misfire_grace_time=None`, I'm expecting the job to start every 3 seconds, but instead it starts at intervals of 4 seconds. "job start" is always on even seconds, when it should alternate between even and odd.
I did see a proposed workaround [here](https://github.com/agronholm/apscheduler/issues/977#issuecomment-2419370460), but this feels like a bit of a hack and something that should be in the domain of the scheduler.
Guía de contribución
Evaluación
Este issue todavía no se ha evaluado.