Question?. Strange behavior using Logtail in Queues with Laravel.

[bashman]

I am using Laravel 10 and for logs delivery I am using queues. The log system works fine, for example if I run it from a command, or a controller:

$logger = new Logger('mychannel);
$logger->pushHandler(new LogtailHandler('xxxx'));
$logger->info('message', $array_data);

To improve the user experience, I decided to use queues for log management:

<?php

namespace App\Jobs;

use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldBeUnique;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Foundation\Bus\Dispatchable;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;

use Monolog\Logger;
use Logtail\Monolog\LogtailHandler;

class LogJob implements ShouldQueue
{
    use Dispatchable, InteractsWithQueue, Queueable, SerializesModels;

    /**
     * Create a new job instance.
     */
    public function __construct(
        public string $channel,
        public string $level,
        public string $message,
        public array $data
    ) {
    }

    /**
     * Execute the job.
     */
    public function handle(): void
    {

        if ($this->channel == 'ychannel') {
            $logger = new Logger($this->channel);
            $logger->pushHandler(new LogtailHandler('dddd'));
        }

        if ($this->channel == 'xchanel') {
            $logger = new Logger($this->channel);
            $logger->pushHandler(new LogtailHandler('zxy'));
        }

        if ($this->level == 'INFO') {
            $logger->info($this->message, $this->data);
        }

        if ($this->level == 'ERROR') {
            $logger->error($this->message, $this->data);
        }

        if ($this->level == 'WARNING') {
            $logger->warning($this->message, $this->data);
        }

    }
}


// dispatch a log on los queue
 LogJob::dispatch('ychannel', 'INFO', 'User Added now',
             ['data' => ['email' => '[email protected]', 'country_id' => 456], ])->onQueue('log_queue');

The queue runs correctly, but the logs do not be delivered to the logtail server. Looking at how the queue works, it seems that the queue finishes the job first, before monolog finishes sending the log.

monolog-logtail 3.0 
php 8.2
Laravel 10.x

Any tips on how to handle this situation?

[mabar]

That's because logs are written in batch and buffer automatically writes only when php terminates on end of the request. You can you synchronous handler, but better solution is to call Monolog\Logger->reset() when logs should be written. It may make sense to add this feature even into Laravel queing system internally, to reset logger after each message

[curusarn]

Hi @bashman,

Thank you for reaching out.

Does calling Monolog\Logger->reset() flush the logs and resolve the issue? I will be happy to look into this more if the problem persists.

Let me know if I can help you to resolve this. 🙏

Thanks again for raising this!

[michaelrimbach]

I had the same issue, changing the handler to "synchronous handler" fixed it.

[PetrHeinz]

Hello @phm46 and thanks for raising this issue 🙌

In the newly released v3.2.0 (and v2.2.0) we've tweaked the default values so this should be an issue anymore. Logs are automatically flushed after 1000 records or 5s (to allow for resolving a regular request before sending any logs over). You can of course customize this behavior to suit your specific needs.

The customization should now be easier with the help of LogtailHandlerBuilder with a nice auto-completion support for any modern IDE. For performance reasons, I would recommend switching over from using synchronous handler to the new settings 🙏

We've also documented a tip for ensuring all logs are sent when a script execution is terminated by CTRL+C, as the doesn't trigger regular shutdown handlers: https://betterstack.com/docs/logs/php/#logging-from-console-scripts

Hope this helps to address logging in long-running scripts 🚀

Please let me know if you have any questions or feedback around these changes, and thanks again for reporting it!