Zookeeper TCP 连接何时清理服务器端？答案

【问题标题】：When are Zookeeper TCP connections cleaned up server side?Zookeeper TCP 连接何时清理服务器端？
【发布时间】：2016-03-30 16:47:02
【问题描述】：

在测试设置中（单客户端服务器 - 本地主机运行 Gatling，在测试期间创建和关闭连接）我的单节点 Zookeeper 保持所有 TCP 连接打开，直到测试运行完成。

在前 2 分钟的测试运行期间，我重复创建多达 10 个并行的客户端连接，它们处于活动状态大约 30 秒，然后再次关闭它们的连接。因此，在任何一个时刻，前 2 分钟内最多有 10 个连接处于活动状态。然后测试再继续 8 分钟，在此期间只有 1 个客户端连接处于活动状态。

客户端：使用 Curator 2.9.1 和 Zookeeper 3.4.6

动物园管理员节点：3.4.8-1--1

AFAIK 客户端正确关闭了他们的连接（证明：我看到它的临时节点在执行 ls /path/to/ephemerals 时被删除，zookeeper 日志也指示关闭的连接）

但是，当向 zookeeper 节点发送 cons 命令时，前 2 分钟 TCP 连接数一直在上升，总共达到 126。测试运行完成，此时所有连接都立即消失。

我预计连接数会低得多，例如 10 到 20，并且在测试的“活动”阶段保持稳定。相反，只要我打开/关闭新连接，它就会不断上升。

在最初的 2 分钟内，zookeeper 日志显示打开和关闭连接：

2016-03-25 15:54:04,305 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:NIOServerCnxnFactory@192] - Accepted socket connection from /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,321 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:ZooKeeperServer@900] - Client attempting to establish new session at /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,324 - INFO  [SyncThread:0:ZooKeeperServer@645] - Established session 0x153ae440b2e000f with negotiated timeout 10000 for client /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,324 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:ZooKeeperServer@924] - got auth packet /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,325 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:ZooKeeperServer@958] - auth success /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,326 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:ZooKeeperServer@924] - got auth packet /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,328 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:ZooKeeperServer@958] - auth success /0:0:0:0:0:0:0:1:60758
2016-03-25 15:54:04,803 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:NIOServerCnxnFactory@192] - Accepted socket connection from /127.0.0.1:37236
2016-03-25 15:54:04,804 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:37236
2016-03-25 15:54:04,805 - INFO  [SyncThread:0:ZooKeeperServer@645] - Established session 0x153ae440b2e0010 with negotiated timeout 10000 for client /127.0.0.1:37236
2016-03-25 15:54:04,828 - INFO  [ProcessThread(sid:0 cport:12182)::PrepRequestProcessor@489] - Processed session termination for sessionid: 0x153ae440b2e0010
2016-03-25 15:54:04,830 - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:12182:NIOServerCnxn@1008] - Closed socket connection for client /127.0.0.1:37236 which had sessionid 0x153ae440b2e0010

然后，仅在运行结束时，对于我看到的每个连接

2016-03-25 15:57:44,002 - INFO  [SessionTracker:ZooKeeperServer@355] - Expiring session 0x153ae440b2e006c, timeout of 10000ms exceeded
2016-03-25 15:57:44,003 - INFO  [SessionTracker:ZooKeeperServer@355] - Expiring session 0x153ae440b2e00b8, timeout of 10000ms exceeded
2016-03-25 15:57:44,003 - INFO  [SessionTracker:ZooKeeperServer@355] - Expiring session 0x153ae440b2e0094, timeout of 10000ms exceeded
...
2016-03-25 15:57:44,014 - INFO  [ProcessThread(sid:0 cport:12182)::PrepRequestProcessor@489] - Processed session termination for sessionid: 0x153ae440b2e006c
2016-03-25 15:57:44,014 - INFO  [ProcessThread(sid:0 cport:12182)::PrepRequestProcessor@489] - Processed session termination for sessionid: 0x153ae440b2e00b8
2016-03-25 15:57:44,015 - INFO  [ProcessThread(sid:0 cport:12182)::PrepRequestProcessor@489] - Processed session termination for sessionid: 0x153ae440b2e0094
...

（请注意，上面的日志是从手动中断的运行中获取的，但如果我让运行完成到 16:02，行为是相同的）

我正在使用以下配置（摘录）运行：

tickTime=2000
maxSessionTimeout=10000
minSessionTimeout=4000
maxClientCnxns=0

连接数量的增加与测试设置有关，还是 Zookeeper 运行方式固有的？

【问题讨论】：

你确定在整个测试过程中实际的 tcp-connections 是打开的吗？ netstat -anp --tcp 之类的东西是什么意思？可能只是 zookeeper 监控连接。
是的，我确定连接确实存在。事实上，仔细检查我们的客户端代码发现连接以不正确的方式关闭（实际的 connection.close 被省略）。所以这不是 Zookeeper 和 Gatling 的问题。

标签： apache-zookeeper apache-curator

【解决方案1】：

原来这是我们的客户端代码中的错误。连接没有正确关闭，只完成了一半的清理（临时节点被删除了，但客户端连接实际上并没有真正关闭）。

抱歉占用您的时间。

【讨论】：