我们有一个客户端服务器应用程序,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
。
问题是:为什么大多数连接在完整GC暂停后变慢?为什么堆栈跟踪以FilterInputStream.read()
结束?难道不应该在BufferedInputStream
或套接字输入流中结束吗?这个read导致服务器负载高吗?
我们用于读取的代码:
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值的限制。但是,建议的改进仍然有效。
问题的堆栈跟踪以对DataInputStream(_socketDIS.read())上的读取结束,该方法继承自FilterInputStream.read(),请参见上面的代码。 DataInputStream,而不是BufferedInputStream,缺少read()方法。在FilterInputStream.read()中,调用了一个BufferedInputStream上的in.read(),它具有其自己定义的read()方法。但是堆栈跟踪在中间停止,没有达到BufferedInputStream.read()。为什么?
_socketDIS
已经被缓存了。我很快会上传另一个使用相同代码并且正常工作的连接的堆栈跟踪。 - dcernahoschiFilterInputStream.read()
中忙碌着。你每次只复制一个字节,而你本可以通过单次读取完成所有操作。 - user207421