search

mcuadros / ofelia

A docker job scheduler (aka. crontab for docker)
MIT License
3.08k stars 177 forks source link

Odd behaviour scheduling every minute with a cron like syntax #86

Open mrtimp opened 4 years ago

mrtimp commented 4 years ago

Hi Ofelia team,

I noticed something odd when trying to implement an "every minute" job with a cron like syntax. I had hoped to schedule a job every one minute:

root@427d538299e7:/app/src/t/ofelia_linux_amd64# cat config.ini 
[job-local "laravel-scheduler"]
schedule = 0 * * * * *
command = su www-data -s /bin/sh -c "php /app/src/artisan schedule:run"

But notice that while it runs every minute it runs the second before and on the second of the minute:

root@427d538299e7:/app/src/t/ofelia_linux_amd64# ./ofelia daemon --config=./config.ini
2020/01/05 17:53:13 scheduler.go:34 ▶ NOTICE New job registered "laravel-scheduler" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run" - "0 * * * * *"
2020/01/05 17:53:13 scheduler.go:54 ▶ DEBUG Starting scheduler with 1 jobs
2020/01/05 17:53:59 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "ed7fb9e02f5f" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:53:59 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "ed7fb9e02f5f" in "20.8947ms", failed: false, skipped: false, error: none
2020/01/05 17:54:00 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "3089b8958ffd" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:54:00 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "3089b8958ffd" in "24.1224ms", failed: false, skipped: false, error: none
2020/01/05 17:54:59 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "795dbe3fb891" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:54:59 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "795dbe3fb891" in "31.0201ms", failed: false, skipped: false, error: none
2020/01/05 17:55:00 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "7e93ba896a49" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:55:00 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "7e93ba896a49" in "24.095ms", failed: false, skipped: false, error: none
2020/01/05 17:55:59 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "9a1a5d5fc019" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:55:59 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "9a1a5d5fc019" in "24.4168ms", failed: false, skipped: false, error: none
2020/01/05 17:56:00 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "013031da4c21" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:56:00 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "013031da4c21" in "22.8529ms", failed: false, skipped: false, error: none

An alternative with @every 1m (but not specifically locked to the 0th second of the new minute):

root@427d538299e7:/app/src/t/ofelia_linux_amd64# cat config.ini 
[job-local "laravel-scheduler"]
schedule = @every 1m
command = su www-data -s /bin/sh -c "php /app/src/artisan schedule:run"
root@427d538299e7:/app/src/t/ofelia_linux_amd64# ./ofelia daemon --config=./config.ini
2020/01/05 17:56:29 scheduler.go:34 ▶ NOTICE New job registered "laravel-scheduler" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run" - "@every 1m"
2020/01/05 17:56:29 scheduler.go:54 ▶ DEBUG Starting scheduler with 1 jobs
2020/01/05 17:57:28 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "8a0a7450d610" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:57:28 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "8a0a7450d610" in "20.9012ms", failed: false, skipped: false, error: none
2020/01/05 17:58:27 scheduler.go:103 ▶ DEBUG laravel-scheduler - Job started "ed1869b6ebba" - "su www-data -s /bin/sh -c php /app/src/artisan schedule:run"
2020/01/05 17:58:27 scheduler.go:124 ▶ NOTICE laravel-scheduler - Job finished "ed1869b6ebba" in "25.4194ms", failed: false, skipped: false, error: none

Notice only a single job is executed every minute (which is expected).

ashleysommer commented 4 years ago

Hi @mrtimp I think this might have to do with the odd behavior of the seconds field in gocron.

Can you try with schedule = 1 * * * * * (every minute on the 01 second), and also try schedule = 60 * * * * * (every minute on the 60th second, this one might throw a config error).