记录使用 TSRPC 遇到重连事故
近期用 tsrpc 搭建了一个消息中转的服务。用起来的感觉挺爽的，但是团队是初次使用。以至于上线后碰到了下面两个事故。 👀
事故 1
心跳缺失导致的"幽灵连接"
因为用户属于全球化的。但是我们在测试服，网络属于比较稳定。工期也比较赶，没有模拟丢包和弱网环境。上线后，发现有的用户在长时间挂机后，接不到消息，只能发送消息。我第一时间想到，用户因该不在房间了。因为我用生命周期 postDisconnectFlow在客户端断开后，我会把他移出相关的房间。以至于拿到了房间号。只能告诉房间里的人，自己却不在房间。后面和前端对接了一下。说明了房间的机制，前端以为是断线没重连的问题，一直在各种场景加上断线了重连的逻辑connect()。好了以为没事了，他们在终端打印日志后，又发现没断线，会有 sendTimeOut 的错误。于是经过多次测试，发现只要挂机久，才会这样。
于是我查阅了作者之前的写的博客。 在 《TSRPC 3.3.0 更新！新增心跳检测，Log Level 支持》，发现要手动设置增心跳检测，心跳检测是长连接服务常见的机制。
没加心跳的连接方式
import { WsClient } from 'tsrpc-browser';
let client = new WsClient(serviceProto, {
server: 'ws://127.0.0.1:3000',
});
加心跳的连接方式
let client = new WsClient(serviceProto, {
// ...
heartbeat: {
// 两次心跳检测的间隔时间（毫秒）
interval: 3000,
// 发出心跳检测包后，多长时间未收到回复视为超时（毫秒），超时将使连接断开
timeout: 5000
}
});
于是前端加进去了，好了这次挂机一天也没有问题，一切都正常。测试那边也通过。😀
事故 2
重连机制的指数级雪崩
在客户端上了心跳之后，以为一切都好了。结果安装包过审发布后，服务器的流量和 cpu 使用度一直在飙升。我一查日志，有多个客户端一直在发包。
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34506 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34507 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34508 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34509 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34510 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34511 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 80.x.x.x Conn#8 [Api:user/Login] SN=34512 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 109.x.x.x Conn#11 [Api:user/Login] SN=1 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 69.x.x.x Conn#9 [Api:user/Login] SN=390 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 193.x.x.x Conn#10 [Api:user/Login] SN=33 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 193.x.x.x Conn#10 [Api:user/Login] SN=34 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 193.x.x.x Conn#10 [Api:user/Login] SN=35 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 193.x.x.x Conn#10 [Api:user/Login] SN=36 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 193.x.x.x Conn#10 [Api:user/Login] SN=37 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1110 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1111 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1112 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1113 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1114 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1115 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1116 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1117 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1118 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1119 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1120 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1121 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1122 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1123 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1124 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1125 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1126 [ApiReq]
<85744> 2024-09-18 18:56:12 [INFO] 67.x.x.x Conn#5 [Api:user/Login] SN=1127 [ApiReq]
.....
看了一下规则发包的速率还是递增的 , 个别 IP 的 SN 已经达到 220000 🥲,太恐怖了，第一反应该不会是 DDoS 吧，但是根据登录态查看了确实是用户。我就问前端，上次发版有没有在登录时写了什么循环逻辑。前端查了也没有。于是只能后端先排查了，我首先用了 iptables 去限制用户的发包评率。但是我发现除非限制所有用户，针对个别 ip 不是很管用。期间服务还宕机了一次，于是我把 nginx 给停了，好家伙，服务器就正常了。于是我看了一下前端写的代码发现了一个比较大的问题。
就是在上一次的版本时，加了很多重连的逻辑。导致每次连接都会新建一个实例，重连时框架会把所有断线的实例拿去发包。
我记得客户端写的代码大概如下 🧐。
export class TSRPCClientMgr {
... 省略
init() {
this.createClient();
this.connect();
}
connect() {
this.client.connect().then((res) => {
if (!res.isSucc) {
setTimeout(() => {
void this.connect();
}, 2000)
} else {
// --- 以下被多次执行 ---
// this.client.flows.postDisconnectFlow.nodes = [] // 先清空已有节点
this.client.flows.postDisconnectFlow.push(v => {
setTimeout(() => {
void this.reconnect();
}, 2000)
return v;
})
// --- 以上被多次执行 ---
this.unListenChatMsg();
this.listenChatMsg();
this.login();
}
});
}
async reconnect() {
await this.client.connect().then(((res) => {
if (!res.isSucc) {
setTimeout(() => {
this.reconnect();
}, 1000)
} else {
this.unListenChatMsg();
this.listenChatMsg();
this.login(vv.GameData.GetUserInfo().base.id);
}
}));
}
}
postDisconnectFlow.push 放在 connect() 内部，每次成功建立连接都会执行，因此会不断向 nodes 数组追加同一个回调。即每当发生断开连接时，nodes 中的所有回调函数都会被按顺序执行。所以在多处调用 this.connect()时，确实存在一个潜在问题：如果多次调用 this.client.flows.postDisconnectFlow.push()，会将多个回调函数添加到 nodes 断线处理节点中，每次重连时，都会一下子发起多个未处理的回调函数请。加上之前设置好心跳，客户端一直在重。
重连次数
可能会引起如下问题：
1. 重复重连：多个 this.connect() 调用在短时间内触发，可能导致并发连接、资源浪费或者连接冲突。
2. 性能问题：过多的重连请求会消耗客户端和服务器端的资源，造成性能下降，特别是如果有多个并发连接请求未正确处理时。
3. 状态混乱：如果客户端处于未连接状态，而多个重连请求同时进行，可能导致客户端状态不一致或者连接状态难以管理。
解决办法
只调用一次 client.flows.postDisconnectFlow.push函数
export class TSRPCClientMgr {
client!: WsClient<ServiceType>;
private connected = false;
init() {
this.createClient();
this.handleDisconnect();
void this.connect();
}
private handleDisconnect() {
this.client.flows.postDisconnectFlow.push(v => {
if (!v.isManual) {
setTimeout(() => {
SystemLogger.log('掉线了，开始重连');
void this.connect(); // 直接复用 connect
}, 2000);
}
return v;
});
}
connect(): Promise<{ isSucc: boolean }> {
return this.client.connect().then(res => {
this.connected = res.isSucc;
if (!res.isSucc) {
setTimeout(() => { void this.connect(); }, 2000);
} else {
this.unListenChatMsg();
this.listenChatMsg();
this.login();
}
return res;
});
}
async reconnect() {
const res = await this.connect();
if (!res.isSucc) {
setTimeout(() => { void this.reconnect(); }, 1000);
} else {
this.login(vv.GameData.GetUserInfo().base.id);
}
}
}
总结
- 全局事件处理器应在构造函数中一次性注册
- 避免在频繁调用的方法中添加事件监听器
- 使用标志位防止重复注册