A brief analysis of how to find the slowest query in Laravel

Is your website slow? Does it take a long time to load? Are users complaining that it's almost unusable? You should check your database queries. I'm going to show you a neat way to easily analyze all your database queries.

Of course, there are many reasons why your website may be slow, but one of the most common reasons is slow database queries.

But in laravel, we (most of the time) don't use SQL to get data from the database, we use Eloquent ORM and query builder, which sometimes This makes it difficult to pinpoint the query that is causing our site to be so slow.

DB::listen()

Fortunately, in laravel, we can define a function that is called every time a query is executed. callback (see here). To do this, add the following code to any service provider (e.g. AppServiceProvider):

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

As you can see, we receive a variable $query, this variable is An instance of the QueryExecuted class. This means we have access to some information about the executed query:

 DB::listen(function ($query) {
     $query->sql; // 执行的 sql 字符串
     $query->bindings; // 传递给sql查询的参数（这将替换sql字符串中的 "?"）
     $query->time; // 执行查询所用的时间；
 });

This is very useful information, now we can identify slow queries by looking at the $query->time property . But this doesn't tell us where in our code the query is executed.

How do I know where the query was executed?

Even if the $query variable does not give us any information about its source, we can still use the PHP built-in function debug_backtrace() to obtain that information.

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

If you run this on your project you will see something like this on the browser:

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 [▶]
  ]
  ....

This is an array containing the values ​​so far in the request every function call. I'll just focus on the file and line keys in each array.

If you look carefully, you will see that there are 63 function calls in my example, this is a simple application, if in a more complex application, it may be more. Even worse, if you look at the ones at the top, they are all internal functions of the laravel framework. Should we look at each one until we find something that might help us?

Find query locationAs I said before, most of them are internal framework calls, which means that in these files Most are in our

vendor/

directory. This means we can check each file and filter out any calls with vendor/ like this: <div class="code" style="position:relative; padding:0px; margin:0px;"><pre class="brush:php;toolbar:false">DB::listen(function ($query) {     $stackTrace = collect(debug_backtrace())-&gt;filter(function ($trace) {         return !str_contains($trace['file'], 'vendor/');     });     dd($stackTrace); });</pre><div class="contentsignin">Copy after login</div></div>Here I convert the array to Collection to use the

filter

method, if file currently $trace has a vendor/ we remove it from the collection. If you run the code above you will see something like this:

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
}

The items are much fewer, we went from 63 to only 5. The best part is that the first item in the collection is the exact location where we trigger the SQL query. This means we can extract this information to find the slowest queries.

Print to logNow that we have all the information we need, why not log it so we can check and find the slowest Inquire? :

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']}
            ------------
        ");
    });
}

If you are using this in your application you can check your log files and you should see query information like this:

[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
----------

Now you know which queries are the slowest , and start processing them one by one, try to make them faster, or at least cache them.

Extended DebuggingThis is useful for debugging, but this technique can be used in a variety of ways.

You can create a weekly report that shows the slowest queries of the week.

You may receive a slack alert if a query exceeds a time threshold

You can create a dashboard that you and your team can View every query executed

The sky is the limit.

[Related recommendations:

laravel video tutorial

]

The above is the detailed content of A brief analysis of how to find the slowest query in Laravel. For more information, please follow other related articles on the PHP Chinese website!