InvoiceNinja v5 Application Lockup, server resources skyrocket

link470 · April 24, 2023, 3:09am

I’m moving this one into it’s own topic. @david , you’d asked earlier about the application lockup I was experiencing (which I think is the only thing left in my v5 migration I haven’t figured out). I’ve done some more testing and I encountered the same thing fairly quick today while using Invoice Ninja. I’m using Supervisor, and I’m using snappdf for rendering invoices locally on the server.

Usually, when viewing the editing screen for an invoice, the preview appears just fine at the bottom of the page within a second or so. I’ll see the line animation at the top of the invoice cycling across the screen and then the invoice will either appear (if showing for the first time on that page load), or refresh (if I’ve made changes to the invoice). Usually, this works fine. But I clicked to open another invoice in editing view, and when I did, Invoice Ninja showed the loading line at the top of the invoice preview area for 10-15 seconds, and I knew something wasn’t right. I attempted to refresh, nothing. I attempted to load another website on that server, nothing. I attempted to SSH into the server, nothing. The server was clearly using very high resources for a moment and had locked itself up.

I gained control of the server around 5 minutes later. This was from roughly 7:40 to 7:45 PM PST. When I refreshed Invoice Ninja, I went back into the same invoice I had just had the lockup with, and the invoice preview rendered perfectly fine. I tried a couple other invoices just for good measure, and they also loaded the invoice preview totally fine. So it doesn’t seem to be any particular problem with a character or something in that invoice, I wouldn’t think.

Here’s the relevant logs (sanitized) around the time this happened. Please let me know if you need anything else.

Laravel log:

[2023-04-24 00:08:25] production.INFO: Broadcasting [App\Events\Invoice\InvoiceWasCreated] on channels [simple-channel] with payload:
{
    "id": "value",
    "socket": null
}  
[2023-04-24 02:40:24] production.ERROR: The process "'/invoiceninja/path/vendor/beganovich/snappdf/versions/1125149-Linux_x64/chrome-linux/chrome' '--headless' '--disable-gpu' '--disable-translate' '--disable-extensions' '--disable-sync' '--disable-background-networking' '--disable-software-rasterizer' '--disable-default-apps' '--disable-dev-shm-usage' '--safebrowsing-disable-auto-update' '--run-all-compositor-stages-before-draw' '--no-first-run' '--no-margins' '--no-sandbox' '--print-to-pdf-no-header' '--hide-scrollbars' '--ignore-certificate-errors' '--print-to-pdf=/tmp/pdf_EbOPj9.pdf' '/tmp/html_TQCD3K.html'" exceeded the timeout of 60 seconds. {"userId":1,"exception":"[object] (Symfony\\Component\\Process\\Exception\\ProcessTimedOutException(code: 0): The process \"'/invoiceninja/path/vendor/beganovich/snappdf/versions/1125149-Linux_x64/chrome-linux/chrome' '--headless' '--disable-gpu' '--disable-translate' '--disable-extensions' '--disable-sync' '--disable-background-networking' '--disable-software-rasterizer' '--disable-default-apps' '--disable-dev-shm-usage' '--safebrowsing-disable-auto-update' '--run-all-compositor-stages-before-draw' '--no-first-run' '--no-margins' '--no-sandbox' '--print-to-pdf-no-header' '--hide-scrollbars' '--ignore-certificate-errors' '--print-to-pdf=/tmp/pdf_EbOPj9.pdf' '/tmp/html_TQCD3K.html'\" exceeded the timeout of 60 seconds. at /invoiceninja/path/vendor/symfony/process/Process.php:1154)
[stacktrace]
#0 /invoiceninja/path/vendor/symfony/process/Process.php(423): Symfony\\Component\\Process\\Process->checkTimeout()
#1 /invoiceninja/path/vendor/symfony/process/Process.php(249): Symfony\\Component\\Process\\Process->wait()
#2 /invoiceninja/path/vendor/beganovich/snappdf/src/Snappdf.php(257): Symfony\\Component\\Process\\Process->run()
#3 /invoiceninja/path/app/Utils/Traits/Pdf/PdfMaker.php(44): Beganovich\\Snappdf\\Snappdf->generate()
#4 /invoiceninja/path/app/Jobs/Util/PreviewPdf.php(50): App\\Jobs\\Util\\PreviewPdf->makePdf()
#5 /invoiceninja/path/app/Http/Controllers/PreviewController.php(325): App\\Jobs\\Util\\PreviewPdf->handle()
#6 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Controller.php(54): App\\Http\\Controllers\\PreviewController->live()
#7 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/ControllerDispatcher.php(43): Illuminate\\Routing\\Controller->callAction()
#8 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Route.php(260): Illuminate\\Routing\\ControllerDispatcher->dispatch()
#9 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Route.php(205): Illuminate\\Routing\\Route->runController()
#10 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Router.php(798): Illuminate\\Routing\\Route->run()
#11 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\\Routing\\Router->Illuminate\\Routing\\{closure}()
#12 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Middleware/ThrottleRequests.php(89): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#13 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Middleware/ThrottleRequests.php(54): Illuminate\\Routing\\Middleware\\ThrottleRequests->handleRequestUsingNamedLimiter()
#14 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Routing\\Middleware\\ThrottleRequests->handle()
#15 /invoiceninja/path/app/Http/Middleware/QueryLogging.php(38): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#16 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): App\\Http\\Middleware\\QueryLogging->handle()
#17 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Middleware/SubstituteBindings.php(50): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#18 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Routing\\Middleware\\SubstituteBindings->handle()
#19 /invoiceninja/path/app/Http/Middleware/Locale.php(44): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#20 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): App\\Http\\Middleware\\Locale->handle()
#21 /invoiceninja/path/app/Http/Middleware/TokenAuth.php(100): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#22 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): App\\Http\\Middleware\\TokenAuth->handle()
#23 /invoiceninja/path/app/Http/Middleware/SetDb.php(40): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#24 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): App\\Http\\Middleware\\SetDb->handle()
#25 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#26 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Router.php(799): Illuminate\\Pipeline\\Pipeline->then()
#27 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Router.php(776): Illuminate\\Routing\\Router->runRouteWithinStack()
#28 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Router.php(740): Illuminate\\Routing\\Router->runRoute()
#29 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Routing/Router.php(729): Illuminate\\Routing\\Router->dispatchToRoute()
#30 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(190): Illuminate\\Routing\\Router->dispatch()
#31 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\\Foundation\\Http\\Kernel->Illuminate\\Foundation\\Http\\{closure}()
#32 /invoiceninja/path/vendor/livewire/livewire/src/DisableBrowserCache.php(19): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#33 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Livewire\\DisableBrowserCache->handle()
#34 /invoiceninja/path/app/Http/Middleware/Cors.php(24): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#35 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): App\\Http\\Middleware\\Cors->handle()
#36 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Http/Middleware/TrustProxies.php(39): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#37 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Http\\Middleware\\TrustProxies->handle()
#38 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#39 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/ConvertEmptyStringsToNull.php(31): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle()
#40 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Foundation\\Http\\Middleware\\ConvertEmptyStringsToNull->handle()
#41 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TransformsRequest.php(21): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#42 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/TrimStrings.php(40): Illuminate\\Foundation\\Http\\Middleware\\TransformsRequest->handle()
#43 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Foundation\\Http\\Middleware\\TrimStrings->handle()
#44 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/ValidatePostSize.php(27): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#45 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Foundation\\Http\\Middleware\\ValidatePostSize->handle()
#46 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Middleware/PreventRequestsDuringMaintenance.php(86): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#47 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(180): Illuminate\\Foundation\\Http\\Middleware\\PreventRequestsDuringMaintenance->handle()
#48 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\\Pipeline\\Pipeline->Illuminate\\Pipeline\\{closure}()
#49 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(165): Illuminate\\Pipeline\\Pipeline->then()
#50 /invoiceninja/path/vendor/laravel/framework/src/Illuminate/Foundation/Http/Kernel.php(134): Illuminate\\Foundation\\Http\\Kernel->sendRequestThroughRouter()
#51 /invoiceninja/path/public/index.php(57): Illuminate\\Foundation\\Http\\Kernel->handle()
#52 {main}
"} 
[2023-04-24 02:44:45] production.INFO: db fails

Supervisor log:

2023-04-24 02:39:12 App\Listeners\Invoice\UpdateInvoiceActivity  2023-04-24 02:39:12 App\Jobs\Entity\CreateEntityPdf ....  2023-04-24 02:39:12 App\Jobs\Entity\CreateEntityPdf ................ RUNNING
 RUNNING
 ................ RUNNING
  2023-04-24 02:39:14 App\Listeners\Invoice\UpdateInvoiceActivity  1,934.94ms DONE
  2023-04-24 02:45:02 App\Jobs\Ninja\QueueSize ....................... RUNNING
  2023-04-24 02:45:02 App\Jobs\Ninja\QueueSize .................. 18.22ms DONE

Apache Error log:

[Sun Apr 23 19:08:06.347335 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:12540] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:38:45.864681 2023] [proxy_fcgi:error] [pid 179619:tid 140599222371904] [client <MyIP>:58446] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:38:56.116234 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:39:01.381586 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:39:07.241892 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:39:11.007058 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:39:12.522014 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:39:12.925148 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:40:24.375158 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:44:44.005506 2023] [proxy_fcgi:error] [pid 179620:tid 140599239157312] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:44:57.494452 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:44:59.532511 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:45:00.872863 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:45:02.038566 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:40560] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:49:56.869280 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:49:57.621890 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:49:59.768253 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:00.715426 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:03.339717 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:03.986107 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:04.736035 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:05.524322 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:06.350139 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:07.083336 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:07.837529 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:08.622953 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:09.342503 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>
[Sun Apr 23 19:50:10.069181 2023] [proxy_fcgi:error] [pid 179620:tid 140599230764608] [client <MyIP>:58051] AH01071: Got error 'PHP message: PHP Deprecated:  Return type of League\\Fractal\\ParamBag::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice in /invoiceninja/path/vendor/league/fractal/src/ParamBag.php on line 108', referer: https://<invoiceninjaapp>

david · April 24, 2023, 7:12am

You may want to edit your php.ini and not log errors for deprecations / warnings, this could use resources unnecessarily.

The chrome timeout is something that can be seen intermittently, if you have a lot of those types of errors, it may indicate a separate issue.

Depending on your server, you may want to limit the number of child processes that Supervisor spins up. Typically you can safely assign 1 process per CPU, however if your server specs are not super high, you may want to reduce this down.

link470 · April 26, 2023, 5:56am

Thanks @david . I still think I must be coming across some sort of bug. The system regularly runs with the default 8 supervisor processes, and it never seems to have an issue throughout the day with all of these running (not actively using Invoice Ninja, just the server running in general). I can load other PHP/MySQL websites on this same server all I want and they have zero issues and are super quick loading, even with multiple users using them.

I didn’t use Invoice Ninja all day yesterday, until I got home and needed to create one invoice. Before doing this, I had turned off Settings > Device Settings > Show PDF Preview, since I thought that’s what triggered the lockup last time. I went ahead and created the invoice and clicked save. No problem. I made another change to the invoice, and clicked Save again, and boom, server lockup, without the preview showing. I gained control again around 5 minutes later. During this time, like before, SSH was locked up, and no other websites would load.

Again just now… I started using Invoice Ninja just a moment ago, and within 20 seconds of using it, server lockup. Something is seriously wrong. I shouldn’t have the server completely die for 5 minutes after 20 seconds of using an app, when everything else on this same server is running flawlessly. Are there any other logs I can provide you?

link470 · April 26, 2023, 6:23am

Just triggered it again @david . Twice in a row by saving an invoice. I went in to edit one invoice, saved it, and then clicked Back, clicked another Invoice, clicked Save, lockup. Running v5.5.104-SC113.

david · April 26, 2023, 6:25am

@link470

I wonder if you are getting mysql deadlocks, these could block and may cause these kind of symptoms. I would inspect the mysql logs and search for any errors there.

link470 · April 26, 2023, 6:34am

@david just locked the server up again, by saving an invoice. Would deadlocks appear in MySQL error.log? My error.log file from today is completely clean for MySQL. Other MySQL web apps are all behaving normally.

david · April 26, 2023, 7:05am

@link470

I would try to put the app into debug mode +/- change your pdf_generator to

hosted_ninja

this will exclude snappdf/chrome as the cause

link470 · April 26, 2023, 7:09am

@david ah, ok, I’ve got a consistent way to overload the server now. It definitely seems to have something to do with saving the invoice, and specifically, snappdf. I watched htop the whole time as well.

As a test, I went to Clients, and then clicked the Edit circle with pencil icon on a client, and then saved. I did this for the top 10 clients in the list. So, edit, save, edit, save, edit, save, etc. for 10 clients. No problem. I watched htop, and server resources were calm the whole time. All good.

Then, I moved onto Products. I did the same thing, edit, save, edit, save, for 10 products. All good as well.

I moved onto Payments, doing the same thing, and again, no problem.

Finally, I returned to Invoices. I clicked to edit the first invoice, and it saved successfully, but as I watched htop in my SSH session, resources were starting to skyrocket. I clicked edit on another invoice, hit save, and unresponsive. It came back after about 45 seconds or so. I clicked save again, unresponsive.

Here’s htop’s system stats when I simply refresh Invoice Ninja. It’s a bit clunky, but the server handles it easily while loading other websites. Disk usage at 26.8MB/s, not bad. Doing everything above (saving products, clients, payments) was next to zero resources.

But wait for it…now I hit save on an invoice.

Yep, just a casual 18.7GB/s of disk usage for a solid few minutes. Here’s where I think snappdf has something to do with it. Check out that virtual memory.

So, all this to say, is there something I’ve done terribly wrong in my snappdf install, or is this a bug?

PDF generation still works totally fine if I download an invoice, so snappdf seems to be working. But some function of its use seems incredibly unoptimized.

Just to help in the troubleshooting, here’s the exact steps I took in my snappdf install awhile back (from my documentation):

Edit the .env file to change the generator.
$ sudo vi /path/to/invoiceninja/.env

Edited the line:
PDF_GENERATOR=snappdf
then saved and exited.

Invoked the download of snappdf:

$ cd /path/to/invoiceninja
$ sudo -u www-data vendor/bin/snappdf download

Ensured dependencies were installed (for me on Ubuntu 22.04 LTS, I only needed to install fonts-liberation, libappindicator3-1, libasound2, libgbm1, and libxss1).

$ sudo apt-get install fonts-liberation libappindicator3-1 libasound2 libatk-bridge2.0-0 libatk1.0-0 libc6 libcairo2 libcups2 libdbus-1-3 libexpat1 libfontconfig1 libgbm1 libgcc1 libglib2.0-0 libgtk-3-0 libnspr4 libnss3 libpango-1.0-0 libpangocairo-1.0-0 libstdc++6 libx11-6 libx11-xcb1 libxcb1 libxcomposite1 libxcursor1 libxdamage1 libxext6 libxfixes3 libxi6 libxrandr2 libxrender1 libxss1 libxtst6 lsb-release wget xdg-utils

Test snappdf:

$ cd /path/to/invoiceninja
$ sudo -u www-data ./vendor/bin/snappdf convert --html "<h1>Hello world</h1>" test.pdf

Finally, re-verified permissions

$ cd /path/to/webroot
$ sudo chown -R www-data:www-data invoiceninja/
$ cd /path/to/invoiceninja
$ sudo -u www-data php artisan optimize

david · April 26, 2023, 10:23am

Change to

PDF_GENERATOR=hosted_ninja

and retest.

If the system locks again you can exclude snappdf as the issue.

I can see you only have a single CPU in your machine, you should only run a single queue worker, not 8, i think this is the most likely reason why your system is locking as it is attempting way too much work.

link470 · April 27, 2023, 4:48am

Change to
PDF_GENERATOR=hosted_ninja
and retest.

@david sounds good, will do. I changed the .env from snappdf to hosted_ninja and saved. I then ran the status check in Invoice Ninja, and it showed PDF as hosted_ninja. Interestingly, even though hosted_ninja was now the pdf generator, I tried saving an invoice, and immediately saw all the snappdf processes fire up and the system start to grind to a halt. I waited a couple more minutes before testing again as maybe something else had to run in the background and I was too quick.

Sure enough, I’ve tried editing/saving 10 or so each of products, clients, payments, just as I did before, and then going to Invoices and editing one and saving, and saving again, and… it seems to be working! I’ve opened a few invoices now, and then saving, and repeating, and watching htop the whole time on the server, CPU usage is staying around 10% or below, and disk activity is next to nothing now. Seems stable!

I can see you only have a single CPU in your machine, you should only run a single queue worker, not 8

Good to know, thanks! I’ve now updated my supervisor conf from the default of 8 processes to 1. But even at 8, it was stable just using ninja_hosted.

I then switched back to snappdf now that I only have 1 supervisor process, and everything is working correctly. So, I was able to use 8 supervisor processes no problem with hosted_ninja, but the combination of snappdf and 8 worker processes was too much. I confirmed this by switching supervisor processes back to 8 with snappdf, and the system locked up for a few minutes again almost right away after saving a couple invoices. Changing back to 1 process again solves this. Thanks again!