ws.Client reconnect loop can hang forever: requests.post in _get_conn_url() has no timeout

オープン
#169 コメント 0 件 リアクション 0 件 担当者 0 名 GitHub で見る

まだ誰も着手していません。

評価

難易度
3/5
見積もり時間
1〜2日
初心者へのやさしさ
68/100
issue の種類
バグ
明瞭さ
おおむね明確
活発さ
活発
技術スタック
python
領域
networking

調査の方向性

lark_oapi/ws/client.py の _get_conn_url() から開始し、_reconnect() 中に _try_connect() がリクエストの失敗をどのように処理するかを追跡します。エンドポイント検出リクエストに上限付きのタイムアウトを追加し、タイムアウトが接続失敗としてログに記録され、その後の再接続試行が継続されることを確認します。また、_connect() の早期リターンするロックのパスも調べ、接続がすでに存在する場合にロックが解放されることを確認します。

索引モデルが issue の本文から書いたものです。

説明

Summary

lark_oapi.ws.Client's auto-reconnect can wedge permanently. When a reconnect attempt
reaches _get_conn_url(), the SDK issues a requests.post with no timeout. If that
TCP connection is established but the server never responds (a half-open connection after
a network blip — common on mobile/NAT/VPN links), the call blocks forever.

Because _connect() holds self._lock across that call and _reconnect() drives attempts
sequentially, the entire reconnect loop stops. No further attempt is ever made, no error
is logged, and the process stays alive and otherwise healthy. The bot goes permanently deaf
with no signal.

Observed in production: a Feishu bot was silently unreachable for 3 days 13 hours.

Version

  • lark-oapi==1.6.8
  • Python 3.11, Linux (also reproducible in principle on macOS — same code path)

Root cause

lark_oapi/ws/client.py, in _get_conn_url():

response = requests.post(
    self._domain + GEN_ENDPOINT_URI,   # -> open.feishu.cn/callback/ws/endpoint
    headers=headers,
    json={
        "AppID": self._app_id,
        "AppSecret": self._app_secret,
    },
)

There is no timeout= argument. requests defaults to no timeout, i.e. block
indefinitely. The string timeout does not appear anywhere in that 432-line module.

Why this call specifically: websockets.connect() carries its own open_timeout, so
websocket handshake failures surface promptly and the loop retries correctly. This
requests.post is the only call on the reconnect path with no timeout at all, so it is
the only place that can hang forever.

Two aggravating factors in the same function:

  1. _connect() acquires self._lock before the call and only releases it in the finally
    of the following try, so the lock is held for the entire (unbounded) request. Anything
    else needing the lock also blocks.

  2. _connect() early-returns while still holding the lock when self._conn is not None,
    because the return sits before the try/finally that releases it:

    async def _connect(self) -> None:
        await self._lock.acquire()
        if self._conn is not None:
            return            # lock never released on this path
        try:
            ...
        finally:
            self._lock.release()
    

    This is a separate latent lock leak; it was not the trigger in our incident
    (_conn was None after the disconnect) but it lives in the same function.

Observed log signature

The log simply stops mid-sequence — this is the whole tell:

21:58:15  receive message loop exit, err: sent 1011 (internal error) keepalive ping timeout
21:58:27  trying to reconnect for the 1st time
21:59:09  connect failed, err: timed out during opening handshake
22:01:09  trying to reconnect for the 2nd time
22:01:29  connect failed, err: NameResolutionError ... Failed to resolve 'open.feishu.cn'
22:03:29  trying to reconnect for the 3rd time
22:04:27  connect failed, err: timed out during opening handshake
22:06:27  trying to reconnect for the 4th time   -> NameResolutionError
22:08:47  trying to reconnect for the 5th time   -> NameResolutionError
22:11:07  trying to reconnect for the 6th time
<nothing, ever again>

The 6th attempt produced neither success nor failure. Note the loop is otherwise
infinite (_reconnect_count = -1 -> while True), so "the log stops" is not exhaustion.

How to confirm it is this bug (no debugger needed)

The SDK talks to two different hosts, which resolve to different addresses:
open.feishu.cn for endpoint discovery, msg-frontier.feishu.cn for the websocket.
So the peer address of the surviving socket localises the hang exactly:

ss -tnpi | grep "pid=<pid>"          # Linux
lsof -nP -a -p <pid> -iTCP -sTCP:ESTABLISHED   # macOS (the -a is required)
getent hosts open.feishu.cn msg-frontier.feishu.cn

In our case the process held exactly one ESTABLISHED socket, and its peer was an
open.feishu.cn address — never msg-frontier — proving it never got past endpoint
discovery. The kernel counters on that socket also dated the hang without any log:

rto:32432  bytes_sent:2936  bytes_retrans:1400  segs_out:13  segs_in:2
lastsnd:308129793  lastrcv:308160186  retrans:0/9

lastrcv is in milliseconds: ~85.6 hours of total silence on a socket still reported
ESTAB, with 9 exhausted retransmissions. A textbook half-open connection.

Why this is worse than a normal outage

Every layer that would normally catch a dead bot reports healthy:

  • The process does not exit, so Restart=always / KeepAlive supervisors never fire.
    Only one thread is wedged; everything else keeps running.
  • Any cached "connected" state stays connected, because the adapter never learns otherwise.
  • An HTTP /health probe on the host process succeeds — the asyncio event loop is fine.

The only signal that discriminates is whether the process still holds a connection to a
msg-frontier address. We ended up writing an external watchdog around exactly that check.

Suggested fix

Give the request a timeout — a few lines, no behaviour change in the healthy path:

-    response = requests.post(
-        self._domain + GEN_ENDPOINT_URI,
-        headers=headers,
-        json={
-            "AppID": self._app_id,
-            "AppSecret": self._app_secret,
-        },
-    )
+    response = requests.post(
+        self._domain + GEN_ENDPOINT_URI,
+        headers=headers,
+        json={
+            "AppID": self._app_id,
+            "AppSecret": self._app_secret,
+        },
+        timeout=(CONNECT_TIMEOUT, READ_TIMEOUT),   # e.g. (10, 30), ideally configurable
+    )

A requests.exceptions.Timeout here is already handled correctly: _try_connect() catches
generic exceptions, logs connect failed, returns False, and the loop proceeds to the next
attempt — which is exactly the desired behaviour.

Worth fixing alongside, in the same function:

  • Release the lock on the self._conn is not None early-return path (move the check inside
    the try, or release before returning).
  • Consider not holding self._lock across a blocking network call at all.

Impact

Any long-running deployment loses its Feishu/Lark connection permanently after a single
unlucky network blip, with no crash, no error, and no log line to alert on. Recovery requires
a manual process restart. Given lark-oapi is pinned by downstream frameworks
(we hit it via a pinned lark-oapi==1.6.8), affected users cannot work around it by upgrading
a dependency of their own.

主要言語
Python
スター
559
フォーク
102
PR マージ指標
30日以内にマージされた PR はありません

コントリビューションガイド

このリポジトリのコントリビューションガイドは索引されていません

はじめの一歩

  1. issue を最後まで読み、次にプロジェクトのコントリビューションガイドを読みます。
  2. 着手することを issue にコメントします — 二人が同じ作業をするのを防げます。
  3. リポジトリをフォークし、ブランチを切って変更します。
  4. issue 番号を参照したプルリクエストを送ります。

larksuite/oapi-sdk-python のほかの issue

larksuite/oapi-sdk-python の issue をすべて見る

似ている issue

Python の issue をもっと見る

新しい issue をメールで受け取る

初心者向けの GitHub issue を短くまとめたダイジェスト。