Slow Events listener with large execution overhead

Hi all,

I've just started with creating Events which will be responsible for logging to database. Idea is to create event which when fired can be processed at any time as it would only write Log details to table using custom Model.

Now I've used very basic setup similar to https://shouts.dev/articles/laravel-10-how-to-use-laravels-events-and-listeners-for-event-driven-architecture and I can Fire off events by calling it in my Controller.

I have test case with using Event and direct Model call from Controller.

public function testValidation(Request $request){
    $start = microtime(true);
    ray("Starting points check");

    // Some other logic

    // @ Using Event
    // event(new MyEvent('VALIDATION_FAILED', 'Short description...', 'E333'));

    // @ Direct via Model
    EventLogging::create([
        'event_name' => 'EVENT_TEST',
        'description' => 'Short decription',
        'event_code' => 'E333',
    ]);

    
    $end = microtime(true);
    $time = $end - $start;
    ray("Time to execute: ", $time);

    return response()->json(['message' => 'Validation completed'], 201);
}

The thing is that for Event to fire off and complete it's thing, takes 1.2s longer then for direct execution via Model. Therefore my Response at very end is delayed by that overhead of 1.2s.

I am new to all this and maybe I am doing it wrong. Idea is to return response ASAP and let Event (or something else) take care of logging to DB. Depending on Error code it may be require to send an Email etc.

I have tried with configuring my Event and adding ShouldQueue but that did not change anything.

Run a worker:

php artisan queue:work

My Event:

<?php

namespace App\Listeners;

use App\Events\MyEvent;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Queue\InteractsWithQueue;
use App\Models\EventLogging;

class MyListener implements ShouldQueue
{
    /**
     * Create the event listener.
     */
    public function __construct()
    {
        //
    }

    /**
     * Handle the event.
     */
    public function handle(MyEvent $event): void
    {
        // Additional logic based on the event 
        $event_name = $event->event_name;
        $description = $event->description;
        $event_code = $event->event_code; 

        // Log the event using the description
        EventLogging::create([
            'event_name' => 'EVENT_TEST',
            'description' => 'Short decription',
            'event_code' => 'E333',
        ]);

    }
}

Does anyone have suggestions on this and what woud be best way to implement such logging?

LaryAI

2 years ago

Level 58

It seems like you're on the right track with using events and listeners for logging, and you've also mentioned implementing the ShouldQueue interface to make the event listener queueable. However, if you're still experiencing a delay, it's possible that your queue is not set up correctly or not running as expected.

Here are the steps to ensure that your event listener is queued and processed asynchronously, which should eliminate the delay in your response time:

Configure Your Queue Connection: Make sure you have a queue connection set up in your config/queue.php file. For example, if you're using the database driver, you should have something like this:

'connections' => [
    'database' => [
        'driver' => 'database',
        'table' => 'jobs',
        'queue' => 'default',
        'retry_after' => 90,
    ],
    // ...
],

Run Migrations for Queue Table: If you're using the database driver, ensure you've run the migrations to create the necessary tables:

php artisan queue:table
php artisan migrate

Dispatch Event to Queue: When you fire the event, Laravel should automatically queue it if the listener implements ShouldQueue. Make sure you're dispatching the event correctly in your controller:

event(new MyEvent('VALIDATION_FAILED', 'Short description...', 'E333'));

Start Queue Worker: Ensure that you have a queue worker running to process the jobs. You can run the worker using the following command:

php artisan queue:work

Check Queue Configuration: Verify that your .env file is set to use the queue connection you've configured:

QUEUE_CONNECTION=database

Error Handling: If the event is still not being queued, check your Laravel logs for any errors. It's possible that there's an issue with the event or listener that's preventing it from being queued properly.
Testing: To test if the queuing is working, you can temporarily add a Log::info('Event queued!'); statement in your event listener's handle method. Then, check your log files after triggering the event to see if the log entry appears.

Here's an example of what your listener might look like with the log statement:

<?php

namespace App\Listeners;

use App\Events\MyEvent;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Queue\InteractsWithQueue;
use App\Models\EventLogging;
use Illuminate\Support\Facades\Log;

class MyListener implements ShouldQueue
{
    // ...

    public function handle(MyEvent $event): void
    {
        Log::info('Event queued!');

        // Log the event using the description
        EventLogging::create([
            'event_name' => $event->event_name,
            'description' => $event->description,
            'event_code' => $event->event_code,
        ]);
    }
}

If you follow these steps and ensure that your queue worker is running, your event listener should process the logging asynchronously, and your response time should not be affected by the logging operation.

1 like

markomo

2 years ago

Level 1

Great resonse from A.I., I've missed configuration in my .env changing from sync to darabase in my case:

QUEUE_CONNECTION=database

This does work now as expected. I do still wonder why it's slow eveny in sync settings mode.

Please or to participate in this conversation.