Что вызвало медленное подключение к сокету после Full GC?

Question

Что вызвало медленное подключение к сокету после Full GC?

У нас есть клиент-серверное приложение, 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() E сть in.read() призвал на BufferedInputStream этот имеет свой read() метод определен. Но трассировка стека останавливается посередине, не доходя BufferedInputStream.read(), Зачем?

18

java sockets networking inputstream high-load

Источник

user895215 20 май '15 в 10:39

4 ответа

Другие вопросы по тегам java sockets networking inputstream high-load

user207421 20 май '15 в 12:24 2015-05-20 12:24 · Answer 1 · 2015-05-20 12:24

Чтение одного байта за раз приводит к расточительству процессора. Выбрось это:

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

Нет, смотри выше.

или в сокет входного потока?

Да, если это было блокирование, но это не так, вероятно, потому что вы вращаетесь в конце потока из-за плохого кода.

Может ли это чтение привести к высокой нагрузке на сервер?

Да.

user823393 20 май '15 в 10:51 2015-05-20 10:51 · Answer 2 · 2015-05-20 10:51

Трассировка стека показывает, что вы используете ScheduledThreadPoolExecutor, Я бы предложил вам изучить график. Вероятно, что задержки происходят просто из-за того, что чтение происходит по какому-то графику, что кажется мне глупым.

3

Источник

user823393 20 май '15 в 10:51

user2580516 23 май '15 в 00:13 2015-05-23 00:13 · Answer 3 · 2015-05-23 00:13

Это скорее расширенный комментарий, но он слишком длинный для комментария, поэтому я предоставлю его в ответе.

Как вы заметили, дамп потока, показывающий поток в середине FilterInputStream.read(), является необычным. Хотя это может произойти случайно, в то время как переопределенный FilterInputStream.read() разрешается в BufferedInputStream.read(), случайное событие кажется довольно маловероятным.

Учитывая, что это произошло после полной сборки мусора, мне кажется более вероятным, что для разрешения вызова FilterInputStream потребовалось больше времени, поскольку класс BufferedInputStream был перемещен или выгружен во время полной сборки мусора. Например, если случайно не было объектов BufferedInputStream, которые использовались, когда происходила полная сборка мусора, класс BufferedInputStream мог быть выгружен, требуя загрузки класса, когда требовался его метод read (). Это может объяснить задержку, которую вы видели, по крайней мере, один раз.

В некоторых ситуациях классы могут выгружаться, когда последний из их экземпляров подвергается сборке мусора, даже при отсутствии полной сборки мусора. Если класс BufferedInputStream каким-то образом выгружался после каждого использования и перезагружался при следующем использовании, это могло бы объяснить сказанные вами симптомы, но я бы не ожидал, что это произойдет.

Также возможно, что происходило перебивание страницы памяти, в которой находился класс BufferedInputStream, возможно, потому, что этот класс был перемещен во время полной сборки мусора, если вы использовали виртуальную память. Если у вас есть какие-либо записи об использовании памяти за это время, их стоит посмотреть.

user4358922 28 май '15 в 22:44 2015-05-28 22:44 · Answer 4 · 2015-05-28 22:44

Я предполагаю, что вы должны попытаться сбросить его, чтобы читать и писать в потоке без ошибок или замедлять соединения.

-1

Источник

user4358922 28 май '15 в 22:44