Laravelのartisanコマンドを実行する場合の処理順序を調べた

# 概要
コントローラー経由でバッチを叩いたら非同期に処理されるのか？バッチの実行完了を待つのか？という確認のため、
 
- 引数にsleep() 秒数を受け取る
- 開始時と終了時にログを出力する

だめの簡単なバッチ処理を書いて、コントローラから呼び出して実験した。
ついでに、気になったので

- 非同期に処理する方法
- コマンド経由の場合の処理順序

についても調べた。

# 結論
- コントローラーからArtisanファサード経由でバッチを呼び出した場合、コマンドの実行終了を待ってから次の処理に移る。
- コマンドから他のコマンドを呼び出した場合も、コマンドの実行終了を待ってから次の処理に移る。（Artisanファサード、$this->call() どちらも）
- 非同期に処理させたい場合、symfony/process を使えば簡単に実装できる
https://symfony.com/doc/current/components/process.html

# 1.コントローラー経由で実行した場合の処理順序の確認
## コマンドの実装
~~~ ExampleCommand.php
<?php

namespace App\Console\Commands;

use Illuminate\Console\Command;
use Illuminate\Support\Facades\Log;

/**
 * 第一引数でsleep秒数を指定
 * Class ExampleCommand
 * @package App\Console\Commands
 */
class ExampleCommand extends Command
{
    /**
     * The name and signature of the console command.
     *
     * @var string
     */
    protected $signature = 'example {sec} {no}';

    /**
     * The console command description.
     *
     * @var string
     */
    protected $description = 'バッチ処理の実行順を確認するために適当に書いた';

    /**
     * Create a new command instance.
     *
     * @return void
     */
    public function __construct()
    {
        parent::__construct();
    }

    /**
     * Execute the console command.
     *
     * @return mixed
     */
    public function handle()
    {
        //バッチ処理内容の実装
        $sec=(int)$this->argument('sec');
        $no=(int)$this->argument('no');

        Log::debug($no."start");
        sleep($sec);
        Log::debug($no."finished");

        //よくわからないコードを返す
        return 999;
    }
}
~~~

## コントローラ側
~~~ HomeController.php
    // その1.Artisanファサードから呼び出し
    public function index(Request $request)
    {
        Log::debug("バッチ処理呼び出し1@HomeController");
        Artisan::call('example',["sec"=>1,"no"=>1]);
        Log::debug("バッチ処理呼び出し1のあと@HomeController");

        Log::debug("バッチ処理呼び出し2@HomeController");
        Artisan::call('example',["sec"=>10,"no"=>2]);
        Log::debug("バッチ処理呼び出し2のあと@HomeController");

        Log::debug("バッチ処理呼び出し3@HomeController");
        Artisan::call('example',["sec"=>4,"no"=>3]);
        Log::debug("バッチ処理呼び出し3のあと@HomeController");
    }
~~~

## 結果
~~~  
[2019-03-06 12:52:03] develop.DEBUG: バッチ処理呼び出し1@HomeController
[2019-03-06 12:52:04] develop.DEBUG: 1start
[2019-03-06 12:52:05] develop.DEBUG: 1finished
[2019-03-06 12:52:05] develop.DEBUG: バッチ処理呼び出し1のあと@HomeController
[2019-03-06 12:52:05] develop.DEBUG: バッチ処理呼び出し2@HomeController
[2019-03-06 12:52:05] develop.DEBUG: 2start
[2019-03-06 12:52:15] develop.DEBUG: 2finished
[2019-03-06 12:52:15] develop.DEBUG: バッチ処理呼び出し2のあと@HomeController
[2019-03-06 12:52:15] develop.DEBUG: バッチ処理呼び出し3@HomeController
[2019-03-06 12:52:15] develop.DEBUG: 3start
[2019-03-06 12:52:19] develop.DEBUG: 3finished
[2019-03-06 12:52:19] develop.DEBUG: バッチ処理呼び出し3のあと@HomeController
~~~

コントローラから呼び出されたバッチ処理1の実行完了を待ってから、次のバッチ処理2を実行している。
ちなみに、hundle() メソッドがreturnする戻り値も取れる。

# 2.並列で叩けるのか？
参考：https://atuweb.net/201601_laravel-comand-async/

Symfony\Component\Process\Process
クラスを使って簡単に叩けるようだ。

## コントローラ側
~~~ HomeController.php 
    //その2.パラレル
    public function index(Request $request)
    {
        Log::debug("バッチ処理呼び出し1@HomeController");
        $process1 = new Process(base_path('artisan').' example 1 1 > /dev/null');
        $result=$process1->start();
        Log::debug("バッチ処理呼び出し1のあと@HomeController");


        Log::debug("バッチ処理呼び出し2@HomeController");
        $process2 = new Process(base_path('artisan').' example 10 2 > /dev/null');
        $process2->start();
        Log::debug("バッチ処理呼び出し2のあと@HomeController");

        Log::debug("バッチ処理呼び出し3@HomeController");
        $process3 = new Process(base_path('artisan').' example 4 3 > /dev/null');
        $process3->start();
        Log::debug("バッチ処理呼び出し3のあと@HomeController");
    }
~~~

※バッチ呼び出しのコマンドに > を書き忘れるとログが出ない。


## 結果

~~~
[2019-03-06 12:45:23] develop.DEBUG: バッチ処理呼び出し1@HomeController
[2019-03-06 12:45:23] develop.DEBUG: バッチ処理呼び出し1のあと@HomeController
[2019-03-06 12:45:23] develop.DEBUG: バッチ処理呼び出し2@HomeController
[2019-03-06 12:45:23] develop.DEBUG: バッチ処理呼び出し2のあと@HomeController
[2019-03-06 12:45:23] develop.DEBUG: バッチ処理呼び出し3@HomeController
[2019-03-06 12:45:23] develop.DEBUG: バッチ処理呼び出し3のあと@HomeController
[2019-03-06 12:45:25] develop.DEBUG: 2start
[2019-03-06 12:45:25] develop.DEBUG: 3start
[2019-03-06 12:45:25] develop.DEBUG: 1start
[2019-03-06 12:45:26] develop.DEBUG: 1finished
[2019-03-06 12:45:29] develop.DEBUG: 3finished
[2019-03-06 12:45:35] develop.DEBUG: 2finished
~~~

できた。
戻り値を捕まえる場合は、ちょっと工夫が要るらしい（試していない）
※当然というか、start() メソッドの戻り値はnull

# 3.コマンドから別のコマンドを呼び出した場合はどうなるのか？
これも気になったので実験。

## exampleコマンドを3回呼び出すだけの親コマンド
~~~ ExampleParentCommand.php
<?php

namespace App\Console\Commands;

use Illuminate\Console\Command;
use Illuminate\Support\Facades\Log;

/**
 * Class ExampleParentCommand
 * @package App\Console\Commands
 */
class ExampleParentCommand extends Command
{
    /**
     * The name and signature of the console command.
     *
     * @var string
     */
    protected $signature = 'parent';

    /**
     * The console command description.
     *
     * @var string
     */
    protected $description = 'バッチ処理の実行順を確認するために適当に書いた2';

    /**
     * Create a new command instance.
     *
     * @return void
     */
    public function __construct()
    {
        parent::__construct();
    }

    /**
     * Execute the console command.
     *
     * @return mixed
     */
    public function handle()
    {
        Log::debug("バッチ処理呼び出し1@Parent");
        $this->call('example',["sec"=>1,"no"=>1]);
        Log::debug("バッチ処理呼び出し1のあと@Parent");

        Log::debug("バッチ処理呼び出し2@Parent");
        $this->call('example',["sec"=>10,"no"=>2]);
        Log::debug("バッチ処理呼び出し2のあと@Parent");

        Log::debug("バッチ処理呼び出し3@Parent");
        $this->call('example',["sec"=>4,"no"=>3]);
        Log::debug("バッチ処理呼び出し3のあと@Parent");

    }
}
~~~

## 結果
~~~
[2019-03-06 13:13:10] develop.DEBUG: バッチ処理呼び出し1@Parent
[2019-03-06 13:13:10] develop.DEBUG: 1start
[2019-03-06 13:13:11] develop.DEBUG: 1finished
[2019-03-06 13:13:11] develop.DEBUG: バッチ処理呼び出し1のあと@Parent
[2019-03-06 13:13:11] develop.DEBUG: バッチ処理呼び出し2@Parent
[2019-03-06 13:13:11] develop.DEBUG: 2start
[2019-03-06 13:13:21] develop.DEBUG: 2finished
[2019-03-06 13:13:21] develop.DEBUG: バッチ処理呼び出し2のあと@Parent
[2019-03-06 13:13:21] develop.DEBUG: バッチ処理呼び出し3@Parent
[2019-03-06 13:13:21] develop.DEBUG: 3start
[2019-03-06 13:13:25] develop.DEBUG: 3finished
[2019-03-06 13:13:25] develop.DEBUG: バッチ処理呼び出し3のあと@Parent
~~~

順番に実行された。