«Прокси-сервер использует некорректные настройки»: как tg-ws-proxy раз в 10 минут сам делал почти 9-секундную яму

Telegram отключал прокси с сообщением, которое выглядит как приговор конфигурации. Конфигурация при этом была в полном порядке: ноль ошибок в логе, процесс не перезапускался ни разу, 1 876 клиентских сессий, 933 МБ скачанного трафика за три часа. Проблема оказалась не в настройках, а в логике ретраев самого прокси: защита от мёртвой первой ступени фолбэка открывала окно, в котором клиент не получал ни одного байта и уходил. Частота этих окон в конкретной инсталляции — раз в 10 минут — задавалась не инструментом, а выставленным здесь значением cooldown: у демона по умолчанию окно раз в час, и на дефолте механизм остаётся, просто срабатывает реже. Ниже — как причина была найдена, воспроизведена пробником, повторяющим поведение клиента Telegram, и устранена; отдельно разобрано, что в этой истории было собственной настройкой, а что — конструкцией прокси.

Коротко: что произошло

• Telegram на телефоне показывал: «Подключённый Вами прокси-сервер использует некорректные настройки и будет отключён. Пожалуйста, выберите другой», и выключал прокси. Через несколько минут всё работало, потом повторялось.

• Прокси при этом был жив: одна и та же сборка, один и тот же процесс, 0 ERROR, 0 перезапусков, 0 сбоев DNS, 33 открытых файловых дескриптора из 1 024, температура роутера 54 °C.

• Причина — не таймаут и не блокировка как таковая, а их сочетание с таймером cooldown: раз в ~10 минут следующий клиент попадал на мёртвую первую ступень и ждал N × --ws-connect-timeout. В логе это ровно те сессии, где клиент получил 0 байт.

• Размер ямы квантуется по таймауту: при 4 с — всплески 4.5–8.8 с; при 1 с — 2.2–2.5 с. Это и есть доказательство механизма.

• Лечится конфигом, без правки кода: --ip-fail-cooldown 600 → 3600 (возврат к дефолту демона) и --ws-connect-timeout 4 → 1 (сознательное уменьшение ниже дефолта 10 с, обоснованное A/B). После правки за час работы телефон не потерял ни одного соединения (до правки — 48 за три часа), глубина паузы на истечении cooldown упала с 4.5–8.8 с до ~1–2 с, а максимальная задержка ответа на проверку прокси — с 8 849 мс до 531 мс.

• Чья это настройка. Дефолты демона — --ip-fail-cooldown 3600 и --ws-connect-timeout 10; в этой инсталляции ранее стояли 600 и 4, то есть окна учащались собственной рукой в шесть раз. Возврат cooldown к дефолту и уменьшение таймаута — это конфигурация, а не патч: три проектных решения в логике прокси (проверка ступени в пути клиента, последовательная лестница, фиксированный cooldown без джиттера) остались нетронутыми.

Стенд

Железо и система. Роутер Netcraze NC-1812, OpenWrt 25.12.2 (aarch64, ядро 6.12.74, apk-tools вместо привычного opkg), фильтрация — fw4/nftables. За ним весь дом: телефоны по Wi-Fi, пара десктопов по кабелю.

Прокси. tg-ws-proxy 2.5.0, а точнее Rust-форк valnesfjord/tg-ws-proxy-rs — у апстрима Flowseal/tg-ws-proxy реализация на Python. Форк даёт 38 длинных флагов и заметно скромнее в требованиях к ресурсам, что для роутера существенно. Запускается он под procd в песочнице ujail, параметры читаются из /etc/tg-ws-proxy.env через враппер /usr/libexec/tg-ws-proxy/run.sh, слушает 192.168.1.1:1443, держит пул из четырёх предподключений. В --dc-ip замаплены только DC2 и DC4 (оба на 149.154.167.220), плюс задан --cf-worker-domain. Флаг --buf-kb 256 в конфиге есть, но ни на что не влияет: буферы в релее фиксированные, флаг оставлен для совместимости. Флага keepalive среди этих 38 нет — это ещё пригодится ниже. Два флага, о которых пойдёт речь дальше, у демона по умолчанию равны 3600 с (--ip-fail-cooldown) и 10 с (--ws-connect-timeout); в этой инсталляции оба были переопределены — разбор в разделе «Фикс». Справка форка отмечает, что семантика --ip-fail-cooldown совпадает с IP_FAIL_COOLDOWN в Python-апстриме, то есть описанный ниже механизм не является особенностью именно Rust-сборки.

Окружение. Рядом с прокси на роутере живут: обход DPI zapret2/nfqws2 (nftables + NFQUEUE), AdGuard Home, переехавший на 53-й порт (dnsmasq сдвинут на 54-й), и nginx как TLS-фронт; xray остановлен и выключен. Лог прокси — /var/log/tg-ws-proxy.log, но /var здесь симлинк на /tmp: лог живёт в памяти и стирается при перезагрузке (об этом отдельно ниже).

Клиент. В описываемом окне прокси использовал ровно один клиент — смартфон по Wi-Fi, 192.168.1.194 (5 ГГц, сигнал −33 dBm). Позже зафиксировано, что тот же сбой затрагивает и кабельный десктоп 192.168.1.50; на нём переподключение проходит незаметнее.

Логика доставки. У tg-ws-proxy есть лестница способов дотянуться до Telegram: прямое WebSocket-подключение к IP из --dc-ip, Cloudflare Worker, CF proxy, внешний MTProto-прокси и последним — сырой TCP на 443. Прокси идёт по ступеням сверху вниз, пока какая-нибудь не ответит.

В рассматриваемом развёртывании настроены только первые две ступени. Прямая ступень ведёт на 149.154.167.220 и работает нестабильно: из шести проб TCP-подключения три проходят за 0.09 с, три завершаются таймаутом. DNS-имена kws2*.web.telegram.org, используемые как альтернатива, резолвятся в 149.154.167.99 и не отвечают ни в одной из шести проб. Единственная надёжная ступень — Worker, он отвечает за ~0.2 с. Через него в итоге проходит почти весь трафик: в окне наблюдения 1 323 раза прокси сознательно пропустил прямой уровень по cooldown, 905 сессий ушли через прогретый пул Worker’а, 488 — через новый туннель, и только 345 — напрямую.

Почему жива именно ступень Worker. Это не случайность и не свойство Cloudflare: трафик к Worker’у десинхронизирует zapret2. В апстрим-документации (docs/CfWorker.md) первый шаг настройки Worker’а — добавить в zapret домены cloudflare.com, cloudflare.dev и workers.dev; там же отмечено, что без этого не загрузится даже страница с кодом Worker’а. На этом стенде все три домена перечислены в пользовательском списке zapret2 (zapret-hosts-user.txt), который попадает в основной профиль десинхронизации TLS. Домены kws*.web.telegram.org, к которым ходит первая ступень, не входят ни в один список zapret2, и её блокировка ничем не компенсируется. Отсюда и наблюдаемая асимметрия: первая ступень мертва, вторая работает.

Следствие — цепочка зависимостей. Остановленный zapret2 или пропавшая запись в его списке уносят не «какую-то», а единственную живую ступень. Сам список достаточно устойчив: автоматическое обновление раз в двое суток переписывает большой сторонний список доменов, а пользовательский файл с workers.dev не трогает — это проверено по времени изменения файлов на момент разбора.

Что именно проверяет Telegram, когда решает, «корректен» ли прокси

Прежде чем что-либо менять, требовалось понять, что именно измеряет клиент. Сообщение «некорректные настройки» — это не про синтаксис конфига. Telegram проверяет прокси как обычный MTProto-сервер: делает obfuscated2-рукопожатие, отправляет req_pq_multi#be7e8ef1 и ждёт ответ resPQ#05162463. Ответ пришёл быстро — прокси рабочий. Не пришёл или пришёл слишком поздно — прокси «некорректный».

Отсюда важное следствие, которое определило всю дальнейшую диагностику: безразлично, почему клиент не дождался ответа. Роутерный DPI, кривой конфиг, перегрузка, чужой таймаут в критическом пути — для Telegram это одно и то же сообщение. Кроме того, судить по логу прокси («ERROR нет — значит, всё в порядке») некорректно: прокси действительно отвечает, но на секунды позже, чем клиент готов ждать.

Симптом при этом известен и описан в апстрим-проекте: issue #646 — роутерная установка, кабельный десктоп не отваливается, телефон по Wi-Fi отваливается пару раз в час, а перевключение прокси мгновенно всё чинит. Описанная топология совпадает с наблюдаемой, и это существенно: проблема не привязана к конкретной сборке или роутеру.

Первая зацепка: 93 % обрывов — в четырёх секундах от события cooldown

Лог прокси подробный: на каждую клиентскую сессию две строки — куда ушло и чем закончилось, с длительностью и объёмом в обе стороны. Это и стало основой.

Рассматривается окно 09:51–13:03 UTC (16:51–20:03 по Новосибирску) — заявленный интервал «с 16 до 19» с запасом:

39 событий timed out, cooldown складываются всего в 13 эпизодов, и между эпизодами проходит от 10 до 17 минут — интервал, который в исходном описании звучал как «работало, потом опять». Внутри эпизода события идут группами по 1–5 в пределах нескольких секунд. Единственный длинный перерыв (50 минут, с 11:09 до 11:59 UTC) совпадает с очередным уходом телефона из Wi-Fi, то есть прокси в этот период не использовался.

Ключевой фрагмент — лог 12:37 UTC. Показательны строки closed by client … ↓0.0B 0.0s: к моменту, когда прокси находит рабочий путь, клиент уже закрыл соединение — ровно ноль байт в ответ.

12:37:07.010 WARN  WS DC2m failed on kws2-1.web.telegram.org: TCP connect timed out
12:37:07.418 INFO  [.50:5125] DC2m → WS connected via 149.154.167.220
12:37:07.418 INFO  [.50:5125] DC2m WS session closed by client: ↑108.0B ↓0.0B  0.0s
12:37:09.959 INFO  [.50:5129] DC2m → WS connected via 149.154.167.220
12:37:09.959 INFO  [.50:5129] DC2m WS session closed by client: ↑211.0B ↓0.0B  0.0s
12:37:12.585 INFO  [.50:5128] DC2m TCP to 149.154.167.220 timed out, cooldown 600s
12:37:12.585 INFO  [.50:5128] DC2m WS failed → CF Worker pool hit (<worker>.workers.dev)
12:37:12.585 INFO  [.50:5128] DC2m WS session closed by client: ↑138.0B ↓0.0B  0.0s
12:37:15.581 INFO  [.50:5131] DC2m TCP to 149.154.167.220 timed out, cooldown 600s
12:37:15.581 INFO  [.50:5131] DC2m WS session closed by client: ↑214.0B ↓0.0B  0.0s

Момент «сработал таймаут → взведён cooldown» и момент «клиент ушёл с нулём байт» стоят в логе в одну и ту же секунду, а нередко и в одну и ту же миллисекунду. Это не статистическая корреляция, а причинная связь.

Две ловушки, из-за которых можно было потерять доказательства

Обе ловушки существенны при диагностике на роутере.

Ловушка первая — лог живёт в tmpfs. На этой прошивке /var — симлинк на /tmp, то есть лог прокси стирается при каждой перезагрузке. Так был потерян предыдущий инцидент: роутер перезагрузился между 04:35 и 06:03 UTC, и всё, что относилось к делу, исчезло без следа. Решение — копирование лога наружу (снятие снимков во внешний каталог) или вынос логов на внешний syslog.

Ловушка вторая — часы без RTC. Первая строка лога может быть датирована вчерашним днём, и это не значит, что прокси перезапускался. На плате нет батарейки, и /etc/init.d/sysfixtime при загрузке ставит время по mtime самого свежего файла в /etc — то есть по времени последней правки чужого конфига. Потом busybox ntpd переставляет часы на настоящее время, и в логе появляется «дыра» в 14 часов. Проверка занимает несколько секунд:

date                                  # текущее время
cat /proc/uptime                      # сколько реально живёт система
stat -c '%y %n' /etc/tg-ws-proxy.env  # откуда взялось «время загрузки»
readlink -f /var                      # не tmpfs ли это часом

Отброшенные гипотезы (и почему это заняло больше времени, чем находка)

Диагностика — это в первую очередь список отброшенного. Здесь он такой:

• Падение, перезапуск, OOM, кончились дескрипторы, сломался DNS. Нет: один процесс с момента загрузки, 0 ERROR, 33/1024 дескриптора, ни одной перезагрузки прокси.

• Wi-Fi телефона. Телефон действительно дважды уходил из сети (18:13–18:59 и 19:02–19:06 NSK), и прокси в эти минуты молчит по объективной причине. Но рассматриваемые кластеры обрывов лежат внутри подтверждённо-онлайновых окон, а тот же рисунок повторился на кабельном десктопе в 12:37. Следовательно, причина не в радиоинтерфейсе.

• Обрыв простаивающих соединений на ~92 секундах. Это настоящий дефект конкретной сборки: в ней нет WS-keepalive, и простаивающие WebSocket-сессии умирают на стороне Cloudflare. Но эти сессии закрывает апстрим, данные в них уже прошли, клиент мгновенно переподключается и ни одного нулевого ответа они не дают. К тому же в апстрим-проекте есть и сам симптом, и попытка лечения: Flowseal/tg-ws-proxy#925 прямо описывает «прокси использует некорректные настройки» и добавляет keepalive, а issue #1023 сообщает, что этот фикс не помог. Данные настоящего разбора объясняют, почему: в рассматриваемом развёртывании триггером выступает не простой, а таймер cooldown.

• Битый или подменённый ответ апстрима. Нет: в оборванных сессиях клиент получил ровно ноль байт — речь о задержке, а не о содержимом.

• Worker. Он отвечает за ~0.2 с в каждом замере вне окна cooldown. Он является следствием устройства лестницы, а не причиной.

Воспроизведение: пробник, который ведёт себя как клиент

Логов достаточно для корреляции, но корреляция не является доказательством. Требовался активный эксперимент, воспроизводящий поведение клиента по расписанию. curl, ping и nc для этого непригодны: они проверяют не то, что проверяет Telegram.

Был написан пробник на ~90 строк: obfuscated2-рукопожатие к прокси, настоящий req_pq_multi, ожидание resPQ, замер времени. Та же последовательность, которую выполняет приложение, оценивая корректность прокси. Запуск — раз в 3 секунды, на каждую попытку пишется строка.

12:47:10.491 n= 49    176ms OK   size=104
12:47:13.679 n= 50    171ms OK   size=104   <- в cooldown, всё через Worker
12:47:16.851 n= 51   8849ms OK   size=104   <- cooldown истёк: 2 таймаута по 4 с
12:47:28.764 n= 52    188ms OK   size=104   <- новый cooldown, снова Worker

Лог роутера для той же попытки — механизм виден построчно:

12:47:19.826 WARN  WS DC2 failed on kws2.web.telegram.org:   TCP connect timed out
12:47:23.826 WARN  WS DC2 failed on kws2.web.telegram.org:   TCP connect timed out
12:47:23.826 WARN  WS DC2 failed on kws2-1.web.telegram.org: TCP connect timed out
12:47:23.828 INFO  [.50:5949] DC2 TCP to 149.154.167.220 timed out, cooldown 600s
12:47:23.828 INFO  [.50:5949] DC2 WS failed → CF Worker pool hit (<worker>.workers.dev)
12:47:24.007 INFO  [.50:5949] DC2 WS session closed by client: ↑44.0B ↓104.0B 0.2s

Попытка, начатая в 12:47:16.9, получила ответ только в 12:47:24.0. Всего за 30 минут — 590 попыток, среднее 229 мс, медиана 175 мс, и пять всплесков длиннее 4 с, причём все пять приходятся на истечение cooldown. Провалов (не-OK) нет ни одного: прокси всегда отвечает — вопрос только «когда».

Механизм: защита, которая сама создаёт яму

Последовательность событий выглядит так.

1. Прямой IP из --dc-ip периодически недоступен. Триггер внешний: то 0.09 с, то таймаут. От прокси это не зависит.

2. Прокси делает то, что задумано: ловит таймаут и взводит --ip-fail-cooldown, после чего все клиенты идут через Worker за ~0.2 с. Внешне это выглядит как безупречная работа.

3. Через --ip-fail-cooldown секунд (в этой инсталляции стояло 600) cooldown истекает. Он не продлевается, пока не случится новый таймаут, — то есть в логе в этот момент не появляется никаких значимых записей.

4. Следующее клиентское подключение снова уходит в прямой уровень. Прокси пробует не один адрес, а несколько вариантов, на каждый по --ws-connect-timeout. Клиент в это время не получает ни байта. При 4 с это 4.5–8.8 с ожидания.

5. Telegram не готов ждать столько: он закрывает сокет (closed by client, ↓0.0B). Несколько таких подключений подряд — и приложение решает, что прокси «использует некорректные настройки», и выключает его.

6. Таймаут, завершивший эту попытку, снова взводит cooldown. Прокси «сам починился». Цикл повторяется примерно через 10 минут.

Существенно, что речь идёт не о случайном сбое, а о расписании. Фиксированный cooldown без экспоненты и джиттера гарантирует повторение отказа с предсказуемым интервалом, а издержки проверки мёртвой ступени несёт первый живой пользователь, а не фоновый пробник. От значения cooldown зависит только частота: и на 600, и на 3600 секундах окно открывается одинаково, разница лишь в том, сколько раз в час клиент на него попадает. Поэтому возврат к дефолту уменьшает ущерб, но не устраняет причину.

Фикс: два параметра и одна строка отката

Правок в коде не потребовалось: в этой сборке уже есть всё необходимое, требовалось лишь выбрать значения. Но у этой фразы есть оговорка, без которой разбор читается неправильно: изменённые значения — это конфигурация конкретной инсталляции, а не патч прокси, и одно из двух изменений вообще является возвратом к дефолту демона.

Ни враппер, ни бинарник, ни init-скрипт не менялись: /usr/libexec/tg-ws-proxy/run.sh не содержит значений по умолчанию вообще — он лишь прокидывает непустые TGWS_* в аргументы (md5 враппера до и после правки совпадает). Значит, и 600, и 4 жили только в /etc/tg-ws-proxy.env, то есть были следствием более ранней настройки, а не свойством поставки.

Зачем вообще уменьшали cooldown до 600 с — понятно: хотелось, чтобы после короткого сетевого сбоя прокси быстрее возвращался на прямой маршрут. Побочный эффект оказался дороже выгоды: частота окон выросла в шесть раз (13 эпизодов за 190 минут вместо примерно двух), а глубина каждого окна осталась прежней, потому что задаётся она не cooldown, а таймаутом.

Обратная сторона значения 1 с. Таймаут ниже дефолта — осознанный размен: при живом, но медленном канале соединение, которое поднималось бы за 1.5–2 с, теперь считается неудачным, и клиент уходит на Worker (плюс ~0.2 с и потеря прямого маршрута). В этом окружении размен оправдан: из шести проб прямого IP три отвечали за 0.09 с, три — не отвечали вовсе, промежуточных значений не наблюдалось. В сети с деградирующим, но работающим каналом то же значение даст больше падений на Worker, и там дефолтные 10 с (или промежуточные 4–5 с) могут оказаться лучше.

# /etc/tg-ws-proxy.env (фрагмент, секрет вырезан)
TGWS_DC_IPS="2:149.154.167.220,4:149.154.167.220"
TG_CF_WORKER_DOMAIN="<worker>.workers.dev"
TGWS_IP_FAIL_COOLDOWN="600"      # было: наша настройка -> стало: дефолт демона 3600
TGWS_WS_CONNECT_TIMEOUT="4"      # было: наша настройка -> стало: 1 (дефолт демона 10)

Правка — один файл, два значения, откат одной строкой:

cp -p /etc/tg-ws-proxy.env.bak /etc/tg-ws-proxy.env && /etc/init.d/tg-ws-proxy restart

Сознательно не выполнялось: патч Rust-форка для добавления WS-keepalive (причина не в его отсутствии) и удаление прямой ступени целиком — это следующий шаг на случай возврата ямы.

Проверка: A/B на одинаковых бинарниках и живой роутер

Сначала — контролируемый эксперимент в контейнере. Два экземпляра одной и той же сборки на 127.0.0.1, отличаются ровно одним флагом. Чтобы истечение cooldown случалось не раз в 10 минут, а раз в минуту, обоим выставлен --ip-fail-cooldown 60. Оба опрашиваются одним и тем же пробником.

В прогоне «стало» 27 попыток первых 48 секунд адресовались неверному порту из-за ошибки в харнессе (впоследствии исправлена) и исключены из таблицы: их учёт не меняет ни максимум, ни вывод.

Из результатов следует главное: величина ямы квантуется по таймауту. 4.5 с — один неудачный вариант, 8.5 с — два; 2.2–2.5 с при таймауте 1 с — те же два варианта, но втрое дешевле. Это и служит доказательством того, что найден именно этот механизм, а не совпадение.

Первые минуты после перезапуска (13:03:03–13:17:40).

• сессий, закрытых с нулём байт: 11, и все 11 — в первые три секунды после рестарта, когда сервис разрывал уже установленные соединения; дальше ни одного;

• 313+ исходящих соединений, все — IP in cooldown → skipping direct WS → CF Worker за ~0.2 с, попыток прямого уровня нет;

• пробник против живого прокси: максимум 531 мс, всплесков нет;

• телефон вернулся в сеть и работал нормально: 90 строк лога, все сессии с данными, ни одного обрыва.

Час работы и первое истечение cooldown (13:03:03–14:06:30). Час — ровно тот интервал, на который рассчитан --ip-fail-cooldown 3600: к 14:03:06 cooldown, взведённые при рестарте, истекли, и следующее клиентское подключение снова ушло в прямой уровень. Итог по окну целиком:

Четыре обрыва вне перезапуска — это и есть измеренная цена истечения cooldown:

• 14:03:52 и 14:03:54, ступень DC4m: первый вариант адреса (kws4-1) отвалился по таймауту за 1 с, после чего прямое подключение к 149.154.167.220 успело установиться за 0.4 с — но клиент закрыл соединение раньше и получил ноль байт;

• 14:05:44 и 14:05:46, ступень DC2m: снова по 1 с на вариант, на этот раз прямое подключение тоже ушло в таймаут, и сработал прежний механизм — TCP to 149.154.167.220 timed out, cooldown 3600s, cooldown взведён заново (следующее окно — около 15:05:46).

Отличие от состояния до правки принципиальное: все четыре обрыва пришлись на кабельный десктоп, который открывает много параллельных соединений, и ни один — на телефон. В ту же секунду 14:05:46 телефонное соединение дождалось ответа через Worker (56 байт за 0.2 с). Глубина паузы, видимой клиенту, упала с 4.5–8.8 с до ~1–2 с: цена одного неудачного варианта вместо двух подряд.

Отдельно — контрольный прогон пробника через час после правки (14:07–14:12 UTC): 101 попытка, все успешные, медиана 185 мс, максимум 446 мс, ни одной длиннее 500 мс. До правки медиана была 175 мс, но пять попыток перешагнули 4 с.

Итог окна: механизм не исчез, но перестал быть событием для пользователя. Телефон, на который была жалоба, за 63 минуты не потерял ни одного соединения; десктоп потерял четыре спекулятивных, тогда как остальные его сессии в те же секунды работали.

Границы результата: чего этот разбор не доказывает

• Точное терпение Telegram не измерено. Известно, что реальные клиенты рвут соединение, не дождавшись ответа при яме 4–8.8 с, и что после фикса максимум составляет 531 мс. Наблюдение на истечении cooldown уточняет картину: кабельный десктоп бросает соединение после ~1–1.5 с ожидания, а телефон в ту же секунду дожидается ответа. Промежуток между «точно плохо» и «точно хорошо» измерениями по-прежнему не покрыт.

• Прямая ступень не удалена, а только задемпфирована. Замер на первом истечении cooldown это подтвердил: пауза ~1–2 с и четыре обрыва на кабельном десктопе. Полностью убрать прямой уровень из пути клиента можно одним параметром — --pinned-upstream cfworker,cfproxy,mtproto,ws,tcp: Worker становится первой ступенью, а прямой уровень пробуется только если всё остальное не сработало. Цена этого шага не фиксированная и зависит от фазы блокировки. В измеренном блокированном окне через Worker шло 69 % сессий, и там он не стоил почти ничего. Но когда прямой уровень оживает, большая часть трафика идёт именно напрямую — за 3.4 минуты после истечения cooldown это 16 новых прямых подключений и 20 попаданий в прогретый пул против 10 и 9 через Worker, — и тогда F3 будет платить лишние ~0.1 с на каждом соединении, отказавшись от более быстрого маршрута. Иными словами, это не «стало лучше» и не «стало хуже», а обмен периодического риска на постоянную небольшую надбавку.

• Измерения — про одну сборку, один канал и один профиль блокировок. Речь о Rust-форке v2.5.0; в Python-апстриме семантика IP_FAIL_COOLDOWN описана как совпадающая, но его поведение не измерялось — там возможны свои нюансы, как и в других версиях форка. В другом окружении таймауты могут отличаться; переносится вывод «величина ямы = N × таймаут», но не конкретные секунды.

• Отдельная находка, которая не лечится конфигом: секрет прокси виден в ps любому, у кого есть шелл на роутере. Враппер читает значение из env-файла, но затем передаёт его аргументом командной строки, а /proc/<pid>/cmdline читается кем угодно — в том числе непривилегированным процессом. В бинарнике есть документированная альтернатива, переменная TG_SECRET, но враппер её не использует. К механизму с cooldown это отношения не имеет, однако на роутере с несколькими пользователями или гостями это существенно: утёкший секрет — это доступ к прокси как таковому, а не к одному соединению.

Инженерные выводы: что не так в конструкции этого стенда

Если смотреть не на симптом, а на саму конструкцию, в этом стенде нашлись четыре проектных решения, которые и сложились в периодический отказ.

1. Проверка здоровья ступени выполняется в критическом пути клиента. Прокси проверяет прямой уровень в момент клиентского подключения, и таймаут этой проверки оплачивает именно клиент. Фоновый пробник, который раз в N секунд сам проверяет прямой IP, снял бы с клиента всю эту работу: решение «в cooldown или нет» принималось бы до прихода первого запроса. Показательно, что механизм такого рода в демоне уже есть: флаг --ws-fail-probe-timeout (по умолчанию 2 с) описан в справке как «fast-probe path, allows quick recovery after a network change» — но относится он к cooldown уровня DC (--ws-fail-cooldown), а не к cooldown прямого IP (--ip-fail-cooldown).

2. Фиксированный cooldown — это расписание отказов. 600 секунд без экспоненты и без джиттера означают, что следующая яма придёт через те же 600 секунд — с точностью до момента следующего подключения. Отсюда и 13 эпизодов с интервалом 10–17 минут, которые видны в логе: конструкция сбоит не «иногда», а по метроному.

3. Последовательная лестница стоит сумму таймаутов мёртвых ступеней. Клиент платит N × --ws-connect-timeout только потому, что вторая ступень ждёт, пока первая отсчитает свой таймаут. Параллельный опрос двух первых ступеней (отдать тому, кто ответил первым, — «hedged request» с задержкой ~300 мс) дал бы те же данные за 0.2 с.

4. Бюджет задержки выбирался из удобства, а не из терпения клиента. Четыре секунды на попытку выглядели как «запас на медленный канал», хотя прямой уровень в этом окружении либо отвечает за 0.09 с, либо не отвечает вовсе. Отправная точка — сколько ждёт Telegram, а не то, сколько не жаль подождать прокси.

Отсюда самая конкретная зацепка для апстрима: распространить уже существующий fast-probe на --ip-fail-cooldown и добавить джиттер к самому значению. Это правка в несколько строк, которая ничего не меняет в здоровой сети и убирает периодичность отказа как класс — в отличие от подбора значений, которым занимались здесь.

Что из этого закрыто конфигом: пункт 2 — частично (3600 с вместо 600), пункт 4 — полностью (1 с вместо 4). Пункты 1 и 3 конфигом не лечатся: это правки в самом прокси, и именно они, а не значения флагов, убрали бы отказ как класс. Замер на первом истечении cooldown показал, что конфиг меняет не сам отказ, а его глубину и адресата: пауза сократилась примерно вчетверо, а пострадавшим устройством вместо телефона стал кабельный десктоп.

Отдельно про наблюдаемость — то, без чего этот разбор не состоялся бы: строки лога с объёмом в обе стороны и длительностью на каждую сессию, и возможность воспроизвести обмен req_pq_multi → resPQ своим инструментом. Если бы в логе было только «connected/disconnected», вывод свёлся бы к формулировке «вероятно, DPI».

Диагностика: минимальный набор проверок

При похожей конструкции и появлении сообщения «прокси использует некорректные настройки» проверку следует начинать с перечисленного.

LOG=/var/log/tg-ws-proxy.log

# 1. Сколько сессий клиент закрыл, не получив ни байта
grep 'closed by client' $LOG | grep -c '↓0.0B'

# 2. Когда взводился cooldown и сколько раз
grep -n 'timed out, cooldown' $LOG

# 3. Куда реально уходит трафик: прямой уровень или Worker
grep -c 'WS connected via' $LOG
grep -c 'IP in cooldown → skipping direct WS' $LOG
grep -c 'CF Worker connected' $LOG

# 4. Доступность прямого IP: 6 проб; значим таймаут, а не код ответа
for i in 1 2 3 4 5 6; do
  curl -m 4 -s -o /dev/null -w '%{time_connect}\n' https://149.154.167.220/ || echo timeout
done

Далее — сопоставление: если обрывы с нулём байт совпадают по времени (в пределах секунды) с событиями cooldown, а задержка прямого IP нестабильна, наблюдается та же петля. Гипотеза проверяется пробником, повторяющим обмен req_pq_multi → resPQ, а не ping.

Приложения: код

REQ_PQ_MULTI = 0xBE7E8EF1
RES_PQ = 0x05162463

def build_req_pq_multi():
    nonce = os.urandom(16)
    payload = struct.pack("<I", REQ_PQ_MULTI) + nonce
    msg_id = int(time.time() * (1 << 32))
    return b"\x00" * 8 + struct.pack("<q", msg_id) + struct.pack("<i", len(payload)) + payload

def one(host, port, secret, dc, timeout):
    """Одна проверка: рукопожатие, req_pq_multi, ожидание resPQ. Возвращает (мс, статус, байт).
    connect() и класс Obfuscated — из следующего спойлера."""
    t0 = time.perf_counter()
    s, ob = connect(host, port, secret, dc=dc, timeout=min(timeout, 15.0))
    try:
        s.sendall(ob.encrypt(ob.frame(build_req_pq_multi())))
        rx = bytearray()
        s.settimeout(timeout)
        while len(rx) < 4:                      # читаем длину кадра
            chunk = s.recv(4096)
            if not chunk:
                return (time.perf_counter() - t0) * 1000, "CLOSED-EARLY", len(rx)
            rx.extend(ob.decrypt(chunk))
        need = 4 + struct.unpack("<I", bytes(rx[:4]))[0]
        while len(rx) < need:                   # дочитываем кадр целиком
            rx.extend(ob.decrypt(s.recv(4096)))
        msg = bytes(rx[4:need])
        aki = int.from_bytes(msg[0:8], "little")          # auth_key_id == 0 для системного ответа
        ctor = int.from_bytes(msg[20:24], "little")       # конструктор: ждём resPQ
        return (time.perf_counter() - t0) * 1000, ("OK" if aki == 0 and ctor == RES_PQ else "BADREPLY"), need
    except socket.timeout:
        return (time.perf_counter() - t0) * 1000, "TIMEOUT", len(rx)
    finally:
        s.close()

# Цикл: раз в 3 секунды, с записью каждой попытки в файл
while time.time() < deadline:
    ms, status, size = one(host, port, secret, dc, timeout)
    print(f"{utcnow()} {ms:8.0f}ms {status} size={size}")
    time.sleep(3)

TAG_INTERMEDIATE = b"\xee\xee\xee\xee"          # транспортный тег, который шлёт клиент
RESERVED_STARTS = (b"HEAD", b"POST", b"GET ", b"\xee\xee\xee\xee",
                   b"\xdd\xdd\xdd\xdd", b"\x16\x03\x01\x02")

def _ctr(key: bytes, iv: bytes):
    return Cipher(algorithms.AES(key), modes.CTR(iv)).encryptor()

class Obfuscated:
    """Клиентский obfuscated2-поток: 64 байта рукопожатия и AES-CTR после них."""

    def __init__(self, secret_hex: str, dc: int = 2, tag: bytes = TAG_INTERMEDIATE):
        self.secret = bytes.fromhex(secret_hex)
        while True:                                  # 64 случайных байта с ограничениями формата
            rnd = bytearray(os.urandom(64))
            if rnd[0] == 0xEF or rnd[0] == 0x16:
                continue
            if bytes(rnd[:4]) in RESERVED_STARTS:    # HEAD/POST/GET/... запрещены
                continue
            break
        self.wire_head = bytes(rnd[:56])
        key = hashlib.sha256(self.wire_head[8:40] + self.secret).digest()
        self._enc = _ctr(key, self.wire_head[40:56])
        full = self._enc.update(bytes(rnd))
        ks_tail = bytes(full[i] ^ rnd[i] for i in range(56, 64))
        tail_plain = self.tag + struct.pack("<h", dc) + os.urandom(2)
        self.handshake = self.wire_head + bytes(
            tail_plain[i] ^ ks_tail[i] for i in range(8))
        # Входящий поток шифруется ключом из развёрнутого хвоста рукопожатия
        enc_pi = self.handshake[8:56][::-1]
        self._dec = _ctr(hashlib.sha256(enc_pi[:32] + self.secret).digest(), enc_pi[32:48])

    def encrypt(self, data): return self._enc.update(data)
    def decrypt(self, data): return self._dec.update(data)

    def frame(self, payload: bytes) -> bytes:        # intermediate: длина + payload
        return struct.pack("<I", len(payload)) + payload

def connect(host, port, secret_hex, dc=2, timeout=15.0):
    s = socket.create_connection((host, port), timeout=timeout)
    s.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
    ob = Obfuscated(secret_hex, dc)
    s.sendall(ob.handshake)
    return s, ob

#!/bin/sh
# Два экземпляра одной сборки на 127.0.0.1. Cooldown 60 с, чтобы истечение
# случалось раз в минуту и эффект был виден за минуты, а не за часы.
# S=<secret>; CF=<worker>.workers.dev
S="<secret>"; CF="<worker>.workers.dev"; DUR=600

for t in 4 1; do
  case $t in 4) port=11444 ;; 1) port=11441 ;; esac
  ./tg-ws-proxy --host 127.0.0.1 --port "$port" --secret "$S" \
      --dc-ip 2:149.154.167.220 --cf-worker-domain "$CF" \
      --ws-connect-timeout "$t" --ip-fail-cooldown 60 --pool-size 4 \
      --log-file "run/ab-$t.log" > "run/ab-$t.out" 2>&1 &
  echo $! > "run/ab-$t.pid"
done
sleep 2

PYTHONPATH=. python3 cooldown_probe.py --host 127.0.0.1 --port 11444 --secret "$S" \
    --duration "$DUR" --interval 2 --out run/ab-t4.txt &
PYTHONPATH=. python3 cooldown_probe.py --host 127.0.0.1 --port 11441 --secret "$S" \
    --duration "$DUR" --interval 2 --out run/ab-t1.txt &
wait
kill "$(cat run/ab-4.pid)" "$(cat run/ab-1.pid)"

Как строилась эта диагностика

Порядок работы здесь был важнее отдельных находок, поэтому его стоит описать отдельно.

1. Сначала только чтение. Первый проход — исключительно снимки логов, ps, ss, md5sum и активные пробы доступности. Изменения на роутере не вносились до появления проверяемой гипотезы.

2. Каждой гипотезе — критерий опровержения. «Прокси падает» — проверяются аптайм процесса и счётчики ошибок. «Виноват Wi-Fi» — окна отсутствия клиента в hostapd сверяются с окнами в логе прокси. «Виноват простой WebSocket» — длительности и объёмы сессий, закрытых апстримом, сопоставляются по времени с рассматриваемыми обрывами. Гипотеза, не прошедшая проверку, отбрасывается.

3. Лог даёт корреляцию, эксперимент — причину. Поэтому появился пробник, повторяющий обмен req_pq_multi → resPQ, и A/B на двух одинаковых сборках, отличающихся одним флагом.

4. Один параметр за раз и заранее подготовленный откат. Правка в конфиг, рестарт, наблюдение, откат одной командой. Вариант «сразу выставить побольше» не рассматривался.

5. Результат проверяется на клиенте, а не только в логе. Финальный критерий — не «в логе ноль обрывов», а «на телефоне сообщение не появляется».

Отдельно стоит сказать о происхождении главной гипотезы: предположение, что клиент платит N × --ws-connect-timeout и что именно это даёт сообщение об «некорректных настройках», было сформулировано ещё до этого разбора и фигурировало в промежуточных материалах проекта как основное. Новое здесь — не догадка, а доказательство: корреляция по логу, активное воспроизведение и A/B дали те числа, которых не хватало, чтобы отличить её от соседних объяснений и, главное, чтобы отличить вклад таймаута от вклада интервала.

Практический результат: гипотеза про keepalive (самая популярная в апстрим-обсуждениях) была отброшена не «по ощущениям», а по данным — обрывы простаивающих сессий не совпадали по времени с обрывами с нулём байт. А решающий аргумент дал не лог, а эксперимент: две одинаковые сборки, один флаг, 8 560 мс против 2 457 мс.

Случаи с другой картиной того же сообщения представляют отдельный интерес: полезны сведения о значениях --ws-connect-timeout и --ip-fail-cooldown и о наличии всплесков задержки на истечении cooldown. Собирать такие данные продуктивнее, чем повторять, что «DPI виноват».