Jake Robb created KAFKA-3131:
--------------------------------
Summary: Inappropriate logging level for SSL Problem
Key: KAFKA-3131
URL: https://issues.apache.org/jira/browse/KAFKA-3131
Project: Kafka
Issue Type: Bug
Reporter: Jake Robb
Priority: Minor
I didn't have my truststore set up correctly. The Kafka client JAR waited until
the connection timed out (60 seconds in my case) and then threw this exception:
{code}
Exception in thread "main" java.util.concurrent.ExecutionException:
org.apache.kafka.common.errors.TimeoutException: Failed to update metadata
after 60000 ms.
at
org.apache.kafka.clients.producer.KafkaProducer$FutureFailure.<init>(KafkaProducer.java:706)
at
org.apache.kafka.clients.producer.KafkaProducer.send(KafkaProducer.java:453)
at
org.apache.kafka.clients.producer.KafkaProducer.send(KafkaProducer.java:339)
{code}
I changed my log level to DEBUG and found this, less than two seconds after
startup:
{code}
[DEBUG] @ 2016-01-22 10:10:34,095
[User: ; Server: ; Client: ; URL: ; ChangeGroup: ]
org.apache.kafka.common.network.Selector - Connection with kafka02/10.0.0.2
disconnected
javax.net.ssl.SSLHandshakeException: General SSLEngine problem
at sun.security.ssl.Handshaker.checkThrown(Handshaker.java:1364)
at
sun.security.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:529)
at
sun.security.ssl.SSLEngineImpl.writeAppRecord(SSLEngineImpl.java:1194)
at sun.security.ssl.SSLEngineImpl.wrap(SSLEngineImpl.java:1166)
at javax.net.ssl.SSLEngine.wrap(SSLEngine.java:469)
at
org.apache.kafka.common.network.SslTransportLayer.handshakeWrap(SslTransportLayer.java:377)
at
org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:242)
at
org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:68)
at org.apache.kafka.common.network.Selector.poll(Selector.java:281)
at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:270)
at
org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:216)
at
org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:128)
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:1708)
at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:303)
at sun.security.ssl.Handshaker.fatalSE(Handshaker.java:295)
at
sun.security.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1369)
at
sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:156)
at sun.security.ssl.Handshaker.processLoop(Handshaker.java:925)
at sun.security.ssl.Handshaker$1.run(Handshaker.java:865)
at sun.security.ssl.Handshaker$1.run(Handshaker.java:862)
at java.security.AccessController.doPrivileged(Native Method)
at sun.security.ssl.Handshaker$DelegatedTask.run(Handshaker.java:1302)
at
org.apache.kafka.common.network.SslTransportLayer.runDelegatedTasks(SslTransportLayer.java:335)
at
org.apache.kafka.common.network.SslTransportLayer.handshakeUnwrap(SslTransportLayer.java:413)
at
org.apache.kafka.common.network.SslTransportLayer.handshake(SslTransportLayer.java:269)
... 6 more
Caused by: sun.security.validator.ValidatorException: PKIX path building
failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to
find valid certification path to requested target
at sun.security.validator.PKIXValidator.doBuild(PKIXValidator.java:387)
at
sun.security.validator.PKIXValidator.engineValidate(PKIXValidator.java:292)
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:1356)
... 15 more
Caused by: sun.security.provider.certpath.SunCertPathBuilderException: unable
to find valid certification path to requested target
at
sun.security.provider.certpath.SunCertPathBuilder.build(SunCertPathBuilder.java:145)
at
sun.security.provider.certpath.SunCertPathBuilder.engineBuild(SunCertPathBuilder.java:131)
at java.security.cert.CertPathBuilder.build(CertPathBuilder.java:280)
at sun.security.validator.PKIXValidator.doBuild(PKIXValidator.java:382)
... 21 more
{code}
There are two problems here:
1. The log level should be ERROR if the Kafka producer cannot connect because
of an SSL handshake problem, as this error is not likely to be intermittent or
recoverable without intervention.
2. Ideally, I would think that the producer's call to {{send}} should throw an
exception immediately rather than waiting for the full timeout.
I'm not sure if it will help, but the full output of my Kafka producer's
session is attached.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
