Kafka error after SSL enabled - Bootstrap broker-name :6667 disconnected (org.apache.kafka.clients.NetworkClient)

[#1]

client-sslproperties.txt

Hello - i've enabled SSL for Kafka, and Kafka is starting up fine with SSL enable.

However, when i run the Kafka console producer, it is give me error as shown below ->

Command :

/usr/hdp/2.5.3.0-37/kafka/bin/kafka-console-producer.sh --broker-list nwk2-bdp-kafka-05.gdcs-qa.apple.com:6667,nwk2-bdp-kafka-04.gdcs-qa.apple.com:6667,nwk2-bdp-kafka-06.gdcs-qa.apple.com:6667 --topic sslTopic --producer.config /tmp/ssl-kafka/client-ssl.properties

Message Typed on console :

hi

On Typing message on the Console Producer, i get the following error :

[2017-07-24 19:10:22,940] WARN Bootstrap broker nwk2-bdp-kafka-06.gdcs-qa.apple.com:6667 disconnected (org.apache.kafka.clients.NetworkClient)
[2017-07-24 19:10:23,106] WARN Bootstrap broker nwk2-bdp-kafka-05.gdcs-qa.apple.com:6667 disconnected (org.apache.kafka.clients.NetworkClient)
[2017-07-24 19:10:23,160] WARN Bootstrap broker nwk2-bdp-kafka-04.gdcs-qa.apple.com:6667 disconnected (org.apache.kafka.clients.NetworkClient)
[2017-07-24 19:10:23,208] WARN Bootstrap broker nwk2-bdp-kafka-05.gdcs-qa.apple.com:6667 disconnected (org.apache.kafka.clients.NetworkClient)
[2017-07-24 19:10:23,260] WARN Bootstrap broker nwk2-bdp-kafka-06.gdcs-qa.apple.com:6667 disconnected (org.apache.kafka.clients.NetworkClient)

Attached is the client-ssl.properties file, used to start the Console produce

[#2]

@mqureshi, @Saulo Sobreiro, @Zhao Chaofeng - looping you in, any ideas ?

[#3]

Here is what i see the logs ..

So, it seems the Kafka Broker is starting up with SSL, however - when the Controller is not able to connect to the Broker ---------

server.log

[2017-07-24 20:57:19,461] INFO [ThrottledRequestReaper-Produce], Starting(kafka.server.ClientQuotaManager$ThrottledRequestReaper)[2017-07-24 20:57:19,464] INFO [ThrottledRequestReaper-Fetch], Starting(kafka.server.ClientQuotaManager$ThrottledRequestReaper)[2017-07-24 20:57:19,467] INFO Will not load MX4J, mx4j-tools.jar is not in the classpath (kafka.utils.Mx4jLoader$)[2017-07-24 20:57:19,474] INFO [Group Metadata Manager on Broker 1001]: Removed 0 expired offsets in 7 milliseconds. (kafka.coordinator.GroupMetadataManager)[2017-07-24 20:57:19,498] INFO Creating /brokers/ids/1001 (is it secure? false) (kafka.utils.ZKCheckedEphemeral)[2017-07-24 20:57:19,508] INFO Result of znode creation is: OK (kafka.utils.ZKCheckedEphemeral)[2017-07-24 20:57:19,510] INFO Registered broker 1001 at path /brokers/ids/1001 with addresses: PLAINTEXT -> EndPoint(nwk2-bdp-kafka-04.gdcs-qa.apple.com,6668,PLAINTEXT),SSL -> EndPoint(nwk2-bdp-kafka-04.gdcs-qa.apple.com,6667,SSL) (kafka.utils.ZkUtils)[2017-07-24 20:57:19,526] INFO [Kafka Server 1001], started (kafka.server.KafkaServer)

controller.log

[2017-07-24 20:59:56,323] WARN [Controller-1001-to-broker-1001-send-thread], Controller 1001's connection to broker nwk2-bdp-kafka-04.gdcs-qa.apple.com:6667 (id: 1001 rack: null) was unsuccessful (kafka.controller.RequestSendThread)java.io.IOException: Connection to nwk2-bdp-kafka-04.gdcs-qa.apple.com:6667 (id: 1001 rack: null) failedat kafka.utils.NetworkClientBlockingOps$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:63)at kafka.utils.NetworkClientBlockingOps$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:59)at kafka.utils.NetworkClientBlockingOps$.recursivePoll$1(NetworkClientBlockingOps.scala:112)at kafka.utils.NetworkClientBlockingOps$.kafka$utils$NetworkClientBlockingOps$pollUntil$extension(NetworkClientBlockingOps.scala:120)at kafka.utils.NetworkClientBlockingOps$.blockingReady$extension(NetworkClientBlockingOps.scala:59)at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:233)at kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:182)at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:181)at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)

[#4]

further update -> i recreated the certificates & here is the result of the verification

(i read in one post that the CN should match the FQDN, else it gives the error -

openssl s_client -debug -connect nwk2-bdp-kafka-04.gdcs-qa.apple.com:6667 -tls1
CONNECTED(00000003)
write to 0x8bd830 [0x908c33] (155 bytes => 155 (0x9B))
0000 - 16 03 01 00 96 01 00 00-92 03 01 59 76 79 79 99 ...........Yvyy.
0010 - 65 b5 a8 26 4c 80 20 9f-cc 73 86 b7 e0 ff b6 93 e..&L. ..s......
0020 - e4 bf 05 b7 34 0c 39 01-c1 b5 f6 00 00 4c c0 14 ....4.9......L..
0030 - c0 0a 00 39 00 38 00 88-00 87 c0 0f c0 05 00 35 ...9.8.........5
0040 - 00 84 c0 13 c0 09 00 33-00 32 00 9a 00 99 00 45 .......3.2.....E
.....
......
0570 - 32 d9 53 62 8d 34 47 ab-10 39 0e 16 ee ef ca 02 2.Sb.4G..9......
0580 - c6 37 12 a7 da 60 69 d3-48 1c 2d 5e f1 9d 55 da .7...`i.H.-^..U.
0590 - cd 11 e8 eb 18 bc ca b8-82 72 98 e7 67 a8 9e 0e .........r..g...
05a0 - 5f 05 6d c0 ae 23 0f c5-8c cf 77 0e _.m..#....w.
05af - <SPACES/NULS>
depth=0 C = us, ST = ca, L = nwk, O = gdcs, OU = gdcs-qa, CN = nwk2-bdp-kafka-04.gdcs-qa.apple.com
verify error:num=18:self signed certificate
verify return:1
depth=0 C = us, ST = ca, L = nwk, O = gdcs, OU = gdcs-qa, CN = nwk2-bdp-kafka-04.gdcs-qa.apple.com
verify return:1
write to 0x8bd830 [0x90e100] (143 bytes => 143 (0x8F))
0000 - 16 03 01 00 8a 10 00 00-86 85 04 00 c2 51 e7 95 .............Q..
0010 - 9a f9 56 c3 78 c7 1a 92-ba 0e 5a e7 17 48 81 d9 ..V.x.....Z..H..
0020 - 25 6a ce 4a 83 2c 31 d1-5a e4 ee d8 b7 db 9e 64 %j.J.,1.Z......d
0030 - 79 e5 e9 c0 58 a4 40 2b-5c 33 69 d7 2b 5f f5 f9 y...X.@+\3i.+_..
0040 - dc 96 2a e7 d6 7c be b9-bd ae 91 11 b3 01 69 0d ..*..|........i.
0050 - f8 45 01 81 44 13 98 d8-10 27 b8 d0 ee c9 50 51 .E..D....'....PQ
0060 - 85 b3 ab 23 46 d7 c1 65-77 d4 57 d0 25 79 4c 48 ...#F..ew.W.%yLH
0070 - c5 03 1d b9 45 43 c8 e2-d4 6b ce 7c 7b 5f 8e a0 ....EC...k.|{_..
0080 - f7 cf 82 ec c2 66 a4 10-79 28 03 7f 74 6e b2.....f..y(..tn.
write to 0x8bd830 [0x90e100] (6 bytes => 6 (0x6))
0000 - 14 03 01 00 01 01 ......
write to 0x8bd830 [0x90e100] (53 bytes => 53 (0x35))
0000 - 16 03 01 00 30 c2 b9 f5-bc 0f fb ce 98 f4 a1 fb ....0...........
0010 - 11 e3 70 b5 5c 14 27 88-72 e0 96 b4 95 cf 86 f5 ..p.\.'.r.......
0020 - 8e 88 91 ff f8 58 b1 a2-cc c5 62 17 a6 c2 22 9a .....X....b...".
0030 - 9a 90 80 7d 04...}.
read from 0x8bd830 [0x9046e3] (5 bytes => 5 (0x5))
0000 - 14 03 01 00 01.....
read from 0x8bd830 [0x9046e8] (1 bytes => 1 (0x1))
0000 - 01.
read from 0x8bd830 [0x9046e3] (5 bytes => 5 (0x5))
0000 - 16 03 01 00 30....0
read from 0x8bd830 [0x9046e8] (48 bytes => 48 (0x30))
0000 - ff bc bf 23 4d fa 4b 8d-cb fc 28 10 c0 c4 57 c8 ...#M.K...(...W.
0010 - 53 14 f7 77 65 71 e5 60-44 a9 27 7b 69 11 fc a9 S..weq.`D.'{i...
0020 - 10 52 f9 06 d3 d9 00 07-e8 5a f0 35 79 23 18 9b .R.......Z.5y#..
---
Certificate chain
0 s:/C=us/ST=ca/L=nwk/O=gdcs/OU=gdcs-qa/CN=nwk2-bdp-kafka-04.gdcs-qa.apple.com
i:/C=us/ST=ca/L=nwk/O=gdcs/OU=gdcs-qa/CN=nwk2-bdp-kafka-04.gdcs-qa.apple.com
---
Server certificate
-----BEGIN CERTIFICATE-----
MIIDvTCCAqWgAwIBAgIEbFXDGDANBgkqhkiG9w0BAQsFADB3MQswCQYDVQQGEwJ1
czELMAkGA1UECBMCY2ExDDAKBgNVBAcTA253azENMAsGA1UEChMEZ2RjczEQMA4G
A1UECxMHZ2Rjcy1xYTEsMCoGA1UEAxMjbndrMi1iZHAta2Fma2EtMDQuZ2Rjcy1x
YS5hcHBsZS5jb20wHhcNMTcwNzI0MjIzNTE2WhcNMTgwNzE5MjIzNTE2WjB3MQsw
CQYDVQQGEwJ1czELMAkGA1UECBMCY2ExDDAKBgNVBAcTA253azENMAsGA1UEChME
Z2RjczEQMA4GA1UECxMHZ2Rjcy1xYTEsMCoGA1UEAxMjbndrMi1iZHAta2Fma2Et
MDQuZ2Rjcy1xYS5hcHBsZS5jb20wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEK
AoIBAQDZxDGpPOh17dhxKnTwdDYLXXQL6Kkq4DLQ56x0DgJGGW2zwfeBhfNpOOnE
6P02NE8BLenSvMs/FqMHJ+ywtCGp/Yxth9QUeheVAr8qHPV7rvnN1p1OL7ezyzQY
d/pwu2KP5c/ROX3izfpMIVvF+04njw56ZMkmHECiTs6Cel3P9649TkTn62ssdlhC
HZT0TaYmoMgEW4Viv5XvEC8TCHTJT03O2zD2JM+P4rFa/JeSjeY7MBHzwMb7O/uV
dqNRQi9ziTfxSA9xCz72nZkLUhk0LGkecoVRaFiImWesQ3xJ/ys4DvAaHY2XeU3g
HMGIiQh0zSvq5xX3EIEa5hOBhgJ3AgMBAAGjUTBPMC4GA1UdEQQnMCWCI253azIt
YmRwLWthZmthLTA0LmdkY3MtcWEuYXBwbGUuY29tMB0GA1UdDgQWBBSc6pEu8gEu
/6xddU9riRIwPQwKBDANBgkqhkiG9w0BAQsFAAOCAQEAckfOcvs2SrdodvHo2DUE
LqkizsSE2T1RI0VNIejDSOZq4kjctj0skUPbu/EyUqt78ZObXQgf4uZHXLKnMp4o
Em2qs/XrQN+SiaFEE/o1ng5XvBBJJbFoAjmh5rNeX621vnx/pqWqNVs+bgwAsfM2
sGESAJqbukm4VgLXuDLBhkbdwhx2E8NT9GnqloJRFeAWjcwQGYsIuXKa7jU1eO4b
MAwWSxW1wk/w3cyZ50j4WgPNM4imFbHjq6B3cUjyU0vFwqbv7SEMTHsFV24X/7n5
+mIASEqRWfgATmTqsKFvmgsFvEZhi8FPoR0yRAZcz78WSijt0NWVFO5KDG1Y12Ok
OQ==
-----END CERTIFICATE-----
subject=/C=us/ST=ca/L=nwk/O=gdcs/OU=gdcs-qa/CN=nwk2-bdp-kafka-04.gdcs-qa.apple.com
issuer=/C=us/ST=ca/L=nwk/O=gdcs/OU=gdcs-qa/CN=nwk2-bdp-kafka-04.gdcs-qa.apple.com
---
No client certificate CA names sent
Server Temp Key: ECDH, secp521r1, 521 bits
---
SSL handshake has read 1519 bytes and written 357 bytes
---
New, TLSv1/SSLv3, Cipher is ECDHE-RSA-AES256-SHA
Server public key is 2048 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
SSL-Session:
Protocol: TLSv1
Cipher: ECDHE-RSA-AES256-SHA
Session-ID: 59767979D3C289D1EB584B04C9CB1DF4659C017296247CC84BB1F7D7842BA9B1
Session-ID-ctx:
Master-Key: 795C06945CBD2BABC55A269FF46EAE6848E3834E5EAB54886E10DFD5289498901A5169AFE268872F4B0A3439DA20A378
Key-Arg : None
Krb5 Principal: None
PSK identity: None
PSK identity hint: None
Start Time: 1500936569
Timeout : 7200 (sec)
Verify return code: 18 (self signed certificate)

[#5]

@mqureshi - any ideas on how to debug this ?

[#6]

@Karan Alang

Can you share your server.properties for review?

[#7]

@Daniel Kozlowski - added additional property in server.properties

ssl.endpoint.identification.algorithm=HTTPS

uploading the updated server.properties, do let me know if you have any ideas on this

serverproperties.txt

thanks!

[#8]

@Karan Alang

Remove:

- ssl.enabled.protocols=TLSv1.2,TLSv1.1,TLSv1 
- ssl.endpoint.identification.algorithm=HTTPS 
- ssl.secure.random.implementation=SHA1PRNG

Add:

advertised.listeners=SSL://nwk2-bdp-kafka-04.gdcs-qa.apple.com:6668,PLAINTEXT://nwk2-bdp-kafka-04.gdcs-qa.apple.com:6667

client-ssl.properties:

security.protocol=SASL_SSL
ssl.truststore.location=/tmp/ssl-kafka/server.truststore.jks
ssl.truststore.password=changeit

Run (if your cluster is non-Kerberized)

./kafka-console-producer.sh --broker-list nwk2-bdp-kafka-04.gdcs-qa.apple.com:6668 --topic <topic> --producer.config client-ssl.properties --security-protocol SSL

[#9]

@Daniel Kozlowski - thanks for the response..

I made the changes suggested, restarted zookeeper & kafka .. however - the error seems the same

Any ideas on how to resolve/debug this ?

Attaching the updated server.properties file

serverproperties-1.txt

error in controller.log

-----------------------------

[2017-07-26 05:02:54,199] WARN [Controller-1001-to-broker-1001-send-thread], Controller 1001's connection to broker nwk2-bdp-kafka-04.gdcs-qa.apple.com:6668 (id: 1001 rack: null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to nwk2-bdp-kafka-04.gdcs-qa.apple.com:6668 (id: 1001 rack: null) failed
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:63)
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:59)
at kafka.utils.NetworkClientBlockingOps$.recursivePoll$1(NetworkClientBlockingOps.scala:112)
at kafka.utils.NetworkClientBlockingOps$.kafka$utils$NetworkClientBlockingOps$$pollUntil$extension(NetworkClientBlockingOps.scala:120)
at kafka.utils.NetworkClientBlockingOps$.blockingReady$extension(NetworkClientBlockingOps.scala:59)
at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:233)
at kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:182)
at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:181)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
[2017-07-26 05:02:54,325] WARN [Controller-1001-to-broker-1002-send-thread], Controller 1001's connection to broker nwk2-bdp-kafka-05.gdcs-qa.apple.com:6668 (id: 1002 rack: null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to nwk2-bdp-kafka-05.gdcs-qa.apple.com:6668 (id: 1002 rack: null) failed
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:63)
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:59)
at kafka.utils.NetworkClientBlockingOps$.recursivePoll$1(NetworkClientBlockingOps.scala:112)
at kafka.utils.NetworkClientBlockingOps$.kafka$utils$NetworkClientBlockingOps$$pollUntil$extension(NetworkClientBlockingOps.scala:120)
at kafka.utils.NetworkClientBlockingOps$.blockingReady$extension(NetworkClientBlockingOps.scala:59)
at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:233)
at kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:182)
at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:181)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
[2017-07-26 05:02:54,440] WARN [Controller-1001-to-broker-1003-send-thread], Controller 1001's connection to broker nwk2-bdp-kafka-06.gdcs-qa.apple.com:6668 (id: 1003 rack: null) was unsuccessful (kafka.controller.RequestSendThread)
java.io.IOException: Connection to nwk2-bdp-kafka-06.gdcs-qa.apple.com:6668 (id: 1003 rack: null) failed
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:63)
at kafka.utils.NetworkClientBlockingOps$$anonfun$blockingReady$extension$2.apply(NetworkClientBlockingOps.scala:59)
at kafka.utils.NetworkClientBlockingOps$.recursivePoll$1(NetworkClientBlockingOps.scala:112)
at kafka.utils.NetworkClientBlockingOps$.kafka$utils$NetworkClientBlockingOps$$pollUntil$extension(NetworkClientBlockingOps.scala:120)
at kafka.utils.NetworkClientBlockingOps$.blockingReady$extension(NetworkClientBlockingOps.scala:59)
at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:233)
at kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:182)
at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:181)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)

Error i see in the Console Producer ->

/usr/hdp/2.5.3.0-37/kafka/bin/kafka-console-producer.sh --broker-list nwk2-bdp-kafka-05.gdcs-qa.apple.com:6668,nwk2-bdp-kafka-04.gdcs-qa.apple.com:6668,nwk2-bdp-kafka-06.gdcs-qa.apple.com:6668 --topic sslTopic3 --producer.config /tmp/ssl-kafka/client-ssl.properties --security-protocol SSL
hi
hello
[2017-07-26 04:42:48,192] ERROR Error when sending message to topic sslTopic3 with key: null, value: 2 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
org.apache.kafka.common.errors.TimeoutException: Failed to update metadata after 60000 ms.
[2017-07-26 04:43:48,196] ERROR Error when sending message to topic sslTopic3 with key: null, value: 5 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
org.apache.kafka.common.errors.TimeoutException: Failed to update metadata after 60000 ms.

[#10]

@Karan Alang

For debugging do this - change the log4j.rootLogger parameter in /etc/kafka/conf/tools-log4j.properties as:

log4j.rootLogger=DEBUG, stderr 

Also check if producer works find for PLAINTEXT like:

/usr/hdp/current/kafka-broker/bin/kafka-console-producer.sh --broker-list <broker-node>:6667 --topic <topic> --security-protocol PLAINTEXT 

For the testing purpose - use only one broker-node.