fix(telegram): log the first confirmed getUpdates progress per generation

Both polling reconnect paths end on the same 'health pending getUpdates progress' line, and _record_polling_progress completed silently — so the log stream for 'reconnected and healthy' was byte-identical to 'reconnected and hung', and a wedged long-poll (#87057 / #69314 / #71239 class) stayed invisible until a user noticed silence. The only detection method was sending the bot a test message (#90504). Emit one INFO on the first confirmed getUpdates round-trip of each generation, inside the existing event-set branch so steady-state polling adds no log volume. This turns the pending line into a resolvable pair ('health pending' -> 'confirmed healthy') whose absence after a reconnect is a reliable hung-poll signature. Fixes #90504
2026-08-20 12:52:58 +08:00
parent 188d47919a
commit fbca706789
2 changed files with 123 additions and 0 deletions
@@ -2517,6 +2517,19 @@ class TelegramAdapter(BasePlatformAdapter):
            return
        if generation != self._polling_generation:
            return
+        if not self._polling_progress_event.is_set():
+            # The first confirmed getUpdates round-trip of this generation
+            # resolves the "health pending getUpdates progress" line both
+            # reconnect paths end on. Without it the log stream for
+            # "reconnected and healthy" is byte-identical to "reconnected
+            # and hung" — a wedged long-poll is invisible until a user
+            # notices silence (#90504).
+            logger.info(
+                "[%s] Telegram polling confirmed healthy: getUpdates progressing "
+                "(generation %d)",
+                self.name,
+                generation,
+            )
        self._polling_progress_event.set()
        self._polling_network_error_count = 0
        if generation == self._polling_conflict_recovery_generation:
@@ -0,0 +1,110 @@
+"""Regression tests for the Telegram polling health-confirmation log (#90504).
+
+Both reconnect paths end on ``health pending getUpdates progress`` and
+``_record_polling_progress`` used to complete silently, so the log stream for
+"reconnected and healthy" was byte-identical to "reconnected and hung". The
+first confirmed getUpdates round-trip of each generation now emits an INFO
+line, turning the pending line into a resolvable pair whose *absence* after a
+reconnect is a reliable hung-poll signature.
+"""
+
+import asyncio
+import logging
+import sys
+from unittest.mock import MagicMock
+
+import pytest
+
+
+def _ensure_telegram_mock():
+    if "telegram" in sys.modules and hasattr(sys.modules["telegram"], "__file__"):
+        return
+    telegram_mod = MagicMock()
+    telegram_mod.ext.ContextTypes.DEFAULT_TYPE = type(None)
+    telegram_mod.constants.ParseMode.MARKDOWN_V2 = "MarkdownV2"
+    telegram_mod.constants.ChatType.GROUP = "group"
+    telegram_mod.constants.ChatType.SUPERGROUP = "supergroup"
+    telegram_mod.constants.ChatType.CHANNEL = "channel"
+    telegram_mod.constants.ChatType.PRIVATE = "private"
+    telegram_mod.error.NetworkError = type("NetworkError", (OSError,), {})
+    telegram_mod.error.TimedOut = type("TimedOut", (OSError,), {})
+    for name in ("telegram", "telegram.ext", "telegram.constants", "telegram.request"):
+        sys.modules.setdefault(name, telegram_mod)
+    sys.modules.setdefault("telegram.error", telegram_mod.error)
+
+
+_ensure_telegram_mock()
+
+from gateway.config import Platform  # noqa: E402
+from plugins.platforms.telegram.adapter import TelegramAdapter  # noqa: E402
+
+
+def _bare_adapter():
+    a = TelegramAdapter.__new__(TelegramAdapter)
+    a.platform = Platform.TELEGRAM
+    a._fatal_error_code = None
+    a._fatal_error_message = None
+    a._fatal_error_retryable = True
+    a._polling_teardown_started = False
+    a._polling_progress_accepting = True
+    a._polling_generation = 1
+    a._polling_progress_event = asyncio.Event()
+    a._polling_network_error_count = 2
+    a._polling_conflict_count = 3
+    a._polling_conflict_recovery_generation = None
+    a._send_path_degraded = True
+    return a
+
+
+class TestPollingHealthConfirmation:
+    def test_first_progress_emits_confirmed_healthy(self, caplog):
+        a = _bare_adapter()
+        with caplog.at_level(logging.INFO, logger="plugins.platforms.telegram.adapter"):
+            a._record_polling_progress(1)
+        rendered = " | ".join(rec.getMessage() for rec in caplog.records)
+        assert "confirmed healthy" in rendered
+        assert "generation 1" in rendered
+        assert a._polling_progress_event.is_set()
+
+    def test_subsequent_progress_is_silent(self, caplog):
+        """Only the FIRST round-trip of a generation logs — a quiet evening
+        must not spam one INFO per getUpdates poll."""
+        a = _bare_adapter()
+        a._record_polling_progress(1)  # first — logs
+        with caplog.at_level(logging.INFO, logger="plugins.platforms.telegram.adapter"):
+            a._record_polling_progress(1)  # second — silent
+            a._record_polling_progress(1)  # third — silent
+        assert not [
+            rec for rec in caplog.records if "confirmed healthy" in rec.getMessage()
+        ]
+
+    def test_new_generation_logs_again(self, caplog):
+        """A reconnect starts a new generation with a fresh event; its first
+        progress must re-emit the confirmation so the pending line of THAT
+        reconnect also resolves."""
+        a = _bare_adapter()
+        a._record_polling_progress(1)
+        # reconnect: new generation, event reset, counters possibly nonzero
+        a._polling_generation = 2
+        a._polling_progress_event = asyncio.Event()
+        a._polling_network_error_count = 1
+        a._send_path_degraded = True
+        with caplog.at_level(logging.INFO, logger="plugins.platforms.telegram.adapter"):
+            a._record_polling_progress(2)
+        rendered = " | ".join(rec.getMessage() for rec in caplog.records)
+        assert "confirmed healthy" in rendered
+        assert "generation 2" in rendered
+
+    def test_stale_generation_progress_stays_silent(self, caplog):
+        """Progress from an abandoned generation must neither log nor set the
+        current event (pre-existing guard, pinned here because the log line
+        must inherit the same generation-scoping)."""
+        a = _bare_adapter()
+        a._polling_generation = 2
+        a._polling_progress_event = asyncio.Event()
+        with caplog.at_level(logging.INFO, logger="plugins.platforms.telegram.adapter"):
+            a._record_polling_progress(1)
+        assert not [
+            rec for rec in caplog.records if "confirmed healthy" in rec.getMessage()
+        ]
+        assert not a._polling_progress_event.is_set()