Ваш сайт работает медленно? Грузится целую вечность? Пользователи жалуются, что он практически непригоден для использования? Вам следует проверить свои запросы к базе данных. И я собираюсь показать вам изящный способ легко профилировать все запросы к базе данных.

Конечно, ваш сайт может работать медленно по многим причинам, но одна из самых распространенных — медленные запросы к базе данных.

Но в laravel мы не используем SQL (в большинстве случаев) для извлечения информации из нашей базы данных, а применяем eloquent ORM и конструктор запросов laravel, что иногда затрудняет выявление того запроса, который делает наш сайт таким медленным.

DB::listen()

К счастью, в laravel мы можем определить коллбэк, который будет вызван каждый раз, когда выполняется запрос (см. здесь). Для этого добавьте следующий код к любому поставщику услуг (например, AppServiceProvider):

public function boot()
    {
        DB::listen(function ($query) {
            // TODO: make this useful
        });
    }

Как видите, мы получаем переменную $query, данная переменная является экземпляром класса QueryExecuted. Это означает, что мы имеем доступ к информации о выполненном запросе:

DB::listen(function ($query) {
            $query->sql; // the sql string that was executed
            $query->bindings; // the parameters passed to the sql query (this replace the '?'s in the sql string)
            $query->time; // the time it took for the query to execute;
        });

Это весьма полезная информация, теперь у нас есть способ определить медленные запросы, просматривая свойство $query->time. Однако это не говорит нам о том, в каком месте нашего кода был выполнен запрос.

Как узнать, где был выполнен запрос?

Несмотря на то, что переменная $query не дает нам никакой информации о том, откуда был получен данный $query, мы все же можем узнать это, используя встроенную функцию PHP debug_backtrace().

   DB::listen(function ($query) {
            dd(debug_backtrace());
        });

Если вы запустите это в своем проекте, то в браузере вы увидите что-то вроде этого:

array:63 [▼
  0 => array:7 [▼
    "file" => "/home/cosme/Documents/projects/cosme.dev/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php"
    "line" => 404
    "function" => "App\Providers\{closure}"
    "class" => "App\Providers\AppServiceProvider"
    "object" => App\Providers\AppServiceProvider {#140 ▶}
    "type" => "->"
    "args" => array:1 [▶]
  ]
  1 => array:7 [▼
    "file" => "/home/cosme/Documents/projects/cosme.dev/vendor/laravel/framework/src/Illuminate/Events/Dispatcher.php"
    "line" => 249
    "function" => "Illuminate\Events\{closure}"
    "class" => "Illuminate\Events\Dispatcher"
    "object" => Illuminate\Events\Dispatcher {#27 ▶}
    "type" => "->"
    "args" => array:2 [▶]
  ]
  2 => array:7 [▼
    "file" => "/home/cosme/Documents/projects/cosme.dev/vendor/laravel/framework/src/Illuminate/Database/Connection.php"
    "line" => 887
    "function" => "dispatch"
    "class" => "Illuminate\Events\Dispatcher"
    "object" => Illuminate\Events\Dispatcher {#27 ▶}
    "type" => "->"
    "args" => array:1 [▶]
  ]
  ....

Это массив, содержащий все вызовы функций до этого момента запроса. Я собираюсь сосредоточиться только на ключах file и line в каждом массиве.

При внимательном рассмотрении видно, что в моем примере было 63 вызова функций, что кажется много, и это простое приложение, в более сложном приложении их может быть гораздо больше. Что еще хуже, если вы посмотрите на те, что сверху, все они являются внутренними функциями фреймворка laravel. Должны ли мы рассматривать каждую из них, пока не найдем что-то, что могло бы нам помочь?

Поиск местоположения запроса

Как я уже говорил, большинство из них являются внутренними вызовами фреймворка, что означает, что большинство этих файлов находятся внутри нашей директории vendor/. Это значит, что мы можем проверять каждый file и отфильтровывать все вызовы, в которых есть vendor/, например, так:

  DB::listen(function ($query) {
            $stackTrace = collect(debug_backtrace())->filter(function ($trace) {
                return !str_contains($trace['file'], 'vendor/');
            });
            
            dd($stackTrace);
        });

Здесь я преобразовываю массив в коллекцию, чтобы использовать метод filter; если file текущего $trace содержит vendor/, мы удаляем его из коллекции.

При выполнении приведенного выше кода вы увидите что-то вроде этого:

Illuminate\Support\Collection {#1237 ▼
  #items: array:5 [▼
    12 => array:7 [▼
      "file" => "/home/cosme/Documents/projects/cosme.dev/app/Models/Post.php"
      "line" => 61
      "function" => "get"
      "class" => "Illuminate\Database\Eloquent\Builder"
      "object" => Illuminate\Database\Eloquent\Builder {#310 ▶}
      "type" => "->"
      "args" => []
    ]
    16 => array:6 [▶]
    17 => array:6 [▶]
    61 => array:7 [▶]
    62 => array:4 [▶]
  ]
  #escapeWhenCastingToString: false
}

Теперь элементов стало намного меньше, мы перешли от 63 к 5. И самое замечательное, что первый элемент в коллекции — это точное место, где мы инициировали SQL-запрос. Это означает, что мы можем извлечь данную информацию для поиска самых медленных запросов.

Собираем все вместе

Теперь, когда у нас есть вся необходимая информация, почему бы нам не записать ее в лог, чтобы мы могли проверить и найти самые медленные запросы?

public function boot()
    {
        DB::listen(function ($query) {
            $location = collect(debug_backtrace())->filter(function ($trace) {
                return !str_contains($trace['file'], 'vendor/');
            })->first(); // grab the first element of non vendor/ calls

            $bindings = implode(", ", $query->bindings); // format the bindings as string

            Log::info("
                   ------------
                   Sql: $query->sql
                   Bindings: $bindings
                   Time: $query->time
                   File: ${location['file']}
                   Line: ${location['line']}
                   ------------
            ");
        });
    }

Если вы используете это в своем приложении, то затем можете проверить лог файл, в котором будет отображаться информация о запросах:

[2022-02-03 02:20:14] local.INFO:
                    ------------
                    Sql: select "title", "slug", "body" from "posts" where "published" = ? order by "id" desc   
                    Bindings: 1
                    Time: 0.18
                    File: /home/cosme/Documents/projects/cosme.dev/app/Models/Post.php
                    Line: 61
                    ----------

Теперь вы знаете, какие запросы самые медленные, и начинаете обрабатывать их один за другим, пытаясь ускорить их, или, по крайней мере, кэшировать.

Не ограничиваясь отладкой

Все это весьма полезно для отладки, но данная методика может быть реализована множеством способов.

Вы можете создать еженедельный отчет, показывающий самые медленные запросы за 7 дней.

Вы можете получить некритический алерт, если запрос превысил временной порог.

Вы можете создать дашборд, где вы и ваша команда сможете видеть каждый выполненный запрос.

Возможности безграничны. Нет предела совершенству.

Laravel 9 вышла в феврале этого года. Релиз содержит достаточно много нововведений, среди которых: поддержка компонентов Symfony 6, Symfony Mailer, Flysystem 3,улучшенный вывод route:list, драйвера Laravel Scout, новый синтаксис аксессор/мутатор Eloquent и различные другие исправления ошибок и улучшения для удобства использования фреймворка. Скоро состоится открытое занятие, на котором мы постараемся затронуть самые важные из них. Регистрация для всех желающих — по ссылке.