You are viewing a plain text version of this content. The canonical link for it is here.
Posted to jira@kafka.apache.org by "radai rosenblatt (JIRA)" <ji...@apache.org> on 2017/11/15 23:51:00 UTC
[jira] [Commented] (KAFKA-6216) kafka logs for misconfigured ssl
clients are unhelpful
[ https://issues.apache.org/jira/browse/KAFKA-6216?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16254473#comment-16254473 ]
radai rosenblatt commented on KAFKA-6216:
-----------------------------------------
i have a proposed fix to address this here - https://github.com/apache/kafka/pull/4223
the current PR carries along the root cause, which gets printed in case of any further exceptions closing the channel.
an alternative is to log SSL exceptions as something other than debug.
> kafka logs for misconfigured ssl clients are unhelpful
> ------------------------------------------------------
>
> Key: KAFKA-6216
> URL: https://issues.apache.org/jira/browse/KAFKA-6216
> Project: Kafka
> Issue Type: Bug
> Affects Versions: 1.0.0
> Reporter: radai rosenblatt
>
> if you misconfigure the keystores on an ssl client, you will currently get a log full of these:
> ```
> java.io.IOException: Connection reset by peer
> at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
> at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
> at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
> at sun.nio.ch.IOUtil.write(IOUtil.java:65)
> at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:470)
> at org.apache.kafka.common.network.SslTransportLayer.flush(SslTransportLayer.java:195)
> at org.apache.kafka.common.network.SslTransportLayer.close(SslTransportLayer.java:163)
> at org.apache.kafka.common.utils.Utils.closeAll(Utils.java:731)
> at org.apache.kafka.common.network.KafkaChannel.close(KafkaChannel.java:54)
> at org.apache.kafka.common.network.Selector.doClose(Selector.java:540)
> at org.apache.kafka.common.network.Selector.close(Selector.java:531)
> at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:378)
> at org.apache.kafka.common.network.Selector.poll(Selector.java:303)
> at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:349)
> at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:233)
> at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:131)
> at java.lang.Thread.run(Thread.java:745)
> ```
> these are caught and printed as part of the client Selector trying to close the channel after having caught an IOException (lets call that the root issue).
> the root issue itself is only logged at debug, which is not on 99% of the time, leaving users with very litle clues as to whats gone wrong.
> after turning on debug log, the root issue clearly indicated what the problem was in our case:
> ```
> javax.net.ssl.SSLHandshakeException: General SSLEngine problem
> at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1409)
> at sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:535)
> at sun.security.ssl.SSLEngineImpl.writeAppRecord(SSLEngineImpl.java:1214)
> at sun.security.ssl.SSLEngineImpl.wrap(SSLEngineImpl.java:1186)
> at javax.net.ssl.SSLEngine.wrap(SSLEngine.java:469)
> at org.apache.kafka.common.network.SslTransportLayer.handshakeWrap(SslTransportLayer.java:382)
> at org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:243)
> at org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:69)
> at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:350)
> at org.apache.kafka.common.network.Selector.poll(Selector.java:303)
> at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:349)
> at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:233)
> at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:131)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: javax.net.ssl.SSLHandshakeException: General SSLEngine problem
> at sun.security.ssl.Alerts.getSSLException(Alerts.java:192)
> at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1728)
> at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:304)
> at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:296)
> at sun.security.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1478)
> at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:212)
> at sun.security.ssl.Handshaker.processLoop(Handshaker.java:957)
> at sun.security.ssl.Handshaker$1.run(Handshaker.java:897)
> at sun.security.ssl.Handshaker$1.run(Handshaker.java:894)
> at java.security.AccessController.doPrivileged(Native Method)
> at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1347)
> at org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:336)
> at org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:417)
> at org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:270)
> ... 7 more
> Caused by: sun.security.validator.ValidatorException: No trusted certificate found
> at sun.security.validator.SimpleValidator.buildTrustedChain(SimpleValidator.java:384)
> at sun.security.validator.SimpleValidator.engineValidate(SimpleValidator.java:133)
> at sun.security.validator.Validator.validate(Validator.java:260)
> at sun.security.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:324)
> at sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:281)
> at sun.security.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:136)
> at sun.security.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1465)
> ... 16 more
> ```
> unlike possibly mundate IOExceptions, SSL exceptions usually indicate a catastrophic failure to configure the client, so it would be very helpful if they were properly captured in the log (that currently only captures a much less useful domino effect)
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)