Почему модель иногда слишком долго добавляется в БД (Laravel)?

Question

[Tutucu]

Периодически в логах сервера проскакивают такие запросы:

Т.е. периодически скорость ответа сервера начинает увеличиваться с 0.2 с до 3 или даже 8 секунд. Это происходит рандомно и не зависит от нагрузки на сервер или времени суток.
В логах медленных запросов php-fpm эти моменты выглядят вот так:

[30-Oct-2020 09:13:46]  [pool www] pid 5494
script_filename = /public/index.php
[0x00007f53c441f0a0] execute() /vendor/laravel/framework/src/Illuminate/Database/Connection.php:459
[0x00007f53c441f010] Illuminate\Database\{closure}() /vendor/laravel/framework/src/Illuminate/Database/Connection.php:658
[0x00007f53c441ef50] runQueryCallback() /vendor/laravel/framework/src/Illuminate/Database/Connection.php:625
[0x00007f53c441ee90] run() /vendor/laravel/framework/src/Illuminate/Database/Connection.php:460
[0x00007f53c441ee10] statement() /vendor/laravel/framework/src/Illuminate/Database/Connection.php:412
[0x00007f53c441ed90] insert() /vendor/laravel/framework/src/Illuminate/Database/Query/Processors/Processor.php:32
[0x00007f53c441ece0] processInsertGetId() /vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php:2658
[0x00007f53c441ec30] insertGetId() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php:1317
[0x00007f53c441eb60] __call() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Model.php:839
[0x00007f53c441eab0] insertAndSetId() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Model.php:804
[0x00007f53c441ea20] performInsert() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Model.php:667
[0x00007f53c441e970] save() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php:749
[0x00007f53c441e910] Illuminate\Database\Eloquent\{closure}() /vendor/laravel/framework/src/Illuminate/Support/helpers.php:424
[0x00007f53c441e890] tap() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Builder.php:750
[0x00007f53c441e810] create() /vendor/laravel/framework/src/Illuminate/Support/Traits/ForwardsCalls.php:23
[0x00007f53c441e730] forwardCallTo() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Model.php:1618
[0x00007f53c441e6a0] __call() /vendor/laravel/framework/src/Illuminate/Database/Eloquent/Model.php:1630
[0x00007f53c441e610] __callStatic() /app/Models/SkillRequest.php:102
[0x00007f53c441e540] send() /app/Http/Controllers/Skills/GameSearchController.php:294
[0x00007f53c441e400] index() /vendor/laravel/framework/src/Illuminate/Routing/Controller.php:54

Участок долгого скрипта, на который указывает лог SkillRequest.php:102 в GameSearchController.php:294 - это всего лишь навсего добавление экземпляра модели в БД базовой функцией Laravel:
SkillRequest::create($skill_request);
Сама модель:

protected $fillable = [
		'skill_id',
		'user_id',
		'type',
		'request_content',
		'response_content',
	];

	protected $casts = [
		'request_content' => 'array',
		'response_content' => 'array',
	];

Структура миграции:

Schema::create('skill_requests', function (Blueprint $table) {
            $table->bigIncrements('id');
            $table->string('skill_id', 255);
            $table->string('user_id', 255);
            $table->string('type')->default(NULL);
            $table->json('request_content')->default(NULL);
            $table->json('response_content')->default(NULL);
            $table->timestamps();
        });

В логе медленных запросах mysql по этому поводу пусто.
Задач данного скрипта - ведением логов, и скрипт заупскается при каждом запросе, но в одних случаях он отрабатывает хорошо, а в других плохо :( В чём может быть проблема?

Comments

[Barmunk]

Предположу что проблема в sql insert. Я бы добавил лог запросов и посмотрел какие именно данные вызывают затык

DB::listen(function($query) {
            
   $data = [
       'query' => $query->sql, 
       'bindings' => $query->bindings, 
       'time' => $query->time, 
       'created_at' => Carbon::now()
   ];
});

А дальше уже смотрел бы в самой базе

[Tutucu]

Barmunk, а listen выполняется до или после запроса? Если после - то код не сработает, т.к. запись в ьд так и не дабавляется (клиент после ожидания просто закрывает соединение).

[Barmunk]

Tutucu, После. Если в этом проблема, создай Job с SkillRequest::create($skill_request), клиент будет только создавать Job, данные будут уходить в очередь и там обрабатываться сколько нужно, никто их уже не прервет. Плюс получаем возможность нормально логировать запросы.

[Tutucu]

Barmunk, Хорошая идея, так и сделаю в качестве временного решения! Но ошибку с БД это не решает :(

[Barmunk]

Tutucu, а ошибку с бд нужно изучать с помощью db listen на уровне базы данных, как писал выше.

Answer 1

[Антон Шаманов]

потому что код работает не в сферическом вакууме, а параллельно с другими задачами

Answer 2

[Константин]

Попробуйте отключить dns resolv
гуглить по skip-name-resolve