かきノート

【Laravel】schedule からコールされる command は、後続のメソッド次第で同期的に処理されたり非同期で処理されたりする(runInBackground)

July 21, 2021 • ☕️ 6 min read

【 環境 】
Laravel のバージョン: 8.16.1
PHP のバージョン: 7.4.7
MySQL のバージョン: 5.7

Laravel :スケジューラの処理順序について

Laravel のスケジューラ( schedule:run コマンド)を使用した時、定義された command は、定義した順番に逐次実行されるの?
それとも、非同期で実行されるの?

気になったんで実験。
結論は既にタイトルに出てます。

以下のコードで実験しました。


実験1:特に何も考えずに記述する

app\Console\Kernel.php

    protected function schedule(Schedule $schedule)
    {
        $this->scheduleExecuteBatches($schedule);
    }

    private function scheduleExecuteBatches(Schedule $schedule)
    {
        $this->scheduleExecuteCommand01($schedule);  // ログを吐く処理がある(「処理1」とする)
        $this->scheduleExecuteCommand02($schedule);  // ログを吐く処理がある(「処理2」とする)
        $this->scheduleExecuteCommand03($schedule);  // ログを吐く処理がある(「処理3」とする)

        \Log::info("AAAAA");  // ログを吐く処理。「処理:A」とする
    }

    private function scheduleExecuteCommand01(Schedule $schedule)
    {
        $schedule->command(Batch01Command::class)
            ->everyMinute();
    }
    // Command02 以降は省略

Batch01Command.php

    public function handle()
    {
        $this->info(__METHOD__);
        \Log::info(__METHOD__);
    }

Command02 以降は省略。全て同じコード。

その後、コマンドを実行。

php artisan schedule:run

以下、その時のログの内容。
今回の検証に不要な部分は、見づらかったのでカットしました。

storage\logs\laravel.log

[2021-07-20 04:54:09] AAAAA  
[2021-07-20 04:54:13] Batch01Command::handle  
[2021-07-20 04:54:16] Batch02Command::handle  
[2021-07-20 04:54:19] Batch03Command::handle  

ログが出力された順番

「処理:A」

「処理1」

「処理2」

「処理3」

各コマンドでどれだけ処理がかかるかによって、結果が変わってくるかもしれないんで、次の実験。


実験2:途中でウェイトが発生するジョブを挟む

上記コードの command を以下のように修正して実験。

Batch02Command, Batch03Command, も、全て同じコードです。

Batch01Command.php

    public function handle()
    {
        $this->info(__METHOD__);
        \Log::info(__METHOD__);

        // 20 秒間遅延させる
        sleep(10);

        $this->info(__METHOD__ . ': 20 seconds later');
        \Log::info(__METHOD__. ': 20 seconds later');

        // 20 秒間遅延させる
        sleep(10);

        $this->info(__METHOD__ . ': 40 seconds later');
        \Log::info(__METHOD__. ': 40 seconds later');

        // 20 秒間遅延させる
        sleep(10);

        $this->info(__METHOD__ . ': 60 seconds later');
        \Log::info(__METHOD__. ': 60 seconds later');

        return 0;
    }

ログは以下のようになりました。

storage\logs\laravel.log

[2021-07-20 04:55:59] AAAAA  
[2021-07-20 04:56:03] Batch01Command::handle  
[2021-07-20 04:56:13] Batch01Command::handle: 20 seconds later  
[2021-07-20 04:56:23] Batch01Command::handle: 40 seconds later  
[2021-07-20 04:56:33] Batch01Command::handle: 60 seconds later  
[2021-07-20 04:56:36] Batch02Command::handle  
[2021-07-20 04:56:46] Batch02Command::handle: 20 seconds later  
[2021-07-20 04:56:56] Batch02Command::handle: 40 seconds later  
[2021-07-20 04:57:06] Batch02Command::handle: 60 seconds later  
[2021-07-20 04:57:09] Batch03Command::handle  
[2021-07-20 04:57:19] Batch03Command::handle: 20 seconds later  
[2021-07-20 04:57:29] Batch03Command::handle: 40 seconds later  
[2021-07-20 04:57:39] Batch03Command::handle: 60 seconds later  

Batch02Command は、Batch01Command の終了を確認した後に実行しているものと思われます。

という事で、schedule で command を順番に呼び出している時、非同期で実行するのではなく、1つ1つ完了した後で実行している事が分かりました。


実験3:runInBackground を追加

runInBackground を付ければ、非同期で動くのでは?
と思ったので、次の実験。

app\Console\Kernel.php

    private function scheduleExecuteCommand01(Schedule $schedule)
    {
        $schedule->command(Batch01Command::class)
            ->everyMinute()
            ->runInBackground();
    }
    // Command02 以降は省略

ログは以下のようになりました。

storage\logs\laravel.log

[2021-07-20 10:41:42] AAAAA  
[2021-07-20 10:41:45] Batch03Command::handle  
[2021-07-20 10:41:45] Batch01Command::handle  
[2021-07-20 10:41:45] Batch02Command::handle  
[2021-07-20 10:41:55] Batch01Command::handle: 20 seconds later  
[2021-07-20 10:41:55] Batch03Command::handle: 20 seconds later  
[2021-07-20 10:41:55] Batch02Command::handle: 20 seconds later  
[2021-07-20 10:42:05] Batch01Command::handle: 40 seconds later  
[2021-07-20 10:42:05] Batch03Command::handle: 40 seconds later  
[2021-07-20 10:42:05] Batch02Command::handle: 40 seconds later  
[2021-07-20 10:42:15] Batch01Command::handle: 60 seconds later  
[2021-07-20 10:42:15] Batch03Command::handle: 60 seconds later  
[2021-07-20 10:42:15] Batch02Command::handle: 60 seconds later  
[2021-07-20 10:42:17] AAAAA  
[2021-07-20 10:42:17] AAAAA  
[2021-07-20 10:42:19] AAAAA  

Batch01Command, Batch02Command, Batch03Command が、並列して同時に動いている。

以下のように使い分けが出来そうですね。

  • 逐次処理をしたい場合、runInBackground を付けない
  • 並列で処理したい場合、runInBackground を付ける

Relative Posts:

【Laravel】Schedule にて実行するコマンドは、withoutOverlapping() を付けないと、同じジョブが重複して実行される可能性がある

July 22, 2021

【Laravel】$schedule->command にて、cron メソッドの引数が不正だった場合、全てのコマンドが実行されない。

July 20, 2021

福岡の物流エンジニアが、七転び八起きしたあと九回転び、寝っ転がったまま何かやってる事を垂れ流しているブログ

RotateLinkImg-iconRotateLinkImg-iconRotateLinkImg-iconRotateLinkImg-icon