hermes-agent/tests/gateway/test_telegram_init_deadline.py
Jaret Bottoms e16743b0d5 fix(telegram): diagnose blocked-loop init hangs, unbind DoH from system DNS
The #63309 hang class — gateway stuck at 'Connecting to Telegram
(attempt 1/8)' with no retry, no timeout, for minutes — can only occur
when the event loop thread itself is blocked in a synchronous call:
_await_with_thread_deadline's timer fires off-loop, but its expiry
hand-off (call_soon_threadsafe) still needs the loop to run, and the
gateway's outer wait_for is a pure loop timer. When the loop is pinned,
every layer goes silent simultaneously and the process wedges with no
evidence of where.

Two changes:

1. Loop-blocked watchdog in _await_with_thread_deadline: a second
   daemon timer fires one grace period (5s) after the deadline; if the
   loop still hasn't processed the expiry, it logs a WARNING from the
   timer thread and faulthandler-dumps all thread stacks to stderr —
   converting the silent hang into a trace that names the exact
   blocking frame. A threading.Event set by the expiry callback (and on
   normal exit) keeps completed awaits from ever being misreported.

2. discover_fallback_ips: the system-resolver leg runs
   socket.getaddrinfo in a worker thread with no timeout, and
   asyncio.gather waited on it unboundedly — a wedged OS resolver
   stalled discovery for minutes between the two startup log lines. Its
   result only feeds a log message, so it no longer gates discovery:
   DoH legs (already client-bounded) are gathered alone and the system
   leg is awaited with a _DOH_TIMEOUT cap, best-effort.

Refs #63309

Tests: 3 watchdog regressions (blocked-loop dump fires; responsive-loop
timeout does not; completed await does not) + 2 hung-resolver
regressions (DoH results returned promptly; worst-case seed fallback
stays bounded).
2026-07-14 17:09:50 +05:30

277 lines
10 KiB
Python

import sys
from unittest.mock import AsyncMock, MagicMock
import pytest
from gateway.config import PlatformConfig
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 plugins.platforms.telegram import adapter as tg_adapter # noqa: E402
from plugins.platforms.telegram.adapter import TelegramAdapter # noqa: E402
@pytest.mark.asyncio
async def test_connect_retries_when_initialize_wall_deadline_expires(monkeypatch):
"""A wedged initialize() attempt must not trap startup on attempt 1/8."""
fake_app = MagicMock()
fake_app.bot = MagicMock()
fake_app.initialize = AsyncMock(return_value=None)
fake_app.start = AsyncMock()
fake_app.add_handler = MagicMock()
chainable = MagicMock()
chainable.token.return_value = chainable
chainable.request.return_value = chainable
chainable.get_updates_request.return_value = chainable
chainable.build.return_value = fake_app
builder_root = MagicMock()
builder_root.builder.return_value = chainable
monkeypatch.setattr(tg_adapter, "Application", builder_root)
monkeypatch.setattr(tg_adapter, "HTTPXRequest", MagicMock)
monkeypatch.setattr(tg_adapter, "discover_fallback_ips", AsyncMock(return_value=[]))
monkeypatch.setattr(tg_adapter, "resolve_proxy_url", lambda *a, **k: None)
monkeypatch.setattr(tg_adapter.asyncio, "sleep", AsyncMock())
deadline_calls = 0
async def _fake_deadline(awaitable, timeout, *, on_abandon=None):
nonlocal deadline_calls
deadline_calls += 1
if deadline_calls == 1:
awaitable.close()
raise tg_adapter.asyncio.TimeoutError()
return await awaitable
monkeypatch.setattr(tg_adapter, "_await_with_thread_deadline", _fake_deadline)
adapter = TelegramAdapter(PlatformConfig(enabled=True, token="test-token"))
monkeypatch.setattr(adapter, "_acquire_platform_lock", lambda *a, **k: True)
monkeypatch.setattr(adapter, "_fallback_ips", lambda: [])
monkeypatch.setattr(adapter, "_delete_webhook_best_effort", AsyncMock())
monkeypatch.setattr(adapter, "_start_polling_resilient", AsyncMock(return_value=True))
monkeypatch.setattr(adapter, "_polling_heartbeat_loop", AsyncMock(return_value=None))
monkeypatch.setattr(adapter, "_start_post_connect_housekeeping", MagicMock())
assert await adapter.connect() is True
assert fake_app.initialize.call_count == 2
assert fake_app.initialize.await_count == 1
assert deadline_calls == 2
tg_adapter.asyncio.sleep.assert_awaited_once_with(1)
fake_app.start.assert_awaited_once()
@pytest.mark.asyncio
async def test_await_with_thread_deadline_returns_value_on_happy_path():
"""The real helper returns the awaited result and raises no timeout."""
async def _ok():
return 42
result = await tg_adapter._await_with_thread_deadline(_ok(), timeout=5.0)
assert result == 42
@pytest.mark.asyncio
async def test_await_with_thread_deadline_abandons_and_runs_cleanup_on_timeout():
"""A wedged awaitable must raise TimeoutError promptly AND trigger the
best-effort on_abandon cleanup (the httpx-pool-leak guard).
This exercises the REAL _await_with_thread_deadline (not a monkeypatched
stub), covering the abandonment + cleanup mechanism directly.
"""
import asyncio as _asyncio
import time as _time
cleanup_ran = _asyncio.Event()
async def _wedged():
# Swallows cancellation for a bounded window — long enough that the
# helper must return control BEFORE this finishes (proving it doesn't
# await cancellation, the #58236 shielded-scope behavior), but bounded
# so the abandoned task can't outlive the test and wedge teardown.
for _ in range(20):
try:
await _asyncio.sleep(0.05)
except _asyncio.CancelledError:
# Keep going despite cancellation, like the shielded scope.
pass
async def _cleanup():
cleanup_ran.set()
started = _time.monotonic()
with pytest.raises(_asyncio.TimeoutError):
await tg_adapter._await_with_thread_deadline(
_wedged(), timeout=0.2, on_abandon=_cleanup
)
elapsed = _time.monotonic() - started
# Returned control promptly — well before the wedged coroutine's ~1s span.
assert elapsed < 0.8
# The detached cleanup was scheduled; give the loop a tick to run it.
await _asyncio.wait_for(cleanup_ran.wait(), timeout=2.0)
assert cleanup_ran.is_set()
@pytest.mark.asyncio
async def test_await_with_thread_deadline_cleanup_error_is_swallowed():
"""A cleanup that raises must not surface as an unhandled task error."""
import asyncio as _asyncio
async def _wedged():
for _ in range(20):
try:
await _asyncio.sleep(0.05)
except _asyncio.CancelledError:
pass
def _boom():
raise RuntimeError("cleanup blew up")
# Must still raise TimeoutError (not the cleanup error) and not crash.
with pytest.raises(_asyncio.TimeoutError):
await tg_adapter._await_with_thread_deadline(
_wedged(), timeout=0.2, on_abandon=_boom
)
# Let the detached cleanup task run and be observed (no unraised error).
await _asyncio.sleep(0.05)
@pytest.mark.asyncio
async def test_shutdown_abandoned_app_closes_request_transports_when_uninitialized():
"""The leak fix must release the httpx transports even when PTB's own
Application.shutdown()/Bot.shutdown() no-op because the wedged initialize()
never flipped _initialized. _shutdown_abandoned_app falls back to closing
each bot._request transport directly (HTTPXRequest.shutdown gates only on
client.is_closed, not on an init flag)."""
from unittest.mock import AsyncMock, MagicMock
# A half-built app: shutdown() is a no-op (uninitialized), but the request
# transports still hold open httpx clients that must be closed.
req0 = MagicMock()
req0.shutdown = AsyncMock()
req1 = MagicMock()
req1.shutdown = AsyncMock()
bot = MagicMock()
bot._request = (req0, req1)
app = MagicMock()
app.bot = bot
app.shutdown = AsyncMock(return_value=None) # PTB no-op on uninitialized app
await tg_adapter._shutdown_abandoned_app(app)
app.shutdown.assert_awaited_once()
# Fell back to closing the transports directly — the actual leak fix.
req0.shutdown.assert_awaited_once()
req1.shutdown.assert_awaited_once()
@pytest.mark.asyncio
async def test_shutdown_abandoned_app_handles_none_and_missing_requests():
"""Robust against app=None and an app whose bot/_request aren't present."""
from unittest.mock import AsyncMock, MagicMock
# None app -> no-op, no crash.
await tg_adapter._shutdown_abandoned_app(None)
# app.shutdown() raising must be swallowed, and missing _request tolerated.
app = MagicMock()
app.shutdown = AsyncMock(side_effect=RuntimeError("still running"))
app.bot = None
await tg_adapter._shutdown_abandoned_app(app) # must not raise
@pytest.mark.asyncio
async def test_blocked_loop_after_expiry_dumps_diagnostics(monkeypatch):
"""#63309: when the loop thread is stuck in a synchronous call, the expiry
callback never runs and every asyncio timeout goes silent. The off-loop
watchdog must detect that state and emit diagnostics from its own thread."""
import asyncio as _asyncio
import time as _time
dumps = []
monkeypatch.setattr(
tg_adapter,
"_dump_loop_blocked_diagnostics",
lambda timeout, grace: dumps.append((timeout, grace)),
)
monkeypatch.setattr(tg_adapter, "_LOOP_BLOCKED_DUMP_GRACE", 0.15)
hung = _asyncio.get_running_loop().create_future() # never completes
task = _asyncio.ensure_future(
tg_adapter._await_with_thread_deadline(hung, timeout=0.05)
)
# Let the helper start its deadline + watchdog timers…
await _asyncio.sleep(0)
# …then block the event loop straight through deadline (0.05s) AND the
# watchdog grace (0.15s): call_soon_threadsafe stays queued, exactly like
# a sync call pinning the loop during Application.initialize().
_time.sleep(0.5)
with pytest.raises(_asyncio.TimeoutError):
await task
assert dumps == [(0.05, 0.15)]
hung.cancel()
@pytest.mark.asyncio
async def test_responsive_loop_expiry_does_not_dump(monkeypatch):
"""A normal timeout on a responsive loop must not trigger the watchdog."""
import asyncio as _asyncio
dumps = []
monkeypatch.setattr(
tg_adapter,
"_dump_loop_blocked_diagnostics",
lambda timeout, grace: dumps.append((timeout, grace)),
)
monkeypatch.setattr(tg_adapter, "_LOOP_BLOCKED_DUMP_GRACE", 0.1)
hung = _asyncio.get_running_loop().create_future()
with pytest.raises(_asyncio.TimeoutError):
await tg_adapter._await_with_thread_deadline(hung, timeout=0.05)
# Give the (cancelled) watchdog window time to have fired if it were going to.
await _asyncio.sleep(0.3)
assert dumps == []
hung.cancel()
@pytest.mark.asyncio
async def test_completed_await_never_reports_blocked_loop(monkeypatch):
"""Success before the deadline must cancel the watchdog (no false dump)."""
import asyncio as _asyncio
dumps = []
monkeypatch.setattr(
tg_adapter,
"_dump_loop_blocked_diagnostics",
lambda timeout, grace: dumps.append((timeout, grace)),
)
monkeypatch.setattr(tg_adapter, "_LOOP_BLOCKED_DUMP_GRACE", 0.05)
async def _quick():
return "ok"
assert await tg_adapter._await_with_thread_deadline(_quick(), timeout=0.2) == "ok"
await _asyncio.sleep(0.4)
assert dumps == []