手机端语音识别"成功了却报失败":一次 WebSocket 关闭握手的排查
我的笔记应用里有个语音转文字功能:浏览器通过 WebSocket 把音频发给 Go 服务端,服务端再转给通义千问的实时识别接口,识别结果沿原路推回网页。
最近发现一个怪问题。电脑上用一切正常;手机上说完点"结束",文字明明已经完整显示出来了,紧接着却弹出"识别失败"。去翻后台日志,千问和服务端都显示任务正常结束,没有任何报错。
后台说成功,前台说失败,文字又都在。下面记录一下是怎么查出来的。
先分清三个"完成"
这条链路上其实有三种"完成",一开始我也没分清,日志越看越糊涂。
| 消息 | 方向 | 含义 | 之后还能继续说吗 |
|---|---|---|---|
final | 服务端 → 网页 | 某一句话识别完了 | 能 |
task-finished | 千问 → 服务端 | 千问整次识别任务结束 | 不能 |
completed | 服务端 → 网页 | 通知网页提交整段结果、退出转写状态 | 不能 |
手机上看到的文字来自一条条 final,而前端判断整段成功,靠的是最后那条 completed。所以文字都在,并不能说明 completed 到了。
日志
为了排查,我临时让手机客户端上报状态,用录音编号把前后端日志串起来。复现一次后拿到这样一组记录(北京时间):
| 时间 | 记录 |
|---|---|
| 17:01:44.636 | 服务端收到并转发结束指令 |
| 17:01:45.039 | 千问返回 task-finished;服务端记录 reason=completed,无错误 |
| 17:01:45.603 | 手机上报 socket_error,最后收到的是 final,completed_received=false |
手机上报的客户端版本也是最新的,可以排除缓存了旧代码。
到这里问题就清楚一半了:服务端 WriteMessage 返回成功,只代表数据写进了本机内核的发送缓冲区,对面的 JavaScript 有没有触发 onmessage,服务端是不知道的。千问正常结束、服务端写出了 completed、手机没读到它,这三件事可以同时成立。前端的错误分支会保留已有的 final 文字再弹失败提示,正好就是我看到的样子。
根因:defer conn.Close()
接着看服务端代码,处理函数大概长这样:
func handleASR(w http.ResponseWriter, r *http.Request) {
conn, _ := upgrader.Upgrade(w, r, nil)
defer conn.Close()
// ... 转发音频、推送 final ...
conn.WriteJSON(Msg{Type: "completed"})
return
}
问题出在 defer conn.Close()。Gorilla WebSocket 的 Close() 只是关掉底层网络连接,既不发 Close 帧,也不等对方回应。按 RFC 6455,正常结束应该是一方发 Close 帧、另一方回一个 Close 帧,然后再断 TCP。少了这一步,浏览器看到的就是连接突然没了,关闭码 1006(abnormal closure),同时触发 onerror。
我补了一个回归测试:客户端读完 completed 后继续读,断言关闭码是 1000。在原代码上跑,拿到的确实是 1006。
为什么只有手机出问题
completed 和连接断开几乎同时到达浏览器,先处理哪个决定了成败,本质是个竞态。至于手机为什么更容易输,下面是我的推测,没有在手机上抓包验证过:
- 服务端关 socket 时,如果接收缓冲区里还有没读的数据(比如手机在点结束前后又发了几帧音频),内核会发 RST 而不是 FIN。对端收到 RST 后,可能把缓冲区里还没交给应用的数据一起丢掉,
completed就到不了 JavaScript。 - 电脑主线程比较闲,数据一到就被读走,等 RST 到的时候
completed早处理完了。手机刚停止录音、还在收拾音频,主线程更忙,这个窗口被拉长了。 - 蜂窝网络、代理、TLS 这些中间环节也会影响最后几个包的到达时机。
日志里手机报错比服务端写出 completed 晚了约 564 毫秒,消息已经在路上了,只是在被应用处理之前就先遇到了断开。
具体是哪种机制我不能确定,但根子是同一个:服务端没做关闭握手。电脑上没出问题,只是赢了这个竞态而已。
修复
收尾顺序改成:
- 写出
completed - 发送
Close(1000) - 由已有的读循环接收对端的 Close 回应,最多等 2 秒
- 释放底层连接
conn.WriteJSON(Msg{Type: "completed"})
msg := websocket.FormatCloseMessage(websocket.CloseNormalClosure, "done")
conn.WriteControl(websocket.CloseMessage, msg, time.Now().Add(time.Second))
// 等已有的读循环收到对端 Close 后退出
select {
case <-readLoopDone:
case <-time.After(2 * time.Second):
}
conn.Close()
有几个地方需要注意。
不要为了等回应另开一个 goroutine 去 ReadMessage。Gorilla 同一时间只允许一个读取者,直接复用已有的读循环就行:它收到对端的 Close 帧会返回 CloseError,退出时通知收尾逻辑。
这 2 秒用户感觉不到。浏览器收到 completed 就立刻显示结果了,2 秒只是服务端释放连接的上限,防止对端不回应时连接一直挂着。
前端不用改。浏览器收到 Close 帧会自动回应,onclose 拿到的 event.code 是 1000,onerror 不会再触发。另外,发完 Close 帧后服务端还在读,接收缓冲区会被读空,也就不会因为残留数据触发 RST。
修复后回归测试拿到了 1000,go test -race 和前端测试也都过了。
如果你也在用 WebSocket 推流式结果
语音识别、大模型流式输出、进度推送这类场景,可以检查一下:
- 发完最后一条"完成"消息后,是不是马上调了底层
Close()、取消了 context,或者有清理回调把连接切了? - 前端有没有把"一句结束"和"整次结束"分开处理?文字到了但完成通知没到时,会表现成什么样?
- 测试除了验证收到文字,有没有断言最终关闭码是
1000? - 等待关闭回应时,是不是复用了已有的读循环?