[ https://issues.apache.org/jira/browse/KAFKA-7450?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Yu Yang updated KAFKA-7450: --------------------------- Description: After updating security.inter.broker.protocol to SSL for our cluster, we observed that the controller can get into almost 100% cpu usage from time to time. {code:java} listeners=PLAINTEXT://:9092,SSL://:9093 security.inter.broker.protocol=SSL {code} There is no obvious error in server.log. But in controller.log, there is repetitive SSL handshare failure error as below: {code:java} [2018-09-28 05:53:10,821] WARN [RequestSendThread controllerId=6042] Controller 6042's connection to broker datakafka06176.ec2.pin220.com:9093 (id: 6176 rack: null) was unsuccessful (kafka.controller.RequestSendThread) org.apache.kafka.common.errors.SslAuthenticationException: SSL handshake failed Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1487) at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:468) at org.apache.kafka.common.network.SslTransportLayer.doHandshake(SslTransportLayer.java:331) at org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:258) at org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:125) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:487) at org.apache.kafka.common.network.Selector.poll(Selector.java:425) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:510) at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:279) at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:233) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:196) at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1026) at sun.security.ssl.Handshaker$1.run(Handshaker.java:966) at sun.security.ssl.Handshaker$1.run(Handshaker.java:963) at java.security.AccessController.doPrivileged(Native Method) at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1416) at org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:393) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:473) ... 10 more {code} {code:java} [2018-09-30 00:30:13,609] WARN [ReplicaFetcher replicaId=59, leaderId=66, fetcherId=0] Error in response for fetch request (type=FetchRequest, replicaId=59, maxWait=500, minBytes=1, maxBytes=10485760, fetchData={the_test_topic-18=(offset=462333447, logStartOffset=462286948, maxBytes=4194304), the_test_topic-58=(offset=462312762, logStartOffset=462295078, maxBytes=4194304)}, isolationLevel=READ_UNCOMMITTED, toForget=, metadata=(sessionId=1991153671, epoch=INITIAL)) (kafka.server.ReplicaFetcherThread) org.apache.kafka.common.errors.SslAuthenticationException: SSL handshake failed Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1538) at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:468) at org.apache.kafka.common.network.SslTransportLayer.doHandshake(SslTransportLayer.java:331) at org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:258) at org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:125) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:487) at org.apache.kafka.common.network.Selector.poll(Selector.java:425) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:510) at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) at kafka.server.ReplicaFetcherBlockingSend.sendRequest(ReplicaFetcherBlockingSend.scala:91) at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:240) at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:43) at kafka.server.AbstractFetcherThread.processFetchRequest(AbstractFetcherThread.scala:149) at kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:114) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:196) at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1052) at sun.security.ssl.Handshaker$1.run(Handshaker.java:992) at sun.security.ssl.Handshaker$1.run(Handshaker.java:989) at java.security.AccessController.doPrivileged(Native Method) at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1467) at org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:393) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:473) ... 13 more {code} was: After updating security.inter.broker.protocol to SSL for our cluster, we observed that the controller can get into almost 100% cpu usage. {code} listeners=PLAINTEXT://:9092,SSL://:9093 security.inter.broker.protocol=SSL {code} There is no obvious error in server.log. But in controller.log, there is repetitive SSL handshare failure error as below: {code} [2018-09-28 05:53:10,821] WARN [RequestSendThread controllerId=6042] Controller 6042's connection to broker datakafka06176.ec2.pin220.com:9093 (id: 6176 rack: null) was unsuccessful (kafka.controller.RequestSendThread) org.apache.kafka.common.errors.SslAuthenticationException: SSL handshake failed Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1487) at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:468) at org.apache.kafka.common.network.SslTransportLayer.doHandshake(SslTransportLayer.java:331) at org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:258) at org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:125) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:487) at org.apache.kafka.common.network.Selector.poll(Selector.java:425) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:510) at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:279) at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:233) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:196) at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1026) at sun.security.ssl.Handshaker$1.run(Handshaker.java:966) at sun.security.ssl.Handshaker$1.run(Handshaker.java:963) at java.security.AccessController.doPrivileged(Native Method) at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1416) at org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:393) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:473) ... 10 more {code} {code} [2018-09-30 00:30:13,609] WARN [ReplicaFetcher replicaId=59, leaderId=66, fetcherId=0] Error in response for fetch request (type=FetchRequest, replicaId=59, maxWait=500, minBytes=1, maxBytes=10485760, fetchData={the_test_topic-18=(offset=462333447, logStartOffset=462286948, maxBytes=4194304), the_test_topic-58=(offset=462312762, logStartOffset=462295078, maxBytes=4194304)}, isolationLevel=READ_UNCOMMITTED, toForget=, metadata=(sessionId=1991153671, epoch=INITIAL)) (kafka.server.ReplicaFetcherThread) org.apache.kafka.common.errors.SslAuthenticationException: SSL handshake failed Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1538) at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:468) at org.apache.kafka.common.network.SslTransportLayer.doHandshake(SslTransportLayer.java:331) at org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:258) at org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:125) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:487) at org.apache.kafka.common.network.Selector.poll(Selector.java:425) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:510) at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) at kafka.server.ReplicaFetcherBlockingSend.sendRequest(ReplicaFetcherBlockingSend.scala:91) at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:240) at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:43) at kafka.server.AbstractFetcherThread.processFetchRequest(AbstractFetcherThread.scala:149) at kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:114) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence violation, 2 at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:196) at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1052) at sun.security.ssl.Handshaker$1.run(Handshaker.java:992) at sun.security.ssl.Handshaker$1.run(Handshaker.java:989) at java.security.AccessController.doPrivileged(Native Method) at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1467) at org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:393) at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:473) ... 13 more {code} > "Handshake message sequence violation" related ssl handshake failure leads to > high cpu usage > -------------------------------------------------------------------------------------------- > > Key: KAFKA-7450 > URL: https://issues.apache.org/jira/browse/KAFKA-7450 > Project: Kafka > Issue Type: Bug > Components: controller > Affects Versions: 2.0.0 > Reporter: Yu Yang > Priority: Major > > After updating security.inter.broker.protocol to SSL for our cluster, we > observed that the controller can get into almost 100% cpu usage from time to > time. > {code:java} > listeners=PLAINTEXT://:9092,SSL://:9093 > security.inter.broker.protocol=SSL > {code} > There is no obvious error in server.log. But in controller.log, there is > repetitive SSL handshare failure error as below: > {code:java} > [2018-09-28 05:53:10,821] WARN [RequestSendThread controllerId=6042] > Controller 6042's connection to broker datakafka06176.ec2.pin220.com:9093 > (id: 6176 rack: null) was unsuccessful (kafka.controller.RequestSendThread) > org.apache.kafka.common.errors.SslAuthenticationException: SSL handshake > failed > Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence > violation, 2 > at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1487) > at > sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) > at > sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) > at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) > at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) > at > org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:468) > at > org.apache.kafka.common.network.SslTransportLayer.doHandshake(SslTransportLayer.java:331) > at > org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:258) > at > org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:125) > at > org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:487) > at org.apache.kafka.common.network.Selector.poll(Selector.java:425) > at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:510) > at > org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) > at > kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:279) > at > kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:233) > at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) > Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence > violation, 2 > at > sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:196) > at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1026) > at sun.security.ssl.Handshaker$1.run(Handshaker.java:966) > at sun.security.ssl.Handshaker$1.run(Handshaker.java:963) > at java.security.AccessController.doPrivileged(Native Method) > at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1416) > at > org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:393) > at > org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:473) > ... 10 more > {code} > {code:java} > [2018-09-30 00:30:13,609] WARN [ReplicaFetcher replicaId=59, leaderId=66, > fetcherId=0] Error in response for fetch request (type=FetchRequest, > replicaId=59, maxWait=500, minBytes=1, maxBytes=10485760, > fetchData={the_test_topic-18=(offset=462333447, logStartOffset=462286948, > maxBytes=4194304), the_test_topic-58=(offset=462312762, > logStartOffset=462295078, maxBytes=4194304)}, > isolationLevel=READ_UNCOMMITTED, toForget=, metadata=(sessionId=1991153671, > epoch=INITIAL)) (kafka.server.ReplicaFetcherThread) > org.apache.kafka.common.errors.SslAuthenticationException: SSL handshake > failed > Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence > violation, 2 > at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1538) > at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535) > at sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:813) > at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:781) > at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624) > at > org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:468) > at > org.apache.kafka.common.network.SslTransportLayer.doHandshake(SslTransportLayer.java:331) > at > org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:258) > at > org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:125) > at > org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:487) > at org.apache.kafka.common.network.Selector.poll(Selector.java:425) > at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:510) > at > org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) > at > kafka.server.ReplicaFetcherBlockingSend.sendRequest(ReplicaFetcherBlockingSend.scala:91) > at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:240) > at kafka.server.ReplicaFetcherThread.fetch(ReplicaFetcherThread.scala:43) > at > kafka.server.AbstractFetcherThread.processFetchRequest(AbstractFetcherThread.scala:149) > at > kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:114) > at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) > Caused by: javax.net.ssl.SSLProtocolException: Handshake message sequence > violation, 2 > at > sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:196) > at sun.security.ssl.Handshaker.processLoop(Handshaker.java:1052) > at sun.security.ssl.Handshaker$1.run(Handshaker.java:992) > at sun.security.ssl.Handshaker$1.run(Handshaker.java:989) > at java.security.AccessController.doPrivileged(Native Method) > at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1467) > at > org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:393) > at > org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:473) > ... 13 more > {code} -- This message was sent by Atlassian JIRA (v7.6.3#76005)