search

lorisleiva / laravel-actions

⚡️ Laravel components that take care of one specific task
https://laravelactions.com
MIT License
2.52k stars 124 forks source link

Job Failure Logs Do Not Show Action Class Name #296

Open jeffersonmartin opened 1 month ago

jeffersonmartin commented 1 month ago

Version

Problem Statement

When an action runs as a dispatched job and the job fails, the storage/logs/laravel.log shows a lot of details about job decorators and framework classes, however no mention of the App\Action\* that actually failed is shown. This leads to difficult triage since we can only go off of the message that can be benign.

MyAction::dispatch(
    source: $source
)->onQueue('high');

When running the action as a dispatched job... 

[2024-10-22 18:29:46] local.ERROR: Unknown named parameter $source {"exception":"[object] (Error(code: 0): Unknown named parameter $source at /Users/jeff/Code/my-laravel-project/vendor/lorisleiva/laravel-actions/src/Concerns/DecorateActions.php:38)
[stacktrace]
#0 /Users/jeff/Code/my-laravel-project/vendor/lorisleiva/laravel-actions/src/Concerns/DecorateActions.php(38): call_user_func_array(Array, Array)
#1 /Users/jeff/Code/my-laravel-project/vendor/lorisleiva/laravel-actions/src/Concerns/DecorateActions.php(49): Lorisleiva\\Actions\\Decorators\\JobDecorator->callMethod('jobFailed', Array)
#2 /Users/jeff/Code/my-laravel-project/vendor/lorisleiva/laravel-actions/src/Decorators/JobDecorator.php(142): Lorisleiva\\Actions\\Decorators\\JobDecorator->fromActionMethod('jobFailed', Array, Array)
#3 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(263): Lorisleiva\\Actions\\Decorators\\JobDecorator->failed(Object(Error))
#4 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(234): Illuminate\\Queue\\CallQueuedHandler->failed(Array, Object(Error), '363d4512-ab50-4...')
#5 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(213): Illuminate\\Queue\\Jobs\\Job->failed(Object(Error))
#6 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(603): Illuminate\\Queue\\Jobs\\Job->fail(Object(Error))
#7 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(549): Illuminate\\Queue\\Worker->failJob(Object(Illuminate\\Queue\\Jobs\\RedisJob), Object(Error))
#8 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(472): Illuminate\\Queue\\Worker->markJobAsFailedIfWillExceedMaxAttempts('redis', Object(Illuminate\\Queue\\Jobs\\RedisJob), 1, Object(Error))
#9 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(446): Illuminate\\Queue\\Worker->handleJobException('redis', Object(Illuminate\\Queue\\Jobs\\RedisJob), Object(Illuminate\\Queue\\WorkerOptions), Object(Error))
#10 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(390): Illuminate\\Queue\\Worker->process('redis', Object(Illuminate\\Queue\\Jobs\\RedisJob), Object(Illuminate\\Queue\\WorkerOptions))
#11 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(177): Illuminate\\Queue\\Worker->runJob(Object(Illuminate\\Queue\\Jobs\\RedisJob), 'redis', Object(Illuminate\\Queue\\WorkerOptions))
#12 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(141): Illuminate\\Queue\\Worker->daemon('redis', 'auth,default,di...', Object(Illuminate\\Queue\\WorkerOptions))
#13 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(124): Illuminate\\Queue\\Console\\WorkCommand->runWorker('redis', 'auth,default,di...')
#14 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): Illuminate\\Queue\\Console\\WorkCommand->handle()
#15 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Container/Util.php(43): Illuminate\\Container\\BoundMethod::Illuminate\\Container\\{closure}()
#16 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(95): Illuminate\\Container\\Util::unwrapIfClosure(Object(Closure))
#17 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(35): Illuminate\\Container\\BoundMethod::callBoundMethod(Object(Illuminate\\Foundation\\Application), Array, Object(Closure))
#18 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Container/Container.php(690): Illuminate\\Container\\BoundMethod::call(Object(Illuminate\\Foundation\\Application), Array, Array, NULL)
#19 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Console/Command.php(213): Illuminate\\Container\\Container->call(Array)
#20 /Users/jeff/Code/my-laravel-project/vendor/symfony/console/Command/Command.php(279): Illuminate\\Console\\Command->execute(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Illuminate\\Console\\OutputStyle))
#21 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Console/Command.php(182): Symfony\\Component\\Console\\Command\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Illuminate\\Console\\OutputStyle))
#22 /Users/jeff/Code/my-laravel-project/vendor/symfony/console/Application.php(1047): Illuminate\\Console\\Command->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#23 /Users/jeff/Code/my-laravel-project/vendor/symfony/console/Application.php(316): Symfony\\Component\\Console\\Application->doRunCommand(Object(Illuminate\\Queue\\Console\\WorkCommand), Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#24 /Users/jeff/Code/my-laravel-project/vendor/symfony/console/Application.php(167): Symfony\\Component\\Console\\Application->doRun(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#25 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(197): Symfony\\Component\\Console\\Application->run(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#26 /Users/jeff/Code/my-laravel-project/vendor/laravel/framework/src/Illuminate/Foundation/Application.php(1203): Illuminate\\Foundation\\Console\\Kernel->handle(Object(Symfony\\Component\\Console\\Input\\ArgvInput), Object(Symfony\\Component\\Console\\Output\\ConsoleOutput))
#27 /Users/jeff/Code/my-laravel-project/artisan(13): Illuminate\\Foundation\\Application->handleCommand(Object(Symfony\\Component\\Console\\Input\\ArgvInput))
#28 {main}

Root Cause

When using Laravel Telescope, I'm able to see that the error message isn't related, and is more than likely a case of the class has a syntax problem and can't load so named arguments aren't accepted since that's further down the processing stack than where we failed at.

My example of the error inside the action class that is easily fixable if I can get more details in the log at runtime when it occurs.

Typed property App\Actions\MyAction::$api_records must not be accessed before initialization

In this case, I can see that I'm trying to access $this->api_records->count() before I set $this->api_records = collect(ApiClient::get('users')->data) above it.

Reproduction Steps

  1. Create a action class and make an obvious typo that PHP will crash on.
  2. Use Tinker(well) to run the action (ex. MyAction::make()->handle(key: $value)).
  3. No logs appear in laravel.log, however Tinkerwell shows the PHP crash error. I'm not sure how to work around this. Maybe they appear in PHP error logs?
  4. Use Tinker(well) to dispatch the action (ex. MyAction::dispatch(key: $value)).

Solution

Is there a better way to see PHP crash/error logs that I'm not aware of? Since I can get it in Telescope, I'm working around it but the logs are sending me on wild goose chases sometimes.

Thanks again for an amazing tool!