Наш внутренний сервер использует Embedded Jetty 8.1.15 уже несколько лет. У него не было проблем до недавнего времени, когда мы начали делать сценарий нагрузочного тестирования с большим количеством одновременно работающих пользователей. Затем нам удалось воспроизвести проблему даже с небольшим количеством пользователей, использующих JMeter (HTTP Sampler с одновременным пулом 1000 и KeepAlive). Связь между клиентом и сервером осуществляется по TLS (с пулом соединений на стороне клиента)
Клиент (пул соединений) -> TLS -> Сервер
Поведение, которое мы видим - в какой-то момент многие потоки «зависают» (ожидая на мониторе различными методами) со следующими следами стека -
Thread "qtp438123546-99":
at java.security.SecureRandom.nextBytes(byte[ ]) (line: 457)
at sun.security.ssl.RandomCookie.<init>(java.security.SecureRandom) (line: 53)
at sun.security.ssl.ServerHandshaker.clientHello(sun.security.ssl.HandshakeMessage$ClientHello) (line: 522)
at sun.security.ssl.ServerHandshaker.processMessage(byte, int) (line: 213)
at sun.security.ssl.Handshaker.processLoop() (line: 925)
at sun.security.ssl.Handshaker$1.run() (line: 865)
at sun.security.ssl.Handshaker$1.run() (line: 862)
at java.security.AccessController.doPrivileged(java.security.PrivilegedExceptionAction, java.security.AccessControlContext)
at sun.security.ssl.Handshaker$DelegatedTask.run() (line: 1302)
at org.eclipse.jetty.io.nio.SslConnection.process(org.eclipse.jetty.io.Buffer, org.eclipse.jetty.io.Buffer) (line: 375)
at org.eclipse.jetty.io.nio.SslConnection.access$900(org.eclipse.jetty.io.nio.SslConnection, org.eclipse.jetty.io.Buffer, org.eclipse.jetty.io.Buffer) (line: 48)
at org.eclipse.jetty.io.nio.SslConnection$SslEndPoint.fill(org.eclipse.jetty.io.Buffer) (line: 678)
at org.eclipse.jetty.http.HttpParser.fill() (line: 1044)
at org.eclipse.jetty.http.HttpParser.parseNext() (line: 280)
at org.eclipse.jetty.http.HttpParser.parseAvailable() (line: 235)
at org.eclipse.jetty.server.AsyncHttpConnection.handle() (line: 82)
at org.eclipse.jetty.io.nio.SslConnection.handle() (line: 196)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle() (line: 696)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run() (line: 53)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(java.lang.Runnable) (line: 608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run() (line: 543)
at java.lang.Thread.run() (line: 745)
ИЛИ иногда на других методах API синхронизации Java Security
Thread "qtp438123546-993":
at sun.security.ssl.SignatureAndHashAlgorithm.getSupportedAlgorithms(java.security.AlgorithmConstraints) (line: 155)
at sun.security.ssl.Handshaker.getLocalSupportedSignAlgs() (line: 422)
at sun.security.ssl.ServerHandshaker.clientHello(sun.security.ssl.HandshakeMessage$ClientHello) (line: 700)
at sun.security.ssl.ServerHandshaker.processMessage(byte, int) (line: 213)
at sun.security.ssl.Handshaker.processLoop() (line: 925)
at sun.security.ssl.Handshaker$1.run() (line: 865)
at sun.security.ssl.Handshaker$1.run() (line: 862)
at java.security.AccessController.doPrivileged(java.security.PrivilegedExceptionAction, java.security.AccessControlContext)
at sun.security.ssl.Handshaker$DelegatedTask.run() (line: 1302)
at org.eclipse.jetty.io.nio.SslConnection.process(org.eclipse.jetty.io.Buffer, org.eclipse.jetty.io.Buffer) (line: 375)
at org.eclipse.jetty.io.nio.SslConnection.access$900(org.eclipse.jetty.io.nio.SslConnection, org.eclipse.jetty.io.Buffer, org.eclipse.jetty.io.Buffer) (line: 48)
at org.eclipse.jetty.io.nio.SslConnection$SslEndPoint.fill(org.eclipse.jetty.io.Buffer) (line: 678)
at org.eclipse.jetty.http.HttpParser.fill() (line: 1044)
at org.eclipse.jetty.http.HttpParser.parseNext() (line: 280)
at org.eclipse.jetty.http.HttpParser.parseAvailable() (line: 235)
at org.eclipse.jetty.server.AsyncHttpConnection.handle() (line: 82)
at org.eclipse.jetty.io.nio.SslConnection.handle() (line: 196)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle() (line: 696)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run() (line: 53)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(java.lang.Runnable) (line: 608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run() (line: 543)
at java.lang.Thread.run() (line: 745)
Когда все в порядке, до появления проблемы существует пул соединений между клиентом и сервером с постоянными соединениями (что можно увидеть в netstat), но когда проблема появляется, существует много соединений в разных состояниях, другие которые УСТАНОВИЛИ:
На стороне клиента:
tcp6 0 0 client-host:39962 server-host:443 FIN_WAIT2
tcp6 0 1 client-host:45266 server-host:443 SYN_SENT
tcp6 0 0 client-host:46234 server-host:443 FIN_WAIT2
tcp6 0 0 client-host:38892 server-host:443 FIN_WAIT2
tcp6 0 0 client-host:39160 server-host:443 FIN_WAIT2
tcp6 0 0 client-host:39188 server-host:443 FIN_WAIT2
tcp6 0 1 client-host:43496 server-host:443 SYN_SENT
tcp6 0 0 client-host:46122 server-host:443 FIN_WAIT2
tcp6 0 1 client-host:44938 server-host:443 SYN_SENT
tcp6 0 0 client-host:46446 server-host:443 ESTABLISHED
На стороне сервера:
tcp 0 2980 server-host:443 client-host-1:34964 LAST_ACK
tcp 0 2980 server-host:443 client-host-3:52430 LAST_ACK
tcp 0 2980 server-host:443 client-host-1:35922 LAST_ACK
tcp 0 0 server-host:443 client-host-1:38362 CLOSE_WAIT
tcp 236 0 server-host:443 client-host-3:58296 CLOSE_WAIT
tcp 0 2980 server-host:443 client-host-1:34980 LAST_ACK
tcp 0 2980 server-host:443 client-host-2:55748 LAST_ACK
tcp 0 2980 server-host:443 client-host-3:53376 LAST_ACK
tcp 0 0 server-host:443 client-host-1:40104 SYN_RECV
tcp 0 0 server-host:443 client-host-1:38718 CLOSE_WAIT
tcp 0 2980 server-host:443 client-host-2:54142 LAST_ACK
tcp 0 2980 server-host:443 client-host-1:50766 LAST_ACK
tcp 0 0 server-host:443 client-host-1:38604 CLOSE_WAIT
tcp 236 0 server-host:443 client-host-3:57604 CLOSE_WAIT
tcp 0 2980 server-host:443 client-host-2:55502 LAST_ACK
tcp 0 2980 server-host:443 client-host-2:58254 LAST_ACK
tcp 0 2980 server-host:443 client-host-1:38042 LAST_ACK
tcp 0 0 server-host:443 client-host-1:38222 CLOSE_WAIT
tcp 0 2980 server-host:443 client-host-3:47812 LAST_ACK
tcp 0 2980 server-host:443 client-host-1:60532 LAST_ACK
tcp 0 2980 server-host:443 client-host-2:54282 LAST_ACK
tcp 0 0 server-host:443 client-host-1:40978 SYN_RECV
Почти все потоки не отвечают, процессор очень высок и GC постоянно работает
введите описание изображения здесь
Мы также установили следующий флаг в JVM:
-Djava.security.egd = файл: / DEV /./ urandom
Чтобы SecureRandom был неблокирующим (в отличие от / dev / random)
Java-версия "1.8.0_05"
Java (TM) SE Runtime Environment (сборка 1.8.0_05-b13)
Java HotSpot (TM) 64-разрядная серверная виртуальная машина (сборка 25.5-b02, смешанный режим)
Ядро: 4.14.94-89.73.amzn2.x86_64 (но проблема также появляется в системе с Ядром 2.6.32-696.20.1.el6.x86_64)
Пределы:
core file size (blocks, -c) unlimited
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 151551
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 65536
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 16384
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
Когда компонент входит в это состояние, он не отвечает, журналы не записываются в файл журнала (кстати, мы используем log4j2)
Когда загрузка компонента останавливается, для восстановления компонента требуется несколько минут, и он снова становится отзывчивым
Кто-нибудь имел подобное поведение в ваших бэкэнд-компонентах Java?
Пожалуйста, прокомментируйте / предложите направление для расследования и / или решения