Compare commits

...
4 Commits
Author SHA1 Message Date
Abiba (pi) 48bc66b42f feat(zulip): Gen 4 — connection pool recovery, heartbeat logging, log sanitization
CI / validate (pull_request) Failing after 6s
Fixes 4 critical reliability issues discovered during Zulip server outage recovery:

1. CLOSE-WAIT socket leak: _reconnect() now creates a fresh httpx.AsyncClient()
   when the queue expires, preventing stuck connection pool. Old client is
   explicitly aclose()'d.

2. Silent poll loop death: After sustained 502 errors, the poll loop was
   returning [] without logging — transport errors are swallowed by _api_call
   returning (None, 0). Added heartbeat logging every 5 minutes and silence
   detection warnings after 60s of no events.

3. HTTP client stuck pool: Added proactive client recreation after 20 consecutive
   empty polls (connection pool exhaustion detection) and periodic refresh every
   500 polls (connection reuse limit).

4. Log spam: 502 error responses from Netbird contain full HTML pages — now
   truncated to 80 chars with newlines stripped.

Also:
- Support ZULIP_URL env var (in addition to ZULIP_SITE)
- expose silence_seconds, consecutive_empty_polls, client_pool_resets in health stats
- Reduced health callback interval from 600s to 300s
2026-06-27 14:12:52 +00:00
Abiba (pi) 6bb438de6e fix(zulip): remove invalid kwargs from SendResult calls
SendResult only accepts: success, message_id, error, raw_response,
retryable. The adapter was passing platform=, chat_id=, and metadata=
which are not valid fields, causing TypeError on every send attempt.

This was the error Tanko was showing in Zulip:
'SendResult.__init__() got an unexpected keyword argument "platform"'
2026-06-27 11:34:14 +00:00
Abiba (pi) b1bef9024f fix(zulip): resolve bot user_id from /users/me for @mention detection
The /register endpoint doesn't always return user_id on all Zulip
server versions. Added _resolve_bot_user_id() that queries the
/users/me endpoint as a fallback. This ensures @mention detection
(is_direct_mention check) works even when register doesn't provide it.

Also bumped to v1.0.3 — cumulative fixes since v1.0.1:
- v1.0.2: BAD_EVENT_QUEUE_ID detection (silent queue expiry)
- v1.0.3: bot user_id resolution (@mention detection)
2026-06-27 05:51:12 +00:00
Abiba (pi) dcf2de0052 fix(zulip): detect BAD_EVENT_QUEUE_ID instead of silently swallowing it
Root cause of Tanko not responding to DMs after initial connection:
Zulip event queues expire after ~10min of dont_block polling. When the
queue expired, _api_call() returned None for all 400-level errors, which
_fetch_events() treated as 'no events' and returned []. The poll loop
never knew the queue died, so it never reconnected.

Fix:
1. _api_call() now returns (Optional[Dict], status_code) tuple
2. _fetch_events() explicitly checks for 400 status and raises
   RuntimeError('BAD_EVENT_QUEUE_ID') for the poll loop to catch
3. All callers updated to unpack the tuple

Now when a queue expires, the poll loop catches the error and
calls _reconnect() to register a fresh queue.
2026-06-27 05:50:13 +00:00
+220 -39
View File
@@ -1,10 +1,19 @@
""" """
Zulip platform adapter (Hermes plugin) — Gen 3. Zulip platform adapter (Hermes plugin) — Gen 4.
Connects a Hermes agent to Zulip via event queue polling. DMs and @mentions Connects a Hermes agent to Zulip via event queue polling. DMs and @mentions
are routed to the agent via the Hermes Gateway's handle_message() interface. are routed to the agent via the Hermes Gateway's handle_message() interface.
Replies use a placeholder->edit streaming pattern for UX feedback. Replies use a placeholder->edit streaming pattern for UX feedback.
Gen 4 Improvements (2026-06-27):
1. HTTP client recreation on reconnect — new httpx.AsyncClient() after queue expiry
or sustained failures to prevent CLOSE-WAIT socket leaks
2. Heartbeat logging — periodic "still alive" message to prove poll loop is running
3. Log sanitization — truncates 502/error HTML to first 80 chars (no Netbird HTML spam)
4. Connection recovery — creates fresh HTTP client after N empty poll cycles
5. Poll silence detection — logs warnings when no events received for extended period
6. Connection reuse limit — periodic client recreation to prevent connection pool exhaustion
Gen 3 Improvements (2026-06-26): Gen 3 Improvements (2026-06-26):
1. Malformed message resilience — try/except wraps each event, no crash on bad JSON 1. Malformed message resilience — try/except wraps each event, no crash on bad JSON
2. Periodic @all-bots refresh — background task re-resolves user ID every hour 2. Periodic @all-bots refresh — background task re-resolves user ID every hour
@@ -66,6 +75,13 @@ DEDUP_CLEANUP_INTERVAL = 120 # Clean old entries every 2 minutes
ALL_BOTS_REFRESH_INTERVAL = 3600 # Re-resolve @all-bots user ID every hour ALL_BOTS_REFRESH_INTERVAL = 3600 # Re-resolve @all-bots user ID every hour
SELFTEST_TIMEOUT = 30 # seconds to wait for self-test response SELFTEST_TIMEOUT = 30 # seconds to wait for self-test response
# Gen 4: Connection pool health
HEARTBEAT_INTERVAL = 300 # Log heartbeat every 5 minutes
MAX_CONSECUTIVE_EMPTY_POLLS = 20 # Reset client after this many empty polls
CLIENT_REUSE_LIMIT = 500 # Create fresh client every N polls to prevent connection leaks
POLL_SILENCE_WARN_INTERVAL = 60 # Warn if no events received for this many seconds
MAX_ERROR_LOG_LEN = 80 # Truncate error response bodies to avoid HTML spam
# Regex to strip Zulip @mention markup # Regex to strip Zulip @mention markup
MENTION_CLEANER = re.compile(r"@\*\*[^*]+\*\*") MENTION_CLEANER = re.compile(r"@\*\*[^*]+\*\*")
@@ -158,7 +174,18 @@ class ZulipAdapter(BasePlatformAdapter):
or os.getenv("ZULIP_POLL_INTERVAL", str(DEFAULT_POLL_INTERVAL)) or os.getenv("ZULIP_POLL_INTERVAL", str(DEFAULT_POLL_INTERVAL))
) )
# --- Gen 4: Connection health ---
self._consecutive_empty_polls: int = 0
self._total_poll_count: int = 0
self._last_event_received_time: float = time.time()
self._last_heartbeat_time: float = 0.0
self._client_pool_reset_count: int = 0
# --- State --- # --- State ---
# Support both ZULIP_SITE and ZULIP_URL env vars
if not self._site:
self._site = (os.getenv("ZULIP_URL", "") or "").rstrip("/")
self._auth_header: str = _build_auth_header(self._email, self._api_key) self._auth_header: str = _build_auth_header(self._email, self._api_key)
self._queue_id: Optional[str] = None self._queue_id: Optional[str] = None
self._last_event_id: int = -1 self._last_event_id: int = -1
@@ -201,7 +228,7 @@ class ZulipAdapter(BasePlatformAdapter):
# --- Gen 3: Health stats callback --- # --- Gen 3: Health stats callback ---
self._health_callback = None self._health_callback = None
self._health_callback_interval: int = 600 # 10 min self._health_callback_interval: int = 300 # 5 min
@staticmethod @staticmethod
def _resolve_int(val: Any, default: int) -> int: def _resolve_int(val: Any, default: int) -> int:
@@ -238,11 +265,16 @@ class ZulipAdapter(BasePlatformAdapter):
return False return False
try: try:
self._http_client = httpx.AsyncClient(timeout=30.0) await self._create_http_client()
self._health_stats["started_at"] = datetime.now(timezone.utc).isoformat() self._health_stats["started_at"] = datetime.now(timezone.utc).isoformat()
# Reset connection health counters
self._consecutive_empty_polls = 0
self._total_poll_count = 0
self._last_event_received_time = time.time()
# Register event queue # Register event queue
queue_resp = await self._api_call( queue_resp, _ = await self._api_call(
"POST", "/api/v1/register", "POST", "/api/v1/register",
data={ data={
"event_types": '["message"]', "event_types": '["message"]',
@@ -259,6 +291,11 @@ class ZulipAdapter(BasePlatformAdapter):
self._last_event_id = data.get("last_event_id", -1) self._last_event_id = data.get("last_event_id", -1)
self._bot_user_id = data.get("user_id") self._bot_user_id = data.get("user_id")
# Resolve bot user_id if register endpoint didn't provide it
# (common on some Zulip versions)
if self._bot_user_id is None:
await self._resolve_bot_user_id()
# Gen 2: Try to resolve @all-bots user ID dynamically # Gen 2: Try to resolve @all-bots user ID dynamically
await self._resolve_all_bots_user_id() await self._resolve_all_bots_user_id()
@@ -337,24 +374,94 @@ class ZulipAdapter(BasePlatformAdapter):
try: try:
events = await self._fetch_events() events = await self._fetch_events()
self._health_stats["poll_count"] += 1 self._health_stats["poll_count"] += 1
self._total_poll_count += 1
self._health_stats["last_poll_at"] = datetime.now( self._health_stats["last_poll_at"] = datetime.now(
timezone.utc timezone.utc
).isoformat() ).isoformat()
for event in events:
try: if events:
await self._process_zulip_event(event) now = time.time()
except Exception as e: self._consecutive_empty_polls = 0
# Gen 3: Malformed message resilience — catch per-event self._last_event_received_time = now
# failures so one bad message never kills the poll loop for event in events:
try:
await self._process_zulip_event(event)
except Exception as e:
# Gen 3: Malformed message resilience — catch per-event
# failures so one bad message never kills the poll loop
logger.warning(
"[%s] Malformed event skipped: %s. "
"Event id=%s",
self.name, e,
event.get("id", "unknown"),
)
self._health_stats["malformed_events"] = (
self._health_stats.get("malformed_events", 0) + 1
)
else:
# Gen 4: Track consecutive empty polls to detect silent failures
self._consecutive_empty_polls += 1
# Gen 4: Detect prolonged silence (no events for too long)
silence_duration = time.time() - self._last_event_received_time
if silence_duration > POLL_SILENCE_WARN_INTERVAL:
logger.warning( logger.warning(
"[%s] Malformed event skipped: %s. " "[%s] No events received for %.0fs "
"Event id=%s", "(consecutive_empty=%d, total_polls=%d, "
self.name, e, "queue=%s)",
event.get("id", "unknown"), self.name, silence_duration,
self._consecutive_empty_polls,
self._total_poll_count,
self._queue_id,
) )
self._health_stats["malformed_events"] = (
self._health_stats.get("malformed_events", 0) + 1 # Gen 4: Reset HTTP client if too many empty polls in a row
# (connection pool likely stuck in CLOSE-WAIT)
if (
self._consecutive_empty_polls
>= MAX_CONSECUTIVE_EMPTY_POLLS
):
logger.warning(
"[%s] %d consecutive empty polls — "
"recreating HTTP client and reconnecting",
self.name, self._consecutive_empty_polls,
) )
await self._reconnect_with_fresh_client()
backoff_idx = 0
self._consecutive_empty_polls = 0
continue
# Gen 4: Periodic client refresh to prevent connection leaks
if self._total_poll_count % CLIENT_REUSE_LIMIT == 0:
logger.info(
"[%s] Client reuse limit reached (%d polls) — "
"creating fresh HTTP client",
self.name, self._total_poll_count,
)
old_client = self._http_client
await self._create_http_client()
if old_client:
try:
await old_client.aclose()
except Exception:
pass
# Gen 4: Heartbeat logging — prove poll loop is alive
now = time.time()
if now - self._last_heartbeat_time > HEARTBEAT_INTERVAL:
self._last_heartbeat_time = now
silence = now - self._last_event_received_time
logger.info(
"[%s] Heartbeat — polls=%d empty=%d "
"silence=%.0fs errors=%d reconnects=%d "
"queue=%s",
self.name, self._total_poll_count,
self._consecutive_empty_polls, silence,
self._health_stats["poll_errors"],
self._health_stats["reconnects"],
self._queue_id,
)
backoff_idx = 0 backoff_idx = 0
except asyncio.CancelledError: except asyncio.CancelledError:
break break
@@ -370,7 +477,7 @@ class ZulipAdapter(BasePlatformAdapter):
err_str = str(e) err_str = str(e)
if "BAD_EVENT_QUEUE_ID" in err_str or "queue_id" in err_str.lower(): if "BAD_EVENT_QUEUE_ID" in err_str or "queue_id" in err_str.lower():
logger.info("[%s] Queue expired, re-registering...", self.name) logger.info("[%s] Queue expired, re-registering...", self.name)
await self._reconnect() await self._reconnect_with_fresh_client()
backoff_idx = 0 backoff_idx = 0
continue continue
logger.warning("[%s] Poll error: %s", self.name, e) logger.warning("[%s] Poll error: %s", self.name, e)
@@ -381,11 +488,15 @@ class ZulipAdapter(BasePlatformAdapter):
await asyncio.sleep(self._poll_interval) await asyncio.sleep(self._poll_interval)
async def _fetch_events(self) -> List[Dict[str, Any]]: async def _fetch_events(self) -> List[Dict[str, Any]]:
"""Fetch events from the Zulip event queue.""" """Fetch events from the Zulip event queue.
Raises RuntimeError with BAD_EVENT_QUEUE_ID when the queue
expires, so _poll_forever can reconnect.
"""
if not self._queue_id: if not self._queue_id:
return [] return []
resp = await self._api_call( resp, raw_status = await self._api_call(
"GET", "/api/v1/events", "GET", "/api/v1/events",
params={ params={
"queue_id": self._queue_id, "queue_id": self._queue_id,
@@ -393,6 +504,9 @@ class ZulipAdapter(BasePlatformAdapter):
"dont_block": "true", "dont_block": "true",
}, },
) )
# Detect queue expiry from HTTP response
if raw_status == 400:
raise RuntimeError("BAD_EVENT_QUEUE_ID: queue expired")
if not resp: if not resp:
return [] return []
@@ -405,11 +519,33 @@ class ZulipAdapter(BasePlatformAdapter):
return [e for e in events if e.get("type") == "message"] return [e for e in events if e.get("type") == "message"]
async def _create_http_client(self) -> None:
"""Create a fresh httpx client, closing the old one if it exists.
Gen 4: This ensures a clean connection pool after sustained failures
or queue expiry, preventing CLOSE-WAIT socket leaks.
"""
old_client = self._http_client
self._http_client = httpx.AsyncClient(
timeout=httpx.Timeout(30.0, connect=15.0),
limits=httpx.Limits(
max_keepalive_connections=5,
max_connections=10,
keepalive_expiry=60.0,
),
)
self._client_pool_reset_count += 1
if old_client:
try:
await old_client.aclose()
except Exception:
pass
async def _reconnect(self) -> None: async def _reconnect(self) -> None:
"""Re-register the event queue.""" """Re-register the event queue."""
self._queue_id = None self._queue_id = None
try: try:
resp = await self._api_call( resp, _ = await self._api_call(
"POST", "/api/v1/register", "POST", "/api/v1/register",
data={ data={
"event_types": '["message"]', "event_types": '["message"]',
@@ -422,9 +558,21 @@ class ZulipAdapter(BasePlatformAdapter):
self._last_event_id = resp.get("last_event_id", -1) self._last_event_id = resp.get("last_event_id", -1)
self._health_stats["reconnects"] += 1 self._health_stats["reconnects"] += 1
logger.info("[%s] Reconnected, queue=%s", self.name, self._queue_id) logger.info("[%s] Reconnected, queue=%s", self.name, self._queue_id)
self._consecutive_empty_polls = 0
self._last_event_received_time = time.time()
except Exception as e: except Exception as e:
logger.error("[%s] Reconnect failed: %s", self.name, e) logger.error("[%s] Reconnect failed: %s", self.name, e)
async def _reconnect_with_fresh_client(self) -> None:
"""Re-register the event queue with a fresh HTTP client.
Gen 4: Creates a new httpx client to break out of stuck connection
pools (CLOSE-WAIT sockets from previous failures).
"""
logger.info("[%s] Reconnecting with fresh HTTP client", self.name)
await self._create_http_client()
await self._reconnect()
# ------------------------------------------------------------------ # ------------------------------------------------------------------
# Gen 2: Background dedup maintenance # Gen 2: Background dedup maintenance
# ------------------------------------------------------------------ # ------------------------------------------------------------------
@@ -496,6 +644,32 @@ class ZulipAdapter(BasePlatformAdapter):
"[%s] @all-bots refresh error (non-fatal)", self.name "[%s] @all-bots refresh error (non-fatal)", self.name
) )
# ------------------------------------------------------------------
# Gen 5: Bot user ID resolution
# ------------------------------------------------------------------
async def _resolve_bot_user_id(self) -> None:
"""Fetch the bot's own user ID from /api/v1/users/me.
The /register endpoint does not always return user_id on
all Zulip server versions. This ensures @mention detection
works by resolving it from the identity endpoint.
"""
try:
resp, _ = await self._api_call("GET", "/api/v1/users/me")
if resp:
uid = resp.get("user_id")
if uid is not None:
self._bot_user_id = int(uid)
logger.info(
"[%s] Resolved bot user_id=%s from /users/me",
self.name, uid,
)
except Exception as e:
logger.debug(
"[%s] Could not resolve bot user_id: %s", self.name, e
)
# ------------------------------------------------------------------ # ------------------------------------------------------------------
# Gen 2: Dynamic @all-bots resolution # Gen 2: Dynamic @all-bots resolution
# ------------------------------------------------------------------ # ------------------------------------------------------------------
@@ -506,7 +680,7 @@ class ZulipAdapter(BasePlatformAdapter):
Falls back to the configured or default value if resolution fails. Falls back to the configured or default value if resolution fails.
""" """
try: try:
resp = await self._api_call("GET", "/api/v1/users") resp, _ = await self._api_call("GET", "/api/v1/users")
if not resp: if not resp:
return return
members = resp.get("members", []) members = resp.get("members", [])
@@ -727,10 +901,7 @@ class ZulipAdapter(BasePlatformAdapter):
self._health_stats["send_count"] += 1 self._health_stats["send_count"] += 1
return SendResult( return SendResult(
success=True, success=True,
platform="zulip",
chat_id=chat_id,
message_id=msg_id, message_id=msg_id,
metadata={"placeholder": True},
) )
# Send actual content # Send actual content
@@ -739,16 +910,12 @@ class ZulipAdapter(BasePlatformAdapter):
self._health_stats["send_count"] += 1 self._health_stats["send_count"] += 1
return SendResult( return SendResult(
success=True, success=True,
platform="zulip",
chat_id=chat_id,
message_id=str(result["id"]), message_id=str(result["id"]),
) )
self._health_stats["send_errors"] += 1 self._health_stats["send_errors"] += 1
return SendResult( return SendResult(
success=False, success=False,
platform="zulip",
chat_id=chat_id,
error="Failed to send message", error="Failed to send message",
) )
@@ -766,7 +933,7 @@ class ZulipAdapter(BasePlatformAdapter):
"content": truncated, "content": truncated,
} }
try: try:
resp = await self._api_call("PATCH", "/api/v1/messages", data=payload) resp, _ = await self._api_call("PATCH", "/api/v1/messages", data=payload)
return resp is not None return resp is not None
except Exception as e: except Exception as e:
logger.warning("[%s] Edit message %s error: %s", self.name, message_id, e) logger.warning("[%s] Edit message %s error: %s", self.name, message_id, e)
@@ -782,6 +949,7 @@ class ZulipAdapter(BasePlatformAdapter):
"POST", "/api/v1/typing", "POST", "/api/v1/typing",
data={"to": user_ids, "op": "start"}, data={"to": user_ids, "op": "start"},
) )
# typing indicator failure is non-critical
except Exception: except Exception:
pass # Non-critical pass # Non-critical
@@ -795,6 +963,7 @@ class ZulipAdapter(BasePlatformAdapter):
"POST", "/api/v1/typing", "POST", "/api/v1/typing",
data={"to": user_ids, "op": "stop"}, data={"to": user_ids, "op": "stop"},
) )
# typing indicator failure is non-critical
except Exception: except Exception:
pass # Non-critical pass # Non-critical
@@ -990,6 +1159,10 @@ class ZulipAdapter(BasePlatformAdapter):
stats["all_bots_user_id"] = self._all_bots_user_id stats["all_bots_user_id"] = self._all_bots_user_id
stats["connected"] = self._connected stats["connected"] = self._connected
stats["checked_at"] = now.isoformat() stats["checked_at"] = now.isoformat()
stats["total_polls"] = self._total_poll_count
stats["consecutive_empty_polls"] = self._consecutive_empty_polls
stats["client_pool_resets"] = self._client_pool_reset_count
stats["silence_seconds"] = round(time.time() - self._last_event_received_time)
# Compute error rate # Compute error rate
total_polls = stats.get("poll_count", 0) or 1 total_polls = stats.get("poll_count", 0) or 1
@@ -1009,10 +1182,15 @@ class ZulipAdapter(BasePlatformAdapter):
path: str, path: str,
data: Optional[Dict] = None, data: Optional[Dict] = None,
params: Optional[Dict] = None, params: Optional[Dict] = None,
) -> Optional[Dict]: ) -> Tuple[Optional[Dict], int]:
"""Make an API call to Zulip.""" """Make an API call to Zulip.
Returns (response_json, status_code). status_code is useful for
callers that need to detect specific HTTP errors like 400
(BAD_EVENT_QUEUE_ID). Returns (None, 0) on transport errors.
"""
if not self._http_client: if not self._http_client:
return None return None, 0
url = f"{self._site}{path}" url = f"{self._site}{path}"
headers = { headers = {
@@ -1033,28 +1211,31 @@ class ZulipAdapter(BasePlatformAdapter):
url, data=data, headers=headers, url, data=data, headers=headers,
) )
else: else:
return None return None, 0
if response.status_code >= 400: if response.status_code >= 400:
# Gen 4: Truncate error bodies to prevent HTML spam
body = response.text[:MAX_ERROR_LOG_LEN].replace("\n", " ")
logger.warning( logger.warning(
"[%s] API %s %s: %d %s", "[%s] API %s %s: %d %s",
self.name, method, path, self.name, method, path,
response.status_code, response.text[:200], response.status_code, body,
) )
return None return None, response.status_code
return response.json() return response.json(), response.status_code
except httpx.TimeoutException: except httpx.TimeoutException:
logger.debug("[%s] Timeout on %s %s", self.name, method, path) logger.debug("[%s] Timeout on %s %s", self.name, method, path)
return None return None, 0
except Exception as e: except Exception as e:
logger.warning("[%s] API error %s %s: %s", self.name, method, path, e) logger.warning("[%s] API error %s %s: %s", self.name, method, path, e)
return None return None, 0
async def _send_api_call(self, payload: Dict) -> Optional[Dict]: async def _send_api_call(self, payload: Dict) -> Optional[Dict]:
"""Send a message to Zulip.""" """Send a message to Zulip."""
return await self._api_call("POST", "/api/v1/messages", data=payload) result, _ = await self._api_call("POST", "/api/v1/messages", data=payload)
return result
# ------------------------------------------------------------------ # ------------------------------------------------------------------
# Utilities # Utilities