You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by Quentin Derory <qu...@arrayent.com> on 2017/08/03 21:25:28 UTC

Fwd: SASL SCRAM failing during Handshake

Hello,

I have a 0.11.0.0 kafka cluster running with SSL and SASL SCRAM enabled
connected with Zookeeper 3.5.3-beta SASL-Plain and SSL enabled.
Kafka is connecting correctly to zookeeper(I replaced default zookeeper
library with the corresponding cluster zookeeper library and added Netty
library as well) but then fails to connect to other brokers due to a SASL
error after successful SSL handshake.

I previously registered correctly the admin users with the kafka-config
command with the corresponding password from the server jaas file.

Note: The same configuration works perfectly with SASL PLAIN instead of
SASL SCRAM

What I tried:
- Got rid of zookeeper ACL
- Put SASL only for external use : The kafka cluster will boot up correctly
but consumer/producer will fail after the ssl handshake with this error  on
the client side:
org.apache.kafka.common.errors.IllegalSaslStateException: Unexpected
handshake request with client mechanism SCRAM-SHA-256, enabled mechanisms
are [SCRAM-SHA-256]
on the server side:
at org.apache.kafka.common.security.scram.ScramSaslServer.evaluateResponse(ScramSaslServer.java:102)
        at org.apache.kafka.common.security.authenticator.
SaslServerAuthenticator.authenticate(SaslServerAuthenticator.java:232)
    ... 6 more Caused by: javax.security.sasl.SaslException: Authentication
failed: Invalid user credentials         at org.apache.kafka.common.
security.scram.ScramSaslServer.evaluateResponse(ScramSaslServer.java:92)


*server.log* (looping on this error):
[2017-07-31 22:55:03,234] DEBUG SSL handshake completed successfully with
peerHost 'kafka1.arrayent.io' peerPort 9093 peerPrincipal 'CN='
kafka1.private.io', OU=private, O=Private, L=Redwood city, ST=CA, C=US'
cipherSuite 'TLS_DHE_DSS_WITH_AES_256_CBC_SHA256' (org.apache.kafka.common.
network.SslTransportLayer)
[2017-07-31 22:55:03,234] DEBUG Set SASL client state to
RECEIVE_HANDSHAKE_RESPONSE (org.apache.kafka.common.security.authenticator.
SaslClientAuthenticator)
[2017-07-31 22:55:03,234] DEBUG Set SASL server state to HANDSHAKE_REQUEST
(org.apache.kafka.common.security.authenticator.SaslServerAuthenticator)
[2017-07-31 22:55:03,234] DEBUG Handle Kafka request SASL_HANDSHAKE
(org.apache.kafka.common.security.authenticator.SaslServerAuthenticator)
[2017-07-31 22:55:03,234] DEBUG Using SASL mechanism 'SCRAM-SHA-256 (or
SCRAM-SHA-512)' provided by client (org.apache.kafka.common.
security.authenticator.SaslServerAuthenticator)
[2017-07-31 22:55:03,234] DEBUG Set SASL server state to AUTHENTICATE
(org.apache.kafka.common.security.authenticator.SaslServerAuthenticator)
[2017-07-31 22:55:03,234] DEBUG Set SASL client state to INITIAL
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2017-07-31 22:55:03,234] WARN Unexpected error from
kafka1.private.io/172.21.1.18; closing connection (org.apache.kafka.common.
network.Selector)
java.lang.NullPointerException
        at org.apache.kafka.common.security.authenticator.
SaslClientAuthenticator.sendSaslToken(SaslClientAuthenticator.java:214)
        at org.apache.kafka.common.security.authenticator.
SaslClientAuthenticator.authenticate(SaslClientAuthenticator.java:183)
        at org.apache.kafka.common.network.KafkaChannel.prepare(
KafkaChannel.java:76)
        at org.apache.kafka.common.network.Selector.
pollSelectionKeys(Selector.java:374)
        at org.apache.kafka.common.network.Selector.poll(Selector.java:326)
        at org.apache.kafka.clients.NetworkClient.poll(
NetworkClient.java:432)
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:71)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)
[2017-07-31 22:55:03,234] DEBUG Node 0 disconnected.
(org.apache.kafka.clients.NetworkClient)
[2017-07-31 22:55:03,234] WARN Connection to node 0 terminated during
authentication. This may indicate that authentication failed due to invalid
credentials. (org.apache.kafka.clients.NetworkClient)
[2017-07-31 22:55:03,234] DEBUG Connection with ip-172-21-1-18.us-west-2.
compute.internal/172.21.1.18 disconnected (org.apache.kafka.common.
network.Selector)
java.io.EOFException
        at org.apache.kafka.common.network.SslTransportLayer.
read(SslTransportLayer.java:492)
        at org.apache.kafka.common.network.NetworkReceive.
readFromReadableChannel(NetworkReceive.java:85)
        at org.apache.kafka.common.network.NetworkReceive.
readFrom(NetworkReceive.java:75)
        at org.apache.kafka.common.security.authenticator.
SaslServerAuthenticator.authenticate(SaslServerAuthenticator.java:214)
        at org.apache.kafka.common.network.KafkaChannel.prepare(
KafkaChannel.java:76)
        at org.apache.kafka.common.network.Selector.
pollSelectionKeys(Selector.java:374)
        at org.apache.kafka.common.network.Selector.poll(Selector.java:326)
        at kafka.network.Processor.poll(SocketServer.scala:499)
        at kafka.network.Processor.run(SocketServer.scala:435)
        at java.lang.Thread.run(Thread.java:745)


logs of the controller node (looping on these errors) :
[2017-07-31 22:57:55,497] WARN [Controller-0-to-broker-1-send-thread]:
Controller 0's connection to broker kafka2.private.io:9093 (id: 1 rack:
null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to kafka2.private.io:9093 (id: 1 rack:
null) failed.
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:68)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)
[2017-07-31 22:57:55,524] WARN [Controller-0-to-broker-0-send-thread]:
Controller 0's connection to broker kafka1.private.io:9093 (id: 0 rack:
null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to kafka1.private.io:9093 (id: 0 rack:
null) failed.
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:68)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)
[2017-07-31 22:57:55,560] WARN [Controller-0-to-broker-2-send-thread]:
Controller 0's connection to broker kafka3.private.io:9093 (id: 2 rack:
null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to kafka3.private.io:9093 (id: 2 rack:
null) failed.
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:68)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)
[2017-07-31 22:57:55,614] WARN [Controller-0-to-broker-1-send-thread]:
Controller 0's connection to broker kafka2.private.io:9093 (id: 1 rack:
null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to kafka2.private.io:9093 (id: 1 rack:
null) failed.
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:68)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)
[2017-07-31 22:57:55,637] WARN [Controller-0-to-broker-0-send-thread]:
Controller 0's connection to broker kafka1.private.io:9093 (id: 0 rack:
null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to kafka1.private.io:9093 (id: 0 rack:
null) failed.
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:68)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)
[2017-07-31 22:57:55,676] WARN [Controller-0-to-broker-2-send-thread]:
Controller 0's connection to broker kafka3.private.io:9093 (id: 2 rack:
null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to kafka3.private.io:9093 (id: 2 rack:
null) failed.
        at org.apache.kafka.clients.NetworkClientUtils.awaitReady(
NetworkClientUtils.java:68)
        at kafka.controller.RequestSendThread.brokerReady(
ControllerChannelManager.scala:264)
        at kafka.controller.RequestSendThread.doWork(
ControllerChannelManager.scala:218)
        at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)

*My broker properties*:

broker.id=1
listeners=INTERNAL://kafka1.private.io:9093,EXTERNAL://ec2-102.52.36.54.us-west-2.compute.amazonaws.com:{{externalPort}}
zookeeper.connect=zk1.private.io:2281,zk2.private.io:2281,zk3.private.io:2281#############################
Log Basics ############################## A comma seperated list of
directories under which to store log
fileslog.dirs=/logs/kafka/1############SECURITY###########################################################ssl.keystore.location={{kafka.keystoreLocation}}ssl.keystore.password={{kafka.keystorePassword}}ssl.key.password={{kafka.keyPassword}}ssl.truststore.location={{kafka.truststoreLocation}}ssl.truststore.password={{kafka.truststorePassword}}ssl.client.auth=nonessl.enabled.protocols=TLSv1.2,TLSv1.1,TLSv1#InterBroker#security.inter.broker.protocol=SASL_SSLinter.broker.listener.name=INTERNALlistener.security.protocol.map
=EXTERNAL:SASL_SSL,INTERNAL:SASL_SSL##Authentication
SASLsasl.mechanism.inter.broker.protocol=SCRAM-SHA-256
sasl.enabled.mechanisms=SCRAM-SHA-256#SASL with
zookeeperzookeeper.set.acl=true##ACLauthorizer.class.name=kafka.security.auth.SimpleAclAuthorizersuper.users=User:adminallow.everyone.if.no.acl.found=true##########################################################################################num.partitions=30message.max.bytes=1000000auto.create.topics.enable=falselog.index.interval.bytes=4096log.index.size.max.bytes=10485760log.retention.hours=12log.flush.interval.ms=10000log.flush.interval.messages=20000log.flush.scheduler.interval.ms=2000log.roll.hours=12log.retention.check.interval.ms=300000log.segment.bytes=1073741824#
Replication configurationsnum.replica.fetchers=4replica.fetch.max.bytes=1048576replica.fetch.wait.max.ms=500replica.high.watermark.checkpoint.interval.ms=5000replica.socket.timeout.ms=30000replica.socket.receive.buffer.bytes=65536replica.lag.time.max.ms=10000replica.lag.max.messages=4000controller.socket.timeout.ms=30000controller.message.queue.size=10#
ZK configurationzookeeper.connection.timeout.ms=6000zookeeper.sync.time.ms=2000#
Socket server configurationnum.io.threads=20num.network.threads=20socket.request.max.bytes=104857600socket.receive.buffer.bytes=1048576socket.send.buffer.bytes=1048576queued.max.requests=1000fetch.purgatory.purge.interval.requests=100producer.purgatory.purge.interval.requests=100



*My jaas server file:*

KafkaServer {  org.apache.kafka.common.security.scram.ScramLoginModule
required  username="admin"  password="admin-secret";};Client {
org.apache.zookeeper.server.auth.DigestLoginModule required
username="kafka1"  password="kafka1secret";};


Thanks in advance for your help,

Quentin