Debugging Laravel 5.x Restufl API Services

If you ever develop an API, recall how many times you wanted to dump SQL queries that were executed during your request?

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 and the time it took to execute.

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().

$results = User::where(function($q) use ($request) {
    $q->andWhere('email', 'like', '%john@doe.com%');
    $q->andWhere('status', '=', self::STATUS_ACTIVATED);
})->toSql();
dd($results)

Running this in the browser will give us the following generated SQL:

select * from `users` where (`email` like ? and `status` = ?)

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. This can be enabled in App\Providers\AppServiceProvider.php boot method.

<?php

namespace App\Providers;

use Illuminate\Support\ServiceProvider;

class AppServiceProvider extends ServiceProvider
{
    /**
     * Bootstrap any application services.
     *
     * @return void
     */
    public function boot()
    {
        //
        \DB::listen(function($sql) {
            var_dump($sql);
        });
    }

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

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 ? and `status` = ?)

DB::listen method is more advanced. It accepts two additional parameters to give us access to the passed in bindings and the time the query took to execute:

\DB::listen(function($sql, $bindings, $time) {
    var_dump($sql);
    var_dump($bindings);
    var_dump($time);
});

The above will output:

string 'select * from `users` where (`email` like ? and `status` = ?)'
array (size=2)
  0 => string '%john@doe.com%' (length=12)
  1 => string '1' (length=1)
float 5.33

As you can see, this gives us the SQL and the bindings, the time the query took to execute.

Embedding SQL Debugger into your Restful API Response

While building complex API’s and optimizing them it becomes time consuming to debug and check each SQL query execution line by line. Specially when you are running 10’s of queries at a request.

Here is an AfterMiddleware that enables Laravel’sQueryLogger and appends debugger info to the jsonresponse

<?php
/**
 * Created by PhpStorm.
 * User: miradnan
 * Date: 9/18/18
 * Time: 12:50 PM
 */

namespace App\Http\Middleware;

use DB;
use Event;
use Closure;

class ApiDebuggerMiddleware
{
    /**
     * @param $request
     * @param Closure $next
     * @return mixed
     */
    public function handle($request, Closure $next)
    {
        $enable = env('OFFICE_IP') == $request->getClientIp() || env('APP_ENV_DEV');

        if ($enable) {
            DB::connection()->enableQueryLog();
        }

        $response = $next($request);

        if ($enable) {
            $content = $response->getContent();
            if ($response->headers->get('Content-Type') === 'application/json') {
                $debugger['queries'] = DB::getQueryLog();
                $contentArray = json_decode($content, true);
                $content = json_encode(array_merge($contentArray, ['debugger' => $debugger]));
            }
            $response->setContent($content);
        }

        return $response;
    }
}

This will output debugger object with SQL query insights:

{
  "users": [
    {
      "id": 1,
      "first_name": "John",
      "last_name": "Doe",
      "email": "john@doe.com",
      "status": 1
    },
    {
      "id": 2,
      "first_name": "John",
      "last_name": "Doe Jr",
      "email": "john@doe.com",
      "status": 1
    }
  ],
  "debugger": {
    "queries": [
      {
        "bindings": [
          "john@doe.com",
          "1"
        ],
        "query": "select * from users where email = ? and status = ?",
        "time": "33.02"
      }
    ]
  }
}

Happy debugging!