Laravel Artisan: How does `schedule:run` work?

I have a dummy Command job set up, whose handle() function is as follows:

public function handle()
{
    $this->line('==================');
    $this->line('Running my job at ' . Carbon::now());
    $this->line('Ending my job at ' . Carbon::now());
}

As you see, it doesn't actually do anything but return a few lines of info to the standard output.

Now, in my App\Console\Kernel class, I have set up the following schedule:

protected function schedule(Schedule $schedule)
{
    $schedule
        -> command('cbh:dummyCommand')
        -> everyMinute()
        -> appendOutputTo (storage_path().'/logs/laravel_output.log');
}

Now, from the command-line I run php artisan schedule:run. The output in my laravel_output.log file reads

==================
Running my job at 2018-02-08 11:01:33
Ending my job at 2018-02-08 11:01:33

So far so good. It seems that my schedule is running. However, if I run the command again within the same minute, my logfile now reads:

==================
Running my job at 2018-02-08 11:01:33
Ending my job at 2018-02-08 11:01:33
==================
Running my job at 2018-02-08 11:01:51
Ending my job at 2018-02-08 11:01:51

In other words, the schedule appears to be running more frequently than every minute, which appears to me to break the rules I defined in my schedule.

What's more confusing is that I can change the schedule to run every 5 minutes instead of every minute:

protected function schedule(Schedule $schedule)
{
    $schedule
        -> command('cbh:dummyCommand')
        -> everyFiveMinutes()
        -> appendOutputTo (storage_path().'/logs/laravel_output.log');
}

then run php artisan schedule:run, then I get the following output

No scheduled commands are ready to run.

I can wait as long as you like (i.e. more than 5 minutes) and still I get no output to my log file.

I observe exactly the same behaviour when I schedule my command with Windows Task Scheduler (yes, my development environment is a Windows 7 box, and yes, this is the Windows equivalent of a cron-job).

The Question

So what's going on? How does the artisan schedule:run command figure out which commands are "waiting" on the schedule to be executed? I had imagined that there would be some kind of log-file to record the fact that "command X is on a 1-hour schedule ran at 09:00, so don't execute it before 10:00", but I have been able to find no trace of such a log.

Can someone give me a clue?

Thanks!!

via Chebli Mohamed