bugsnag / bugsnag-laravel

BugSnag notifier for the Laravel PHP framework. Monitor and report Laravel errors.
https://docs.bugsnag.com/platforms/php/laravel/
MIT License
876 stars 129 forks source link

Reporting unhandled exceptions in Laravel not working #428

Closed fpcorso closed 3 years ago

fpcorso commented 3 years ago

Describe the bug

We have followed the installation and configuration documentation for adding BugSnag to our Laravel application: https://docs.bugsnag.com/platforms/php/laravel/

Our Laravel app is within a docker container. We have our API key as an env variable.

Our logging.php is lengthy, but here are the relevant parts:

return [
    'default' => env('LOG_CHANNEL', 'dev_stack'),
    'channels' => [
        'dev_stack' => [
            'driver' => 'stack',
            'channels' => ['single_dev', 'bugsnag'],
        ],

        // Other channels omitted...

        'bugsnag' => [
            'driver' => 'bugsnag',
        ],
    ],
];

If I use the Bugsnag client, it works correctly:

Bugsnag::notifyError('Testing bugsnag notifyError', 'This is the message....');
dd();

shows here: image

However, any unhandled exception gets put into our emergency logger and stating Driver [bugsnag] is not supported.

I saw previous issues of #379 and #333. I have tried:

  1. php artisan config:clear
  2. php artisan clear-compiled
  3. php artisan cache:clear
  4. php artisan optimize:clear
  5. php artisan route:clear

Unfortunately, none of those resolved the issue.

Environment

Error

Here is the stacktrace of the error:

[2021-01-25 17:23:50] laravel.EMERGENCY: Unable to create configured logger. Using emergency logger. {"exception":"[object] (InvalidArgumentException(code: 0): Driver [bugsnag] is not supported. at /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php:205)
[stacktrace]
#0 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(118): Illuminate\\Log\\LogManager->resolve()
#1 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(98): Illuminate\\Log\\LogManager->get()
#2 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(87): Illuminate\\Log\\LogManager->driver()
#3 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(245): Illuminate\\Log\\LogManager->channel()
#4 [internal function]: Illuminate\\Log\\LogManager->Illuminate\\Log\\{closure}()
#5 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Collections/Collection.php(630): array_map()
#6 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Collections/Traits/EnumeratesValues.php(343): Illuminate\\Support\\Collection->map()
#7 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(246): Illuminate\\Support\\Collection->flatMap()
#8 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(202): Illuminate\\Log\\LogManager->createStackDriver()
#9 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(118): Illuminate\\Log\\LogManager->resolve()
#10 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(98): Illuminate\\Log\\LogManager->get()
#11 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Log/LogManager.php(551): Illuminate\\Log\\LogManager->driver()
#12 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Exceptions/Handler.php(238): Illuminate\\Log\\LogManager->error()
#13 /var/www/html/podchaser-api/app/Exceptions/Handler.php(40): Illuminate\\Foundation\\Exceptions\\Handler->report()
#14 /var/www/html/podchaser-api/vendor/dingo/api/src/Exception/Handler.php(83): App\\Exceptions\\Handler->report()
#15 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Routing/Pipeline.php(49): Dingo\\Api\\Exception\\Handler->report()
#16 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(130): Illuminate\\Routing\\Pipeline->handleException()
#17 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Routing/Middleware/SubstituteBindings.php(41): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#18 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Routing\\Middleware\\SubstituteBindings->handle()
#19 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/VerifyCsrfToken.php(77): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#20 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\VerifyCsrfToken->handle()
#21 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/View/Middleware/ShareErrorsFromSession.php(49): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#22 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\View\\Middleware\\ShareErrorsFromSession->handle()
#23 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Session/Middleware/StartSession.php(121): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#24 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Session/Middleware/StartSession.php(63): Illuminate\\Session\\Middleware\\StartSession->handleStatefulRequest()
#25 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Session\\Middleware\\StartSession->handle()
#26 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/AddQueuedCookiesToResponse.php(37): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#27 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Cookie\\Middleware\\AddQueuedCookiesToResponse->handle()
#28 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/EncryptCookies.php(67): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#29 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Cookie\\Middleware\\EncryptCookies->handle()
#30 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(103): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#31 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Routing/Router.php(694): Illuminate\\Pipeline\\Pipeline->then()
#32 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Routing/Router.php(669): Illuminate\\Routing\\Router->runRouteWithinStack()
#33 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Routing/Router.php(635): Illuminate\\Routing\\Router->runRoute()
#34 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Routing/Router.php(624): Illuminate\\Routing\\Router->dispatchToRoute()
#35 /var/www/html/podchaser-api/vendor/dingo/api/src/Routing/Adapter/Laravel.php(88): Illuminate\\Routing\\Router->dispatch()
#36 /var/www/html/podchaser-api/vendor/dingo/api/src/Routing/Router.php(518): Dingo\\Api\\Routing\\Adapter\\Laravel->dispatch()
#37 /var/www/html/podchaser-api/vendor/dingo/api/src/Http/Middleware/Request.php(126): Dingo\\Api\\Routing\\Router->dispatch()
#38 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(128): Dingo\\Api\\Http\\Middleware\\Request->Dingo\\Api\\Http\\Middleware\\{closure}()
#39 /var/www/html/podchaser-api/vendor/laravel/nova/src/Http/Middleware/ServeNova.php(27): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#40 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Laravel\\Nova\\Http\\Middleware\\ServeNova->handle()
#41 /var/www/html/podchaser-api/vendor/fruitcake/laravel-cors/src/HandleCors.php(57): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#42 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Fruitcake\\Cors\\HandleCors->handle()
#43 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#44 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle()
#45 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#46 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle()
#47 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/ValidatePostSize.php(27): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#48 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\ValidatePostSize->handle()
#49 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/PreventRequestsDuringMaintenance.php(87): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#50 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\PreventRequestsDuringMaintenance->handle()
#51 /var/www/html/podchaser-api/vendor/fruitcake/laravel-cors/src/HandleCors.php(57): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#52 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Fruitcake\\Cors\\HandleCors->handle()
#53 /var/www/html/podchaser-api/vendor/fideloper/proxy/src/TrustProxies.php(57): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#54 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Fideloper\\Proxy\\TrustProxies->handle()
#55 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(103): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#56 /var/www/html/podchaser-api/vendor/dingo/api/src/Http/Middleware/Request.php(127): Illuminate\\Pipeline\\Pipeline->then()
#57 /var/www/html/podchaser-api/vendor/dingo/api/src/Http/Middleware/Request.php(103): Dingo\\Api\\Http\\Middleware\\Request->sendRequestThroughRouter()
#58 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Dingo\\Api\\Http\\Middleware\\Request->handle()
#59 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(103): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#60 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(141): Illuminate\\Pipeline\\Pipeline->then()
#61 /var/www/html/podchaser-api/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(110): Illuminate\\Foundation\\Http\\Kernel->sendRequestThroughRouter()
#62 /var/www/html/podchaser-api/public/index.php(52): Illuminate\\Foundation\\Http\\Kernel->handle()
#63 {main}
"} 
GrahamCampbell commented 3 years ago

This error usually happens when the bugsnag service provider has not been added (in the right place) to your config/app.php file.

fpcorso commented 3 years ago

@GrahamCampbell We have it in the app.php file above the app service provider as the documentation says to. Is there a different place for it?

// Other providers omitted...
Bugsnag\BugsnagLaravel\BugsnagServiceProvider::class,
\App\Providers\DingoServiceProvider::class,
App\Providers\AppServiceProvider::class,
// Other providers omitted...
GrahamCampbell commented 3 years ago

What happens when you type config('app') into php artisan tinker?

fpcorso commented 3 years ago

@GrahamCampbell Using config('app') inside tinker shows a variety of information including the providers. Bugsnag is listed in the providers as shown in this screenshot:

image

GrahamCampbell commented 3 years ago

The Bugsnag provider is too low there. You need to add it before your app service providers.

fpcorso commented 3 years ago

Ah, sorry @GrahamCampbell , thought the docs meant before the AppServiceProvider not before all app level providers.

Unfortunately, that did not resolve this issue. First, I tried moving it to the top of the app-level providers and clearing config and cache. The same issue occurred. Here is the screenshot of it's order using config('app'):

image

Then, I tried moving it all the way to the beginning of the array and clearing the config and cache. The same issue occurred. Here is the screenshot of it's order using config('app'):

image

xljones commented 3 years ago

Edit: Hey @fpcorso, sorry, I missed the default selection for dev_stack you've made in your code. Do you also have a LOG_CHANNEL in your .env.

As per the email comms too, are you able to send us a cut down repro for us to investigate this a bit further?

fpcorso commented 3 years ago

@xander-jones This is a fairly large Laravel app with Scout, Nova, Elastic Search, and many integrations and layers. Not sure I'll have the time to create a cut-down repo for you. But, I did take a few minutes to walk through Xdebug to see if I can get some more details.

Unfortunately, it mostly mirrors the info from the stack trace:

During an exception, we do get into Laravel's LogManager's get which is where this error message is coming from: https://github.com/laravel/framework/blob/8.x/src/Illuminate/Log/LogManager.php#L123

Within that with function, it calls its resolve function. That is where the exception occurs. We pass all the if conditonals and end on the throw new InvalidArgumentException line: https://github.com/laravel/framework/blob/8.x/src/Illuminate/Log/LogManager.php#L205

As shown in the screenshot, the $driverMethod that is checked for is createBugsnagDriver:

image

I've never dived into Laravel's logging system before so I am sorry if all of this was super obvious to you already.

If there is a better section of code for me to step through to give you info, please let me know.

GrahamCampbell commented 3 years ago

Do you have a package which is re-registering laravel'\s logger after bugsnag has already registered itself with it, effectively deleting bugnsnag's driver registration?

fpcorso commented 3 years ago

@GrahamCampbell @xander-jones over in an email response from Bugsnag, John pointed out the stack trace goes through Dingo. I did a little digging and it seems Dingo has its own exception handling.

All of our routes go through or adds in the Dingo router and we have many hooks into it throughout our provider(s) so I am not sure if I can eliminate/comment out enough of Dingo to know for sure if that is indeed the issue.

That said, their handler does call its parent handler's report method so not sure if this is this issue or not: https://github.com/dingo/api/blob/master/src/Exception/Handler.php#L83

Unfortunately, I don't have any more time this week to debug this further.

johnkiely1 commented 3 years ago

Hi @fpcorso,

Did you manage to get any further with this? We've not been able to reproduce the issue you are seeing. Has any new information come to light? I appreciate there would be some effort involved but if it were possible to create a reproduction example project that demonstrates this behaviour it would really help us progress the investigation. Thanks

abigailbramble commented 3 years ago

Closing as we have not heard back. If you do have any further information on this or are able to send through a reproduction example, please comment below and we will reopen this issue. Please also feel free to write into support@bugsnag.com.