search

laravel / horizon

Dashboard and code-driven configuration for Laravel queues.
https://laravel.com/docs/horizon
MIT License
3.85k stars 645 forks source link

Jobs get processed multiple times #205

Closed elynnaie closed 6 years ago

elynnaie commented 6 years ago

I have a job that gets dispatched to a queue inside a supervisor that has 20 workers assigned to it to handle large concurrency. There seems to be an issue (race condition maybe?) whereby a single dispatched job gets picked up by multiple horizon workers and processed multiple times. This causes problems because the job can only be processed once or it will fail.

I added a bunch of info logs in various places, including the job itself, the code that dispatches the job, and Repositories/RedisJobRepository.php inside Horizon. Here is what I found.

First the logs:

  1. "dispatching job" right before the call to dispatch(new MyJob())
  2. "enter job constructor" inside the job's constructor
  3. "executing job " inside the job's execute method
  4. "returning from job " at the very end of the job's execute method
  5. "reserving job " inside RedisJobRepository::reserved
  6. "completed job " inside RedisJobRepository::completed

Then the output:

[2017-10-17 20:15:38] pre.INFO: dispatching job
[2017-10-17 20:15:38] pre.INFO: enter job constructor 27262
[2017-10-17 20:15:38] pre.INFO: reserving job 202 3316
[2017-10-17 20:15:38] pre.INFO: executing job 3316
[2017-10-17 20:15:43] pre.INFO: reserving job 202 3307
[2017-10-17 20:15:43] pre.INFO: executing job 3307
[2017-10-17 20:15:45] pre.INFO: returning from job 3316
[2017-10-17 20:15:45] pre.INFO: completed job 202 3316
[2017-10-17 20:15:48] pre.INFO: reserving job 202 3323
[2017-10-17 20:15:48] pre.INFO: executing job 3323
[2017-10-17 20:15:48] pre.INFO: completed job 202 3323
[2017-10-17 20:15:48] pre.ERROR: <exception thrown from job because it already ran>
[2017-10-17 20:15:50] pre.INFO: returning from job 3307
[2017-10-17 20:15:50] pre.INFO: completed job 202 3307

Note that only a single job was constructed and dispatched, but the same job got reserved 3 times by 3 different horizon workers, and executed 3 times. I'm not quite sure how 2 jobs managed to succeed while the 3rd one failed; according to the code, it is supposed to clean up a temp file that is required in the job, but perhaps the jobs from processes 3316 and 3307 both managed to load the file for processing before one or the other deleted it.

The above output is quite consistent and reproducible, obviously with different ids each time. I tried to set 'tries' => 1 in my horizon config for this supervisor and ended up with a different set of consistently reproducible logs:

[2017-10-17 20:20:55] pre.INFO: dispatching job  
[2017-10-17 20:20:55] pre.INFO: enter job constructor 28229  
[2017-10-17 20:20:55] pre.INFO: reserving job 204 4358  
[2017-10-17 20:20:55] pre.INFO: executing job 4358  
[2017-10-17 20:21:00] pre.INFO: reserving job 204 4369  
[2017-10-17 20:21:00] pre.INFO: completed job 204 4369  
[2017-10-17 20:21:01] pre.ERROR: A queued job has been attempted too many times or run too long. The job may have previously timed out. {"exception":"[object] (Illuminate\\Queue\\MaxAttemptsExceededException(code: 0): A queued job has been attempted too many times or run too long. The job may have previously timed out. at /opt/www/pre/site/vendor/laravel/framework/src/Illuminate/Queue/Worker.php:394)
[2017-10-17 20:21:02] pre.INFO: returning from job 4358  
[2017-10-17 20:21:02] pre.INFO: completed job 204 4358

Now, it only reserves the job twice on two workers, and instead of getting my "file not found" exception inside the job, it throws the MaxAttemptsExceededException.

I would be happy to try anything and provide more details as needed!

Laravel: 5.5.14 Horizon: 1.0.4

Horizon supervisor config:

            'high-concurrency' => [
                'connection' => 'redis',
                'queue' => ['a', 'bunch', 'of', 'queues''],
                'balance' => 'false',
                'processes' => 20, 
                'tries' => 1, // or 3
                'timeout' => 300,
            ],

config/queue.php:

        'redis' => [
            'driver' => 'redis',
            'connection' => 'default',
            'queue'  => env('REDIS_QUEUE', 'default'), // set to "pre"
            'retry_after' => 5,
        ],

config/database.php:

    'redis' => [

        'client' => 'predis',

        'default' => [
            'host' => env('REDIS_HOST', 'localhost'),
            'password' => env('REDIS_PASSWORD', null),
            'port' => env('REDIS_PORT', 6379),
            'database' => env('REDIS_DATABASE', 0), // not set in the .env
        ],

    ],
themsaid commented 6 years ago

Dispatching a job with a supervisor that monitors 20 processes seems to be running it only once for me, my job simply logs a string on start then sleeps 5 seconds before it succeeds to check if any workers would pick it while it's still running, but seems like everything works normally.

The job ran only once, the logged string was added only once.

What else should I do be able to replicate your issue given the setup I shared?

elynnaie commented 6 years ago

I tried to pare down my setup, and I have been able to reproduce my issue with this job:

namespace App\Jobs;                                                            

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

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

    public function __construct()                                              
    {
        info('enter job constructor ' . getmypid());                           
    }   

    public function handle()                                                   
    {   
        info('executing job ' . getmypid());                                   
        sleep(5);
        info('returning from job ' . getmypid());
    }
}

My entire config/horizon.php:

return [
    'use' => 'default',
    'prefix' => 'horizon:',
    'waits' => [],
    'environments' => [
        'pre' => [
            'my-supervisor' => [
                'connection' => 'redis',
                'queue' => ['default'],
                'balance' => 'false',
                'processes' => 20,
                'tries' => 3,
                'timeout' => 300,
            ],
        ],
    ],

];

Entire config/queue.php:

return [                                                                       
    'default' => 'redis',                                                      
    'connections' => [                                                         
        'sync' => [                                                            
            'driver' => 'sync',                                                
        ],                                                                     
        'redis' => [                                                           
            'driver' => 'redis',                                               
            'connection' => 'default',                                         
            'queue'  => 'default',                                             
            'retry_after' => 5,                                                
        ],                                                                     

    ],                                                                         
    'failed' => [                                                              
        'database' => env('DB_CONNECTION', 'pgsql'),                           
        'table' => 'failed_jobs',                                              
    ],                                                                         
];

redis section of config/database:

    'redis' => [                                                               
        'client' => 'predis',                                                  
        'default' => [                                                         
            'host' => 'localhost',                                             
            'password' => null,                                                
            'port' => 6379,                                                    
            'database' => 0,                                                   
        ],                                                                     
    ],

My environment is pre. The job is dispatched from a route:

Route::get('/test', function () {
    info('dispatching job');
    dispatch((new \App\Jobs\MyJob())->onQueue('default'));
});

As far as I know, that's it. Weirdly, if I open up tinker and run dispatch((new \App\Jobs\MyJob())->onQueue('default'));, it does not run the job at all...even once. It has to be called from a route for some reason.

elynnaie commented 6 years ago

@themsaid I figured it would be easier to create a brand new repo. I did this here: https://github.com/denaje/horizon-bug-test

Instructions that I used to replicate my issue are here: https://github.com/denaje/horizon-bug-test/commit/303e0a0a4e126836fea6c07ceb6555929a9c55e7

themsaid commented 6 years ago

Here's the output after running your code:

[2017-10-18 13:14:03] local.INFO: executing job 15359  
[2017-10-18 13:14:08] local.INFO: returning from job 15359

The job is still running only once.

elynnaie commented 6 years ago

I was able to reproduce on our server and two local laptops. These are all running Arch Linux. So I spun up a new Ubuntu server VM on GCP and tried it there...worked fine. So the strange behavior seems to be dependent on OS or possibly some other package. redis-server on my Ubuntu box is version 3.2.1, whereas on Arch it is 4.0.2. Maybe that makes a difference? I will attempt to post back if I can manage to downgrade and see if that changes things.

elynnaie commented 6 years ago

Downgrading redis to 3.2.0 on my Arch Linux machine did not fix the problem. Seems the issue is elsewhere, not necessarily related to horizon code or redis version. Would still be nice if I could track it down though.

themsaid commented 6 years ago

Yeah that's interesting indeed, please let us know if you reach anywhere with this.

themsaid commented 6 years ago

Going to close this since it does seem like an issue with your specific setup, but please feel free to ping me in case you found an issue with Horizon.

elynnaie commented 6 years ago

@themsaid Reproducible on a fresh install of Arch Linux and Ubuntu 17.10 (released Oct 19, 2017).

Arch Linux:

Ubuntu Server 17.10:

I was going to install Ubuntu Server 17.04 again, see it behave correctly, then try to narrow down the thing that causes the issue, but now I am able to consistently able to reproduce the problem there too, unlike before.

Ubuntu Server 17.04:

I performed 15 tests and here are the number of times that the test job ran each time according to the Horizon output: 3 3 2 3 2 1 4 3 3 4 2 4 3 2 2

The entirety of my terminal output, working with a fresh install of Ubuntu Server 17.04: https://gist.github.com/denaje/bb72950d9edf9ddc6232eae9a45ab149

Same as above but only listing the commands I ran: https://gist.github.com/denaje/2ba1725cfe4431470d84297306df52e1

So I do not think that it is an issue with my specific setup, and it does not seem to be dependent on kernel version, redis version, or Linux distribution. I'm not sure where to go with it next. Are there additional places I can log to try to track down why the job runs multiple times? Or perhaps this info helps you reproduce it?

themsaid commented 6 years ago

I really can't produce this at all, also nobody reported this behaviour before, so we'll wait to see if anyone else reports a similar thing.

elynnaie commented 6 years ago

After delving into Horizon, Redis Queues, Lua script, and redis-cli, I finally determined what my problem was. I thought that the retry_after option in config/queue.php meant "After a job fails, wait this many seconds before trying it again." When in actuality it was "how many seconds the queue connection should wait before retrying a job that is being processed." I had retry_after set to a low value, like 0 or 5 seconds, because I misunderstood what this option did and thought, "I don't want there to be a long delay before the job is retried".

nikklass commented 6 years ago

Hmm. I also had a similar issue where my system was queueing and sending multiple sms to the same client in a short span of time (upto 4 simultaneous sms) and it seems setting the 'retry_after' duration to a higher value actually sorts out the problem! This had troubled me for quite some time. Thanks.

eriktobben commented 6 years ago

Hi!

I think I have the same problem as you guys.

I have just installed Horizon, and set my QUEUE_DRIVER to redis in .env-file. When I run php artisan horizon the job gets executed four times.

I have no stats in Horizon dashboard, and the status is a cross. Screen grab: https://imgur.com/a/rtlbf This is after running php artisan horizon and getting Horizon started successfully.

.env

QUEUE_DRIVER=redis
HORIZON_PREFIX=projectone:

config/horizon.php

'use' => 'default',

'prefix' => env('HORIZON_PREFIX', 'horizon:'),

'waits' => [
        'redis:default' => 60,
    ],

'environments' => [
        'production' => [
            'supervisor-1' => [
                'connection' => 'redis',
                'queue' => ['default'],
                'balance' => 'auto',
                'processes' => 10,
                'tries' => 3,
            ],
        ],

        'local' => [
            'supervisor-1' => [
                'connection' => 'redis',
                'queue' => ['default'],
                'balance' => 'auto',
                'processes' => 3,
                'tries' => 3,
            ],
        ],
    ],

Terminal

[2017-12-31 21:17:27] Processing: App\Jobs\GenerateInvoice
[2017-12-31 21:17:32] Processing: App\Jobs\GenerateInvoice
[2017-12-31 21:17:32] Processing: App\Jobs\GenerateInvoice
[2017-12-31 21:17:32] Failed:     App\Jobs\GenerateInvoice

The error message for the failed job is just because the file name of the generated invoice already exists.

elynnaie commented 6 years ago

Your log output looks similar to my issue, which was solved by setting the config value queue.redis.retry_after to either null or a large number, though your screenshot indicates that horizon was not running at the time. (...maybe? It does seem that you are getting some stats, like the supervisor you have running, but I would expect a green check in "status" and stats to show up. I don't think I've had this particular issue before.) Can you check your retry_after setting and see what it is?

eriktobben commented 6 years ago

Before the screenshot was taken, I started Horizon with "php artisan horizon" and got the message "Horizon started successfully.". But in the Horizon dashboard the cross is still there. But I am able to see the supervisor and I also get the failed jobs.

My retry_after was set to 90 and I changed it to 900, but I got the same result. EDIT: Also tested with null, same result.

eriktobben commented 6 years ago

I tested with setting queue to redis and running "php artisan queue:work", and this is the response from Terminal:

[2018-01-01 17:08:37] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:41] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:42] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:43] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice
[2018-01-01 17:08:44] Processing: App\Jobs\GenerateInvoice

This was one job pushed to the queue, so not sure what is happening. I'm running the latest version of Laravel and Redis on macOS High Sierra.

elynnaie commented 6 years ago

Strange. Three things I would check for:

  1. Try changing retry_after to null and see if that makes a difference.
  2. Double check that you don't have any other Horizon processes running on the same server. I've had many problems similar to this when I had multiple horizons running.
  3. Is Laravel and Horizon up-to-date?

Based on your most recent comment however...something seems really wonky. I don't think I've seen that kind of behavior before.

eriktobben commented 6 years ago
  1. Just tried changing to null and got the same result.
  2. I am running this locally on my Mac. No other sites are using Horizon or Redis.
  3. Yes, they are up to date. Laravel install 5 days old, and Horizon is from yesterday.

Really not sure what is happening here. I've tried rebooting my machine to see if that helped, but no..

eriktobben commented 6 years ago

@themsaid Any recommendations as to what could cause this behavior?

goodjun commented 6 years ago

try changing redirect_stderr to true (supervisor program config).

eriktobben commented 6 years ago

@goodjun Where do I change this? (Not familiar with configs for Redis or Supervisor).

goodjun commented 6 years ago

supervisor program config.

example:

[program:photo_work_queue]
autorestart=true
autostart=true
command=php artisan queue:work --tries=5 --memory=1024 --timeout=1800
user=photo
directory=/data/project
numprocs=5
process_name = %(program_name)s-%(process_num)d
redirect_stderr=true

@eriktobben

sebastiansulinski commented 6 years ago

@eriktobben - I had the very same issue a few times on redis - unfortunately there is no clear indication of what's causing it - in my case it was code issue - i.e. I tried to load relationship, which I forgot to declare on the model etc. Check your code all the way from where you dispatch mail down to the contents of the mailable - I'm pretty sure you'll find the issue somewhere along the way.

nikklass commented 6 years ago

I agree with @sebastiansulinski. I initially said that "setting the 'retry_after' duration to a higher value actually sorts out the problem", but I discovered later that it didn't seem to sort out the mess. I think it was some code problem that I later corrected which stopped the problem. I think whenever Laravel encounters any code errors, tis problem is bound to happen. So check your php code thoroughly...

Camotubi commented 6 years ago

@eriktobben does your job run as intended? That output in the console seems like the job is failing and laravel is retrying. I would recommend you to add this to your boostrap.php https://stackoverflow.com/questions/39255883/logging-not-working-in-laravel-queue-job This allows the artisan console to log errors to storage/logs/ Is the output of the console yellow? If so, I think your job is failing.

eriktobben commented 6 years ago

@Camotubi Hi! Well, it was a code error. When running the job with no code inside it works. Looks like a problem with the PDF generation itself. But the strange thing is that it was retrying so many times, even when I set the tries to 3.

The other thing is that the Horizon dashboard has never been working. Screen grab: https://imgur.com/a/rtlbf

Never got any failed jobs in the failed jobs tab, and the status is always a cross. No other stats is being populated.

Camotubi commented 6 years ago

Yeah, thats what I meant. Maybe the definition of a "job failing" doesn't include a job not being executable. Did you do the boostrap thingy? I still recommend it. The code errors will appear in the logs files.

I have 0 knowledge about the horizon dashboard, soo I can't help you there.

nicorafales commented 6 years ago

Hi, i've a similar problem, where my queue jobs work only once when executed (as expected) on my local environment (using laradock with mariadb redix nginx workspace) and on staging server (ubuntu) with apache, redis and mariadb, also running supervisor. Processes run ok but it creates a loop until it fails. I dissabled supervisor on server and it's working as expected. I don't know how to configure it, so i guess i will leave it as it is and run a command at start up calling horizon on background.

itailulu commented 6 years ago

We're having the same issue, when running multiple queue workers and dispatching one job** it will suddenly "duplicate" the job, which causes problems, since a job with same attributes is not designed to run more than once in our system. When running only one worker, it works fine and doesn't duplicate the job in the queue...

We've used very "conservative" timeout and retry_after on the job itself, and it still happens:

public $timeout = 600;
public $retry_after = 700;

we're using database as for queue connection, and the default retry_after is set to 90, which should be overridden by the job

itailulu commented 6 years ago

amazingly, after 2 days of holding my head - I think thought i found the issue: there is no way to set retry_after in a per-job basis - you have to do it in the queue.php config

I tried to follow the steps described here which basically instruct you to create another connection for long-running processes, something like:

'database-long-running' => [
            'driver' => 'database',
            'table' => 'jobs',
            'queue' => 'default-long',
            'retry_after' => 1800,
        ],

and then when running your long-running job, use 

LongRunningJob::dispatch()->onQueue('some-queue')->onConnection('database-long-running');

Unfortunately, it didn't work for me. It seems that no matter what connection/queue I use, the job will run on the default database connection. I tried both in the way described above, and by using the long way:

$job = new LongRunningJob();
$connection = Queue::connection(database-long-running)
    ->pushOn('some-queue', $job);

When I increase the retry_after of the default database connection to a greater number - everything works fine.

So my questions are:

  1. Is there any way to set the retry_after value on a per-job basis?
  2. If not - is it possible to create another connection with different retry_after value? If yes - is it possible to choose on what connection the job will run?
itailulu commented 6 years ago

I found how to run worker in a specific connection, was missing the info on Laravel docs: queue:work database-long-running --queue= some-queue

But i still don't understand why the onConnection(...) didn't work...

nCuXaP commented 5 years ago

@elynnaie Thanks alot, my problem was also the wrong understanding of retry_after. You saved me a lot of time (not that I haven`t wasted 2 hours before searching online and finding your solution :D). Thanks alot!!!

DrudgeRajen commented 4 years ago

@elynnaie Thank you :+1:

MichaelHuyPhan commented 4 years ago

It took me 10 days to find out a solution for my case is the jobs table engine was set to MyISAM.

Solution => Switch it to InnoDB than everything work like a charm.

So maybe, MyISAM doesn't support transaction cause the job not lock and be processed multiple time

antonioribeiro commented 3 years ago

In my case it was a Livewire button dispatching the job twice to the queue. When a maintainer ask, are you sure it's not your code doing it? You better be sure 😆

The generate button below

<div wire:poll>
    @if ($isGenerating)
        <button wire:click="resetGeneratingStatus" type="button" class="button button--primary button--medium">
            Generating... click to reset reset generating status
        </button>
    @else
        <button wire:click="generate" type="button" class="button button--primary button--medium">
            Generate report
        </button>
    @endif
</div>

Was executing this method twice:

public function generate()
{
    $this->validate($this->rules);

    ReportTransactions::dispatch($this->date);
}
bwabt commented 2 months ago

Old post, but still relevant! We used Laravel Shift to upgrade to 11, but it did not catch our custom value. Took hours to find this, but problem solved. Thanks!!