Search code examples
phplaravel-5redisqueuebroadcast

Lavel 5.x with Redis Queues generating huge logs


I have a project that's setup with Laravel and Redis Queues. The application is configured to send push notifications when it receives a message. As soon as message is received, it's stored in the DB and a push is generated:

dispatch(new CreateMessageNotification($message));

Project is using Redis queue and Service Provider. The problem is that queue dispatch doesn't work if we don't execute the following command:

php artisan queue:work redis --daemon

However, when we do run this command, the application start to generate error logs below. It appears that some routine is stuck somewhere, and we're unable to figure out where, why and how? If we don't run this script, push notifications don't work. If we do run this script, push notifications work with delay, and ERROR logs are produced AND the size of log reaches to GB in a matter of an hour. What are we doing wrong here?

We're using Redis/Predis:

'redis' => [
    'client' => 'predis',
    'cluster' => env('REDIS_CLUSTER', false),
    'default' => [
        'host' => env('REDIS_HOST', 'localhost'),
        'password' => env('REDIS_PASSWORD', null),
        'port' => env('REDIS_PORT', 6379),
        'database' => env('REDIS_DB', 0),
        'timeout' => 15.0,
    ],
],

For broadcasting, we're using Pusher:

'default' => env('BROADCAST_DRIVER', 'pusher'),

For queue, we're using Redis:

'default' => env('QUEUE_DRIVER', 'sync'),

QUEUE_DRIVER=redis

For cache, we're using Redis:

'default' => env('CACHE_DRIVER', 'file'),

CACHE_DRIVER=redis

CreateMessageNotification

<?php
namespace App\Jobs\EventHandlers;

use App\Events\Notifications\NewMessageCreatedEvent;
use App\Repositories\UserDevicesRepository;
use Event;
use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;

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

    private $message;

    public function __construct($message)
    {
        $this->message = $message;
    }

    public function handle()
    {
        Event::fire(new NewMessageCreatedEvent($this->message));
    }
}

NewMessageCreatedEvent

<?php
namespace App\Events\Notifications;

use App\Models\Chat\Message;
use Event;
use Illuminate\Queue\SerializesModels;

class NewMessageCreatedEvent extends Event
{
    use SerializesModels;

    public function __construct(Message $message)
    {
        $message->load(['other', 'chat', 'chat.chatUsers']);

        foreach ($message->chat->chatUsers as $chatUser) {
            if ($chatUser->user_id !== $message->other->id) {
                Event::fire(new NewMessageNotificationEvent($message, $chatUser->user_id));
            }
        }
    }
}

ERROR LOG

[2018-09-06 06:28:55] local.ERROR: exception 'Illuminate\Broadcasting\BroadcastException' with message 'API call failed since (daily) message quota exceeded
' in /var/www/html/project/vendor/laravel/framework/src/Illuminate/Broadcasting/Broadcasters/PusherBroadcaster.php:106
Stack trace:
#0 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Broadcasting/BroadcastEvent.php(49): Illuminate\Broadcasting\Broadcasters\PusherBroadcaster->broadcast(Array, 'new_$
#1 [internal function]: Illuminate\Broadcasting\BroadcastEvent->handle(Object(Illuminate\Broadcasting\Broadcasters\PusherBroadcaster))
#2 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(30): call_user_func_array(Array, Array)
#3 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#4 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Appli$
#5 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/Container.php(539): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Arr$
#6 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(94): Illuminate\Container\Container->call(Array)
#7 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(114): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}(Object(Illuminate\Broadcasting\Broa$
#8 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(102): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Broadcast$
#9 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(98): Illuminate\Pipeline\Pipeline->then(Object(Closure))
#10 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(43): Illuminate\Bus\Dispatcher->dispatchNow(Object(Illuminate\Broadcasting\BroadcastEv$
#11 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(69): Illuminate\Queue\CallQueuedHandler->call(Object(Illuminate\Queue\Jobs\RedisJob), Array)
#12 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(317): Illuminate\Queue\Jobs\Job->fire()
#13 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(267): Illuminate\Queue\Worker->process('redis', Object(Illuminate\Queue\Jobs\RedisJob), Object(Il$
#14 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(113): Illuminate\Queue\Worker->runJob(Object(Illuminate\Queue\Jobs\RedisJob), 'redis', Object(Ill$
#15 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(102): Illuminate\Queue\Worker->daemon('redis', 'default', Object(Illuminate\Queue\Wo$
#16 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(86): Illuminate\Queue\Console\WorkCommand->runWorker('redis', 'default')
#17 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#18 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(30): call_user_func_array(Array, Array)
#19 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#20 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Appl$
#21 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/Container.php(539): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Ar$
#22 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Console/Command.php(182): Illuminate\Container\Container->call(Array)
#23 /var/www/html/project/vendor/symfony/console/Command/Command.php(252): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\$
#24 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Console/Command.php(168): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\Ar$
#25 /var/www/html/project/vendor/symfony/console/Application.php(946): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\C$
#26 /var/www/html/project/vendor/symfony/console/Application.php(248): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symf$
#27 /var/www/html/project/vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfon$
#28 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(122): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\In$
#29 /var/www/html/project/artisan(36): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\Conso$
#30 {main}

[2018-09-06 06:28:55] local.ERROR: exception 'ErrorException' with message 'Trying to get property of non-object' in /var/www/html/project/app/Events/Notifications/NewMessageCreate$
Stack trace:
#0 /var/www/html/project/app/Events/Notifications/NewMessageCreatedEvent.php(27): Illuminate\Foundation\Bootstrap\HandleExceptions->handleError(8, 'Trying to get p...', '/var/www/h$
#1 /var/www/html/project/app/Jobs/EventHandlers/CreateMessageNotification.php(38): App\Events\Notifications\NewMessageCreatedEvent->__construct(Object(App\Models\Chat\Message))
#2 [internal function]: App\Jobs\EventHandlers\CreateMessageNotification->handle()
#3 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(30): call_user_func_array(Array, Array)
#4 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#5 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Appli$
#6 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/Container.php(539): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Arr$
#7 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(94): Illuminate\Container\Container->call(Array)
#8 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(114): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}(Object(App\Jobs\EventHandlers\Creat$
#9 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(102): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(App\Jobs\EventHandle$
#10 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(98): Illuminate\Pipeline\Pipeline->then(Object(Closure))
#11 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(43): Illuminate\Bus\Dispatcher->dispatchNow(Object(App\Jobs\EventHandlers\CreateMessag$
#12 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(69): Illuminate\Queue\CallQueuedHandler->call(Object(Illuminate\Queue\Jobs\RedisJob), Array)
#13 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(317): Illuminate\Queue\Jobs\Job->fire()
#14 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(267): Illuminate\Queue\Worker->process('redis', Object(Illuminate\Queue\Jobs\RedisJob), Object(Il$
#15 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(113): Illuminate\Queue\Worker->runJob(Object(Illuminate\Queue\Jobs\RedisJob), 'redis', Object(Ill$
#16 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(102): Illuminate\Queue\Worker->daemon('redis', 'default', Object(Illuminate\Queue\Wo$
#17 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(86): Illuminate\Queue\Console\WorkCommand->runWorker('redis', 'default')
#18 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#19 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(30): call_user_func_array(Array, Array)
#20 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#21 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Appl$
#22 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Container/Container.php(539): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Ar$
#23 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Console/Command.php(182): Illuminate\Container\Container->call(Array)
#24 /var/www/html/project/vendor/symfony/console/Command/Command.php(252): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\$
#25 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Console/Command.php(168): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\Ar$
#26 /var/www/html/project/vendor/symfony/console/Application.php(946): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\C$
#27 /var/www/html/project/vendor/symfony/console/Application.php(248): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symf$
#28 /var/www/html/project/vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfon$
#29 /var/www/html/project/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(122): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\In$
#30 /var/www/html/project/artisan(36): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\Conso$

Solution

  • What worked for me was to remove all failed jobs from the queue (after attempting to retry just one more time):

    php artisan queue:restart
    php artisan queue:work redis --daemon --tries=1
    

    Re-run the queue:

    php artisan queue:work redis --daemon
    

    Also, I had to get rid to calls to Pusher which were failing to get this to work.