dongmoyu0336
dongmoyu0336
2019-05-22 14:15
浏览 700
已采纳

当我使用queue:listen时,Laravel队列作业永远不会以超时结束

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)) /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.

  • 点赞
  • 写回答
  • 关注问题
  • 收藏
  • 邀请回答

2条回答 默认 最新

  • dongtaijiao7140
    dongtaijiao7140 2019-06-18 18:45
    已采纳

    In the end I found that the queue worker was really exceeding the timeout. It was due to the fact that during some data migration were removed all foreign keys and indexes, thus loading relations from tables took too long. Redefining relationships in the DB made the queue worker significantly faster and error disappeared.

    点赞 评论
  • douwu8251
    douwu8251 2019-05-22 14:30

    You could check your log, in storage/logs/laravel.log, Maybe the error could be there

    点赞 评论

相关推荐