关于ERR server connection close 报错问题分析和解决方案讨论 #208
Description
问题描述
在测试Predixy时客户端收到 ERR server connection close 报错，存在两种现象：
问题现象1：4个predixy中，偶发一个Pod 出现1-2次：ERR no server connection available报错， sacc服务1000 QPS 1-2天出现一次。Kvrocks自身监控正常。
问题现象：4个predixy中，偶发一个Pod 在一段时间内（30s-120s）特定Server请求全失败：ERR no server connection available，到其他Server请求成功，同时间段其他pod 请求正常。Kvrocks QPS有下降，但没有掉零。
部署架构：
- 后端存储采用Kvrocks， 分别是2分片2副本，共6个节点，故障期间kvrocks IP未变化，节点运行正常。
- predixy 分别4个pod， 使用statefulset 编排。
- 访问链路：client → LB → Predixy → Kvrocks
关键配置：
a. Kvrocks timeout 600：连接空闲超过10分钟会被关闭
b. Predixy ServerFailureLimit 10：每10次失败触发整Server连接FAILED状态
c. Predixy ServerRetryTimeout 3：Server端重连间隔3秒
排查结论：
现象1：Server端失败计数达到ServerFailureLimit后，触发Handler主动重连，在主动重连窗口期的请求会失败。
影响范围：主动重连窗口期为1ms左右，1-2个请求触发条件。
恢复机制：正常重连成功后即可恢复。
现象2：Server端失败计数达到ServerFailureLimit后，触发Handler主动重连，多Handler竞态条件下，因连接状态不一致触发死锁。
影响范围：在死锁期间，指定Server的请求全部失败。当前观察到的时间范围在30s-120之间。
恢复机制：只有等将Server判死的Handler重新抢到CAS锁进行重连，死锁才会消除。
2. 现象一：正常的主动重连导致请求失败
2.1 基本信息
持续时间: 1.518ms （实测）
错误次数: 1个
失败计数: 10 (10 % 10 == 0，第一次触发)
2.2 完整时序（实测，微秒级精度）
T+0μs (304637): H7 检测到连接错误
"read error Resource temporarily unavailable"
↓
T+13μs (304650): setFail(true) ← 服务器标记FAILED
mNextActivateTime = T + 3,000,000μs
"server marked as FAILED after 10 failures"
↓
T+39μs (304676): Socket::close() 完成
fd: 59 → -1
"socket closed: old_fd=59, new_fd=-1"
↓
T+43μs (304680): H7 check() 被调用 ← 事件驱动
"server is FAILED, attempting activate()"
↓
T+46μs (304683): H7 activate() CAS 成功
"activate() CAS result=SUCCESS"
↓
T+57μs (304694): reopen() 完成
"old_fd=-1, new_fd=59"
↓
T+93μs (304730): connect() 返回 EINPROGRESS
"::connect() returned: ret=-1, errno=115"
"EINPROGRESS: status=Connecting"
↓
T+105μs (304742): PING 发送完成
"sent PING command (req id=41214)"
"init() SUCCESS, waiting for PONG"
↓
┌────────────────────────────────┐
│ 错误窗口（1.518ms） │
├────────────────────────────────┤
T+1176μs (305813): │ H5 请求到达 → 被拒绝 │
│ "no server connection │
│ available" │
└────────────────────────────────┘
↓
T+1518μs (306155): H7 收到 PONG
setFail(false) ← 服务器恢复
"state changed: FAILED to ALIVE"
↓
T+1522μs (306159): 日志记录恢复
"received PONG, marking server as ALIVE"
2.3 关键测量数据
| 指标 | 实测值 |
| 错误检测→FAILED | 13μs |
| FAILED→check()触发 | 43μs ← 事件驱动 |
| check()→PING发送 | 62μs (304742-304680) |
| PING→PONG往返 | 1.413ms ← 正常网络RTT |
| 错误窗口总长 | 1.518ms |
| 受影响请求数 | 1个 |
2.4 根因分析
✅ Server连接主动重连期间，其他handler收到请求因Server fail而失败
1.
关键发现：✅ failCnt 累积到 10，触发 FAILED 状态（配置：每 10 次触发一次），触发主动重连
2.
✅ 主动重连由内部事件驱动，连接关闭后43μs即触发check()
3.
✅ 错误窗口 = FAILED 期间（~1.5ms），只影响1个请求
4.
✅ H7（关闭连接的Handler）获得activate()权限，立即reopen()成功
5.
✅ EINPROGRESS 是非阻塞connect()的正常行为
6.
✅ 网络RTT正常（1.4ms），连接建立成功
影响评估：
●
● ✅ 恢复非常快（事件驱动，1.5ms）
● ✅ 影响极小（QPS=1000时，1-2个请求）
● ✅ 自动恢复（无需人工介入）
3. 案例二：多Handler死锁
3.1 基本信息
时间: 2025-11-07 09:17:11 ~ 09:17:44
持续时间: 33.037秒
错误次数: 14个
失败计数: 60 → 61 (第6次触发)
状态: ✅ 已验证，明确代码BUG
3.2 完整时序（实测，微秒级精度）
T+0s (09:17:11.249):
H0 检测到连接错误（fd=46）
↓
incrFail() → failCnt=60
↓
setFail(true) ← 服务器标记FAILED
↓
H0 close() → fd: 46 → -1
↓
EventLoop 触发所有Handler的 check()
↓
┌──────────────────────────────────────┐
│ CAS 竞争 (微秒级差距) │
├──────────────────────────────────────┤
│ H4 activate() at ...1249101 → TRUE │ ← 赢家
│ H0 activate() at ...1249104 → FALSE │ ← 输家(3μs差距)
│ 其他Handler都被阻止 │
└──────────────────────────────────────┘
↓
T+57μs: H4 检查自己的连接
├─ fd=25 >= 0 ← 有效
└─ good() == true ← 正常
↓
🐛 H4: "connection fd=25 is good, skip reopen"
↓
❌ setFail(false) 永远不会被调用
❌ 服务器保持FAILED状态
↓
┌──────────────────────────────────────┐
│ 死锁期（33秒） │
├──────────────────────────────────────┤
│ Server.mFail = true │
│ mNextActivateTime 每3秒更新一次 │
│ │
│ T+3s: H4 activate() → skip reopen │
│ T+6s: H4 activate() → skip reopen │
│ T+9s: H4 activate() → skip reopen │
│ T+12s: H4 activate() → skip reopen │
│ T+15s: H4 activate() → skip reopen │
│ T+18s: H4 activate() → skip reopen │
│ T+21s: H4 activate() → skip reopen │
│ T+24s: H4 activate() → skip reopen │
│ T+27s: H4 activate() → skip reopen │
│ T+30s: H6 activate() → skip reopen │
│ │
│ 期间：14个客户端请求被拒绝 │
│ "no server connection available" │
└──────────────────────────────────────┘
↓
T+33s (09:17:44.267):
🎉 H0 终于获得 activate() 权限
↓
H0 检查自己的连接
├─ fd=-1 < 0 ← 无效
└─ 必须 reopen
↓
H0 reopen() → fd=15
↓
H0 init() → EINPROGRESS
↓
H0 PING 发送
↓
T+33.187s (09:17:44.286):
H0 收到 PONG (RTT=19.155ms)
↓
setFail(false) ✅
↓
服务器恢复ALIVE
3.3 关键测量数据
| 指标 | 实测值 |
| 错误窗口 | 33.037秒 |
| 受影响请求 | 14个 |
| activate()尝试次数 | 12次（H4×10，H6×1，H0×1成功） |
| H4连接检查 | 10次 fd=25 is good |
| H0等待时间 | 33秒 |
| PING→PONG RTT | 19.155ms |
3.4 根本原因
🐛 多Handler竞态条件下，因连接状态不一致触发死锁。
核心问题：
┌─────────────────────────────────────────────────────────────┐
│ Predixy架构 │
├─────────────────────────────────────────────────────────────┤
│ │
│ Server对象（全局共享，单例） │
│ ├─ mFail = true/false ← 所有Handler共享 │
│ └─ mNextActivateTime ← CAS控制 │
│ │
│ Handler 0 (失败者) Handler 4 (幸运者) │
│ ├─ ConnectConnection ├─ ConnectConnection │
│ │ ├─ fd = 46 → -1 │ ├─ fd = 25 ← 正常 │
│ │ └─ status = End │ └─ status = Normal │
│ └─ 连接错误触发 └─ 连接正常运行 │
│ │
└─────────────────────────────────────────────────────────────┘
问题流程：
1. H0的连接失败 → Server.mFail = true（全局）
2. H0 close() → H0.connection.fd = -1（局部）
3. activate() CAS竞争 → H4获胜（微秒级差距）
4. H4检查自己的连接 → fd=25 is good（局部）
5. H4: "skip reopen" → 不调用 setFail(false)
6. 死锁：Server.mFail保持true，所有请求被拒绝
7. 33秒后H0获得权限，检查自己的连接 → fd=-1
8. H0: reopen() → PONG → setFail(false) ✅
代码BUG位置：
文件: src/ConnectConnectionPool.cpp:284-292
bool Server::activate()
{
long v = mNextActivateTime;
long now = Util::nowUSec();
logWarn("server %s activate() called: now=%ld, mNextActivateTime=%ld, diff=%ld",
mAddr.data(), now, v, now - v);
if (now < v) {
logWarn("server %s activate() returning FALSE: blocked by time window (need to wait %ld us)",
mAddr.data(), v - now);
return false;
}
bool result = AtomicCAS(mNextActivateTime, v, now + mPool->serverRetryTimeout());
logWarn("server %s activate() CAS result=%s, new_mNextActivateTime=%ld",
mAddr.data(), result ? "SUCCESS" : "FAILED", now + mPool->serverRetryTimeout());
if (result) {
long retryTimeout = mPool->serverRetryTimeout();
logWarn("server %s activate() returning TRUE: CAS succeeded, next activation window after %ld us (failCnt=%ld)",
mAddr.data(), retryTimeout, (long)mFailureCnt);
} else {
logWarn("server %s activate() returning FALSE: CAS failed (another handler won)",
mAddr.data());
}
return result;
}
void ConnectConnectionPool::check()
{
if (!mServ->fail()) {
return;
}
if (mServ->activate()) { // ← CAS竞争 标记了fd < 0 和good的线程，但CAS失败了。
auto c = mShareConns[0];
int oldFd = c->fd();
if (oldFd >= 0) {
if (c->good()) { // ← 只检查自己Handler的连接
logWarn("connection fd=%d is good, skip reopen", oldFd);
return; // 🐛 BUG: 服务器仍然FAILED，但跳过reopen()
// setFail(false) 永远不会被调用
}
}
// 只有当 fd < 0 或 good() == false 才会reopen
c->reopen();
init(c); // init()成功会收到PONG，调用setFail(false)
}
}
4. 修复方案
4.1 案例一 修复建议
Predixy主动重连机制的目的是当Server端失败统计达到一定数时，避免多Handler重试增加服务端负载，因此采用主动重试只会有一个handler重试，且阻塞其他handler ServerRetryTimeout秒，避免引起服务端雪崩。
#方案1： 提高触发阈值，避免触发主动重连
ServerFailureLimit 2147483647
#方案2：当每个handler对Server建连成功后，将ServerFailureLimit归零，避免服务端正常回收连接导致被判死失败。当Server端真异常时，所有Handler都会重连失败，再触发主动重连失败避免Handler持续重连。
ServerFailureLimit 8
4.2 案例二（死锁BUG）
修复方案1：强制reopen当Server FAILED时
原理：Server是FAILED说明其他Handler有问题，即使自己的连接good()也强制reopen
文件: src/ConnectConnectionPool.cpp:284-310
void ConnectConnectionPool::check()
{
if (!mServ->fail()) {
return;
}
if (mServ->activate()) {
auto c = mShareConns[0];
int oldFd = c->fd();
// === 修改开始 ===
if (oldFd >= 0) {
if (c->good()) {
// Server是FAILED，说明其他Handler有问题
// 即使自己的连接看起来good()，也强制关闭重连
logWarn("h %d server %s is FAILED but connection fd=%d seems good, "
"force close and reopen to restore server",
mHandler->id(), mServ->addr().data(), oldFd);
c->close(mHandler); // 强制关闭
} else {
logWarn("h %d server %s connection fd=%d NOT good (status=%d %s), "
"will reopen",
mHandler->id(), mServ->addr().data(), oldFd,
c->status(), c->statusStr());
}
}
// === 修改结束 ===
// 总是执行reopen和init
c->reopen();
logWarn("h %d check server reopen connection %s %d",
mHandler->id(), c->peer(), c->fd());
if (!init(c)) {
logError("h %d server %s init() FAILED, closing connection",
mHandler->id(), mServ->addr().data());
c->close(mHandler);
} else {
logWarn("h %d server %s init() SUCCESS, waiting for PONG to restore",
mHandler->id(), mServ->addr().data());
}
}
}
优点：
● ✅ 简单，直接
● ✅ 彻底解决死锁问题
● ✅ 逻辑清晰：Server FAILED → 强制reopen
缺点：
●
●
修复方案2：让失败的Handler优先获得activate()（推荐）
原理：记录触发setFail(true)的Handler，让它优先获得重连权限，跳过CAS
文件: src/Server.h
class Server {
// ...现有成员...
// 添加：
AtomicLong mFailingHandlerId; // 记录触发失败的Handler ID，-1表示无
};
文件: src/Server.cpp
// 修改 incrFail
void Server::incrFail(int handlerId) // 需要传入Handler ID
{
long cnt = ++mFailureCnt;
logWarn("server %s failure count incremented to %ld (limit=%d)",
mAddr.data(), cnt, mPool->serverFailureLimit());
if (cnt % mPool->serverFailureLimit() == 0) {
mFailingHandlerId = handlerId; // 记录触发者
setFail(true);
logWarn("server %s marked as FAILED after %ld failures (limit=%d), "
"failing handler=%d",
mAddr.data(), cnt, mPool->serverFailureLimit(), handlerId);
}
}
// 修改 activate
bool Server::activate(int handlerId) // 需要传入Handler ID
{
// 如果是触发失败的Handler，立即允许（优先级）
if (handlerId == mFailingHandlerId) {
mFailingHandlerId = -1; // 清除标记
mNextActivateTime = Util::nowUSec() + mPool->serverRetryTimeout();
logWarn("server %s activate: failing handler %d gets priority",
mAddr.data(), handlerId);
return true;
}
// 其他Handler走正常CAS
long v = mNextActivateTime;
long now = Util::nowUSec();
if (now < v) {
return false;
}
return AtomicCAS(mNextActivateTime, v, now + mPool->serverRetryTimeout());
}
优点：
● ✅ 根本性解决，失败的Handler总是优先重连
● ✅ 逻辑最合理
● ✅ 避免CAS竞争导致的问题
缺点：
●
●
关于以上两个现象的问题原因和修复方案，大家是否建议？
ps: 在我们的场景不能配置kvrocks timeout = 0 , 客户端也会直连kvrocks，需要避免连接一直不释放。