9

I'm creating a website using Laravel 5. I'm using queues with beanstalkd with 2 tubes. I have 10 workers monitored by daemontools. 5 workers process tube A and B. The other 5 workers only process tube B.

Things work great most of the time, but occasionally tube B seems to lock up. The logs show that the workers are throwing an exception.

[2015-04-24 07:09:36] local.ERROR: exception 'Pheanstalk\Exception\ServerException' with message 'Cannot delete job 273812: NOT_FOUND' in /x/website/vendor/pda/pheanstalk/src/Command/DeleteCommand.php:44
Stack trace:
#0 /x/website/vendor/pda/pheanstalk/src/Connection.php(121): Pheanstalk\Command\DeleteCommand->parseResponse('NOT_FOUND', NULL)
#1 /x/website/vendor/pda/pheanstalk/src/Pheanstalk.php(384): Pheanstalk\Connection->dispatchCommand(Object(Pheanstalk\Command\DeleteCommand))
#2 /x/website/vendor/pda/pheanstalk/src/Pheanstalk.php(67): Pheanstalk\Pheanstalk->_dispatch(Object(Pheanstalk\Command\DeleteCommand))
#3 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Jobs/BeanstalkdJob.php(73): Pheanstalk\Pheanstalk->delete(Object(Pheanstalk\Job))
#4 /x/website/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(46): Illuminate\Queue\Jobs\BeanstalkdJob->delete()
#5 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(126): Illuminate\Queue\CallQueuedHandler->call(Object(Illuminate\Queue\Jobs\BeanstalkdJob), Array)
#6 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Jobs/BeanstalkdJob.php(51): Illuminate\Queue\Jobs\Job->resolveAndFire(Array)
#7 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(207): Illuminate\Queue\Jobs\BeanstalkdJob->fire()
#8 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(159): Illuminate\Queue\Worker->process('beanstalkd', Object(Illuminate\Queue\Jobs\BeanstalkdJob), '20', '120')
#9 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(113): Illuminate\Queue\Worker->pop(NULL, NULL, '120', 3, '20')
#10 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(85): Illuminate\Queue\Worker->runNextJobForDaemon(NULL, NULL, '120', 3, '20')
#11 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(101): Illuminate\Queue\Worker->daemon(NULL, NULL, '120', 128, 3, '20')
#12 /x/website/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(67): Illuminate\Queue\Console\WorkCommand->runWorker(NULL, NULL, '120', 128, true)
#13 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#14 /x/website/vendor/laravel/framework/src/Illuminate/Container/Container.php(523): call_user_func_array(Array, Array)
#15 /x/website/vendor/laravel/framework/src/Illuminate/Console/Command.php(115): Illuminate\Container\Container->call(Array)
#16 /x/website/vendor/symfony/console/Symfony/Component/Console/Command/Command.php(257): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#17 /x/website/vendor/laravel/framework/src/Illuminate/Console/Command.php(101): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#18 /x/website/vendor/symfony/console/Symfony/Component/Console/Application.php(874): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#19 /x/website/vendor/symfony/console/Symfony/Component/Console/Application.php(195): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#20 /x/website/vendor/symfony/console/Symfony/Component/Console/Application.php(126): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#21 /x/website/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(94): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#22 /x/website/artisan(36): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#23 {main}

I'm wondering if the problem might be caused by several workers going for the same job. Is that possible or is there some sort of mutex to control this?

What else might cause this?

Kebian
  • 664
  • 6
  • 17

3 Answers3

14

The queued command was taking too long and the problem was caused by the TTR value on the tube in beanstalkd, but it's not necessary to change that value.

In a nutshell, beanstalkd will keep the job reserved only for a maximum period of time (up to the TTR) and then it will assume that something has gone wrong and return the job back to the ready state.

Instead, it's possible to periodically touch the job to reset the reservation timer.

In Laravel, I've added this to my App\Commands\Command class and I periodically call it inside of loops on long running jobs.

public function touch()
{
    if (method_exists($this->job, 'getPheanstalk')) {
        $this->job->getPheanstalk()->touch($this->job->getPheanstalkJob());
    }
}
Kebian
  • 664
  • 6
  • 17
  • Can I get some clarification on how exactly I implement this? If you said need to add it to the App\Command so are you saying I make a new command called TouchCommand.php for example with that because in commands all I usually see is constructor and handle so not sure where that goes. Then in my actual job how do I call it? – dmotors Dec 18 '15 at 18:16
  • You can just put that function straight in to the Command class. Your other command classes will extend from it and inherit that function. Then in their handle() method you can periodically call $this->touch() to reset the timer. – Kebian Jan 04 '16 at 22:46
  • 3
    For reference I used this code on my abstract Job class and then called the method from with my long running jobs. – ghindle Mar 01 '16 at 13:15
  • I don't understand.. I am using Laravel 5.2 and so I added the touch command to my Job.php class. I call it ever so often during my job's execution and I've confirmed the call is being made and it's reaching inside the if statement. It isn't throwing any errors either. But my jobs are still timing out as per my TTR in the queue.php config file. Am I doing anything wrong? – vesperknight Jun 03 '16 at 12:36
  • Can you please post a more completed code sample? Thanks! – Misagh Laghaei Sep 06 '18 at 12:10
1

Had the same problem. My jobs took more than 60 seconds to finish. Increasing the ttr value in config queue on the default tube did the trick. Hope that helps.

Mirceac21
  • 1,741
  • 17
  • 24
  • Thanks. I've also managed to isolate it to jobs that are taking far too long to complete. A combination of optimising my code and changing the ttr as you suggest may resolve it. I'll update here with my findings. – Kebian Apr 28 '15 at 20:41
  • 1
    If your tasks are idempotent then this will be OK otherwise just think what might happen if a task suddenly takes a lot longer? The approach to keep touching the job is much safer. This also allows you to only apply it to the job you want and not the entire queue. Some items may never need to take a really long time and in fact might want to be caught quickly. – Ian Chadwick Mar 02 '16 at 17:07
0

To be more precise with your touching, you can use the working function provided above and do the following in your Job:

1) Declare a property and set it's value in the constructor:

Protected $ttr;

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

2) Then measure the difference in time inside your loop. In my case, I was downloading and cropping thousands of images, so in that loop I inserted the following:

//With a ttr of 60.
if((time() - 50) >= $this->ttr) { //If over 50 seconds since ttr start,
    $this->touch(); //reset ttr, 
    $this->ttr = time(); //and set new time.
}