Hi,
We are running a 4 broker cluster with kafka 1.1 (confluent), and we are
currently securing our cluster with SASL_SSL.
Before we introduced SASL, we had no problems taking all brokers down and
up again without any issues with producers or consumers, they
would all resume processing once the cluster was back up.
However, after introducing SASL authentication one problem has occured,
when the are coming back up, consumers receives an athentication error
which
is propagated all the way up and kills the client. We have tried this with
logstash (kafka clients 1.0) and kafka-console-consumer (1.1). Kafka
producers does not seem to have this issue.
My question is if this is expected behaviour? I would expect this to not
happen or at least that some retries would be performed to see if the error
persists.
In the logs (below) it looks like there is a failure on the first SASL
attempt which triggers shutdown but later there seems to be a succesful
attempt but to late since shutdown has already begun.
I have tried this many times and with the same result each time. I have
also tried the producer many times and this always works.
See Consumer and Producer logs below.
Any input on this would be highly appreciated.
Regards /Johan
#Kafka consumer config
security.protocol=SASL_SSL
sasl.mechanism=SCRAM-SHA-256
ssl.truststore.location=/<path>/cacerts.jks
ssl.truststore.password=changeit
group.id=kafka-cli-consumer-group
client.id=kafka-cli-consumer-1
sasl.jaas.config=org.apache.kafka.common.security.scram.ScramLoginModule
required \
username="<username>" \
password="<password>";
# Consumer log file
--- Cluster is down, lots of "Give up sending metadata request..."
[2018-05-31 08:02:00,240] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:00,291] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Initialize connection to node
analytics1-kafka4-ft.se.host.biz:9094 (id: 4 rack: TEG) for sending
metadata request (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:00,291] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Initiating connection to node
analytics1-kafka4-ft.se.host.biz:9094 (id: 4 rack: TEG)
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:00,292] DEBUG Set SASL client state to
SEND_APIVERSIONS_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:00,292] DEBUG Creating SaslClient:
client=null;service=kafka;serviceHostname=analytics1-kafka4-ft.se.host.biz;mechs=[SCRAM-SHA-256]
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:00,292] DEBUG Setting SASL/SCRAM_SHA_256 client state to
SEND_CLIENT_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:02:00,313] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Created socket with SO_RCVBUF = 65536,
SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node 4
(org.apache.kafka.common.network.Selector)
[2018-05-31 08:02:00,313] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Completed connection to node 4. Fetching
API versions. (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:00,987] DEBUG SSL handshake completed successfully with
peerHost 'analytics1-kafka4-ft.se.host.biz' peerPort 9094 peerPrincipal 'CN=
analytics1-kafka4-ft.se.host.biz, OU=CD, O=Company AB (publ) internal, L=S,
ST=S, C=SE' cipherSuite 'TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384'
(org.apache.kafka.common.network.SslTransportLayer)
[2018-05-31 08:02:00,991] DEBUG Set SASL client state to
RECEIVE_APIVERSIONS_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:01,025] DEBUG Set SASL client state to
SEND_HANDSHAKE_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:01,025] DEBUG Set SASL client state to
RECEIVE_HANDSHAKE_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:01,038] DEBUG Set SASL client state to INITIAL
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:01,038] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:02:01,039] DEBUG Set SASL client state to INTERMEDIATE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:01,052] DEBUG Set SASL client state to FAILED
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:01,052] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Connection with
analytics1-kafka4-ft.se.host.biz/10.133.225.4 disconnected due to
authentication exception (org.apache.kafka.common.network.Selector)
org.apache.kafka.common.errors.SaslAuthenticationException: Authentication
failed due to invalid credentials with SASL mechanism SCRAM-SHA-256
[2018-05-31 08:02:01,053] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Node 4 disconnected.
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,053] ERROR [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Connection to node 4 failed
authentication due to: Authentication failed due to invalid credentials
with SASL mechanism SCRAM-SHA-256 (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,054] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] No broker available to send
FindCoordinator request
(org.apache.kafka.clients.consumer.internals.AbstractCoordinator)
[2018-05-31 08:02:01,055] ERROR Error processing message, terminating
consumer process: (kafka.tools.ConsoleConsumer$)
org.apache.kafka.common.errors.SaslAuthenticationException: Authentication
failed due to invalid credentials with SASL mechanism SCRAM-SHA-256
[2018-05-31 08:02:01,055] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Sending synchronous auto-commit of
offsets {in.ft.logs.anly-1=OffsetAndMetadata{offset=59, metadata=''},
in.ft.logs.anly-0=OffsetAndMetadata{offset=62, metadata=''}}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
[2018-05-31 08:02:01,055] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] No broker available to send
FindCoordinator request
(org.apache.kafka.clients.consumer.internals.AbstractCoordinator)
[2018-05-31 08:02:01,055] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Coordinator discovery failed, refreshing
metadata (org.apache.kafka.clients.consumer.internals.AbstractCoordinator)
[2018-05-31 08:02:01,156] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,207] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,262] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,315] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,366] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,416] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,469] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,521] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,573] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,628] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,681] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,732] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,785] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,837] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,892] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,945] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Give up sending metadata request since no
node is available (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,999] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Initialize connection to node
analytics1-kafka4-ft.se.host.biz:9094 (id: 4 rack: TEG) for sending
metadata request (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:01,999] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Initiating connection to node
analytics1-kafka4-ft.se.host.biz:9094 (id: 4 rack: TEG)
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:02,001] DEBUG Set SASL client state to
SEND_APIVERSIONS_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,001] DEBUG Creating SaslClient:
client=null;service=kafka;serviceHostname=analytics1-kafka4-ft.se.host.biz;mechs=[SCRAM-SHA-256]
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,001] DEBUG Setting SASL/SCRAM_SHA_256 client state to
SEND_CLIENT_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:02:02,012] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Created socket with SO_RCVBUF = 65536,
SO_SNDBUF = 131072, SO_TIMEOUT = 0 to node 4
(org.apache.kafka.common.network.Selector)
[2018-05-31 08:02:02,012] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Completed connection to node 4. Fetching
API versions. (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:02:02,057] DEBUG SSL handshake completed successfully with
peerHost 'analytics1-kafka4-ft.se.host.biz' peerPort 9094 peerPrincipal 'CN=
analytics1-kafka4-ft.se.host.biz, OU=CD, O=Company AB (publ) internal, L=s,
ST=s, C=SE' cipherSuite 'TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384'
(org.apache.kafka.common.network.SslTransportLayer)
[2018-05-31 08:02:02,057] DEBUG Set SASL client state to
RECEIVE_APIVERSIONS_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,069] DEBUG Set SASL client state to
SEND_HANDSHAKE_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,069] DEBUG Set SASL client state to
RECEIVE_HANDSHAKE_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,082] DEBUG Set SASL client state to INITIAL
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,083] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:02:02,083] DEBUG Set SASL client state to INTERMEDIATE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,106] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FINAL_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:02:02,120] DEBUG Setting SASL/SCRAM_SHA_256 client state to
COMPLETE (org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:02:02,120] DEBUG Set SASL client state to COMPLETE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:02:02,120] DEBUG [Consumer clientId=kafka-cli-consumer-1,
groupId=kafka-cli-consumer-group] Initiating API versions fetch from node
4. (org.apache.kafka.clients.NetworkClient)
# Producer log file
[2018-05-31 08:30:03,502] DEBUG [Producer clientId=console-producer] Give
up sending metadata request since no node is available
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,553] DEBUG [Producer clientId=console-producer] Give
up sending metadata request since no node is available
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,604] DEBUG [Producer clientId=console-producer] Give
up sending metadata request since no node is available
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,654] DEBUG [Producer clientId=console-producer]
Initialize connection to node analytics1-kafka3-ft.se.host.biz:9094 (id: 3
rack: TOR) for sending metadata request
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,654] DEBUG [Producer clientId=console-producer]
Initiating connection to node analytics1-kafka3-ft.se.host.biz:9094 (id: 3
rack: TOR) (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,657] DEBUG Set SASL client state to
SEND_APIVERSIONS_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,657] DEBUG Creating SaslClient:
client=null;service=kafka;serviceHostname=analytics1-kafka3-ft.se.host.biz;mechs=[SCRAM-SHA-256]
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,658] DEBUG Setting SASL/SCRAM_SHA_256 client state to
SEND_CLIENT_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:03,681] DEBUG [Producer clientId=console-producer]
Created socket with SO_RCVBUF = 32768, SO_SNDBUF = 102400, SO_TIMEOUT = 0
to node 3 (org.apache.kafka.common.network.Selector)
[2018-05-31 08:30:03,682] DEBUG [Producer clientId=console-producer]
Completed connection to node 3. Fetching API versions.
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,722] DEBUG SSL handshake completed successfully with
peerHost 'analytics1-kafka3-ft.se.host.biz' peerPort 9094 peerPrincipal 'CN=
analytics1-kafka3-ft.se.host.biz, OU=CD, O=Company AB (publ) internal, L=s,
ST=s, C=SE' cipherSuite 'TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384'
(org.apache.kafka.common.network.SslTransportLayer)
[2018-05-31 08:30:03,723] DEBUG Set SASL client state to
RECEIVE_APIVERSIONS_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,735] DEBUG Set SASL client state to
SEND_HANDSHAKE_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,736] DEBUG Set SASL client state to
RECEIVE_HANDSHAKE_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,749] DEBUG Set SASL client state to INITIAL
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,750] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:03,751] DEBUG Set SASL client state to INTERMEDIATE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,774] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FINAL_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:03,790] DEBUG Setting SASL/SCRAM_SHA_256 client state to
COMPLETE (org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:03,790] DEBUG Set SASL client state to COMPLETE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:03,790] DEBUG [Producer clientId=console-producer]
Initiating API versions fetch from node 3.
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,805] DEBUG [Producer clientId=console-producer]
Recorded API versions for node 3: (Produce(0): 0 to 5 [usable: 5],
Fetch(1): 0 to 7 [usable: 7], ListOffsets(2): 0 to 2 [usable: 2],
Metadata(3): 0 to 5 [usable: 5], LeaderAndIsr(4): 0 to 1 [usable: 1],
StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 4 [usable: 4],
ControlledShutdown(7): 0 to 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable:
3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1
[usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1
[usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1
[usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1
[usable: 1], SaslHandshake(17): 0 to 1 [usable: 1], ApiVersions(18): 0 to 1
[usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1
[usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0
[usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0],
AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0],
EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0],
TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0],
CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0],
DescribeConfigs(32): 0 to 1 [usable: 1], AlterConfigs(33): 0 [usable: 0],
AlterReplicaLogDirs(34): 0 [usable: 0], DescribeLogDirs(35): 0 [usable: 0],
SaslAuthenticate(36): 0 [usable: 0], CreatePartitions(37): 0 [usable: 0],
CreateDelegationToken(38): 0 [usable: 0], RenewDelegationToken(39): 0
[usable: 0], ExpireDelegationToken(40): 0 [usable: 0],
DescribeDelegationToken(41): 0 [usable: 0], DeleteGroups(42): 0 [usable:
0]) (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,806] DEBUG [Producer clientId=console-producer]
Sending metadata request (type=MetadataRequest, topics=in.ft.logs.anly) to
node analytics1-kafka3-ft.se.host.biz:9094 (id: 3 rack: TOR)
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:03,830] DEBUG Updated cluster metadata version 6 to
Cluster(id = RHg87JZrR42-5ubz6Di7Qw, nodes = [
analytics1-kafka2-ft.se.host.biz:9094 (id: 2 rack: TEG),
analytics1-kafka3-ft.se.host.biz:9094 (id: 3 rack: TOR),
analytics1-kafka1-ft.se.host.biz:9094 (id: 1 rack: TOR)], partitions =
[Partition(topic = in.ft.logs.anly, partition = 1, leader = 2, replicas =
[1,2], isr = [2], offlineReplicas = []), Partition(topic = in.ft.logs.anly,
partition = 0, leader = 3, replicas = [2,3], isr = [3], offlineReplicas =
[])]) (org.apache.kafka.clients.Metadata)
[2018-05-31 08:30:14,546] DEBUG [Producer clientId=console-producer]
Initiating connection to node analytics1-kafka2-ft.se.host.biz:9094 (id: 2
rack: TEG) (org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:14,550] DEBUG Set SASL client state to
SEND_APIVERSIONS_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,550] DEBUG Creating SaslClient:
client=null;service=kafka;serviceHostname=analytics1-kafka2-ft.se.host.biz;mechs=[SCRAM-SHA-256]
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,551] DEBUG Setting SASL/SCRAM_SHA_256 client state to
SEND_CLIENT_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:14,573] DEBUG [Producer clientId=console-producer]
Created socket with SO_RCVBUF = 32768, SO_SNDBUF = 102400, SO_TIMEOUT = 0
to node 2 (org.apache.kafka.common.network.Selector)
[2018-05-31 08:30:14,574] DEBUG [Producer clientId=console-producer]
Completed connection to node 2. Fetching API versions.
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:14,613] DEBUG SSL handshake completed successfully with
peerHost 'analytics1-kafka2-ft.se.host.biz' peerPort 9094 peerPrincipal 'CN=
analytics1-kafka2-ft.se.host.biz, OU=CD, O=Company AB (publ) internal, L=S,
ST=S, C=SE' cipherSuite 'TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384'
(org.apache.kafka.common.network.SslTransportLayer)
[2018-05-31 08:30:14,613] DEBUG Set SASL client state to
RECEIVE_APIVERSIONS_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,626] DEBUG Set SASL client state to
SEND_HANDSHAKE_REQUEST
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,627] DEBUG Set SASL client state to
RECEIVE_HANDSHAKE_RESPONSE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,640] DEBUG Set SASL client state to INITIAL
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,640] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FIRST_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:14,641] DEBUG Set SASL client state to INTERMEDIATE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,662] DEBUG Setting SASL/SCRAM_SHA_256 client state to
RECEIVE_SERVER_FINAL_MESSAGE
(org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:14,675] DEBUG Setting SASL/SCRAM_SHA_256 client state to
COMPLETE (org.apache.kafka.common.security.scram.ScramSaslClient)
[2018-05-31 08:30:14,675] DEBUG Set SASL client state to COMPLETE
(org.apache.kafka.common.security.authenticator.SaslClientAuthenticator)
[2018-05-31 08:30:14,676] DEBUG [Producer clientId=console-producer]
Initiating API versions fetch from node 2.
(org.apache.kafka.clients.NetworkClient)
[2018-05-31 08:30:14,689] DEBUG [Producer clientId=console-producer]
Recorded API versions for node 2: (Produce(0): 0 to 5 [usable: 5],
Fetch(1): 0 to 7 [usable: 7], ListOffsets(2): 0 to 2 [usable: 2],
Metadata(3): 0 to 5 [usable: 5], LeaderAndIsr(4): 0 to 1 [usable: 1],
StopReplica(5): 0 [usable: 0], UpdateMetadata(6): 0 to 4 [usable: 4],
ControlledShutdown(7): 0 to 1 [usable: 1], OffsetCommit(8): 0 to 3 [usable:
3], OffsetFetch(9): 0 to 3 [usable: 3], FindCoordinator(10): 0 to 1
[usable: 1], JoinGroup(11): 0 to 2 [usable: 2], Heartbeat(12): 0 to 1
[usable: 1], LeaveGroup(13): 0 to 1 [usable: 1], SyncGroup(14): 0 to 1
[usable: 1], DescribeGroups(15): 0 to 1 [usable: 1], ListGroups(16): 0 to 1
[usable: 1], SaslHandshake(17): 0 to 1 [usable: 1], ApiVersions(18): 0 to 1
[usable: 1], CreateTopics(19): 0 to 2 [usable: 2], DeleteTopics(20): 0 to 1
[usable: 1], DeleteRecords(21): 0 [usable: 0], InitProducerId(22): 0
[usable: 0], OffsetForLeaderEpoch(23): 0 [usable: 0],
AddPartitionsToTxn(24): 0 [usable: 0], AddOffsetsToTxn(25): 0 [usable: 0],
EndTxn(26): 0 [usable: 0], WriteTxnMarkers(27): 0 [usable: 0],
TxnOffsetCommit(28): 0 [usable: 0], DescribeAcls(29): 0 [usable: 0],
CreateAcls(30): 0 [usable: 0], DeleteAcls(31): 0 [usable: 0],
DescribeConfigs(32): 0 to 1 [usable: 1], AlterConfigs(33): 0 [usable: 0],
AlterReplicaLogDirs(34): 0 [usable: 0], DescribeLogDirs(35): 0 [usable: 0],
SaslAuthenticate(36): 0 [usable: 0], CreatePartitions(37): 0 [usable: 0],
CreateDelegationToken(38): 0 [usable: 0], RenewDelegationToken(39): 0
[usable: 0], ExpireDelegationToken(40): 0 [usable: 0],
DescribeDelegationToken(41): 0 [usable: 0], DeleteGroups(42): 0 [usable:
0]) (org.apache.kafka.clients.NetworkClient)
