Рабочие Gunicorn в Google App Engine случайным образом отправляют SIGKILL, что приводит к TIMEOUT. Что происходит?
Это происходит случайным образом, иногда при запуске нового экземпляра (пример ниже), иногда когда экземпляр уже работает какое-то время.
Этот цикл ошибок «Boot Worker — SIGKILL — TIMEOUT» может длиться от 10 секунд до более часа.
Это также может произойти с любой конечной точкой моего приложения, это произошло с запросами POST, запросами GET на разных конечных точках.
Сначала я думал, что это произошло из-за какой-то ошибки в моем коде или каких-то неверных данных в запросе POST, но после расследования я понял, что отправка точно такого же запроса POST/GET, когда экземпляр не застрял в этом цикле ошибок, работает отлично.
Ниже приведены журналы примера, где запрос POST, который привел к запуску нового экземпляра, застрял в этом цикле более часа, а затем внезапно разрешился сам и нормально обрабатывает запрос POST со статусом 200.
DEFAULT 2024-04-07T07:56:06.463491Z [2024-04-07 07:56:06 +0000] [11] [INFO] Starting gunicorn 21.2.0
DEFAULT 2024-04-07T07:56:06.464623Z [2024-04-07 07:56:06 +0000] [11] [DEBUG] Arbiter booted
DEFAULT 2024-04-07T07:56:06.464637Z [2024-04-07 07:56:06 +0000] [11] [INFO] Listening at: http://0.0.0.0:8081 (11)
DEFAULT 2024-04-07T07:56:06.464712Z [2024-04-07 07:56:06 +0000] [11] [INFO] Using worker: gthread
INFO 2024-04-07T07:56:06.466397Z [pid1-nginx] Successfully connected to 127.0.0.1:8081 after 3.361200658s [session:RB4VHXB]
INFO 2024-04-07T07:56:06.466735Z [pid1-nginx] Successfully connected to localhost:8081 after 3.361617817s [session:RB4VHXB]
INFO 2024-04-07T07:56:06.469263Z [pid1-nginx] Creating config at /tmp/nginxconf-644813283/nginx.conf [session:RB4VHXB]
INFO 2024-04-07T07:56:06.472325Z [pid1-nginx] Starting nginx (pid 17): /usr/sbin/nginx -c /tmp/nginxconf-644813283/nginx.conf [session:RB4VHXB]
DEFAULT 2024-04-07T07:56:06.544837Z [2024-04-07 07:56:06 +0000] [16] [INFO] Booting worker with pid: 16
DEFAULT 2024-04-07T07:56:06.576102Z [2024-04-07 07:56:06 +0000] [16] [DEBUG] Closing connection.
DEFAULT 2024-04-07T07:56:06.577868Z [2024-04-07 07:56:06 +0000] [16] [DEBUG] Closing connection.
DEFAULT 2024-04-07T07:56:06.579116Z [2024-04-07 07:56:06 +0000] [16] [DEBUG] GET /_ah/start
DEFAULT 2024-04-07T07:56:06.618933Z [2024-04-07 07:56:06 +0000] [19] [INFO] Booting worker with pid: 19
DEFAULT 2024-04-07T07:56:06.666217Z [2024-04-07 07:56:06 +0000] [11] [DEBUG] 2 workers
DEFAULT 2024-04-07T07:56:06.739491Z [2024-04-07 07:56:06 +0000] [16] [DEBUG] POST /processNewOrder
DEFAULT 2024-04-07T07:57:07.717148Z [2024-04-07 07:57:07 +0000] [11] [CRITICAL] WORKER TIMEOUT (pid:16)
DEFAULT 2024-04-07T07:57:08.720797Z [2024-04-07 07:57:08 +0000] [11] [ERROR] Worker (pid:16) was sent SIGKILL! Perhaps out of memory?
DEFAULT 2024-04-07T07:57:08.720910Z 2024/04/07 07:57:08 [error] 18#18: *6 upstream prematurely closed connection while reading response header from upstream, client: 169.254.1.1, server: _, request: "POST /processNewOrder HTTP/1.1", upstream: "http://127.0.0.1:8081/processNewOrder", host: "redacted.et.r.appspot.com"
DEFAULT 2024-04-07T07:57:08.824712Z [protoPayload.method: POST] [protoPayload.status: 502] [protoPayload.responseSize: 272 B] [protoPayload.latency: 61.15 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
DEFAULT 2024-04-07T07:57:08.898539Z [2024-04-07 07:57:08 +0000] [19] [DEBUG] POST /processNewOrder
DEFAULT 2024-04-07T07:57:08.990455Z [2024-04-07 07:57:08 +0000] [27] [INFO] Booting worker with pid: 27
DEFAULT 2024-04-07T07:58:08.968963Z [2024-04-07 07:58:08 +0000] [11] [CRITICAL] WORKER TIMEOUT (pid:19)
DEFAULT 2024-04-07T07:58:09.973588Z 2024/04/07 07:58:09 [error] 18#18: *7 upstream prematurely closed connection while reading response header from upstream, client: 169.254.1.1, server: _, request: "POST /processNewOrder HTTP/1.1", upstream: "http://127.0.0.1:8081/processNewOrder", host: "redacted.et.r.appspot.com"
DEFAULT 2024-04-07T07:58:09.973611Z [2024-04-07 07:58:09 +0000] [11] [ERROR] Worker (pid:19) was sent SIGKILL! Perhaps out of memory?
DEFAULT 2024-04-07T07:58:10.106688Z [2024-04-07 07:58:10 +0000] [33] [INFO] Booting worker with pid: 33
DEFAULT 2024-04-07T07:58:10.177760Z [protoPayload.method: POST] [protoPayload.status: 502] [protoPayload.responseSize: 272 B] [protoPayload.latency: 61.976 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
DEFAULT 2024-04-07T07:58:10.196059Z [2024-04-07 07:58:10 +0000] [33] [DEBUG] POST /processNewOrder
DEFAULT 2024-04-07T07:59:11.149239Z [2024-04-07 07:59:11 +0000] [11] [CRITICAL] WORKER TIMEOUT (pid:33)
DEFAULT 2024-04-07T07:59:12.153215Z 2024/04/07 07:59:12 [error] 18#18: *9 upstream prematurely closed connection while reading response header from upstream, client: 169.254.1.1, server: _, request: "POST /processNewOrder HTTP/1.1", upstream: "http://127.0.0.1:8081/processNewOrder", host: "redacted.et.r.appspot.com"
DEFAULT 2024-04-07T07:59:12.153281Z [2024-04-07 07:59:12 +0000] [11] [ERROR] Worker (pid:33) was sent SIGKILL! Perhaps out of memory?
DEFAULT 2024-04-07T07:59:12.307443Z [2024-04-07 07:59:12 +0000] [39] [INFO] Booting worker with pid: 39
DEFAULT 2024-04-07T08:00:45.632391Z [protoPayload.method: POST] [protoPayload.status: 502] [protoPayload.responseSize: 272 B] [protoPayload.latency: 61.725 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
...
Repeat of same, POST request recieved, worker boot, worker timeout then worker sent SIGKILL for the next 1 hour.
...
DEFAULT 2024-04-07T09:01:47.742589Z [protoPayload.method: POST] [protoPayload.status: 502] [protoPayload.responseSize: 272 B] [protoPayload.latency: 61.369 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
DEFAULT 2024-04-07T09:01:47.916781Z [2024-04-07 09:01:47 +0000] [387] [INFO] Booting worker with pid: 387
DEFAULT 2024-04-07T09:01:48.003333Z [2024-04-07 09:01:48 +0000] [387] [DEBUG] POST /processNewOrder
DEFAULT 2024-04-07T09:02:13.317927Z [protoPayload.method: POST] [protoPayload.status: 502] [protoPayload.responseSize: 272 B] [protoPayload.latency: 86.175 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
DEFAULT 2024-04-07T09:02:36.933886Z [2024-04-07 09:02:36 +0000] [11] [CRITICAL] WORKER TIMEOUT (pid:381)
DEFAULT 2024-04-07T09:02:37.938484Z [2024-04-07 09:02:37 +0000] [11] [ERROR] Worker (pid:381) was sent SIGKILL! Perhaps out of memory?
DEFAULT 2024-04-07T09:02:37.938619Z 2024/04/07 09:02:37 [error] 18#18: *140 upstream prematurely closed connection while reading response header from upstream, client: 169.254.1.1, server: _, request: "POST /processNewOrder HTTP/1.1", upstream: "http://127.0.0.1:8081/processNewOrder", host: "redacted.et.r.appspot.com"
DEFAULT 2024-04-07T09:02:38.097720Z [2024-04-07 09:02:38 +0000] [393] [INFO] Booting worker with pid: 393
DEFAULT 2024-04-07T09:02:38.142051Z [protoPayload.method: POST] [protoPayload.status: 502] [protoPayload.responseSize: 272 B] [protoPayload.latency: 61.351 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
DEFAULT 2024-04-07T09:02:38.189106Z [2024-04-07 09:02:38 +0000] [393] [DEBUG] POST /processNewOrder
DEFAULT 2024-04-07T09:02:38.196806Z [2024-04-07 09:02:38 +0000] [393] [DEBUG] POST /processNewOrder
DEFAULT 2024-04-07T09:02:48.105780Z [2024-04-07 09:02:48 +0000] [11] [CRITICAL] WORKER TIMEOUT (pid:387)
DEFAULT 2024-04-07T09:02:49.112205Z 2024/04/07 09:02:49 [error] 18#18: *142 upstream prematurely closed connection while reading response header from upstream, client: 169.254.1.1, server: _, request: "POST /processNewOrder HTTP/1.1", upstream: "http://127.0.0.1:8081/processNewOrder", host: "redacted.et.r.appspot.com"
DEFAULT 2024-04-07T09:02:49.112209Z [2024-04-07 09:02:49 +0000] [11] [ERROR] Worker (pid:387) was sent SIGKILL! Perhaps out of memory?
Finally it processes the POST request correctly with status 200.
DEFAULT 2024-04-07T09:02:49.114051Z [protoPayload.method: POST] [protoPayload.status: 200] [protoPayload.responseSize: 135 B] [protoPayload.latency: 81.691 s] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /processNewOrder
DEFAULT 2024-04-07T09:02:49.367448Z [2024-04-07 09:02:49 +0000] [401] [INFO] Booting worker with pid: 401
DEFAULT 2024-04-07T09:02:49.464783Z [2024-04-07 09:02:49 +0000] [401] [DEBUG] POST /processNewOrder
Я также проверил использование памяти, но, похоже, проблем нет. Я использую класс экземпляра B2, который должен иметь 768 МБ ОЗУ, и в период инцидента использование ОЗУ было низким и составляло примерно ~ 210 МБ.
Эта проблема также никогда не возникает, когда я запускаю сервер Gunicorn через App Engine локально.
Я попытался увеличить размер экземпляра до B4 (1536 МБ ОЗУ), думая, что, возможно, об использовании памяти сообщается неправильно, но возникает та же проблема.
Я попытался увеличить параметр тайм-аута в моем файле конфигурации Gunicorn до 20 минут, но та же проблема все еще возникает, просто теперь каждому работнику требуется 20 минут, прежде чем истечет время ожидания.
Я также попытался установить
preload_app=Trueв своем файле конфигурации Gunicorn, так как подумал, что, возможно, проблема вызвана тем, что рабочий процесс разворачивается, но код приложения не готов, но та же проблема все еще возникает.
Учитывая, насколько случайно это происходит, я не могу достоверно воспроизвести проблемы и, следовательно, не могу найти решение этой проблемы. Одна из возможностей заключается в том, что на стороне Google Cloud произошел какой-то сбой, но прежде чем мы перейдем к этому, я хотел узнать, сталкивался ли кто-нибудь еще с этой проблемой раньше и может ли дать какие-либо советы по потенциальному решению.
@RobertG Я считаю, что проблема в другом, поскольку у этого пользователя возникает определенная ошибка OutOfMemoryError, выданная Java, тогда как моя проблема - это SIGKILL, которая может возникнуть из-за других проблем, а не из-за проблем с памятью. Пользователь также использует устаревшую версию GAE, тогда как я использую последнюю стабильную версию всех библиотек. Но спасибо за ссылку для регистрации ошибок, не знаю, почему я не видел эту страницу раньше... Сейчас открою там ошибку.
Простите за вопрос. Вы уже пробовали увеличить TIMEOUT из-за отсутствия ответа от рабочих? Иногда работник занят выполнением задания и просто не может ответить в отведенное время. «Отрегулируйте таймаут: вы можете увеличить таймаут, установив флаг --timeout при запуске Gunicorn (например, --timeout 120 на 120 секунд). Однако будьте осторожны: если вы установите его слишком большим, вы можете получить действительно зависшие процессы, потребляющие ресурсы».
@JohnnyCheesecutter Да, как я уже упоминал в своем вопросе: «Я пытался увеличить параметр тайм-аута в моем файле конфигурации Gunicorn до 20 минут, но та же проблема все еще возникает, просто теперь каждому работнику потребуется 20 минут, прежде чем истечет время ожидания».
Извините, не могли бы вы предоставить более подробную информацию о вашей конфигурации. Сколько рабочих и потоков вы используете в конфигурации Gunicorn?
@JohnnyCheesecutter Я использовал 4 рабочих по 8 потоков каждый, используя рабочий класс "gthread"
Может ли быть так, что здесь слишком много рабочих/потоков? Судя по журналам, рабочие процессы начали отключаться до того, как были созданы все рабочие процессы/потоки. Вы тестировали код с меньшим количеством рабочих? С 1 рабочим или меньшим количеством потоков? Например с 4 рабочими и 2 потоками?
Ответы 1
Для всех, кто столкнется с этой проблемой в будущем, я в конечном итоге перешел к запуску своего приложения в Docker-контейнере в Google Cloud Run с настройкой preload_app=True в моем файле конфигурации Gunicorn и полностью устранил проблему.
По какой-то причине любая другая конфигурация вызывает проблему TIMEOUT. Например, запуск Cloud Run без Dockerfile (означает, что Google решит, что необходимо в вашем контейнере) вызовет проблему, с настройкой preload_app=True или без нее.
Я предполагаю, что в настройках Google Cloud есть некоторая конфигурация, используемая для контейнеризации (которая, вероятно, также используется для App Engine), которая каким-то образом несовместима с моим кодом. Переход на Cloud Run также помог значительно сократить мои расходы, что тоже полезно.
Кажется, у вас похожая проблема с этим ТАК вопрос , разница в том, что ОП использует Java. Пробовали ли вы сообщить об ошибке, поскольку случайно столкнулись с этой проблемой?