SavePearlHarbor

Как мы вывели в админку ошибки yt-dlp, которые жили только в логах. Bridge на 200 строк и борьба с alert-fatigue

—

от автора

admin

Привет, Хабр. Я делаю онлайн-сервис для скачивания видео, бэкенд на Python (FastAPI + yt-dlp). За месяц набрали ~1500 DAU и упёрлись в проблему: пользователи жалуются на «не работает», а в админке зелёные графики. История о том, как сделать видимыми ошибки, которые молча умирали в логах воркера, и почему первый же релиз пришлось переделывать из-за alert-fatigue.

TL;DR

  1. У нас 3 ноды: master (FastAPI на :443) и 2 worker’а (Docker, yt-dlp). Воркеры падали в unavailable / private / age-restricted, но эти ошибки никогда не доходили до админки — они умирали в docker logs, где их никто не читал.

  2. Сделали bridge: воркер POST’ит ошибку в master по /admin/api/incidents/external с X-Internal-Secret, master пишет в SQLite (AdminEvent) и шлёт push админам, если ≥5 ошибок за 60 секунд.

  3. Сразу же словили alert-fatigue: 90% событий — это «юзер скинул удалённое/приватное видео», то есть это не наша проблема. Доделали классификатор content-vs-infra: «контентные» ошибки в журнал пишем, но push не дёргаем.

  4. Через 24 часа админка показала реальную картину: 7 событий вместо ожидаемых 200. Из них 2 — реально наш баг (определённый ID видео ронял preflight на обоих воркерах). Починили за час.

Ниже — как это устроено, почему именно так, и что я бы сделал иначе.

Контекст: почему ошибки умирали

Архитектура примерно такая:

[ браузер юзера ]       │       ▼[ master  FastAPI :443 ]──┬──> /api/info  (preflight, yt-dlp --skip-download)       │                   └──> /api/prepare → выбор воркера → POST к worker'у       │       ▼[ worker1 ] [ worker2 ]   (docker compose, yt-dlp скачивает в /tmp)       │       ▼   результат → клиент скачивает с master по /file/{task_id}

/api/info бьётся в YouTube-API через yt-dlp прямо с master’а. Если видео приватное / удалено / age-gated — yt-dlp бросает исключение, master ловит его в стандартном try/except и возвращает 400 пользователю.

Беда вот в чём: исключение уходило в access.log с status=400 и всё. Никаких метрик. Никакой агрегации. Я знал, что у нас «4xx около 5%», но не знал, почему именно 5%.

В системе аналитики стояла цель download_error, но она триггерилась только на /api/prepare и дальше — то есть когда юзер уже нажал «скачать». А половина ошибок жила на стадии preflight (/api/info), куда аналитика не доставала вообще.

Шаг 1: bridge worker → master

Самое простое, что можно сделать — добавить fire-and-forget POST из обработчика исключения.

# master_main.py — внутри /api/info exception handlerexcept Exception as e:    msg = str(e)    asyncio.create_task(_report_info_error(req.url, msg))    if "unavailable" in msg.lower() or "copyright" in msg.lower():        raise HTTPException(status_code=400, detail="Видео недоступно или удалено")    raise HTTPException(status_code=500, detail=msg)

_report_info_error шлёт POST на /admin/api/incidents/external соседнего сервиса (auth-service, тоже FastAPI на :8770, отвечает за личный кабинет и админку). Заголовок X-Internal-Secret — общий env-secret, чтобы внешний интернет не мог писать в админский журнал.

async def _report_info_error(url: str, error: str):    try:        async with aiohttp.ClientSession(timeout=aiohttp.ClientTimeout(total=2)) as s:            await s.post(                "http://127.0.0.1:8770/admin/api/incidents/external",                json={"source": "info", "video_id": _extract_video_id(url),                      "error": error[:500], "worker": "master"},                headers={"X-Internal-Secret": INTERNAL_SECRET},            )    except Exception:        # bridge упал — это его проблема, не пользователя        pass

Ключевые моменты:

  • asyncio.create_task, а не await. Юзер не должен ждать, пока bridge достучится до соседнего сервиса. Если bridge сломан, фронту это безразлично.

  • timeout=2 сек. Иначе подвисший bridge утянет за собой ответ юзеру.

  • error[:500] — обрезаем traceback. Я обжёгся — yt-dlp иногда выдаёт исключения по 8 КБ с дампом всего конфига.

  • except: pass в bridge — да, антипаттерн. Но это телеметрия, а не бизнес-логика. Если bridge ронит обработчик /api/info, у тебя дыра.

На стороне master’а ещё добавил такой же bridge в worker callback (когда воркер заканчивает обработку и сообщает результат master’у — мы тоже ловим status и шлём в админку, если 4xx/5xx).

Шаг 2: storage в master

В auth-service (тот, что админка) уже была табличка AdminEvent:

class AdminEvent(Base):    __tablename__ = "admin_events"    id = Column(Integer, primary_key=True)    created_at = Column(DateTime, server_default=func.now())    kind = Column(String(64))         # 'download_error', 'login', и т.д.    payload_json = Column(Text)       # сырой JSON

Endpoint простой:

@router.post("/admin/api/incidents/external")async def incidents_external(payload: IncidentPayload, request: Request):    if request.headers.get("X-Internal-Secret") != INTERNAL_SECRET:        raise HTTPException(403, "Forbidden")    async with SessionLocal() as session:        ev = AdminEvent(            kind="download_error",            payload_json=json.dumps({                "source": payload.source,           # 'info' / 'task_status' / ...                "video_id": payload.video_id,                "error": payload.error,                "worker": payload.worker,                "url": payload.url,            }, ensure_ascii=False),        )        session.add(ev)        await session.commit()    # вот здесь у нас был баг — см. ниже    incidents_svc.report_error(payload.status_code or 500, f"download:{payload.video_id}")    return {"ok": True}

incidents_svc.report_error — это in-memory счётчик: если за 60 секунд приходит ≥5 ошибок, дёргается push-broadcast админам через Web Push API.

И всё это работало. Один день. До первого вечернего пика.

Шаг 3: alert-fatigue

В 21:43 мне на телефон прилетело подряд 4 push’а: «Burst: 12 download_errors». Открываю админку — там 47 событий за минуту.

Из них:

  • 31 — Sign in to confirm you're not a bot

  • 8 — Private video. Sign in if you've been granted access

  • 5 — This video is age-restricted and only available on YouTube

  • 2 — Video unavailable. The uploader has not made this video available in your country

  • 1 — реально наша ошибка (тaймаут на воркере)

То есть 46 из 47 событий — это не баги, это пользователи скидывали ссылки на удалённые/приватные/age-gated/гео-блокированные ролики. Это нормальное поведение системы. Это не нужно пушить.

Ещё хуже: пуши бесполезные, но я теперь к ним привык. Через две недели я бы пропустил настоящий инцидент.

Шаг 4: классификатор content vs infra

Решение в лоб — список паттернов:

err_lower = (payload.error or "").lower()is_content_error = any(p in err_lower for p in (    "sign in to confirm",         # bot-check, IP problem (но всё равно не моя проблема в моменте)    "приватное", "private video",    "age-restricted", "members-only",    "video unavailable", "недоступно", "удалено",    "copyright",    "this video is not available in your country",))if not is_content_error:    incidents_svc.report_error(payload.status_code or 500, f"download:{payload.video_id}")return {"ok": True, "content_error": is_content_error}

Контентные ошибки всё равно пишутся в admin_events — мне нужна статистика, какие именно ошибки наиболее частые (вдруг 80% — age-restricted и я смогу обойти их через специальный fallback). Но push-burst не дёргают.

В админке на вкладке «Ошибки» появился фильтр: «Все / Только инфра / Только контентные». По умолчанию — только инфра.

Почему Sign in to confirm я отнёс к контентным

Это спорно. Sign in to confirm you're not a bot означает, что YouTube решил, что наш IP похож на бота. Это наша проблема в том смысле, что в идеале мы должны были бы переключиться на запасной IP (через прокси-пул).

Но в моменте, когда юзер уже получил ошибку, поднимать админа push’ом — бессмысленно, я не починю это руками за 60 секунд. Поэтому отношу к контентным и решаю через отдельный механизм: метрика bot_check_rate на отдельной вкладке, и если она >5% за час — тогда уже алерт. Burst-detection на каждое событие тут нерелевантен.

Шаг 5: что пошло не так с миграцией

При первом деплое словил две глупых ошибки:

1. AdminEvent has no attribute 'payload'

Я по памяти написал ev.payload = ..., а в реальной модели поле называется payload_json. Старый я бы отловил это локальным запуском, но FastAPI на тот момент в dev-режиме не ругался — ошибка вылетала только при первом обращении к endpoint.

Урок: mypy --strict на моделях, даже если в остальном коде типы дырявые. Pydantic + SQLAlchemy дают enough metadata, чтобы поймать такое.

2. Cannot import name 'async_session'

Я написал from app.db import async_session, а реальное имя — SessionLocal. Опять — ловится либо запуском, либо линтером. Я запустил.

Раньше я думал, что dev-сервер с auto-reload + ручные curl’ы — достаточная замена тестам. После третьего такого инцидента понял: нет, не достаточная. Поставил pre-commit hook с python -m py_compile $(git diff --name-only --cached | grep '\.py$') — тупо, но 80% таких ошибок ловит.

Шаг 6: что увидел в продакшене через 24 часа

После фикса админка показала за сутки:

Топ ошибок:  31  qa6jISTY9WI  Sign in to confirm (контентная)   8  OcY18G8szfI  Private video (контентная)   5  J6420DF-6RU  Age-restricted (контентная)   2  -            HTTPSConnectionPool timeout (инфра)  ← вот оно

Те 2 timeout’а оказались интересными: оба прилетели в одну минуту, оба на воркере №2. Полез в docker logs — оказалось, у воркера разогнался /tmp (yt-dlp оставлял временные .part после прерванных скачиваний), и df показывал 96%. yt-dlp не падал явно, он тормозил, и наш timeout 90 сек его обрезал. Починил отдельным фоновым cleanup’ом каждые 60 секунд.

Без bridge’а я бы это не нашёл. Точнее, нашёл бы — через неделю, когда юзеры массово пожалуются. А так — за час.

Шаг 7: что ещё хочу добавить

  • Корреляция со sources: сейчас я знаю «эта ошибка прилетела с /api/info», но не знаю, какой именно referer, какое UA, какая IP. Добавлю — но осторожно, чтобы не угодить в ПДн.

  • Auto-retry на bot-check: если Sign in to confirm ≥3 раз за минуту с одного воркера — автоматом вынуть его из round-robin на 30 минут, дёрнуть админу alert. Сейчас руками.

  • Группировка по video_id в журнале: чтобы 31 событие на qa6jISTY9WI не флудили список — свернуть в одну строку с counter’ом.

  • TTL на admin_events: сейчас всё растёт, через год будет 100к строк. Поставлю partition по дням + cleanup >30 дней.

Что бы я сделал иначе

  1. Сразу с классификатором, без alert-fatigue стадии. Я знал, что у меня в логах много content-ошибок, но решил «сначала запушу всё, потом поправлю». Лучше было сначала сесть с grep -E 'private|unavailable|age' worker.log | wc -l и оценить долю. Сэкономил бы себе один испорченный вечер.

  2. Bridge через очередь, а не fire-and-forget HTTP. Сейчас если auth-service лежит, события теряются молча. Локальная Redis (или даже SQLite-WAL очередь) дала бы at-least-once delivery без больших затрат.

  3. Не SQLite. Я взял SQLite потому что «у нас всё небольшое». Через месяц admin_events уже 50к строк, простые запросы по created_at DESC LIMIT 100 ещё летают, но GROUP BY video_id уже секунду думает. Postgres был бы правильнее с самого начала.

  4. TypeScript на админке вместо vanilla JS. Когда добавлял фильтр content/infra, два раза опечатался в имени поля и получил пустой список. Потратил 20 минут на debug. С TS такого не было бы.

Резюме

Если делаете похожий сервис с пользовательскими ошибками — два совета:

  • Не верьте «у нас 5% 4xx, это нормально», пока не разложили эти 5% по причинам.

  • Не пушьте админам всё подряд. Push-fatigue хуже, чем отсутствие push’ей.

Спасибо за внимание. Готов отвечать на вопросы в комментариях.

ссылка на оригинал статьи https://habr.com/ru/articles/1036904/