Laravel 8 - Hangs Intermittently every minute or so (Local and Live Server)

Ok - so I've added this to AppServiceProvider.php, so I can log any queries that happen...

<?php

namespace App\Providers;

use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Log;
use Illuminate\Support\ServiceProvider;

class AppServiceProvider extends ServiceProvider
{
    /**
     * Register any application services.
     *
     * @return void
     */
    public function register()
    {
        //
    }

    /**
     * Bootstrap any application services.
     *
     * @return void
     */
    public function boot()
    {
        DB::listen(function ($query) {
            Log::info($query->sql);
        });
    }
}

I have this very basic function in the web.php route file which performs just one query:

Route::get('/greeting', function () {
    Log::error('hello world::::');
    return response()->json([FinanceBudgetingPSTSetGroup::find(1)], 201);
});

I am logging to the laravel.log file. Here is what I see:

[2024-01-26 08:14:00] local.ERROR: hello world::::  
[2024-01-26 08:14:00] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:02] local.ERROR: hello world::::  
[2024-01-26 08:14:02] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:03] local.ERROR: hello world::::  
[2024-01-26 08:14:03] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:05] local.ERROR: hello world::::  
[2024-01-26 08:14:05] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:06] local.ERROR: hello world::::  
[2024-01-26 08:14:06] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:08] local.ERROR: hello world::::  
[2024-01-26 08:14:08] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:10] local.ERROR: hello world::::  
[2024-01-26 08:14:10] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 08:14:39] local.ERROR: hello world::::  
[2024-01-26 08:14:39] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  

Notice the hang after 2024-01-26 08:14:10 - no other queries were executed, just the one I intended.

I'm very confused

Update: Using app.inspector.dev, the only information I can see that's different is the memory usage on the requests that hang are 20.16mb, compared to 19.96mb.

Another update:

Logging in the RouteServiceProvider:

    public function boot()
    {
        Log::alert('ROUTESERVICEPROVIDER'); <------------------------------
        $this->configureRateLimiting();

        $this->routes(function () {
            Route::prefix('api')
                ->middleware('api')
                ->namespace($this->namespace)
                ->group(base_path('routes/api.php'));

            Route::middleware('web')
                ->namespace($this->namespace)
                ->group(base_path('routes/web.php'));
        });
    }

and then in my web.php function:

Route::get('/greeting', function () {
    Log::alert('WEB.PHP'); <------------------------------
    return response()->json([FinanceBudgetingPSTSetGroup::find(1)], 201);
});

Reveals that it hits RouteServiceProvider instantly, then hangs before it gets to web.php:

[2024-01-26 11:18:14] local.ALERT: ROUTESERVICEPROVIDER  
[2024-01-26 11:18:14] local.INFO: select * from `users` where `id` = ? and `users`.`deleted_at` is null order by `last_name` asc, `first_name` asc limit 1  
[2024-01-26 11:18:14] local.ALERT: WEB.PHP  
[2024-01-26 11:18:14] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 11:18:16] local.ALERT: ROUTESERVICEPROVIDER  
[2024-01-26 11:18:16] local.INFO: select * from `users` where `id` = ? and `users`.`deleted_at` is null order by `last_name` asc, `first_name` asc limit 1  
[2024-01-26 11:18:16] local.ALERT: WEB.PHP  
[2024-01-26 11:18:16] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 11:18:17] local.ALERT: ROUTESERVICEPROVIDER  
[2024-01-26 11:18:17] local.INFO: select * from `users` where `id` = ? and `users`.`deleted_at` is null order by `last_name` asc, `first_name` asc limit 1  
[2024-01-26 11:18:17] local.ALERT: WEB.PHP  
[2024-01-26 11:18:17] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 11:18:19] local.ALERT: ROUTESERVICEPROVIDER  
[2024-01-26 11:18:19] local.INFO: select * from `users` where `id` = ? and `users`.`deleted_at` is null order by `last_name` asc, `first_name` asc limit 1  
[2024-01-26 11:18:19] local.ALERT: WEB.PHP  
[2024-01-26 11:18:19] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  
[2024-01-26 11:18:21] local.ALERT: ROUTESERVICEPROVIDER  
[2024-01-26 11:18:21] local.INFO: select * from `users` where `id` = ? and `users`.`deleted_at` is null order by `last_name` asc, `first_name` asc limit 1  
[2024-01-26 11:18:21] local.ALERT: WEB.PHP  
[2024-01-26 11:18:21] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  

------- It hits the routeserviceprovider instantly ----------

[2024-01-26 11:18:22] local.ALERT: ROUTESERVICEPROVIDER  

-------          Hangs for around 30 seconds         ----------

[2024-01-26 11:18:50] local.INFO: select * from `users` where `id` = ? and `users`.`deleted_at` is null order by `last_name` asc, `first_name` asc limit 1  
[2024-01-26 11:18:50] local.ALERT: WEB.PHP  
[2024-01-26 11:18:50] local.INFO: select * from `finance_budgeting_pst_set_groups` where `finance_budgeting_pst_set_groups`.`id` = ? order by `ord` asc limit 1  

Apologies for yet another update. This seems to be as far as I can get with nailing the issue down during the process...

public/index.php:

file_put_contents('logs.txt', "1".PHP_EOL , FILE_APPEND | LOCK_EX);
require __DIR__.'/../vendor/autoload.php';

/*
|--------------------------------------------------------------------------
| Run The Application
|--------------------------------------------------------------------------
|
| Once we have the application, we can handle the incoming request using
| the application's HTTP kernel. Then, we will send the response back
| to this client's browser, allowing them to enjoy our application.
|
*/
file_put_contents('logs.txt', "2".PHP_EOL , FILE_APPEND | LOCK_EX);
$app = require_once __DIR__.'/../bootstrap/app.php';
file_put_contents('logs.txt', "3".PHP_EOL , FILE_APPEND | LOCK_EX);
$kernel = $app->make(Kernel::class);
file_put_contents('logs.txt', "4".PHP_EOL , FILE_APPEND | LOCK_EX);
$response = $kernel->handle(
    $request = Request::capture()
)->send();
file_put_contents('logs.txt', "6".PHP_EOL , FILE_APPEND | LOCK_EX);
$kernel->terminate($request, $response);
file_put_contents('logs.txt', "7".PHP_EOL , FILE_APPEND | LOCK_EX);

Resultant file when it hangs (it gets to just before #4, then 30 seconds later it logs the rest):

Ok, I seemed to have finally nailed down the issue. The storage/framework/sessions folder had over 220,000 files in it! I cleared all these out and now everything seems fine. I have also amended the following in the session config file to stop this happening again:

'expire_on_close' => false,

'expire_on_close' => false,

only affects cookies and tells the browser via a flag on the cookie that it should discard the cookie if the user closes their browser. It won't make any difference to session files.

Sessions should be cleared by session sweeping, and the default config is;

'lottery' => [2, 100],

check you have this?

Also check the rate that the session files are being created, and that the session lifetime is a sensible value.

Thanks for that Snapey.

Here is my session config, it appears I do have it

<?php

use Illuminate\Support\Str;

return [

    /*
    |--------------------------------------------------------------------------
    | Default Session Driver
    |--------------------------------------------------------------------------
    |
    | This option controls the default session "driver" that will be used on
    | requests. By default, we will use the lightweight native driver but
    | you may specify any of the other wonderful drivers provided here.
    |
    | Supported: "file", "cookie", "database", "apc",
    |            "memcached", "redis", "dynamodb", "array"
    |
    */

    'driver' => env('SESSION_DRIVER', 'file'),

    /*
    |--------------------------------------------------------------------------
    | Session Lifetime
    |--------------------------------------------------------------------------
    |
    | Here you may specify the number of minutes that you wish the session
    | to be allowed to remain idle before it expires. If you want them
    | to immediately expire on the browser closing, set that option.
    |
    */

    'lifetime' => env('SESSION_LIFETIME', 120),

    'expire_on_close' => true,

    /*
    |--------------------------------------------------------------------------
    | Session Encryption
    |--------------------------------------------------------------------------
    |
    | This option allows you to easily specify that all of your session data
    | should be encrypted before it is stored. All encryption will be run
    | automatically by Laravel and you can use the Session like normal.
    |
    */

    'encrypt' => false,

    /*
    |--------------------------------------------------------------------------
    | Session File Location
    |--------------------------------------------------------------------------
    |
    | When using the native session driver, we need a location where session
    | files may be stored. A default has been set for you but a different
    | location may be specified. This is only needed for file sessions.
    |
    */

    'files' => storage_path('framework/sessions'),

    /*
    |--------------------------------------------------------------------------
    | Session Database Connection
    |--------------------------------------------------------------------------
    |
    | When using the "database" or "redis" session drivers, you may specify a
    | connection that should be used to manage these sessions. This should
    | correspond to a connection in your database configuration options.
    |
    */

    'connection' => env('SESSION_CONNECTION', null),

    /*
    |--------------------------------------------------------------------------
    | Session Database Table
    |--------------------------------------------------------------------------
    |
    | When using the "database" session driver, you may specify the table we
    | should use to manage the sessions. Of course, a sensible default is
    | provided for you; however, you are free to change this as needed.
    |
    */

    'table' => 'sessions',

    /*
    |--------------------------------------------------------------------------
    | Session Cache Store
    |--------------------------------------------------------------------------
    |
    | While using one of the framework's cache driven session backends you may
    | list a cache store that should be used for these sessions. This value
    | must match with one of the application's configured cache "stores".
    |
    | Affects: "apc", "dynamodb", "memcached", "redis"
    |
    */

    'store' => env('SESSION_STORE', null),

    /*
    |--------------------------------------------------------------------------
    | Session Sweeping Lottery
    |--------------------------------------------------------------------------
    |
    | Some session drivers must manually sweep their storage location to get
    | rid of old sessions from storage. Here are the chances that it will
    | happen on a given request. By default, the odds are 2 out of 100.
    |
    */

    'lottery' => [2, 100],

    /*
    |--------------------------------------------------------------------------
    | Session Cookie Name
    |--------------------------------------------------------------------------
    |
    | Here you may change the name of the cookie used to identify a session
    | instance by ID. The name specified here will get used every time a
    | new session cookie is created by the framework for every driver.
    |
    */

    'cookie' => env(
        'SESSION_COOKIE',
        Str::slug(env('APP_NAME', 'laravel'), '_').'_session'
    ),

    /*
    |--------------------------------------------------------------------------
    | Session Cookie Path
    |--------------------------------------------------------------------------
    |
    | The session cookie path determines the path for which the cookie will
    | be regarded as available. Typically, this will be the root path of
    | your application but you are free to change this when necessary.
    |
    */

    'path' => '/',

    /*
    |--------------------------------------------------------------------------
    | Session Cookie Domain
    |--------------------------------------------------------------------------
    |
    | Here you may change the domain of the cookie used to identify a session
    | in your application. This will determine which domains the cookie is
    | available to in your application. A sensible default has been set.
    |
    */

    'domain' => env('SESSION_DOMAIN', null),

    /*
    |--------------------------------------------------------------------------
    | HTTPS Only Cookies
    |--------------------------------------------------------------------------
    |
    | By setting this option to true, session cookies will only be sent back
    | to the server if the browser has a HTTPS connection. This will keep
    | the cookie from being sent to you when it can't be done securely.
    |
    */

    'secure' => env('SESSION_SECURE_COOKIE'),

    /*
    |--------------------------------------------------------------------------
    | HTTP Access Only
    |--------------------------------------------------------------------------
    |
    | Setting this value to true will prevent JavaScript from accessing the
    | value of the cookie and the cookie will only be accessible through
    | the HTTP protocol. You are free to modify this option if needed.
    |
    */

    'http_only' => true,

    /*
    |--------------------------------------------------------------------------
    | Same-Site Cookies
    |--------------------------------------------------------------------------
    |
    | This option determines how your cookies behave when cross-site requests
    | take place, and can be used to mitigate CSRF attacks. By default, we
    | will set this value to "lax" since this is a secure default value.
    |
    | Supported: "lax", "strict", "none", null
    |
    */

    'same_site' => 'lax',

];

I realised I had set my session timeout value to something silly when I was doing some testing and it got overlooked. I have now put a more sensible number in