У меня есть функция ванильного облака, которая занимает 60 секунд, а затем возвращает статус 200 с помощью простого объекта JSON. Время ожидания для функции установлено на 150 с. При локальном тестировании и при запуске функции через ее адрес cloudfunctions.net функция завершается через 60 с, а ответ 200 и тело сообщения корректно доставляются клиенту. Пока все хорошо.
Вот кикер - если я запускаю точно такую же функцию через прокси через хостинг firebase (настройка через «цель» внутри firebase.json), согласно журналам стекового драйвера, функция мгновенноперезапускается где-то 1-3 раза, и когда они завершают, функция иногда ВНОВЬ перезапускается, в конечном итоге возвращая таймаут 503 из Varnish.
Это поведение ТОЛЬКО последовательно реплицируется, когда функция вызывается в прокси-доменечерез хостинг firebase. Кажется, это ТОЛЬКО происходит, когда функция занимает ~ 60 секунд или дольше. Это не зависит от возвращенного кода ответа или тела ответа.
Это поведение можно увидеть в тестовой функции, которую я настроил здесь: https://trellisconnect.com/testtimeout?sleepAmount=60&retCode=200
Это поведение было первоначально идентифицировано в функцииэто развернуто через без сервера. Чтобы исключить отсутствие сервера, я создал тестовую функцию, которая упрощает тестирование и проверку поведения, и развернул ее с помощью обычных функций firebase, вызвал ее из домена cloudfunctions.net и убедился, что я всегда получал правильный ответ в 60-х годах. Затем я обновил свой firebase.json, добавив новый маршрут, который указывает на эту функцию и смог повторить проблему.
index.js
function sleep(ms) {
return new Promise(resolve => setTimeout(resolve, ms));
}
exports.testtimeout = functions.https.onRequest((req, res) => {
const { sleepAmount, retCode } = req.query;
console.log(`starting test sleeping ${sleepAmount}...`);
sleep(1000 * sleepAmount).then(result => {
console.log(`Ending test func, returning ${retCode}`);
return res.status(retCode).json({ message: 'Random Response' });
});
});
firebase.json
{
"hosting": {
"public": "public",
"ignore": ["firebase.json", "**/.*", "**/node_modules/**"],
"rewrites": [
{
"source": "/testtimeout",
"function": "testtimeout"
}
]
},
"functions": {}
}
</snip>
Правильный / ожидаемый ответ (sleepAmount = 2 секунды)
zgoldberg@zgblade:~$ time curl "https://trellisconnect.com/testtimeout?sleepAmount=2&retCode=200"
{"message":"Random Response"}
real 0m2.269s
user 0m0.024s
sys 0m0.000s
И пример того, как все выглядит, когда sleepAmount установлен на 60 секунд
zgoldberg@zgblade:~$ curl -v "https://trellisconnect.com/testtimeout?sleepAmount=60&retCode=200"
* Trying 151.101.65.195...
* TCP_NODELAY set
* Connected to trellisconnect.com (151.101.65.195) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
* subject: CN=admin.cliquefood.com.br
* start date: Oct 16 20:44:55 2019 GMT
* expire date: Jan 14 20:44:55 2020 GMT
* subjectAltName: host "trellisconnect.com" matched cert's "trellisconnect.com"
* issuer: C=US; O=Let's Encrypt; CN=Let's Encrypt Authority X3
* SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x563f92bdc580)
> GET /testtimeout?sleepAmount=60&retCode=200 HTTP/2
> Host: trellisconnect.com
> User-Agent: curl/7.58.0
> Accept: */*
>
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
< HTTP/2 503
< server: Varnish
< retry-after: 0
< content-type: text/html; charset=utf-8
< accept-ranges: bytes
< date: Fri, 08 Nov 2019 03:12:08 GMT
< x-served-by: cache-bur17523-BUR
< x-cache: MISS
< x-cache-hits: 0
< x-timer: S1573182544.115433,VS0,VE184552
< content-length: 449
<
<?xml version="1.0" encoding="utf-8"?>
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Strict//EN"
"http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd">
<html>
<head>
<title>503 first byte timeout</title>
</head>
<body>
<h1>Error 503 first byte timeout</h1>
<p>first byte timeout</p>
<h3>Guru Mediation:</h3>
<p>Details: cache-bur17523-BUR 1573182729 2301023220</p>
<hr>
<p>Varnish cache server</p>
</body>
</html>
* Connection #0 to host trellisconnect.com left intact
real 3m3.763s
user 0m0.024s
sys 0m0.031s
Вот сумасшедшая часть: посмотрите журналы стекового драйвера, обратите внимание, как функция завершается за 60 секунд и почти сразу после запуска еще 3-х выполнений. ..
Обратите внимание, что исходный звонок поступает в 19: 09: 04.235 и заканчивается в 19: 10: 04.428 - почти ровно через 60 с. Почти ровно через 500 мс, 19: 10: 05.925 функция перезапускается. Я обещаю вам, что я не нажимал мою команду curl снова через 0,5 с после первоначального ответа. Ни одно из последующих представлений о функции здесь не было сгенерировано мной, все они кажутся фантомными повторениями?
https://i.imgur.com/WDY17pw.png (редактировать: у меня нет 10 репутации, чтобы опубликовать реальное изображение, поэтому просто ссылка выше)
Любые мысли или помощь приветствуются