Artisan に関する投稿を表示しています

Laravel でマイグレーションなどの artisan コマンドを実行するときのエラーを詳し表示した

artisan コマンドでエラーが出た場合、そのまま実行していると例外クラスとメッセージが出る程度で、どこでエラーになっとんねん!がわかりません。

実は自分で作った artisan コマンド含めてすべての artisan コマンドは verbose なオプションをサポートしています。そのためオプションを指定するだけで、例外を詳しく見ることができます。

$ php artisan migrate

  [Illuminate\Database\QueryException]
  SQLSTATE[42000]: Syntax error or access violation: 1091 Can't DROP 'created_at'; check that column/key exists (SQL: alter table `my_tables` drop `created_at`, drop `updated_at`)

  [Doctrine\DBAL\Driver\PDOException]
  SQLSTATE[42000]: Syntax error or access violation: 1091 Can't DROP 'created_at'; check that column/key exists
  
  [PDOException]
  SQLSTATE[42000]: Syntax error or access violation: 1091 Can't DROP 'created_at'; check that column/key exists 


$ php artisan migrate -v
                                                                                       
  [Illuminate\Database\QueryException (42000)]
  SQLSTATE[42000]: Syntax error or access violation: 1091 Can't DROP 'created_at'; check that column/key exists (SQL: alter table `my_tables` drop `created_at`, drop `updated_at`)

Exception trace:
 () at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:647
 Illuminate\Database\Connection->runQueryCallback() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:607
 Illuminate\Database\Connection->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:450
 Illuminate\Database\Connection->statement() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Blueprint.php:86
 Illuminate\Database\Schema\Blueprint->build() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Builder.php:239
 Illuminate\Database\Schema\Builder->build() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Builder.php:148
 Illuminate\Database\Schema\Builder->table() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php:221
 Illuminate\Support\Facades\Facade::__callStatic() at /var/www/myapp/database/migrations/2017_08_28_190905_modify_my_tables.php:21
 ModifyMstGraphTransitionTerms11->up() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:357
 Illuminate\Database\Migrations\Migrator->Illuminate\Database\Migrations\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:363
 Illuminate\Database\Migrations\Migrator->runMigration() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:177
 Illuminate\Database\Migrations\Migrator->runUp() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:146
 Illuminate\Database\Migrations\Migrator->runPending() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:95
 Illuminate\Database\Migrations\Migrator->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Console/Migrations/MigrateCommand.php:69
 Illuminate\Database\Console\Migrations\MigrateCommand->fire() at n/a:n/a
 call_user_func_array() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:29
 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:87
 Illuminate\Container\BoundMethod::callBoundMethod() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:31
 Illuminate\Container\BoundMethod::call() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/Container.php:539
 Illuminate\Container\Container->call() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Console/Command.php:182
 Illuminate\Console\Command->execute() at /var/www/myapp/vendor/symfony/console/Command/Command.php:264
 Symfony\Component\Console\Command\Command->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Console/Command.php:167
 Illuminate\Console\Command->run() at /var/www/myapp/vendor/symfony/console/Application.php:874
 Symfony\Component\Console\Application->doRunCommand() at /var/www/myapp/vendor/symfony/console/Application.php:228
 Symfony\Component\Console\Application->doRun() at /var/www/myapp/vendor/symfony/console/Application.php:130
 Symfony\Component\Console\Application->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php:122
 Illuminate\Foundation\Console\Kernel->handle() at /var/www/myapp/artisan:35


  [Doctrine\DBAL\Driver\PDOException (42000)]
  SQLSTATE[42000]: Syntax error or access violation: 1091 Can't DROP 'created_at'; check that column/key exists

Exception trace:
 () at /var/www/myapp/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php:107
 Doctrine\DBAL\Driver\PDOStatement->execute() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:449
 Illuminate\Database\Connection->Illuminate\Database\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:640
 Illuminate\Database\Connection->runQueryCallback() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:607
 Illuminate\Database\Connection->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:450
 Illuminate\Database\Connection->statement() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Blueprint.php:86
 Illuminate\Database\Schema\Blueprint->build() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Builder.php:239
 Illuminate\Database\Schema\Builder->build() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Builder.php:148
 Illuminate\Database\Schema\Builder->table() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php:221
 Illuminate\Support\Facades\Facade::__callStatic() at /var/www/myapp/database/migrations/2017_08_28_190905_modify_my_tables.php:21
 ModifyMstGraphTransitionTerms11->up() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:357
 Illuminate\Database\Migrations\Migrator->Illuminate\Database\Migrations\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:363
 Illuminate\Database\Migrations\Migrator->runMigration() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:177
 Illuminate\Database\Migrations\Migrator->runUp() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:146
 Illuminate\Database\Migrations\Migrator->runPending() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:95
 Illuminate\Database\Migrations\Migrator->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Console/Migrations/MigrateCommand.php:69
 Illuminate\Database\Console\Migrations\MigrateCommand->fire() at n/a:n/a
 call_user_func_array() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:29
 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:87
 Illuminate\Container\BoundMethod::callBoundMethod() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:31
 Illuminate\Container\BoundMethod::call() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/Container.php:539
 Illuminate\Container\Container->call() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Console/Command.php:182
 Illuminate\Console\Command->execute() at /var/www/myapp/vendor/symfony/console/Command/Command.php:264
 Symfony\Component\Console\Command\Command->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Console/Command.php:167
 Illuminate\Console\Command->run() at /var/www/myapp/vendor/symfony/console/Application.php:874
 Symfony\Component\Console\Application->doRunCommand() at /var/www/myapp/vendor/symfony/console/Application.php:228
 Symfony\Component\Console\Application->doRun() at /var/www/myapp/vendor/symfony/console/Application.php:130
 Symfony\Component\Console\Application->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php:122
 Illuminate\Foundation\Console\Kernel->handle() at /var/www/myapp/artisan:35


  [PDOException (42000)]
  SQLSTATE[42000]: Syntax error or access violation: 1091 Can't DROP 'created_at'; check that column/key exists

Exception trace:
 () at /var/www/myapp/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php:105
 PDOStatement->execute() at /var/www/myapp/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php:105
 Doctrine\DBAL\Driver\PDOStatement->execute() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:449
 Illuminate\Database\Connection->Illuminate\Database\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:640
 Illuminate\Database\Connection->runQueryCallback() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:607
 Illuminate\Database\Connection->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Connection.php:450
 Illuminate\Database\Connection->statement() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Blueprint.php:86
 Illuminate\Database\Schema\Blueprint->build() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Builder.php:239
 Illuminate\Database\Schema\Builder->build() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Schema/Builder.php:148
 Illuminate\Database\Schema\Builder->table() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Support/Facades/Facade.php:221
 Illuminate\Support\Facades\Facade::__callStatic() at /var/www/myapp/database/migrations/2017_08_28_190905_modify_my_tables.php:21
 ModifyMstGraphTransitionTerms11->up() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:357
 Illuminate\Database\Migrations\Migrator->Illuminate\Database\Migrations\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:363
 Illuminate\Database\Migrations\Migrator->runMigration() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:177
 Illuminate\Database\Migrations\Migrator->runUp() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:146
 Illuminate\Database\Migrations\Migrator->runPending() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Migrations/Migrator.php:95
 Illuminate\Database\Migrations\Migrator->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Database/Console/Migrations/MigrateCommand.php:69
 Illuminate\Database\Console\Migrations\MigrateCommand->fire() at n/a:n/a
 call_user_func_array() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:29
 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:87
 Illuminate\Container\BoundMethod::callBoundMethod() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php:31
 Illuminate\Container\BoundMethod::call() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Container/Container.php:539
 Illuminate\Container\Container->call() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Console/Command.php:182
 Illuminate\Console\Command->execute() at /var/www/myapp/vendor/symfony/console/Command/Command.php:264
 Symfony\Component\Console\Command\Command->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Console/Command.php:167
 Illuminate\Console\Command->run() at /var/www/myapp/vendor/symfony/console/Application.php:874
 Symfony\Component\Console\Application->doRunCommand() at /var/www/myapp/vendor/symfony/console/Application.php:228
 Symfony\Component\Console\Application->doRun() at /var/www/myapp/vendor/symfony/console/Application.php:130
 Symfony\Component\Console\Application->run() at /var/www/myapp/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php:122
 Illuminate\Foundation\Console\Kernel->handle() at /var/www/myapp/artisan:35

ちなみにサポートするオプションと、表示レベルは以下のようになっています。


// /vendor/laravel/framework/src/Illuminate/Console/Command.php
// ※抜粋

use Symfony\Component\Console\Output\OutputInterface;

protected $verbosity = OutputInterface::VERBOSITY_NORMAL;

protected $verbosityMap = [
    'v' => OutputInterface::VERBOSITY_VERBOSE,
    'vv' => OutputInterface::VERBOSITY_VERY_VERBOSE,
    'vvv' => OutputInterface::VERBOSITY_DEBUG,
    'quiet' => OutputInterface::VERBOSITY_QUIET,
    'normal' => OutputInterface::VERBOSITY_NORMAL,
];
オプション レベル 生数値
v OutputInterface::VERBOSITY_VERBOSE 64
vv OutputInterface::VERBOSITY_VERY_VERBOSE 128
vvv OutputInterface::VERBOSITY_DEBUG 256
quiet OutputInterface::VERBOSITY_QUIET 16
normal OutputInterface::VERBOSITY_NORMAL 32

まあ、これってソースのとこにもあるんですけど、ベースになってる Symfony2 のものなんですけどね。

Verbosity Levels (current)

Symfony2 で定義されている値を使って artisan コマンドも同じように verbose な指定をサポートしているんですねー。もし自分で作るコマンドも verbose な指定をサポートするなら、指定されている定数を目安に出力すると良さそう。

Laravel5 で Log ファサードを使ったときに一緒に標準出力にも出した

artisan コマンドを作ったとき、何かと様子を出力するために Log ファサードを使ってログファイルに出している。

 

ちなみに。そのとき Monolog のハンドラを使って、レベル別にファイルを分けたりなどしている。こんな具合にするとログレベルごとにファイルが分かれる、めっちゃ便利。

// bootstrap/app.php
$app->configureMonologUsing(function ($monolog) {
    $logConfigure = config('log');
    foreach ($logConfigure['file'] as $logLevel => $logFile) {
        $path = storage_path('logs/' . $logFile . '.log');
        $handler = new \Monolog\Handler\RotatingFileHandler(
            $path,
            $logConfigure['rotate'],
            $logLevel,
            false,
            $logConfigure['permission']
        );
        $handler->setFormatter(new Monolog\Formatter\JsonFormatter());
        $monolog->pushHandler($handler);
    }
});


// config/log
return [
    'permission' => 0777,
    'rotate' => 30,
    'file' => [
        \Monolog\Logger::DEBUG     => 'debug',
        \Monolog\Logger::INFO      => 'debug',
        \Monolog\Logger::NOTICE    => 'debug',
        \Monolog\Logger::WARNING   => 'warning',
        \Monolog\Logger::ERROR     => 'error',
        \Monolog\Logger::CRITICAL  => 'error',
        \Monolog\Logger::ALERT     => 'error',
        \Monolog\Logger::EMERGENCY => 'error',
    ],
];

自分で用意する artisan コマンド、ようはバッチでは様子の出力などをファイルに出すために Log::info(); とかして、いろいろな情報をログに出ていく。この ID のデータをやるよー、とか、おわったよー、とか、色々。

しかし開発中はそれって厄介で、パッとコマンド実行してログ見て。いや、横で tail -f とかしておけば良いのだろうけど、それはそれでちょっと面倒だなあ。というか artisan コマンドって verbose なオプションをサポートしているので、それをうまく使ってログに出すと同時に標準出力にも出せないだろうか。

と思って出来たのがコレ。

namespace App\Console;

use Illuminate\Console\Command;
use Monolog\Handler\StreamHandler;
use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Output\OutputInterface;

trait LogWithStdout
{
    /**
     * execute メソッドに割り込み Monolog の設定をする
     */
    public function execute(InputInterface $input, OutputInterface $output)
    {
        // verboseなオプションが付いたらログを画面に出す
        if ($output->getVerbosity() >= $this->verbosityMap['v']) {
            $monolog = \Log::getMonolog();
            $handler = new StreamHandler("php://stdout", 'info');
            $monolog->pushHandler($handler);
        }

        // 元の処理の呼び出し
        return parent::execute($input, $output);
    }
}
namespace App\Console\Commands;

use App\Console\LogWithStdout;
use Illuminate\Console\Command;

class FetchTrafficSummary extends Command
{
    use LogWithStdout;

    public function handle()
    {
        Log::info('start!');

        ...

        Log::info('complete!');
    }
}

本当はサービスプロバイダにしてイベントにしてあげたほうがキレイなのだが、 Laravel の実装上、それは出来ないっぽい…。うぬ。。

具体的にはコマンドの発火時は取れるのだが verbose オプションがあるかどうかが取れない。 OutputInterface がイベントに入ってこないのだ。ソースも追いかけてみたがイベント引数に入ってくるのは Application インスタンスだけ。 OutputInterface を持ったものは Application から Command を呼ぶときにしか作られないらしい。

 
 
とまあ、作ってみたものの Artisan コマンドでも $this->info などして標準出力に出せるので、そちらをオーバーラップしたほうがキレイなんじゃないかなーと思った。こういうイメージ。

public function info($string, $verbosity = null)
{
    parent::info($string, $verbosity);
    \Log::info($string);
}

どちらかといえばこちらのほうが、メソッド別にログファサードのメソッドを呼べるのでパッと見でわかりやすそうだ。