Profiling Laravel with Excimer

Profiling Laravel with Excimer

Integrating the Excimer profiling tool into a Laravel application enables developers to monitor performance with minimal overhead. Excimer is a PHP extension that provides an interrupting timer and a low-overhead sampling profiler. Enough Intro, and let’s dive in.

There are several reasons why web accessibility is important. Here are some of the key benefits:

Install Excimer

To utilize Excimer in our Laravel application, we need to install the Excimer PHP extension. Since, I’m using Ubuntu. I’ll use apt install php-excimer.

To ensure Excimer is installed correctly, run php -m | grep excimer. If we see excimer in the output, the installation was successful.

Integrating Excimer in Laravel

Now that Excimer is installed, let’s integrate it into a Laravel application. We’ll use Excimer to profile a RESTful CRUD API and a background job. Note that the code I provided is for example only and not optimized for production.

Scenario 1: Profiling a RESTful CRUD API

Create Middleware for Profiling:

php artisan make:middleware ProfileRequests

Update the middleware to use Excimer:

namespace App\Http\Middleware;

use Closure;
use ExcimerProfiler;

final class ProfileRequests
{
    public function handle($request, Closure $next)
    {
        $profiler = new ExcimerProfiler();
        $profiler->setPeriod(0.01); // Sample every 10ms
        $profiler->start();

        register_shutdown_function(function () use ($profiler) {
            $profiler->stop();
            $data = $profiler->getLog()->formatCollapsed();
            file_put_contents(
                storage_path('logs/api-profile.log'), 
                $data, 
                FILE_APPEND
            );
        });

        return $next($request);
    }
}

Add the middleware to the api middleware group in app/Http/Kernel.php:

protected $middlewareGroups = [
    'api' => [
        \App\Http\Middleware\ProfileRequests::class,
        // Other middleware
    ],
];

Now, every API request will be profiled, and the results will be saved to storage/logs/api-profile.log

Scenario 2: Profiling a Background Job

Let’s create a background job and profile it using Excimer with setFlushCallback for periodic flushing. Let’s generate a job by running php artisan make:job ProcessTask.

Update the job to use Excimer with setFlushCallback: namespace App\Jobs;

use ExcimerProfiler;
use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;

class ProcessTask implements ShouldQueue
{
    use InteractsWithQueue, Queueable, SerializesModels;

    public function handle()
    {
        static $profiler;
        $profiler = new ExcimerProfiler();
        $profiler->setEventType(EXCIMER_REAL); // Can be set to EXCIMER_CPU as well
        $profiler->setPeriod(30);
        $profiler->setFlushCallback(function ($log) {
            //Send this to rsyslog, Multicast UDP-to-file, Redis, UDP, local file log etc.
            //We're using local file log for this example
            file_put_contents(
                storage_path('logs/job-profile.log'), 
                $log->formatCollapsed(), 
                FILE_APPEND
            );
        },
        1 // Max samples
        ); 
        $profiler->start();

        // Simulate a long-running task
        sleep(120); // 2 minutes
    }
}

The setPeriod(30) means that Excimer will capture stack traces every 30 seconds during the execution of PHP script. Short sampling period provides more detailed profiling data, useful for identifying bottlenecks in shorter requests. Long sampling period captures stack traces less frequently, useful for identifying issues in long-running operations. The 1 in the second argument of setFlushCallback() is a sampling period, meaning the flush callback will be called after every single profiling sample. If we put 30, it will flush after 30 samples.

For the setEventType(), choose EXCIMER_REAL if you’re interested in the total elapsed time of your code execution, including external waits. Opt for EXCIMER_CPU to focus on the actual CPU processing time, excluding idle periods.

Now, let’s dispatch the job from the TaskController: use App\Jobs\ProcessTask;

public function store(Request $request)
{
    $task = Task::create($request->all());
    ProcessTask::dispatch($task);
    return response()->json($task, 201);
}

Now, the job will be profiled, the data will be flushed to storage/logs/job-profile.log.

Analyzing Excimer Profiles

Excimer provides detailed profiling data, including:

  • Execution time: Total time taken for the request or job.
  • Function calls: Time spent in each function.
  • Memory usage: Memory consumption during execution.

You can log this data or store it in a database for further analysis. Tools like FlameGraph can help visualize the profiling data.

Conclusion

This is only the tip of an iceberg. All I can say is that integrating Excimer into our Laravel application, we can gain valuable insights into our application’s performance. Whether we’re building a RESTful API or managing background tasks, Excimer’s low-overhead profiling capabilities make it an excellent choice for optimizing our application.

  • Use register_shutdown_function for profiling web requests and processing data at the end.
  • Use setFlushCallback for profiling long-running tasks and processing data periodically.

Interested in integrating profiling into your Laravel app? Let me handle it for you! Contact me to get started.