Имаме приложение за клиентски сървър, 1 сървър, около 10 клиента. Те комуникират чрез tcp сокети, използвайки персонализирани заявки.
Системата работеше гладко в продължение на много месеци, но в някакъв момент, след ежедневния планиран FULL GC на сървъра, който отне около 50 секунди, разбрахме, че времето между заявките, изпратени от клиента, и получените отговори от сървъра беше голям, > 10-20s. След около 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
или в сокет? Може ли това четене да доведе до голямо натоварване на сървъра?
Кодът, който използваме за четене:
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()
имаin.read()
, извикан наBufferedInputStream
, този има собствен дефиниран методread()
. Но проследяването на стека спира по средата, не достигаBufferedInputStream.read()
. Защо?