Monitoring API Endpoints Speed on Laravel/Lumen using Loki and Grafana [1/3]

If you are a backend developer, you may have faced this issue where you want to know which endpoints of your API takes a long time to run, therefore consuming a lots of resource of your server. To optimize your API, you need to find which endpoints are the ones that need to be optimized.

By the end of the tutorial, here is how will look like our Monitoring Dashboard:

Here are the data we will be able to visualize:

Endpoints Execution Time
Highest Execution Time per Endpoint
Average Execution Time per Endpoint
Total Logs scrapped
Total Calls per Endpoints

#1 – Create and setup the middleware to get the execution time

First, let’s create a middleware:

php artisan make:middleware LogExecutionTime

Then let’s fill it:

<?php

namespace App\Http\Middleware;

use \Carbon\Carbon;
use Closure;
use Illuminate\Support\Facades\Log;

class LogExecutionTime
{
    public function handle($request, Closure $next)
    {
        // Start calculating execution time
        $start_time = microtime(true);

        // Process the request
        $response = $next($request);

        // Calculate the execution time
        $end_time = microtime(true);

        $execution_time = $end_time - $start_time;
        $request_name = $request->path();
        $exploded_path = explode('/',$request_name);

        // Store the information to the logs
        $category = match($exploded_path[0]){
            'admin' => 'admin',
            default => 'platform'
        };

        Log::channel('json')->info("execution_time",[
            'path' => $request_name,
            'category' => $category,
            'start_time' => Carbon::createFromFormat('U.u',$start_time,env('APP_TIMEZONE'))->format('Y-m-d H:i:s.u'),
            'end_time' => Carbon::createFromFormat('U.u',$end_time,env('APP_TIMEZONE'))->format('Y-m-d H:i:s.u'),
            'value' => $execution_time,
        ]);
        return $response;
        // Force dying to avoid double execution logging
        die;
    }
}

Then, register your middleware:

Laravel

// Within App\Http\Kernel class
...
protected $middlewareAliases = [
    ...
    'log.execution_time' => App\Http\Middleware\LogExecutionTime::class,
];

Lumen

// Within bootstrap/app.php
$app->routeMiddleware([
  ...
  'log.execution_time' => App\Http\Middleware\LogExecutionTime::class,
]);

To make sure logs are formatted in JSON, we will set the “json” log channel in the configuration.

Laravel

// within config/logging.php
...
  'channels' => [
    ...
    'json' => [
      'driver' => 'daily',
      'path' => env('LOG_PATH', storage_path('logs/laravel.log')),
      'level' => 'debug',
      'days' => 14,
      'formatter' => \Monolog\Formatter\JsonFormatter::class,
    ],
...

Lumen

First, if you don’t have the /config directory, create one.
Then add the configuration file logging.php.

<?php

use Monolog\Handler\NullHandler;
use Monolog\Handler\StreamHandler;
use Monolog\Handler\SyslogUdpHandler;

return [

    /*
    |--------------------------------------------------------------------------
    | Default Log Channel
    |--------------------------------------------------------------------------
    |
    | This option defines the default log channel that gets used when writing
    | messages to the logs. The name specified in this option should match
    | one of the channels defined in the "channels" configuration array.
    |
    */

    'default' => env('LOG_CHANNEL', 'stack'),

    /*
    |--------------------------------------------------------------------------
    | Deprecations Log Channel
    |--------------------------------------------------------------------------
    |
    | This option controls the log channel that should be used to log warnings
    | regarding deprecated PHP and library features. This allows you to get
    | your application ready for upcoming major versions of dependencies.
    |
    */

    'deprecations' => env('LOG_DEPRECATIONS_CHANNEL', 'null'),

    /*
    |--------------------------------------------------------------------------
    | Log Channels
    |--------------------------------------------------------------------------
    |
    | Here you may configure the log channels for your application. Out of
    | the box, Laravel uses the Monolog PHP logging library. This gives
    | you a variety of powerful log handlers / formatters to utilize.
    |
    | Available Drivers: "single", "daily", "slack", "syslog",
    |                    "errorlog", "monolog",
    |                    "custom", "stack"
    |
    */

    'channels' => [
        'stack' => [
            'driver' => 'stack',
            'channels' => ['daily_storage','json'],
            'ignore_exceptions' => false,
        ],
        'json' => [
            'driver' => 'daily',
            'path' => env('LOG_PATH', storage_path('logs/laravel.log')),
            'level' => 'debug',
            'days' => 14,
            'formatter' => \Monolog\Formatter\JsonFormatter::class,
        ],

        'single' => [
            'driver' => 'single',
            'path' => env('LOG_PATH', storage_path('logs/laravel.log')),
            'level' => env('LOG_LEVEL', 'debug'),
        ],

        'daily' => [
            'driver' => 'daily',
            'path' => env('LOG_PATH', storage_path('logs/laravel.log')),
            'level' => env('LOG_LEVEL', 'debug'),
            'days' => 14,
        ],

        'slack' => [
            'driver' => 'slack',
            'url' => env('LOG_SLACK_WEBHOOK_URL'),
            'username' => 'Laravel Log',
            'emoji' => ':boom:',
            'level' => env('LOG_LEVEL', 'critical'),
        ],

        'papertrail' => [
            'driver' => 'monolog',
            'level' => env('LOG_LEVEL', 'debug'),
            'handler' => env('LOG_PAPERTRAIL_HANDLER', SyslogUdpHandler::class),
            'handler_with' => [
                'host' => env('PAPERTRAIL_URL'),
                'port' => env('PAPERTRAIL_PORT'),
                'connectionString' => 'tls://'.env('PAPERTRAIL_URL').':'.env('PAPERTRAIL_PORT'),
            ],
        ],

        'stderr' => [
            'driver' => 'monolog',
            'level' => env('LOG_LEVEL', 'debug'),
            'handler' => StreamHandler::class,
            'formatter' => env('LOG_STDERR_FORMATTER'),
            'with' => [
                'stream' => 'php://stderr',
            ],
        ],

        'syslog' => [
            'driver' => 'syslog',
            'level' => env('LOG_LEVEL', 'debug'),
        ],

        'errorlog' => [
            'driver' => 'errorlog',
            'level' => env('LOG_LEVEL', 'debug'),
        ],

        'null' => [
            'driver' => 'monolog',
            'handler' => NullHandler::class,
        ],

        'emergency' => [
            'path' => storage_path('logs/laravel.log'),
        ],
    ],

];

Then register the configuration file:

// within bootstrap/app.php
...
$app->configure('app');
$app->configure('logging');

Finally, let’s set the middleware to handle every endpoints. To do so, you shall create a global middleware group in each of your route files: api.php, channels.php, console.php and web.php.

// Within each route files
$router->group(['middleware' => ['log.execution_time']], function () use ($router) {
  // your endpoints routes
  ...
});

#2 – Checking your logs

Now that your middleware is set up, call some of your endpoints, and check your logs in /storage/logs/laravel.log, it will look like this:

...
{"message":"execution_time","context":{"path":"login","category":"platform","start_time":"2023-11-01 13:28:49.316800","end_time":"2023-11-01 13:28:49.534000","value":0.2172548770904541015625},"level":200,"level_name":"INFO","channel":"local","datetime":"2023-11-01T13:28:49.540383+07:00","extra":{}}
{"message":"execution_time","context":{"path":"products/list","category":"platform","start_time":"2023-11-01 13:29:16.008900","end_time":"2023-11-01 13:29:16.122600","value":0.1136929988861083984375},"level":200,"level_name":"INFO","channel":"local","datetime":"2023-11-01T13:29:16.128345+07:00","extra":{}}
{"message":"execution_time","context":{"path":"products/list","category":"platform","start_time":"2023-11-01 13:29:32.362800","end_time":"2023-11-01 13:29:32.465100","value":0.1022260189056396484375},"level":200,"level_name":"INFO","channel":"local","datetime":"2023-11-01T13:29:32.469219+07:00","extra":{}}
{"message":"execution_time","context":{"path":"product/get","category":"platform","start_time":"2023-11-01 13:29:49.953500","end_time":"2023-11-01 13:29:50.591200","value":0.6376569271087646484375},"level":200,"level_name":"INFO","channel":"local","datetime":"2023-11-01T13:29:50.595926+07:00","extra":{}}
{"message":"execution_time","context":{"path":"login","category":"platform","start_time":"2023-11-01 14:10:48.269500","end_time":"2023-11-01 14:10:48.509000","value":0.2394979000091552734375},"level":200,"level_name":"INFO","channel":"local","datetime":"2023-11-01T14:10:48.516528+07:00","extra":{}}
...