Full GC后socket连接变慢的原因是什么？答案

【问题标题】：What caused socket connections to be slow after Full GC?Full GC后socket连接变慢的原因是什么？
【发布时间】：2015-08-01 13:21:26
【问题描述】：

我们有一个客户端服务器应用程序，1 个服务器，大约 10 个客户端。它们使用自定义查询通过 tcp 套接字进行通信。

系统已经平稳运行了好几个月，但是在某个时间点，在每天约 50 秒的预定服务器 FULL GC 之后，我们计算出客户端发送查询之间的时间从服务器收到的响应很大，> 10-20 秒。大约 3 小时后，系统恢复正常，一切正常。

在调查该问题时，我们发现：

客户端和服务器都没有垃圾回收问题
服务器上的查询处理时间很短。
服务器负载很高。
网络带宽未饱和。
在 FULL GC 期间未重置连接（在此之前，每日 FULL GC 是正常事件）
机器和操作系统最近从 Centos 6（内核 2.6.32）更改为 Centos 7（内核 3.10.0），但新配置经过了广泛的测试。 Oracle JDK 版本也从 1.7.65 更改为 1.7.75。

我们在服务器上进行了线程转储：

java.lang.Thread.State: RUNNABLE
    at java.io.FilterInputStream.read(FilterInputStream.java:83)
    at util.network.BytesBasedSocketConnection$ReadConnectionRunnable.run(BytesBasedSocketConnection.java:293)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

FilterInputStream.read() 如下：

    public int read() throws IOException {
    return in.read();
}

我们代码中的in 是BufferedInputStream。

问题是：为什么在 Full GC 暂停后大多数连接变慢了？为什么堆栈跟踪以FilterInputStream.read() 结尾？它不应该在BufferedInputStream 或套接字输入流中的某处结束吗？这种读取会导致服务器负载过高吗？

我们用来阅读的代码：

int constructLength = _socketDIS.readInt();
ByteArrayOutputStream constructBOAS = new ByteArrayOutputStream(constructLength);
for (int i = 0; i != constructLength; i++)
      constructBOAS.write(_socketDIS.read());
constructBOAS.close();
byte[] bytes = constructBOAS.toByteArray();

地点：

_socketDIS = new DataInputStream(new BufferedInputStream(_socket.getInputStream()));

这是来自运行良好的客户端连接的堆栈跟踪：

java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
    - locked <0x00007f522cbebca8> (a java.io.BufferedInputStream)
    at java.io.DataInputStream.readInt(DataInputStream.java:387)
    at util.network.BytesBasedSocketConnection$ReadConnectionRunnable.run(BytesBasedSocketConnection.java:287)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

更新：

关于 EJP 答案：

没有涉及 EOS，连接已建立，但速度很慢
即使有 EOS，我也看不出代码如何在 EOS 上旋转，for 受constructLength 值的限制。但是，建议的改进仍然有效。
有问题的堆栈跟踪以对继承自 FilterInputStream.read() 的 DataInputStream ((_socketDIS.read()) 的读取结束，请参见上面的代码。 DataInputStream，而不是 BufferedInputStream 缺少 read()。在FilterInputStream.read() 中有一个in.read() 调用BufferedInputStream，这个有自己的read() 方法定义。但是堆栈跟踪在中间停止，没有到达BufferedInputStream.read()。为什么？

【问题讨论】：

标签： java sockets networking inputstream high-load

【解决方案1】：

一次读取一个字节会浪费 CPU。扔掉这个：

int constructLength = _socketDIS.readInt();
ByteArrayOutputStream constructBOAS = new ByteArrayOutputStream(constructLength);
for (int i = 0; i != constructLength; i++)
      constructBOAS.write(_socketDIS.read());
constructBOAS.close();
byte[] bytes = constructBOAS.toByteArray();

并使用它：

int constructLength = _socketDIS.readInt();
byte[] bytes = new byte[constructLength];
_socketDIS.readFully(bytes);

NB _socketDIS 显然不是 BufferedInputStream 而是 DataInputStream, 没有缓冲。

编辑

为什么堆栈跟踪以 FilterInputStream.read() 结尾？

仔细看。 BufferedInputStream 没有实现所有三个 read() 重载。其中一个，我忘记了，是在基类 FilterInputStream 中实现的，另外两个重载调用它。

它不应该在 BufferedInputStream 的某个地方结束

不，见上文。

还是在套接字输入流中？

是的，如果它被阻塞了，但它不是，可能是因为你在流的末尾旋转，因为你的代码很糟糕。

这种读取会导致服务器负载过高吗？

是的。

【讨论】：

好的，但大多数时候这段代码运行良好。并且肯定_socketDIS 被缓冲了。我将很快从工作正常且使用相同代码的连接上传另一个堆栈跟踪。
随便，但无论如何这是更好的代码。它会妥善处理极端情况，例如过早的 EOS，您的只是自旋循环。
谢谢，我同意这更好，但这不是问题所在，连接一直保持活动状态，并且在某些时候恢复，速度恢复正常。
当然是问题所在。您自己的堆栈跟踪证明了这一点。您正忙于FilterInputStream.read(). 您正在复制一个字节，而您可以在一次读取中完成所有操作。
不是。在问题中添加了更多解释。更好地描述了在什么情况下出现问题。

【解决方案2】：

堆栈跟踪显示您正在使用ScheduledThreadPoolExecutor。我建议你研究一下时间表。延迟很可能仅仅是因为阅读是按某种时间表进行的——这对我来说似乎很愚蠢。

【讨论】：

啊，确实有一个ScheduledThreadPoolExecutor用错了，但是这个任务是一个持续运行的任务，它只是从socket读取查询并将它们放入队列中。

【解决方案3】：

这更像是一个扩展评论，但评论太长了，所以我会在答案中提供。

正如您所注意到的，在 FilterInputStream.read() 中间显示线程的线程转储是不寻常的。虽然它可能是偶然发生的，虽然被覆盖的 FilterInputStream.read() 被解析为 BufferedInputStream.read()，但偶然发生似乎不太可能。

鉴于这是在完全垃圾回收之后发生的，在我看来，解决 FilterInputStream 调用需要更长的时间，因为 BufferedInputStream 类在完全垃圾回收期间被移动或卸载。例如，如果在完全垃圾回收发生时碰巧没有正在使用的 BufferedInputStream 对象，则 BufferedInputStream 类可能已被卸载，当需要其 read() 方法时需要加载类。这可能是您看到的延迟的原因，至少有一次。

在某些情况下，当最后一个实例被垃圾回收时，类可能会被卸载，即使没有完整的垃圾回收。如果 BufferedInputStream 类在每次使用后以某种方式被卸载并在下次使用时重新加载，这可以解释您所说的症状，但我通常不会期望会发生这种情况。

如果您使用虚拟内存，保存 BufferedInputStream 类的内存页面也可能出现抖动，这可能是因为该类在完全垃圾回收期间重新定位。如果您有任何关于这段时间内存使用的记录，它们可能值得一看。

【讨论】：

谢谢。 BufferedInputStream 实例不应该被垃圾收集，因为套接字连接保持活动状态。不，内存仍然很低，也没有垃圾。

【解决方案4】：

我想您必须尝试刷新它才能在流中读取和写入而不会出现错误或减慢连接速度。

【讨论】：