dbader / schedule

Python job scheduling for humans.
https://schedule.readthedocs.io/
MIT License
11.84k stars 963 forks source link

Daylight saving to winter time caused scheduler to stop #636

Open kimdre opened 2 weeks ago

kimdre commented 2 weeks ago

Tonight my scheduler app stopped running right after the time was set back by one hour. Did anyone experience something similiar? Unfortunately there were no errors/exceptions in the logs, this is the only information I can provide:

[2024-10-27 02:59:12.406] [client.py.start_scheduler:83] INFO: Running pending jobs: ['check_100th_checkins']
[2024-10-27 02:01:40.857] [main.py.<module>:28] INFO: Stopping App...
[2024-10-27 02:01:40.861] [main.py.<module>:33] INFO: App stopped.

My main:

if __name__ == '__main__':
    log.info("Starting App...")

    loop = asyncio.new_event_loop()

    mq_connection = loop.run_until_complete(get_connection(loop))
    message_publisher = MessagePublisher(mq_connection)

    try:
        loop.run_until_complete(message_publisher.connect())
        loop.run_until_complete(start_scheduler(loop=loop, message_publisher=message_publisher))

    except (KeyboardInterrupt, SystemExit):
        pass

    except Exception as e:
        log.error(e, exc_info=True)

    finally:
        log.info("Stopping App...")
        loop.run_until_complete(message_publisher.disconnect())
        loop.run_until_complete(mq_connection.close())
        loop.stop()
        loop.close()
        log.info("App stopped.")

My scheduler:

def run_async(func, loop: asyncio.AbstractEventLoop, *args):
    """
    Wrapper to run async functions in the scheduler

    :param func: The async function to run
    :param loop: The event loop
    :param args: The arguments to pass to the function
    """

    logger.debug(f"Running async function: {func}")
    loop.call_soon_threadsafe(loop.create_task, func(*args))

async def start_scheduler(loop: asyncio.AbstractEventLoop, message_publisher: MessagePublisher):
    """
    Start the scheduler

    :param message_publisher: The message publisher
    :param loop: The event loop
    """

    logger.info("Starting scheduler...")

    # Health check job

    schedule.every(5).seconds.do(run_async, write_health, loop)
    schedule.run_all()

    # Schedule normal jobs

    schedule.every(15).minutes.do(run_async, check_100th_checkins, loop, message_publisher)

    schedule.every().day.at("10:00").do(run_async, check_birthdays, loop, message_publisher)
    schedule.every().day.at("10:15").do(run_async, check_inactive_midterm_members_premium, loop, message_publisher)
    schedule.every().day.at("10:30").do(run_async, check_inactive_longterm_members_premium, loop, message_publisher)
    schedule.every().day.at("10:45").do(run_async, check_active_members_weekend_only_premium, loop, message_publisher)
    schedule.every().day.at("12:45").do(run_async, check_inactive_new_members_premium, loop, message_publisher)
    schedule.every().day.at("13:00").do(run_async, check_inactive_members, loop, message_publisher)

    logger.info("Scheduler started.")

    # Create multiline string with scheduled job names, interval and next run time
    jobs = "\n• ".join(
        [
            f"{job.job_func.args[0].__name__} - runs at {job.at_time or f'every {job.interval} {job.unit}'} - next run: {job.next_run}"
            for job in schedule.jobs
        ]
    )
    logger.info(f"Scheduled jobs:\n• {jobs}")

    while True:
        try:
            pending_jobs = get_pending_jobs(schedule.jobs)
            if pending_jobs:
                jobs = [job.job_func.args[0].__name__ for job in pending_jobs]
                logger.info(f"Running pending jobs: {jobs}")
            schedule.run_pending()
            await asyncio.sleep(1)
        except asyncio.CancelledError:
            break

    logger.info("Scheduler stopped.")
nburlett commented 2 weeks ago

I just ran into the opposite problem, which may be related. I have:

schedule.every().tuesday.at('10:30', 'America/Los_Angeles').do(...)

This has run correctly for several months until this morning, when at 10:30 am Pacific time it started running every single second. I have some debugging code in the process, so I could trigger a dump of the job list and the scheduler's next_run and idle_seconds

For this job, repr(job) was:

Every 1 week at 10:30:00 do handler() (last run: 2024-10-29 17:37:18, next run: 2024-10-29 17:30:00)

For the scheduler I had:

idle_seconds: -439.449066
next_run: 2024-10-29T17:30:00

Restarting the process did not fix the problem: last_run started as None but then started running every 1s again and I needed to remove the job from my schedule while I diagnose further.

I'm running from commit 1173f2820b6e996fd80c51e61353a31a4c260b3b. I'll try 1.2.2 to see if the fixes from #623 will improve the situation.

edit: 1.2.2 fixed the issue