fix(diag): причина отказа туннеля и судьба домена Worker'а попадали в никуда (#50) (#54)

`TransportEngine::connect` собирает подробный перечень попыток — какой адрес не
ответил, где истёк TLS, что вернул воркер, — и возвращает его в `Err`. Дальше
этот `Err` доходил до `serve`, где выбрасывался: `let _ = handle(...)`.
Увеличивался только счётчик.

Снаружи это выглядит как `туннелей 0 · сбоев 249 · падений маршрутов 395` без
единого слова о том, почему их ноль. Отличить «провайдер режет закреплённые
адреса» от «воркер отвечает отказом» нечем, хотя рядом есть журнал событий, в
который пишутся куда менее важные вещи.

Теперь причина попадает в журнал строкой вида:

    Не поднялся туннель до DC2: 149.154.167.51 — не отвечает (таймаут TCP);
    kws2.web.telegram.org — таймаут TLS/WebSocket

Дедупликация журнала делает её разовой: набор маршрутов у DC стабилен.

Там же вторая слепая зона. Домен воркера, не похожий на имя хоста, отбрасывался
молча: `https://name.workers.dev/` со схемой или слэшем не проходит
`valid_domain`, маршрут не появляется, и «воркер настроен» неотличимо от
«воркера нет». `set_worker_domains` теперь возвращает принятые и отвергнутые
по отдельности, отвергнутые называются вместе с причиной, принятые
подтверждаются.

Тексты отказов переведены на русский: их читает не разработчик, а человек,
который прислал скриншот и ждёт ответа.

Co-authored-by: by-sonic <171230345+by-sonic@users.noreply.github.com>

docs/ARCHITECTURE_V2.md

@@ -116,6 +116,32 @@ LAN-режим превращал бы машину в открытый прок
 Счётчик `ws_failures` от них отличается тем, что растёт после успешного
 рукопожатия с клиентом: там договорились с клиентом, но не смогли с Telegram.
 
+### Почему не поднялся туннель
+
+`ws_failures` говорит, что каскад маршрутов упал целиком, и молчит о причине.
+Текст с перечислением попыток собирался в `TransportEngine::connect` и там же
+пропадал: наверх уходил `Err`, который выбрасывался в `serve`. При `туннелей 0`
+и растущих сбоях отличить «провайдер режет закреплённые адреса» от «воркер
+отвечает отказом» было нечем — ровно та стена, в которую упёрся репортёр #50.
+
+Теперь причина попадает в журнал одной строкой на каждый набор отказов:
+
+```
+Не поднялся туннель до DC2: 149.154.167.51 — не отвечает (таймаут TCP);
+kws2.web.telegram.org — таймаут TLS/WebSocket; my.workers.dev — рукопожатие
+WebSocket: HTTP error: 403 Forbidden
+```
+
+Дедупликация журнала делает эту строку разовой: маршруты у DC стабильны, и
+повтор той же комбинации отказов не пишется.
+
+Домены Cloudflare Worker отчитываются так же. Строка, не похожая на имя хоста,
+раньше отбрасывалась молча — `https://name.workers.dev/` со схемой или слэшем не
+проходит `valid_domain`, маршрут не появлялся, и «воркер настроен» ничем не
+отличалось от «воркера нет». Теперь отвергнутая строка называется вместе с
+причиной, а принятая подтверждается: `Cloudflare Worker в списке маршрутов:
+name.workers.dev`.
+
 ## Туннель: два независимых направления
 
 Каждое клиентское соединение получает свой WebSocket-туннель, и внутри него

src/proxy.rs

@@ -217,7 +217,18 @@ impl Stats {
             .filter(|value| !value.trim().is_empty())
             .map(str::to_owned)
             .collect::<Vec<_>>();
-        self.transport.set_worker_domains(&domains);
+        let result = self.transport.set_worker_domains(&domains);
+        // Молчание здесь неотличимо от «воркер работает»: пока строка не
+        // попадала в список маршрутов, об этом не сообщалось ничем, и человек
+        // считал резервный маршрут настроенным (by-sonic/tglock#50).
+        for rejected in &result.rejected {
+            self.note(format!(
+                "Cloudflare Worker «{rejected}» не похож на имя хоста — маршрут не добавлен.                  Нужно только имя, без https:// и без косой черты: example.workers.dev"
+            ));
+        }
+        for accepted in &result.accepted {
+            self.note(format!("Cloudflare Worker в списке маршрутов: {accepted}"));
+        }
     }
 
     pub fn stop(&self) {
@@ -665,7 +676,17 @@ async fn ws_tunnel(
 ) -> Result<(), Box<dyn std::error::Error + Send + Sync>> {
     use futures_util::{SinkExt, StreamExt};
 
-    let (ws, connected) = stats.transport.connect(dc, media).await?;
+    let (ws, connected) = match stats.transport.connect(dc, media).await {
+        Ok(connected) => connected,
+        Err(error) => {
+            // Единственное место, где известно, ПОЧЕМУ туннеля нет. Раньше
+            // текст уходил в `Err` и там пропадал: оставался счётчик сбоев без
+            // причины, и отличить «провайдер режет адреса» от «воркер отвечает
+            // отказом» было нечем (by-sonic/tglock#50).
+            stats.note(error.clone());
+            return Err(error.into());
+        }
+    };
     let _tunnel = EstablishedTunnel::new(stats);
     stats.note_tunnel(dc, connected.route.kind.ui_code());
 
@@ -1473,6 +1494,68 @@ mod tests {
         let _ = server.await.unwrap();
     }
 
+    /// Диагностика обязана называть причину, а не только считать сбои.
+    ///
+    /// При `туннелей 0` счётчик сбоев говорит, что не получилось, и молчит о
+    /// том, почему. Текст ошибки собирался и выбрасывался, и разобрать
+    /// «провайдер режет адреса» против «воркер отвечает отказом» было нечем
+    /// (by-sonic/tglock#50).
+    #[tokio::test]
+    async fn a_cascade_that_failed_says_why_in_the_log() {
+        let dead = TcpListener::bind("127.0.0.1:0").await.unwrap();
+        let dead_port = dead.local_addr().unwrap().port();
+        drop(dead);
+
+        let stats = Stats::new();
+        stats.transport.force_local_route(dead_port);
+        let (port, server) = start_proxy(stats.clone(), false).await;
+
+        let init = unambiguous_client_init(&stats.secret, 2);
+        let mut client = TcpStream::connect(("127.0.0.1", port)).await.unwrap();
+        client.write_all(&init).await.unwrap();
+
+        wait_until("сбой засчитан", || {
+            stats.ws_failures.load(Ordering::Relaxed) > 0
+        })
+        .await;
+
+        let events = stats.drain_events();
+        let named = events
+            .iter()
+            .find(|event| event.contains("Не поднялся туннель до DC2"))
+            .unwrap_or_else(|| panic!("причина отказа не попала в журнал: {events:?}"));
+        assert!(
+            named.contains("127.0.0.1"),
+            "в журнале должен быть назван адрес, до которого не дошли: {named}"
+        );
+
+        stats.stop();
+        let _ = server.await.unwrap();
+    }
+
+    /// Строка, не похожая на имя хоста, отбрасывалась молча, и «воркер
+    /// настроен» ничем не отличалось от «воркера нет» (by-sonic/tglock#50).
+    #[test]
+    fn a_worker_domain_is_confirmed_or_named_as_rejected() {
+        let stats = Stats::new();
+        stats.set_worker_domain("https://mine.workers.dev/, spare.workers.dev");
+        let events = stats.drain_events();
+
+        assert!(
+            events
+                .iter()
+                .any(|event| event.contains("https://mine.workers.dev/")
+                    && event.contains("не похож на имя хоста")),
+            "отвергнутый домен должен быть назван вместе с причиной: {events:?}"
+        );
+        assert!(
+            events
+                .iter()
+                .any(|event| event.contains("в списке маршрутов: spare.workers.dev")),
+            "принятый домен нужно подтвердить, иначе проверить нечем: {events:?}"
+        );
+    }
+
     #[tokio::test]
     #[ignore = "requires live Telegram network access"]
     async fn accepts_mtproto_and_builds_live_media_tunnel() {

src/transport.rs

@@ -87,6 +87,15 @@ impl Route {
     }
 }
 
+/// Что случилось с доменами Worker'а, которые задал пользователь.
+#[derive(Clone, Debug, Default, Eq, PartialEq)]
+pub struct WorkerDomains {
+    /// Домены, попавшие в список маршрутов.
+    pub accepted: Vec<String>,
+    /// Строки, не похожие на имя хоста, — маршрута из них не вышло.
+    pub rejected: Vec<String>,
+}
+
 #[derive(Clone, Debug)]
 pub struct ConnectedRoute {
     pub route: Route,
@@ -151,15 +160,29 @@ impl TransportEngine {
         Self::default()
     }
 
-    pub fn set_worker_domains(&self, domains: &[String]) {
+    /// Задать домены Worker'ов, вернув принятые и отвергнутые по отдельности.
-        let mut normalized = Vec::new();
+    ///
+    /// Отвергнутые возвращаются, потому что раньше они отбрасывались молча:
+    /// вписанный со схемой или слэшем `https://name.workers.dev/` не проходил
+    /// проверку, маршрут не появлялся, и «воркер настроен» ничем не отличалось
+    /// от «воркера нет» (by-sonic/tglock#50).
+    pub fn set_worker_domains(&self, domains: &[String]) -> WorkerDomains {
+        let mut accepted = Vec::new();
+        let mut rejected = Vec::new();
         for domain in domains {
-            let domain = domain.trim().to_ascii_lowercase();
+            let trimmed = domain.trim();
-            if valid_domain(&domain) && !normalized.contains(&domain) {
+            if trimmed.is_empty() {
-                normalized.push(domain);
+                continue;
+            }
+            let normalized = trimmed.to_ascii_lowercase();
+            if !valid_domain(&normalized) {
+                rejected.push(trimmed.to_owned());
+            } else if !accepted.contains(&normalized) {
+                accepted.push(normalized);
             }
         }
-        *self.worker_domains.lock().unwrap() = normalized;
+        *self.worker_domains.lock().unwrap() = accepted.clone();
+        WorkerDomains { accepted, rejected }
     }
 
     pub async fn connect(
@@ -179,18 +202,22 @@ impl TransportEngine {
                 }
                 Err(error) => {
                     self.record_failure(&route);
-                    errors.push(format!(
+                    let attempt = format!("{} — {}", route.connect_host, error);
-                        "{} via {}: {}",
+                    if !errors.contains(&attempt) {
-                        route.websocket_host, route.connect_host, error
+                        errors.push(attempt);
-                    ));
+                    }
                 }
             }
         }
 
+        // Текст читает человек: он попадает в журнал событий, и по нему
+        // отличают «провайдер режет закреплённые адреса» от «воркер отвечает
+        // отказом». Раньше причина отказа не доходила никуда, и при
+        // `туннелей 0` узнать, почему их ноль, было нечем (by-sonic/tglock#50).
         Err(format!(
-            "all Telegram routes for DC{}{} failed: {}",
+            "Не поднялся туннель до DC{}{}: {}",
             dc,
-            if media { " media" } else { "" },
+            if media { " (медиа)" } else { "" },
             errors.join("; ")
         ))
     }
@@ -376,8 +403,8 @@ async fn connect_route(route: &Route) -> Result<TelegramWebSocket, String> {
         TcpStream::connect((route.connect_host.as_str(), route.port)),
     )
     .await
-    .map_err(|_| "TCP connect timeout".to_owned())?
+    .map_err(|_| "не отвечает (таймаут TCP)".to_owned())?
-    .map_err(|error| format!("TCP connect: {}", error))?;
+    .map_err(|error| format!("соединение не открылось: {}", error))?;
     tcp.set_nodelay(true)
         .map_err(|error| format!("TCP_NODELAY: {}", error))?;
 
@@ -402,9 +429,9 @@ async fn connect_route(route: &Route) -> Result<TelegramWebSocket, String> {
             tokio_tungstenite::client_async(request, MaybeTlsStream::Plain(tcp)),
         )
         .await
-        .map_err(|_| "WebSocket timeout".to_owned())?
+        .map_err(|_| "таймаут WebSocket".to_owned())?
         .map(|(websocket, _)| websocket)
-        .map_err(|error| format!("WebSocket handshake: {}", error));
+        .map_err(|error| format!("рукопожатие WebSocket: {}", error));
     }
 
     // The URI host remains the real Telegram hostname even when the TCP socket
@@ -417,7 +444,7 @@ async fn connect_route(route: &Route) -> Result<TelegramWebSocket, String> {
         tokio_tungstenite::client_async_tls_with_config(request, tcp, None, Some(connector)),
     )
     .await
-    .map_err(|_| "TLS/WebSocket timeout".to_owned())?
+    .map_err(|_| "таймаут TLS/WebSocket".to_owned())?
     .map(|(websocket, _)| websocket)
     .map_err(|error| format!("TLS/WebSocket handshake: {}", error))
 }
@@ -612,7 +639,7 @@ mod tests {
     #[test]
     fn worker_domains_are_rejected_unless_they_are_plain_hostnames() {
         let engine = TransportEngine::new();
-        engine.set_worker_domains(&[
+        let result = engine.set_worker_domains(&[
             "https://scheme.workers.dev".to_owned(),
             "with.a/path".to_owned(),
             "no-dot".to_owned(),
@@ -633,6 +660,17 @@ mod tests {
             .filter(|route| route.kind == RouteKind::CloudflareWorker)
             .collect();
         assert_eq!(workers.len(), 1, "only the valid hostname may survive");
+        assert_eq!(result.accepted, vec!["good.workers.dev".to_owned()]);
+        assert!(
+            result.rejected.contains(&"https://scheme.workers.dev".to_owned()),
+            "отвергнутая строка обязана вернуться названной, иначе о ней некому              сообщить: {:?}",
+            result.rejected
+        );
+        assert!(
+            !result.rejected.iter().any(String::is_empty),
+            "пустая строка — не то, о чём стоит предупреждать: {:?}",
+            result.rejected
+        );
         assert_eq!(workers[0].websocket_host, "good.workers.dev");
     }