I have an issue with the Laravel queue. It will start processing jobs, but then it hangs somewhere in the middle (based on custom echos to the log) and ends only with timeout. The problem is that the job should take no more than 1 min, but the job in the queue runs for more than 10 mins without any results nor any errors - except the standard timeout error.
The job
The job that should be processed in the queue is containing standard Eloquent selection and one update method that should update the other model's property.
// app\Listeners\CountReceivedTextAnswers
// There follows the listener's handle method. Nothing else is inside the
// Listener, it also implements ShouldQueue interface and InteractsWithQueue trait.
public function handle($event)
{
$questions = $this->question->whereTarget(['gl', 'povinn', 'ucit'], $event->evaluation->id, 'text');
$this->evaluation->updateOptions(
$event->evaluation->id,
'number_of_answers_to_text_questions',
$this->answer->countAnswersToManyQuestions($questions)
);
}
// app\Repositories\Answers\AnswersEloquentRepository
// This is the method that is called inside the listener. It passes
// collection of questions to the following method which should count
// answers on them.
public function countAnswersToManyQuestions(Collection $questions): int
{
$result = 0;
foreach ($questions as $question) {
$result += $this->countAnswersToQuestion($question);
}
return $result;
}
// This is the count method, it accepts Question model and count
// number of answers received on that question.
public function countAnswersToQuestion(Question $question): int
{
$select = [
'id',
'import_id',
'question_id',
'content',
'value',
'hidden',
'hidden_by',
'signed_by',
];
return Answer::select($select)
->whereDoesntHave('answered')
->where('question_id', '=', $question->id)
// Remove unwanted answers e.g. empty.
->when($question->form === 'text', function (Builder $query) {
$query->whereNotNull('content');
})
->when($question->form === 'slider', function (Builder $query) {
$query->whereNotNull('value');
})
->count();
}
// app\Repositories\Evaluation\EvaluationEloquentRepository
// This is the update method that is called to update the value
// inside the listener.
public function updateOptions($id, $field, $value)
{
$evaluation = $this->find($id);
$options = json_decode($evaluation->options, true);
$options[$field] = $value;
return $this->update($id, [
'options' => $options
]);
}
When I call the same method from listener manually in Tinker it takes around 30 sec to complete. Thus I guess the problem should not be related to the method itself, but something else, possibly configuration?
My setup
I'm using docker with five containers, two are based on my docker image (.dockerfile) which is based on the official php:7.3-fpm image with installed oci8 and few other extensions. The container's start script is based on this tutorial so I can use one container for both - the queue and the app. The rest of the containers are base on their official docker images - httpd:2.4-alpine, mysql:8.0 and redis:5-alpine. I should also note that I'm using Laravel 5.5
php.ini
These values I change in php.ini configuration. Rest should be default. It is set to be a quite generous, because at first I thought the error is related to php config, however is seems not, because there is no error in php's error log.
date.timezone=UTC
display_errors=on
log_errors=On
error_log=/var/www/storage/logs/php.log
opcache.enable=1
opcache.enable_cli=1
memory_limit = 512M
upload_max_filesize = 128M
post_max_size = 64M
max_execution_time=900
max_input_time=900
default_socket_timeout=60
starth.sh
#!/usr/bin/env bash
set -e
role=${CONTAINER_ROLE:-app}
env=${APP_ENV:-production}
if [[ "$env" != "local" ]]; then
echo "Caching configuration..."
(cd /var/www && php artisan config:cache && php artisan route:cache && php artisan view:cache)
fi
if [[ "$role" = "app" ]]; then
exec php-fpm
elif [[ "$role" = "queue" ]]; then
echo "Running the queue..."
php /var/www/artisan queue:listen --verbose --tries=10 --sleep=0 --timeout=800 --memory=512
elif [[ "$role" = "scheduler" ]]; then
while [[ true ]]
do
php /var/www/artisan schedule:run --verbose --no-interaction &
sleep 60
done
else
echo "Could not match the container role \"$role\""
exit 1
fi
The only error
There is the only error, that I'm able to find in laravel.log, however I don't think that the actual problem is in the length of the job as running it in Tinker takes far less time than the timeout is set to be.
[2019-05-22 16:06:39] local.ERROR: The process "'/usr/local/bin/php' 'artisan' queue:work 'redis' --once --queue='default' --delay=0 --memory=512 --sleep=0 --tries=10" exceeded the timeout of 800 seconds. {"exception":"[object] (Symfony\Component\Process\Exception\ProcessTimedOutException(code: 0): The process \"'/usr/local/bin/php' 'artisan' queue:work 'redis' --once --queue='default' --delay=0 --memory=512 --sleep=0 --tries=10\" exceeded the timeout of 800 seconds. at /var/www/vendor/symfony/process/Process.php:1335) [stacktrace] /var/www/vendor/symfony/process/Process.php(424): Symfony\Component\Process\Process->checkTimeout() /var/www/vendor/symfony/process/Process.php(212): Symfony\Component\Process\Process->wait() /var/www/vendor/laravel/framework/src/Illuminate/Queue/Listener.php(193): Symfony\Component\Process\Process->run(Object(Closure)) /var/www/vendor/laravel/framework/src/Illuminate/Queue/Listener.php(115): Illuminate\Queue\Listener->runProcess(Object(Symfony\Component\Process\Process), '512') /var/www/vendor/laravel/framework/src/Illuminate/Queue/Console/ListenCommand.php(68): Illuminate\Queue\Listener->listen('redis', 'default', Object(Illuminate\Queue\ListenerOptions)) [internal function]: Illuminate\Queue\Console\ListenCommand->handle() /var/www/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(29): call_user_func_array(Array, Array) /var/www/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(87): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}() /var/www/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(31): Illuminate\Container\BoundMethod::callBoundMethod(Object(Illuminate\Foundation\Application), Array, Object(Closure)) /var/www/vendor/laravel/framework/src/Illuminate/Container/Container.php(549): Illuminate\Container\BoundMethod::call(Object(Illuminate\Foundation\Application), Array, Array, NULL) /var/www/vendor/laravel/framework/src/Illuminate/Console/Command.php(183): Illuminate\Container\Container->call(Array) /var/www/vendor/symfony/console/Command/Command.php(255): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle)) /var/www/vendor/laravel/framework/src/Illuminate/Console/Command.php(170): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Illuminate\Console\OutputStyle)) /var/www/vendor/symfony/console/Application.php(960): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput)) /var/www/vendor/symfony/console/Application.php(255): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\ListenCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput)) /var/www/vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput)) /var/www/vendor/laravel/framework/src/Illuminate/Console/Application.php(88): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput)) /var/www/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(121): Illuminate\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput)) /var/www/artisan(35): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput)) {main} "}
I have tried probably all possible advices that I've found on internet, I have changed all values in the php artisan queue:listen command and also in php.ini but it always ends with the same outcome. I have also tried to locate redis log, but without success, thus I moved the queue to the database and the result was always the same. Queue listener started the job, but then somehow hanged without any further information or error. I shuld also say that the worker with all these listeners and jobs works very well outside docker images.
I will be very grateful for any advice or tip! Also if you'd like to see more information, please let me know, I'll add them.
