故障現象
昨天同事反饋一個奇怪的問題,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
]);