From 75f377fd4d287fff3d2ad68e78cdcfbf92ecf3e3 Mon Sep 17 00:00:00 2001 From: JianFeeeee Date: Mon, 14 Sep 2026 11:15:21 +0800 Subject: [PATCH] =?UTF-8?q?fix(remotedevice):=20=E5=BF=83=E8=B7=B3=20pong?= =?UTF-8?q?=20=E5=BF=98=E4=BA=86=20Flush=20=E2=80=94=E2=80=94=20=E4=BF=AE?= =?UTF-8?q?=E3=80=8C=E8=AE=BE=E5=A4=87=E9=80=9A=E9=81=93=E6=AF=8F=2060=20?= =?UTF-8?q?=E7=A7=92=E6=8E=89=E7=BA=BF=E9=87=8D=E8=BF=9E=E3=80=8D?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 真因(实测定位):服务端 writePong 只调 writeFrameHeader,**不 Flush**。 pong 只有两个字节,且设备空闲时没有任何别的写会顺带把 bufio 缓冲刷出去 —— 于是 pong 永远留在服务端缓冲里。 链路:客户端每 30s 发一个 ping(pingLoop)→ 服务端算出 pong 却没发出 → 客户端的读循环设的是「2 倍 ping 间隔」读超时(默认 60s)→ 每 60 秒准点 i/o timeout → 桥断开 → 3s 后重连 → 服务端 markOffline 注销 outputch, 重连后再注册。 生产日志就是这个指纹(online :20 → offline 下一分钟 :20 → 重连 :23, 连续数小时无一次例外);面板上表现为设备通道/工具凭空消失又出现, /devices 列表跟着闪。 改法:writePong 复用 writeFrame(它 Flush)。另把客户端读循环退出时的 静默 return 改成带错误与 opcode 的日志 —— 此前断线真因在设备侧完全不可见, 只能靠对端日志倒推,正是这次排查一开始卡住的地方。 回归用例 TestWSPingGetsPongWhileIdle:只发一个 ping,随后什么都不发, 要求 2s 内必须收到 pong。**反向验证过**:把修复改回 writeFrameHeader, 用例即以 `read tcp ...: i/o timeout` 失败(与生产症状一致)。 --- internal/devicebridge/client/bridge.go | 7 ++- internal/plugins/remotedevice/ping_test.go | 53 ++++++++++++++++++++++ internal/plugins/remotedevice/registry.go | 8 +++- 3 files changed, 66 insertions(+), 2 deletions(-) create mode 100644 internal/plugins/remotedevice/ping_test.go diff --git a/internal/devicebridge/client/bridge.go b/internal/devicebridge/client/bridge.go index af74ebe..639c549 100644 --- a/internal/devicebridge/client/bridge.go +++ b/internal/devicebridge/client/bridge.go @@ -411,7 +411,12 @@ func (b *Bridge) readLoop() { _ = ws.writePong() continue } - // 超时或其他错误,退出 + // 超时或其他错误,退出。 + // + // **必须记日志**:此前这里静默 return,设备断线的真因(读超时 / 对端 + // 关闭 / 帧错)在设备侧完全不可见,只能靠对端日志倒推。 + // 2 倍 ping 间隔内的读超时通常是“心跳没人回”——查服务端 writePong 是否真发出。 + log.Printf("[devicebridge] read loop exit (opcode=%#x, close=%v): %v", opcode, isClose, err) return } if isClose { diff --git a/internal/plugins/remotedevice/ping_test.go b/internal/plugins/remotedevice/ping_test.go new file mode 100644 index 0000000..b8dd66b --- /dev/null +++ b/internal/plugins/remotedevice/ping_test.go @@ -0,0 +1,53 @@ +package remotedevice + +import ( + "net/http" + "net/http/httptest" + "testing" + "time" +) + +// 心跳回包必须**真的发出去**:pong 只有两个字节,且设备空闲时没有任何别的写 +// 会顺带把 bufio 缓冲刷出去——`writePong` 一旦忘了 Flush,pong 就永远留在 +// 服务端缓冲里。 +// +// 这就是「device channel 不稳定」的真因(实测):客户端每 30s 发一个 ping, +// 服务端算好了 pong 却没发;客户端的读循环设的是 2 倍 ping 间隔(默认 60s) +// 读超时,于是**每 60 秒准点断开一次**,重连后 outputch 被注销又注册, +// 模型侧看到的就是工具/通道凭空消失又出现。 +// +// 本用例只发一个 ping,随后**什么都不发**:pong 必须在无后续流量的情况下到达。 +func TestWSPingGetsPongWhileIdle(t *testing.T) { + reg := NewRegistry() + token := "test-token-ping" + reg.SetAcceptToken(func(provided string) bool { return provided == token }) + + srv := httptest.NewServer(http.HandlerFunc(reg.ServeWS)) + defer srv.Close() + + cli := dialTestWS(t, srv.URL, token) + defer cli.close() + + // 先走完 hello + bind(服务端要先把设备登记进 conns,pong 才写得回来)。 + cli.sendText([]byte(`{"op":"hello","device":{"device_id":"ping-dev","name":"前端机","kind":"computer","caps":["cmd"]}}`)) + cli.readHelloAckAndBind(t, token) + + cli.sendFrame(0x9, nil) // ping + + if err := cli.conn.SetReadDeadline(time.Now().Add(2 * time.Second)); err != nil { + t.Fatalf("set read deadline: %v", err) + } + payload, isClose, opcode, err := readFrame(cli.rw.Reader) + if err != nil { + t.Fatalf("2s 内没收到 pong(writePong 忘了 Flush?): %v", err) + } + if isClose { + t.Fatal("连接被关闭,而不是回了 pong") + } + if opcode != 0xa { + t.Fatalf("期望 pong(0xa),实际 opcode=%#x payload=%q", opcode, payload) + } + if len(payload) != 0 { + t.Fatalf("pong 不该带负载,实际 %q", payload) + } +} diff --git a/internal/plugins/remotedevice/registry.go b/internal/plugins/remotedevice/registry.go index 0bb3c8c..31b5499 100644 --- a/internal/plugins/remotedevice/registry.go +++ b/internal/plugins/remotedevice/registry.go @@ -606,7 +606,13 @@ func writeFrame(w *bufio.Writer, opcode byte, payload []byte) error { } func writePong(w *bufio.Writer) error { - return writeFrameHeader(w, 0xa, 0) + // 必须走 writeFrame(它 Flush)。 + // + // 回归的 bug:这里原先是裸的 writeFrameHeader,**不 Flush**。设备空闲时 + // 没有任何别的写会顺带把 bufio 缓冲刷出去,于是 pong 永远留在服务端缓冲里, + // 客户端等 2 倍 ping 间隔(默认 30s×2 = 60s)读超时断开、重连—— + // 实测表现就是「设备通道每 60 秒掉线一次」,连带着 outputch 反复注销/注册。 + return writeFrame(w, 0xa, nil) } func writeFrameHeader(w *bufio.Writer, opcode byte, length int) error {