Laravel队列任务超时后不退出,导致队列挂起的故障分析
故障现象
昨天同事反馈一个奇怪的问题,Laravel的队列整个挂住了,任务都有设置超时,但是超时以后,任务并不会被自动终止,导致后续的任务一直得不到处理。
故障重现
最初我的反应是队列任务配置不正确导致超时机制失效,但是经过同事的验证,大部分的情况任务超时会被正常终止,只有通过Guzzle
发API请求的时候才会出现这个问题。结合反馈的信息,设计了一组实验来验证此问题:
- 超时时间设置成
10s
,然后任务执行sleep(15)
,没有故障; - 超时时间设置成
10s
,然后任务执行sleep(8)
,接着调用Guzzle
(或者curl
)发起请求,这个请求需要20秒
才能完成,故障就出现了。
可见故障一定跟Guzzle
(实际上是curl
)有关。能重现故障的代码如下:
// app/Jobs/TestJob.php
<?php
namespace App\Jobs;
use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Foundation\Bus\Dispatchable;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;
use Log;
class TestJob implements ShouldQueue
{
use Dispatchable, InteractsWithQueue, Queueable, SerializesModels;
public $timeout = 10;
public $tries = 1;
/**
* Execute the job.
*
* @return void
*/
public function handle()
{
sleep(8); // 设置为15s,超过$timeout的值,则可以正常工作
$client = new \GuzzleHttp\Client();
$url = 'http://dev1.test/longtime'; // 这是一个执行时间超过20秒的脚本
$res = $client->get($url);
}
public function failed(\Exception $e)
{
Log::info('test job failed');
}
}
通过php artisan tinker
连续执行多次dispatch(new App\Jobs\TestJob())
。队列一开立刻就重现了故障,如下面日志所示,队列在执行第1个任务时就没在打出任务东西了。
$php artisan queue:work
[2020-09-03 20:15:27][UP4PcTPaZgx2ckI4RCZhZeih5KtosfSs] Processing: App\Jobs\TestJob
故障分析
在分析的时候,有两个基本的判断:
- 由于
Guzzle
库只是对curl
的封装,所以这个问题可以断定跟curl
有关; - 队列的超时处理需要操作系统级别的支持才能做得到,因此需要了解下Laravel是怎么实现超时的。
根据这2个判断,首先应该了解队列的超时机制,其次去分析curl
为什么会影响到队列的超时机制。
于是首先查看了Larvel队列的源码关于处理超时的原理,不出意外,Laravel
利用了UNIX
的信号机制,通过pcntl
注册SIGALRM
信号的方式实现超时处理,防止进程无限等待。对应的代码在Laravel工程的vendor/laravel/framework/src/Illuminate/Queue/Worker.php
可以看到:
{
// We will register a signal handler for the alarm signal so that we can kill this
// process if it is running too long because it has frozen. This uses the async
// signals supported in recent versions of PHP to accomplish it conveniently.
pcntl_signal(SIGALRM, function () use ($job, $options) {
if ($job) {
$this->markJobAsFailedIfWillExceedMaxAttempts(
$job->getConnectionName(), $job, (int) $options->maxTries, $this->maxAttemptsExceededException($job)
);
}
$this->kill(1);
});
pcntl_alarm(
max($this->timeoutForJob($job, $options), 0)
);
}
curl
会影响到队列的超时机制不能工作只有两种可能性:信号被屏蔽了
或者定时器被重新注册
。在GOOGLE搜索关于Laravel队列和curl的影响,果然发现其他人也碰到类似的问题。Guzzle
在不设置超时的时候,就会设置CURLOPT_NOSIGNAL
,于是信号被屏蔽了,SIGLARM
发不出来,队列也就无法做超时处理。详见解释
https://github.com/laravel/framework/issues/22301
既然知道了原因,可以通过设置一个超时来防止CURLOPT_NOSIGNAL
被设置。从Guzzle
的超时参数来看,它有3个超时参数,刚开始只设置timeout
没生效,于是加read_timeout
和connect_timeout
也一起设置了就生效了。调整后的TestJob
,执行代码如下:
// app/Jobs/TestJob.php
public function handle()
{
sleep(8); // 设置为15s,超过$timeout的值,则可以正常工作
$client = new \GuzzleHttp\Client();
$url = 'http://dev1.test/longtime'; // 这是一个执行时间超过20秒的脚本
$res = $client->get($url, ['timeout' => 60, 'read_timeout' => 60, 'connect_timeout' => 60]); // 增加超时参数
}
这样修改以后,任务会被终止,日志如下:
$ php artisan queue:work
[2020-09-03 22:08:42][pkcCTZvVDeFRzKBo2QLz2qJ8KDIqGpsh] Processing: App\Jobs\TestJob
[2020-09-03 22:09:50][pkcCTZvVDeFRzKBo2QLz2qJ8KDIqGpsh] Failed: App\Jobs\TestJob
Killed
但是仔细观察, 终止的时间并不是队列设置的超时时间,而是68秒。这是由于curl
的超时也是使用了SIGALRM
信号,于是队列的超时机制就被curl
给代替了。关于curl
的超时使用的是信号机制,在CURLOPT_TIMEOUT
的参数(https://curl.haxx.se/libcurl/c/CURLOPT_TIMEOUT.html) 就有详细的说明。
结合整个分析,得出以下结论:任务队列的超时机制,在使用curl
时将会无效。要想让任务在指定时间内被终止,应该设置curl
的超时时间与任务的超时时间相等。任务最长被终止的时间将为2*任务超时时间
。
解决方案
代码中的Guzzle
或者curl
,都必须设置超时参数。防止在队列中调用时挂住。超时时间根据实际情况设置。
(new \GuzzleHttp\Client())->get('https://demo.test/api', [
'timeout' => 30,
'connect_timeout' => 30,
'read_timeout' => 30
]);