Ignition causes timeout after RelationNotFoundException

[miken32]

In a controller method I was trying to load a relationship. I accidentally used snake case instead of camel case for a 2-word relationship, and Laravel immediately threw a RelationNotFoundException. However, the browser kept on spinning for another 60 seconds before PHP killed execution due to timeout.

The timeout error doesn't happen in a consistent place, I saw a number of different code locations for it, none of which are in the Ignition codebase, but this only happens with Ignition enabled. If I uninstall Ignition, a "whoops" error is triggered immediately.

Using Laravel 8.79 and PHP 8.1. Tested with Ignition 0.0.9 and 1.0.1. Tried setting enable_runnable_solutions => false and solution_providers => [] without any change.

Code being run was a basic controller method:

    public function edit(Client $client): Response
    {
        $client->load("users", "user_profiles");
        return response()->view("clients.edit", compact("client"));
    }

Stack trace is as follows, please advise if there's any other detail I can provide.

[2022-01-19 23:48:25] local.ERROR: Call to undefined relationship [user_profiles] on model [App\Models\Client]. {"userId":1,"exception":"[object] (Illuminate\\Database\\Eloquent\\RelationNotFoundException(code: 0): Call to undefined relationship [user_profiles] on model [App\\Models\\Client]. at /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/RelationNotFoundException.php:35)
[stacktrace]
#0 /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php(692): Illuminate\\Database\\Eloquent\\RelationNotFoundException::make(Object(App\\Models\\Client), 'user_profiles')
#1 /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/Relations/Relation.php(106): Illuminate\\Database\\Eloquent\\Builder->Illuminate\\Database\\Eloquent\\{closure}()
#2 /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php(694): Illuminate\\Database\\Eloquent\\Relations\\Relation::noConstraints(Object(Closure))
#3 /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php(662): Illuminate\\Database\\Eloquent\\Builder->getRelation('user_profiles')
#4 /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php(642): Illuminate\\Database\\Eloquent\\Builder->eagerLoadRelation(Array, 'user_profiles', Object(Closure))
#5 /project/vendor/laravel/framework/src/Illuminate/Database/Eloquent/Model.php(597): Illuminate\\Database\\Eloquent\\Builder->eagerLoadRelations(Array)
#6 /project/app/Http/Controllers/ClientController.php(56): Illuminate\\Database\\Eloquent\\Model->load('users', 'user_profiles')
#7 /project/vendor/laravel/framework/src/Illuminate/Routing/Controller.php(54): App\\Http\\Controllers\\ClientController->edit(Object(App\\Models\\Client))
#8 /project/vendor/laravel/framework/src/Illuminate/Routing/ControllerDispatcher.php(45): Illuminate\\Routing\\Controller->callAction('edit', Array)
#9 /project/vendor/laravel/framework/src/Illuminate/Routing/Route.php(262): Illuminate\\Routing\\ControllerDispatcher->dispatch(Object(Illuminate\\Routing\\Route), Object(App\\Http\\Controllers\\ClientController), 'edit')
#10 /project/vendor/laravel/framework/src/Illuminate/Routing/Route.php(205): Illuminate\\Routing\\Route->runController()
#11 /project/vendor/laravel/framework/src/Illuminate/Routing/Router.php(721): Illuminate\\Routing\\Route->run()
#12 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(128): Illuminate\\Routing\\Router->Illuminate\\Routing\\{closure}(Object(Illuminate\\Http\\Request))
#13 /project/vendor/laravel/framework/src/Illuminate/Routing/Middleware/SubstituteBindings.php(50): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#14 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Routing\\Middleware\\SubstituteBindings->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#15 /project/vendor/laravel/framework/src/Illuminate/Auth/Middleware/Authenticate.php(44): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#16 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Auth\\Middleware\\Authenticate->handle(Object(Illuminate\\Http\\Request), Object(Closure), 'admin')
#17 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/VerifyCsrfToken.php(78): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#18 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\VerifyCsrfToken->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#19 /project/vendor/laravel/framework/src/Illuminate/View/Middleware/ShareErrorsFromSession.php(49): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#20 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\View\\Middleware\\ShareErrorsFromSession->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#21 /project/vendor/laravel/framework/src/Illuminate/Session/Middleware/StartSession.php(121): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#22 /project/vendor/laravel/framework/src/Illuminate/Session/Middleware/StartSession.php(64): Illuminate\\Session\\Middleware\\StartSession->handleStatefulRequest(Object(Illuminate\\Http\\Request), Object(Illuminate\\Session\\Store), Object(Closure))
#23 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Session\\Middleware\\StartSession->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#24 /project/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/AddQueuedCookiesToResponse.php(37): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#25 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Cookie\\Middleware\\AddQueuedCookiesToResponse->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#26 /project/vendor/laravel/framework/src/Illuminate/Cookie/Middleware/EncryptCookies.php(67): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#27 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Cookie\\Middleware\\EncryptCookies->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#28 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(103): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#29 /project/vendor/laravel/framework/src/Illuminate/Routing/Router.php(723): Illuminate\\Pipeline\\Pipeline->then(Object(Closure))
#30 /project/vendor/laravel/framework/src/Illuminate/Routing/Router.php(698): Illuminate\\Routing\\Router->runRouteWithinStack(Object(Illuminate\\Routing\\Route), Object(Illuminate\\Http\\Request))
#31 /project/vendor/laravel/framework/src/Illuminate/Routing/Router.php(662): Illuminate\\Routing\\Router->runRoute(Object(Illuminate\\Http\\Request), Object(Illuminate\\Routing\\Route))
#32 /project/vendor/laravel/framework/src/Illuminate/Routing/Router.php(651): Illuminate\\Routing\\Router->dispatchToRoute(Object(Illuminate\\Http\\Request))
#33 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(167): Illuminate\\Routing\\Router->dispatch(Object(Illuminate\\Http\\Request))
#34 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(128): Illuminate\\Foundation\\Http\\Kernel->Illuminate\\Foundation\\Http\\{closure}(Object(Illuminate\\Http\\Request))
#35 /project/vendor/barryvdh/laravel-debugbar/src/Middleware/InjectDebugbar.php(67): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#36 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Barryvdh\\Debugbar\\Middleware\\InjectDebugbar->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#37 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#38 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/ConvertEmptyStringsToNull.php(31): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#39 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\ConvertEmptyStringsToNull->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#40 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#41 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TrimStrings.php(40): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#42 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\TrimStrings->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#43 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/ValidatePostSize.php(27): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#44 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\ValidatePostSize->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#45 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/PreventRequestsDuringMaintenance.php(86): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#46 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Foundation\\Http\\Middleware\\PreventRequestsDuringMaintenance->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#47 /project/vendor/fruitcake/laravel-cors/src/HandleCors.php(38): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#48 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Fruitcake\\Cors\\HandleCors->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#49 /project/vendor/laravel/framework/src/Illuminate/Http/Middleware/TrustProxies.php(39): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#50 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(167): Illuminate\\Http\\Middleware\\TrustProxies->handle(Object(Illuminate\\Http\\Request), Object(Closure))
#51 /project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(103): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}(Object(Illuminate\\Http\\Request))
#52 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(142): Illuminate\\Pipeline\\Pipeline->then(Object(Closure))
#53 /project/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(111): Illuminate\\Foundation\\Http\\Kernel->sendRequestThroughRouter(Object(Illuminate\\Http\\Request))
#54 /project/public/index.php(52): Illuminate\\Foundation\\Http\\Kernel->handle(Object(Illuminate\\Http\\Request))
#55 /project/server.php(21): require_once('/Users/mike/Sit...')
#56 {main}
"} 
[2022-01-19 23:49:25] local.ERROR: Maximum execution time of 60 seconds exceeded {"userId":1,"exception":"[object] (Symfony\\Component\\ErrorHandler\\Error\\FatalError(code: 0): Maximum execution time of 60 seconds exceeded at /project/vendor/nesbot/carbon/src/Carbon/Traits/Date.php:908)
[stacktrace]
#0 {main}
"} 

[freekmurze]

Could you provide us with a small example app that triggers this issue?

[miken32]

Ok, I'm not able to recreate the 60 second timeout, but I do have some code that consistently takes 10 seconds before returning. Not sure if this is an environment difference between apps, or due to the other app having a database full of data?

Clone https://github.com/miken32/example-app, migrate, seed, and serve. Then try to access /user/1/edit. I consistently get a 10 second delay before the error page displays, which did not occur when using the default facade/ignition 2.17.4. It's always exactly 10 seconds:

Starting Laravel development server: http://127.0.0.1:8001
[Fri Jan 21 11:20:04 2022] PHP 8.1.0 Development Server (http://127.0.0.1:8001) started
[Fri Jan 21 11:20:07 2022] 127.0.0.1:51893 Accepted
[Fri Jan 21 11:20:17 2022] 127.0.0.1:51893 Closing
[Fri Jan 21 11:20:58 2022] 127.0.0.1:51909 Accepted
[Fri Jan 21 11:21:08 2022] 127.0.0.1:51909 Closing
[Fri Jan 21 11:21:34 2022] 127.0.0.1:51916 Accepted
[Fri Jan 21 11:21:44 2022] 127.0.0.1:51916 Closing
[Fri Jan 21 11:25:29 2022] 127.0.0.1:51949 Accepted
[Fri Jan 21 11:25:39 2022] 127.0.0.1:51949 Closing

Editing the controller to remove the valid relationship foos makes the error page return immediately. The same happens on my actual app; if I attempt to load the invalid relationship alone, it errors out immediately. The timeout only occurs if another relationship is loaded first.

[spatie-bot]

Dear contributor,

because this issue seems to be inactive for quite some time now, I've automatically closed it. If you feel this issue deserves some attention from my human colleagues feel free to reopen it.