Scheduled ->everyMinute() task is running twice per minute

[emilebourquin]

Steps To Reproduce

1. Install a brand-new copy of Laravel in a new test directory

2. Change contents of routes/console.php to:

<?php
use Illuminate\Support\Facades\Log;

Schedule::call(function () {
    Log::debug('THIS IS A SCHEDULED LOG ENTRY '.time());
})->everyMinute();

3. Add a file named Dockerfile_scheduled:

FROM serversideup/php:8.3-cli
USER www-data
COPY --chown=www-data:www-data ./src /var/www/html
CMD ["php", "artisan", "schedule:work"]

4. Build the Docker image using the command:

docker build -t test_scheduled -f Dockerfile_scheduled .

5. In Docker Desktop, run the test_scheduled image

6. Observe the log of the container

2024-09-25 09:23:10    INFO  Running scheduled tasks every minute.  
2024-09-25 09:23:10 
2024-09-25 09:24:00   2024-09-25 16:24:00 Running [Callback] ......................... 2.29ms DONE
2024-09-25 09:24:00   2024-09-25 16:24:00 Running [Callback] ......................... 0.05ms DONE
2024-09-25 09:24:00 
2024-09-25 09:25:00   2024-09-25 16:25:00 Running [Callback] ......................... 6.69ms DONE
2024-09-25 09:25:00   2024-09-25 16:25:00 Running [Callback] ......................... 0.07ms DONE
2024-09-25 09:25:00 
2024-09-25 09:26:00   2024-09-25 16:26:00 Running [Callback] ......................... 2.19ms DONE
2024-09-25 09:26:00   2024-09-25 16:26:00 Running [Callback] ......................... 0.05ms DONE

7. Observe the Laravel log file

[2024-09-25 16:24:00] local.DEBUG: THIS IS A SCHEDULED LOG ENTRY 1727281440
[2024-09-25 16:24:00] local.DEBUG: THIS IS A SCHEDULED LOG ENTRY 1727281440
[2024-09-25 16:25:00] local.DEBUG: THIS IS A SCHEDULED LOG ENTRY 1727281500
[2024-09-25 16:25:00] local.DEBUG: THIS IS A SCHEDULED LOG ENTRY 1727281500
[2024-09-25 16:26:00] local.DEBUG: THIS IS A SCHEDULED LOG ENTRY 1727281560
[2024-09-25 16:26:00] local.DEBUG: THIS IS A SCHEDULED LOG ENTRY 1727281560

Observations
The Container log file shows the first callback run in a few milliseconds, and the second run in 100ths of a millisecond, as if the same PHP process is running the second closure call quickly, as it has already been loaded into memory/bytecode.

I built the Dockerfile with procps in it:

FROM serversideup/php:8.3-cli
USER root
RUN apt-get update \
    && apt-get install -y procps \
    && apt-get clean \
    && rm -rf /var/lib/apt/lists/* /tmp/* /var/tmp/* /usr/share/doc/*
USER www-data
COPY --chown=www-data:www-data ./src /var/www/html
CMD ["php", "artisan", "schedule:work"]

and "ps ax" shows:

PID TTY      STAT   TIME COMMAND
    1 ?        Ss     0:00 php artisan schedule:work
   17 pts/0    Ss     0:00 /bin/sh
   29 pts/0    R+     0:00 ps ax

Outcome

I expect the scheduled closure to run once per minute.

The scheduled closure runs twice per minute.

Affected Docker Images

serversideup/php:8.3-cli

Anything else?

No response

[jaydrogers]

We had another community member ask us about this today (@fouteox). He mentioned it was happening in our Docker images and in Laravel Herd, so this issue could be related to the framework.

laravel/framework#52929

Maybe chime in on that and see if you can help the Laravel Community get it replicated and a fix in place?

If it's possible to eliminate our Docker Images from the equation, that will help clarify if it's truly a Laravel issue.

[emilebourquin]

"If it's possible to eliminate our Docker Images from the equation, that will help clarify if it's truly a Laravel issue." , agreed, I always feel a bit guilty reporting it here, as I can't tell where the issue lies, and it may very well be with the framework. I'll see what I can cook up to clear your good name and pin it on Laravel :)

[jaydrogers]

Never have shame opening an issue! Always great to have you around the community 👍

[emilebourquin]

Probably related to laravel/framework#52867 ?

[jaydrogers]

Very well could be!

I know @fouteox mentioned he locked into Laravel Version 11.23.5 for now.

Maybe try that and see if that works?

[jaydrogers]

A new version of Laravel is out (11.25.0). According to @fouteox this should fix the issue: https://github.com/laravel/framework/releases/tag/v11.25.0

[emilebourquin]

I can confirm this fixes the double scheduled job run when using schedule:work . Thanks for letting me know about the Laravel update, Jay, I appreciate it.

[jaydrogers]

Sweet! Thanks for the update 👍