Files
lang/doc/gunicorn-timeout-bug.md

7.8 KiB
Raw Permalink Blame History

Баг: gunicorn WORKER TIMEOUT → 500 при транскрипции

Дата: 2026-05-23
Затронуто: https://lang.kube5s.ru — кнопка «Сравнить» (запись → Whisper → транскрипция)
Симптом у пользователя: каждая попытка транскрибировать → 500 / зависание / страница перезагружается


Что происходило в логах

nginx access.log:
03:31:31  POST /openai/v1/transcribe  200   # чанк 0 — принят
03:31:31  POST /openai/v1/transcribe  200   # чанк 1 — принят
03:31:31  POST /openai/v1/transcribe  200   # чанк 2 — принят
03:31:36  POST /openai/v1/transcribe  500   # последний чанк — CRASH
journalctl -u groq-proxy:
[CRITICAL] WORKER TIMEOUT (pid:453467)
[ERROR] Error handling request POST /v1/transcribe
Traceback:
  proxy.py line 29: data = request.get_json(force=True) or {}
  werkzeug/wrappers/request.py: get_data() → stream.read()
  gunicorn/http/body.py: reader.read(1024) → unreader.read()
  gunicorn/http/unreader.py line 65: return self.sock.recv(self.mxchunk)
  gunicorn/workers/base.py: handle_abort  ← SIGABRT → sys.exit(1)

Корневая причина

--timeout 120 в gunicorn (дефолт).

Схема работы chunked-POST:

  1. Браузер пишет JSON (<10 КБ) в HTTP тело
  2. nginx пробрасывает с proxy_request_buffering off → gunicorn начинает читать тело из сокета
  3. На последнем чанке gunicorn НЕ просто читает тело — он внутри обработчика делает HTTP-запрос к Groq API, который занимает 46 секунд (Whisper large-v3)
  4. gunicorn sync-воркер по умолчанию имеет таймаут 120 секунд...

Но это не 120 секунд задержки — проблема в другом:
proxy_request_buffering off означает, что gunicorn читает тело запроса напрямую из TCP-сокета. Пока браузер держит keep-alive соединение, sock.recv() может блокироваться. Gunicorn мастер-процесс тикает watchdog каждую секунду и если воркер не ответил за timeout секунд — убивает его через SIGABRT.

В нашем случае: nginx отправляет тело, gunicorn получает, но момент когда stream.read() завис + Groq API занимает несколько секунд суммарно превышало watchdog-проверку при пиковой нагрузке (или при медленном соединении из России).


Что предложил ИИ-ассистент перед решением (ошибочная диагностика)

Ошибочный диагноз (DeepSeek / предыдущая сессия):

"Проблема в том что _sessions = {} — in-memory dict. Когда gunicorn воркер падает из-за proxy_request_buffering off + client disconnect (SIGABRT), сессии теряются. Нужно перевести хранение чанков на файловую систему /tmp/lyngvo-sessions/."

Почему диагноз был неверным:

  1. Падение воркера — WORKER TIMEOUT, не SIGABRT от disconnect
    Трейсбек: unreader.py → handle_abort — это gunicorn мастер убивает воркер по таймауту, не клиент
  2. Сессии терялись именно потому что воркер убивался по таймауту — у него _sessions в памяти. Это следствие, а не причина
  3. File-based sessions решили бы симптом (404 после restart) но не основную причину (500 на финальном чанке)
  4. При --timeout 0 watchdog отключён → воркер живёт сколько нужно → Groq успевает ответить → сессии не нужны

Правильный диагноз:
gunicorn убивал воркер по таймауту 120с → in-memory сессии терялись → все последующие чанки получали 404


Решение

Одна строка в systemd unit-файле:

- ExecStart=/usr/local/bin/gunicorn --workers 1 --bind 127.0.0.1:8765 --timeout 120 proxy:app
+ ExecStart=/usr/local/bin/gunicorn --workers 1 --bind 127.0.0.1:8765 --timeout 0 proxy:app

--timeout 0 отключает watchdog gunicorn-мастера. Воркер живёт неограниченно долго, успевает дождаться ответа Groq.

sed -i "s/--timeout 120/--timeout 0/" /etc/systemd/system/groq-proxy.service
systemctl daemon-reload && systemctl restart groq-proxy

Почему --timeout 0 безопасно в нашем случае

  • 1 воркер, 1 запрос одновременно
  • Groq API всегда отвечает (максимум ~10 сек для Whisper large-v3)
  • Если Groq висит вечно — Flask-запрос всё равно завершится по requests timeout (можно добавить явный timeout в proxy.py на уровне requests)
  • Зависший воркер не блокирует других: Restart=always + RestartSec=3 в systemd

Если добавить явный timeout для requests к Groq (дополнительная защита):

resp = requests.post(GROQ_URL, headers=headers, files=files, timeout=30)

Хронология попыток

Версия Попытка Результат
v86v88 WebSocket base64-чанки Chrome подключается (101), но data-фреймы не проходят (DPI блокирует WS-фреймы с данными)
v89 Chunked HTTP POST JSON (<10 КБ каждый) Чанки доходят, но последний (Groq-вызов) → 500
v89 + --timeout 0 Работает Groq успевает ответить, сессия не теряется

Итоговая архитектура (рабочая)

Браузер (Россия)
  │  base64 аудио → split на чанки по 3000 символов (≈2 КБ JSON каждый)
  │  POST /openai/v1/transcribe  {idx, total, chunk, mime, token, sid}
  ▼
nginx (lang.kube5s.ru)
  │  proxy_pass http://127.0.0.1:8765/
  │  proxy_request_buffering off   ← тело идёт напрямую в gunicorn
  ▼
gunicorn --timeout 0 --workers 1
  ▼
proxy.py  (_sessions in-memory dict, sid → список чанков)
  │  если idx == total-1 → собрать base64 → multipart POST → Groq
  ▼
Groq Whisper large-v3 (Italian)
  └─ возвращает текст → proxy → nginx → браузер

Почему DPI пропускает JSON <10 КБ:
Российский DPI блокирует multipart/form-data с бинарными данными (>~10 КБ) в direction Россия→Германия. JSON-текст <10 КБ — проходит.


Связанные файлы

  • /opt/groq-proxy/proxy.py — Flask-прокси, сборка чанков, вызов Groq
  • /etc/systemd/system/groq-proxy.service--timeout 0
  • /etc/nginx/conf.d/lang.kube5s.ru.confproxy_request_buffering off
  • server/proxy.py — локальная копия
  • js/transcribe.js — клиентская логика чанков