Tuesday, February 13, 2018

Debugging Queries in Laravel ― Scotch

Debugging Queries in Laravel ― Scotch



Laravel provides a fantastic database query builder and ORM system named Eloquent. It makes running queries extremely simple and allows you to get records with minimal effort. However, there may be times when you need to build an advanced query and would like to see the actual SQL being generated.
In this tutorial let's go through some of the ways we can easily get access to this information. Starting with the simplest methods and moving into more powerful packages.
Before we jump in let's build an Eloquent query for a fictitious bug report that has been assigned to us:

Issue #22321
Problem: Searching users is showing to many results
Steps to reproduce: I search for "John Doe john@example.org" and I'm getting back hundreds of results. 
As we dig into the code, we find this query that seems to be where the problem lies:

$results = User::where(function($q) use ($request) {
    $q->orWhere('email', 'like', '%john@example.org%');
    $q->orWhere('first_name', 'like', '%John%');
    $q->orWhere('last_name', 'like', '%Doe%');
})->get();
Can you already spot the problem? If not, don't worry as we will start debugging this and see what is actually going on.

#Simple Query Debugging

The simplest method to see the query generated is by utilizing a ->toSql() method. All that we need to do is replace the closing ->get() with ->toSql(). Then printing out the results with the dd(), die and dump, helper.
Here is the updated query:

$results = User::where(function($q) use ($request) {
    $q->orWhere('email', 'like', '%john@example.org%');
    $q->orWhere('first_name', 'like', '%John%');
    $q->orWhere('last_name', 'like', '%Doe%');
})->toSql();
dd($results)
Running this in the browser will give us the following generated SQL:

select * from `users` where (`email` like ? or `first_name` like ? or `last_name` like ?)
This method is great for quickly seeing the SQL. However, it doesn't include the query bindings, only a ? for where they are to be inserted. Depending on the complexity of the bindings, this may be enough information for you to debug it.

#Listening For Query Events

The second option is to listen for query events on the DB object. To set this up above the query add this little helper:

\DB::listen(function($sql) {
    var_dump($sql);
});
Now when you load the page in the browser you will get the same output as in the simple query debugging section:

select * from `users` where (`email` like ? or `first_name` like ? or `last_name` like ?)
DB::listen is also more advanced, and it accepts two additional parameters to give us access to the passed in bindings and the time the query took to run:

\DB::listen(function($sql, $bindings, $time) {
    var_dump($sql);
    var_dump($bindings);
    var_dump($time);
});
Running this again will then display the following results:

string 'select * from `users` where (`email` like ? or `first_name` like ? or `last_name` like ?)' (length=89)
array (size=3)
  0 => string '%john@example.org%' (length=18)
  1 => string '%John%' (length=6)
  2 => string '%Doe%' (length=5)
float 35.63
As you can see, this gives us the query, the bindings, and the time the query took to run. With this, we can match up the bindings to the query.

#Debugbar Package

Another viable option is to install the Laravel Debugbar package. Once installed you will get a heads up overview of your app that is displayed at the bottom of the browser. It's a very full-featured package and will give you lots of insights into your application.
The part we want to focus is the query tab that outputs every query ran to generate the page.
debugbar-package
This gives us the full query with the bindings inserted into the correct place and a bonus of showing query hints to improve it.
Another advantage of having the query shown instantly like this is you can quickly spot areas that might not be eager loaded. This can lead to a significate database performance hit, and it's easy to notice as you will see the total number of queries being high.

#Conclusion

Have you spotted the error with the query now? Instead of using orWhere we needed to be using where. Here is the final code that fixes the bug:

$results = User::where(function($q) use ($request) {
    $q->where('email', 'like', '%john@example.org%');
    $q->where('first_name', 'like', '%John%');
    $q->where('last_name', 'like', '%Doe%');
})->get();
Which gives us the corrected query:

select * from `users` where (`email` like '%john@example.org%' and `first_name` like '%John%' and `last_name` like '%Doe%')
Now the next time you get stuck needing to debug a query you have three tools available in your toolbelt to get the job done. Happy debugging!
If you enjoy Laravel, join my weekly Laravel newsletter to stay up to date on all the latest Laravel news, tips, and resources.

No comments: