My kafka pods are failing to start because of a timeout connecting to ZooKeeper. The details look very similar to #1392, but I'm on Kubernetes v1.14.3-rancher1-1 and this is still happening. The referenced issue fixes in #1392 seem to imply that the fix described there has already been merged.
Kafka
2019-08-01 19:25:36,967 INFO Initiating client connection, connectString=localhost:2181 sessionTimeout=6000 watcher=kafka.zookeeper.ZooKeeperClient$ZooKeeperClientWatcher$@6a400542 (org.apache.zookeeper.ZooKeeper) [main]
2019-08-01 19:25:36,984 INFO Starting poller (io.strimzi.kafka.agent.KafkaAgent) [main]
2019-08-01 19:25:36,987 INFO [ZooKeeperClient Kafka server] Waiting until connected. (kafka.zookeeper.ZooKeeperClient) [main]
2019-08-01 19:25:36,988 INFO Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn) [main-SendThread(localhost:2181)]
2019-08-01 19:25:36,997 INFO Socket connection established to localhost/127.0.0.1:2181, initiating session (org.apache.zookeeper.ClientCnxn) [main-SendThread(localhost:2181)]
2019-08-01 19:25:42,990 INFO [ZooKeeperClient Kafka server] Closing. (kafka.zookeeper.ZooKeeperClient) [main]
2019-08-01 19:25:42,996 WARN Client session timed out, have not heard from server in 6000ms for sessionid 0x0 (org.apache.zookeeper.ClientCnxn) [main-SendThread(localhost:2181)]
2019-08-01 19:25:43,100 INFO Session: 0x0 closed (org.apache.zookeeper.ZooKeeper) [main]
2019-08-01 19:25:43,101 INFO EventThread shut down for session: 0x0 (org.apache.zookeeper.ClientCnxn) [main-EventThread]
2019-08-01 19:25:43,103 INFO [ZooKeeperClient Kafka server] Closed. (kafka.zookeeper.ZooKeeperClient) [main]
2019-08-01 19:25:43,107 ERROR Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer) [main]
kafka.zookeeper.ZooKeeperClientTimeoutException: Timed out waiting for connection while in state: CONNECTING
at kafka.zookeeper.ZooKeeperClient.$anonfun$waitUntilConnected$3(ZooKeeperClient.scala:258)
at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:253)
at kafka.zookeeper.ZooKeeperClient.waitUntilConnected(ZooKeeperClient.scala:254)
at kafka.zookeeper.ZooKeeperClient.
at kafka.zk.KafkaZkClient$.apply(KafkaZkClient.scala:1826)
at kafka.server.KafkaServer.createZkClient$1(KafkaServer.scala:364)
at kafka.server.KafkaServer.initZkClient(KafkaServer.scala:387)
at kafka.server.KafkaServer.startup(KafkaServer.scala:207)
at kafka.server.KafkaServerStartable.startup(KafkaServerStartable.scala:38)
at kafka.Kafka$.main(Kafka.scala:84)
at kafka.Kafka.main(Kafka.scala)
tls sidecar
2019.08.01 19:25:23 LOG5[1:140071593224256]: stunnel 4.56 on x86_64-redhat-linux-gnu platform
2019.08.01 19:25:23 LOG5[1:140071593224256]: Compiled/running with OpenSSL 1.0.1e-fips 11 Feb 2013
2019.08.01 19:25:23 LOG5[1:140071593224256]: Threading:PTHREAD Sockets:POLL,IPv6 SSL:ENGINE,OCSP,FIPS Auth:LIBWRAP
2019.08.01 19:25:23 LOG5[1:140071593224256]: Reading configuration from file /tmp/stunnel.conf
2019.08.01 19:25:23 LOG5[1:140071593224256]: FIPS mode is enabled
2019.08.01 19:25:23 LOG4[1:140071593224256]: Insecure file permissions on /etc/tls-sidecar/kafka-brokers/my-cluster-kafka-0.key
2019.08.01 19:25:23 LOG5[1:140071593224256]: Configuration successful
2019.08.01 19:25:26 LOG5[1:140071593219840]: Service [zookeeper-2181] accepted connection from 127.0.0.1:56070
2019.08.01 19:25:26 LOG5[1:140071593219840]: connect_blocking: connected 10.43.52.117:2181
2019.08.01 19:25:26 LOG5[1:140071593219840]: Service [zookeeper-2181] connected remote server from 10.42.3.21:51230
2019.08.01 19:25:26 LOG5[1:140071593219840]: Certificate accepted: depth=1, /O=io.strimzi/CN=cluster-ca v0
2019.08.01 19:25:26 LOG5[1:140071593219840]: Certificate accepted: depth=0, /O=io.strimzi/CN=my-cluster-zookeeper
2019.08.01 19:25:26 LOG5[1:140071593219840]: SSL socket error: Connection reset by peer (104)
2019.08.01 19:25:26 LOG5[1:140071593219840]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.01 19:25:27 LOG5[1:140071593219840]: Service [zookeeper-2181] accepted connection from 127.0.0.1:56082
2019.08.01 19:25:37 LOG3[1:140071593219840]: connect_blocking: s_poll_wait 10.43.52.117:2181: TIMEOUTconnect exceeded
2019.08.01 19:25:37 LOG5[1:140071593219840]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.01 19:25:38 LOG5[1:140071593219840]: Service [zookeeper-2181] accepted connection from 127.0.0.1:56120
2019.08.01 19:25:48 LOG3[1:140071593219840]: connect_blocking: s_poll_wait 10.43.52.117:2181: TIMEOUTconnect exceeded
2019.08.01 19:25:48 LOG5[1:140071593219840]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.01 19:26:05 LOG5[1:140071593219840]: Service [zookeeper-2181] accepted connection from 127.0.0.1:56190
2019.08.01 19:26:15 LOG3[1:140071593219840]: connect_blocking: s_poll_wait 10.43.52.117:2181: TIMEOUTconnect exceeded
2019.08.01 19:26:15 LOG5[1:140071593219840]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.01 19:26:39 LOG5[1:140071593219840]: Service [zookeeper-2181] accepted connection from 127.0.0.1:56290
2019.08.01 19:26:49 LOG3[1:140071593219840]: connect_blocking: s_poll_wait 10.43.52.117:2181: TIMEOUTconnect exceeded
2019.08.01 19:26:49 LOG5[1:140071593219840]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
It looks like the TLS sidecar cannot connect to the Zookeeper nodes. Do the TLS sidecars in the Zookeeper pod show some errors? If the connection went through, they should show it.
Sorry for the delayed reply! Yes it looks like the TLS sidecars aren't connecting. I'll paste some logs as I track it back.
my-cluster-kafka-0 tls-sidecar
Starting Stunnel with configuration:
pid = /usr/local/var/run/stunnel.pid
foreground = yes
debug = notice
[zookeeper-2181]
client = yes
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/kafka-brokers/my-cluster-kafka-0.crt
key = /etc/tls-sidecar/kafka-brokers/my-cluster-kafka-0.key
accept = 127.0.0.1:2181
connect = my-cluster-zookeeper-client:2181
delay = yes
verify = 2
2019.08.06 20:49:09 LOG5[1:140239478401088]: stunnel 4.56 on x86_64-redhat-linux-gnu platform
2019.08.06 20:49:09 LOG5[1:140239478401088]: Compiled/running with OpenSSL 1.0.1e-fips 11 Feb 2013
2019.08.06 20:49:09 LOG5[1:140239478401088]: Threading:PTHREAD Sockets:POLL,IPv6 SSL:ENGINE,OCSP,FIPS Auth:LIBWRAP
2019.08.06 20:49:09 LOG5[1:140239478401088]: Reading configuration from file /tmp/stunnel.conf
2019.08.06 20:49:09 LOG5[1:140239478401088]: FIPS mode is enabled
2019.08.06 20:49:09 LOG4[1:140239478401088]: Insecure file permissions on /etc/tls-sidecar/kafka-brokers/my-cluster-kafka-0.key
2019.08.06 20:49:09 LOG5[1:140239478401088]: Configuration successful
2019.08.06 20:49:11 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54160
2019.08.06 20:49:11 LOG5[1:140239478396672]: connect_blocking: connected 10.43.170.24:2181
2019.08.06 20:49:11 LOG5[1:140239478396672]: Service [zookeeper-2181] connected remote server from 10.42.3.60:57914
2019.08.06 20:49:11 LOG5[1:140239478396672]: Certificate accepted: depth=1, /O=io.strimzi/CN=cluster-ca v0
2019.08.06 20:49:11 LOG5[1:140239478396672]: Certificate accepted: depth=0, /O=io.strimzi/CN=my-cluster-zookeeper
2019.08.06 20:49:11 LOG5[1:140239478396672]: SSL socket error: Connection reset by peer (104)
2019.08.06 20:49:11 LOG5[1:140239478396672]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:13 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54172
2019.08.06 20:49:23 LOG3[1:140239478396672]: connect_blocking: s_poll_wait 10.43.170.24:2181: TIMEOUTconnect exceeded
2019.08.06 20:49:23 LOG5[1:140239478396672]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:23 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54202
2019.08.06 20:49:23 LOG5[1:140239478396672]: connect_blocking: connected 10.43.170.24:2181
2019.08.06 20:49:23 LOG5[1:140239478396672]: Service [zookeeper-2181] connected remote server from 10.42.3.60:57956
2019.08.06 20:49:23 LOG5[1:140239478396672]: SSL socket error: Connection reset by peer (104)
2019.08.06 20:49:23 LOG5[1:140239478396672]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:24 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54210
2019.08.06 20:49:24 LOG5[1:140239478396672]: connect_blocking: connected 10.43.170.24:2181
2019.08.06 20:49:24 LOG5[1:140239478396672]: Service [zookeeper-2181] connected remote server from 10.42.3.60:57964
2019.08.06 20:49:24 LOG5[1:140239478396672]: SSL socket error: Connection reset by peer (104)
2019.08.06 20:49:24 LOG5[1:140239478396672]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:26 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54220
2019.08.06 20:49:36 LOG3[1:140239478396672]: connect_blocking: s_poll_wait 10.43.170.24:2181: TIMEOUTconnect exceeded
2019.08.06 20:49:36 LOG5[1:140239478396672]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:54 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54302
2019.08.06 20:49:54 LOG5[1:140239478396672]: connect_blocking: connected 10.43.170.24:2181
2019.08.06 20:49:54 LOG5[1:140239478396672]: Service [zookeeper-2181] connected remote server from 10.42.3.60:58056
2019.08.06 20:49:54 LOG5[1:140239478396672]: SSL socket error: Connection reset by peer (104)
2019.08.06 20:49:54 LOG5[1:140239478396672]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:55 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54310
2019.08.06 20:50:05 LOG3[1:140239478396672]: connect_blocking: s_poll_wait 10.43.170.24:2181: TIMEOUTconnect exceeded
2019.08.06 20:50:05 LOG5[1:140239478396672]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:50:36 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54424
2019.08.06 20:50:36 LOG5[1:140239478396672]: connect_blocking: connected 10.43.170.24:2181
2019.08.06 20:50:36 LOG5[1:140239478396672]: Service [zookeeper-2181] connected remote server from 10.42.3.60:58178
2019.08.06 20:50:36 LOG5[1:140239478396672]: SSL socket error: Connection reset by peer (104)
2019.08.06 20:50:36 LOG5[1:140239478396672]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:50:37 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54440
2019.08.06 20:50:47 LOG3[1:140239478396672]: connect_blocking: s_poll_wait 10.43.170.24:2181: TIMEOUTconnect exceeded
2019.08.06 20:50:47 LOG5[1:140239478396672]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:51:29 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54584
2019.08.06 20:51:29 LOG5[1:140239478396672]: connect_blocking: connected 10.43.170.24:2181
2019.08.06 20:51:29 LOG5[1:140239478396672]: Service [zookeeper-2181] connected remote server from 10.42.3.60:58338
2019.08.06 20:51:29 LOG5[1:140239478396672]: SSL socket error: Connection reset by peer (104)
2019.08.06 20:51:29 LOG5[1:140239478396672]: Connection reset: 49 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:51:30 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54590
2019.08.06 20:51:40 LOG3[1:140239478396672]: connect_blocking: s_poll_wait 10.43.170.24:2181: TIMEOUTconnect exceeded
2019.08.06 20:51:40 LOG5[1:140239478396672]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:53:09 LOG5[1:140239478396672]: Service [zookeeper-2181] accepted connection from 127.0.0.1:54856
2019.08.06 20:53:19 LOG3[1:140239478396672]: connect_blocking: s_poll_wait 10.43.170.24:2181: TIMEOUTconnect exceeded
2019.08.06 20:53:19 LOG5[1:140239478396672]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
Here's one for one of the Zookeeper pods:
Detected Zookeeper ID 1
Starting Zookeeper with configuration:
dataDir=/var/lib/zookeeper/data
clientPort=21810
autopurge.purgeInterval=1
tickTime=2000
initLimit=5
syncLimit=2
server.1=127.0.0.1:28880:38880
server.2=127.0.0.1:28881:38881
server.3=127.0.0.1:28882:38882
OpenJDK 64-Bit Server VM warning: If the number of processors is expected to increase from one, then you should configure the number of parallel GC threads appropriately using -XX:ParallelGCThreads=N
2019-08-06T20:48:42.463+0000: 0.250: [GC pause (G1 Evacuation Pause) (young), 0.0094574 secs]
[Parallel Time: 9.0 ms, GC Workers: 1]
[GC Worker Start (ms): 249.9]
[Ext Root Scanning (ms): 3.7]
[Update RS (ms): 0.0]
[Processed Buffers: 0]
[Scan RS (ms): 0.0]
[Code Root Scanning (ms): 0.2]
[Object Copy (ms): 5.0]
[Termination (ms): 0.0]
[Termination Attempts: 1]
[GC Worker Other (ms): 0.0]
[GC Worker Total (ms): 8.9]
[GC Worker End (ms): 258.8]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.0 ms]
[Other: 0.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.2 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.0 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.0 ms]
[Eden: 4096.0K(4096.0K)->0.0B(4096.0K) Survivors: 0.0B->4096.0K Heap: 4096.0K(128.0M)->1385.5K(128.0M)]
[Times: user=0.01 sys=0.01, real=0.01 secs]
2019-08-06T20:48:42.558+0000: 0.345: [GC pause (G1 Evacuation Pause) (young), 0.0100555 secs]
[Parallel Time: 9.2 ms, GC Workers: 1]
[GC Worker Start (ms): 345.1]
[Ext Root Scanning (ms): 2.6]
[Update RS (ms): 0.0]
[Processed Buffers: 0]
[Scan RS (ms): 0.0]
[Code Root Scanning (ms): 0.4]
[Object Copy (ms): 6.1]
[Termination (ms): 0.0]
[Termination Attempts: 1]
[GC Worker Other (ms): 0.0]
[GC Worker Total (ms): 9.1]
[GC Worker End (ms): 354.2]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.0 ms]
[Other: 0.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.7 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.0 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.0 ms]
[Eden: 4096.0K(4096.0K)->0.0B(4096.0K) Survivors: 4096.0K->4096.0K Heap: 5481.5K(128.0M)->3845.7K(128.0M)]
[Times: user=0.01 sys=0.00, real=0.01 secs]
2019-08-06 20:48:42,572 INFO Reading configuration from: /tmp/zookeeper.properties (org.apache.zookeeper.server.quorum.QuorumPeerConfig) [main]
2019-08-06 20:48:42,581 INFO Resolved hostname: 127.0.0.1 to address: /127.0.0.1 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,581 INFO Resolved hostname: 127.0.0.1 to address: /127.0.0.1 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,581 INFO Resolved hostname: 127.0.0.1 to address: /127.0.0.1 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,581 INFO Defaulting to majority quorums (org.apache.zookeeper.server.quorum.QuorumPeerConfig) [main]
2019-08-06 20:48:42,585 INFO autopurge.snapRetainCount set to 3 (org.apache.zookeeper.server.DatadirCleanupManager) [main]
2019-08-06 20:48:42,585 INFO autopurge.purgeInterval set to 1 (org.apache.zookeeper.server.DatadirCleanupManager) [main]
2019-08-06 20:48:42,586 INFO Purge task started. (org.apache.zookeeper.server.DatadirCleanupManager) [PurgeTask]
2019-08-06 20:48:42,598 INFO Starting quorum peer (org.apache.zookeeper.server.quorum.QuorumPeerMain) [main]
2019-08-06 20:48:42,601 INFO Purge task completed. (org.apache.zookeeper.server.DatadirCleanupManager) [PurgeTask]
2019-08-06T20:48:42.601+0000: 0.388: [GC pause (G1 Evacuation Pause) (young), 0.0097869 secs]
[Parallel Time: 8.9 ms, GC Workers: 1]
[GC Worker Start (ms): 387.7]
[Ext Root Scanning (ms): 1.8]
[Update RS (ms): 0.0]
[Processed Buffers: 0]
[Scan RS (ms): 0.0]
[Code Root Scanning (ms): 0.4]
[Object Copy (ms): 6.5]
[Termination (ms): 0.0]
[Termination Attempts: 1]
[GC Worker Other (ms): 0.0]
[GC Worker Total (ms): 8.8]
[GC Worker End (ms): 396.5]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.1 ms]
[Other: 0.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.7 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.0 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.0 ms]
[Eden: 4096.0K(4096.0K)->0.0B(4096.0K) Survivors: 4096.0K->4096.0K Heap: 7941.7K(128.0M)->3039.5K(128.0M)]
[Times: user=0.01 sys=0.00, real=0.01 secs]
2019-08-06 20:48:42,614 INFO Using org.apache.zookeeper.server.NIOServerCnxnFactory as server connection factory (org.apache.zookeeper.server.ServerCnxnFactory) [main]
2019-08-06 20:48:42,617 INFO binding to port 0.0.0.0/0.0.0.0:21810 (org.apache.zookeeper.server.NIOServerCnxnFactory) [main]
2019-08-06 20:48:42,619 INFO tickTime set to 2000 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,619 INFO initLimit set to 5 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,619 INFO minSessionTimeout set to -1 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,619 INFO maxSessionTimeout set to -1 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,625 INFO QuorumPeer communication is not secured! (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,625 INFO quorum.cnxn.threads.size set to 20 (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,627 INFO currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,628 INFO acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation (org.apache.zookeeper.server.quorum.QuorumPeer) [main]
2019-08-06 20:48:42,635 INFO My election bind port: /127.0.0.1:38880 (org.apache.zookeeper.server.quorum.QuorumCnxManager) [ListenerThread]
2019-08-06 20:48:42,649 INFO LOOKING (org.apache.zookeeper.server.quorum.QuorumPeer) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:42,652 INFO New election. My id = 1, proposed zxid=0x0 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:42,655 INFO Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) (org.apache.zookeeper.server.quorum.FastLeaderElection) [WorkerReceiver[myid=1]]
2019-08-06 20:48:42,659 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [WorkerSender[myid=1]]
2019-08-06 20:48:42,659 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [WorkerSender[myid=1]]
2019-08-06 20:48:42,857 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:42,858 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:42,858 INFO Notification time out: 400 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:43,258 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:43,259 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:43,259 INFO Notification time out: 800 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:44,060 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:44,061 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:44,061 INFO Notification time out: 1600 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:45,662 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:45,662 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:45,663 INFO Notification time out: 3200 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:48,863 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:48,864 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:48,864 INFO Notification time out: 6400 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:55,265 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:55,265 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:55,265 INFO Notification time out: 12800 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:48:58,606 INFO Accepted socket connection from /127.0.0.1:46698 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:48:58,614 INFO The list of known four letter word commands is : [{1936881266=srvr, 1937006964=stat, 2003003491=wchc, 1685417328=dump, 1668445044=crst, 1936880500=srst, 1701738089=envi, 1668247142=conf, 2003003507=wchs, 2003003504=wchp, 1668247155=cons, 1835955314=mntr, 1769173615=isro, 1920298859=ruok, 1735683435=gtmk, 1937010027=stmk}] (org.apache.zookeeper.server.ServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:48:58,614 INFO The list of enabled four letter word commands is : [[wchs, stat, stmk, conf, ruok, mntr, srvr, envi, srst, isro, dump, gtmk, crst, cons]] (org.apache.zookeeper.server.ServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:48:58,614 INFO Processing ruok command from /127.0.0.1:46698 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:48:58,616 INFO Closed socket connection for client /127.0.0.1:46698 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-2]
2019-08-06 20:49:03,603 INFO Accepted socket connection from /127.0.0.1:46710 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:03,603 INFO Processing ruok command from /127.0.0.1:46710 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:03,604 INFO Closed socket connection for client /127.0.0.1:46710 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-3]
2019-08-06 20:49:08,066 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:49:08,067 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:49:08,067 INFO Notification time out: 25600 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:49:08,595 INFO Accepted socket connection from /127.0.0.1:46734 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:08,595 INFO Processing ruok command from /127.0.0.1:46734 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:08,596 INFO Closed socket connection for client /127.0.0.1:46734 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-4]
2019-08-06 20:49:11,488 INFO Accepted socket connection from /127.0.0.1:46744 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:11,490 WARN Exception causing close of session 0x0: ZooKeeperServer not running (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:11,490 INFO Closed socket connection for client /127.0.0.1:46744 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:13,602 INFO Accepted socket connection from /127.0.0.1:46756 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:13,603 INFO Processing ruok command from /127.0.0.1:46756 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:13,604 INFO Closed socket connection for client /127.0.0.1:46756 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-5]
2019-08-06 20:49:18,565 INFO Accepted socket connection from /127.0.0.1:46768 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:18,565 INFO Processing ruok command from /127.0.0.1:46768 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:18,566 INFO Closed socket connection for client /127.0.0.1:46768 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-6]
2019-08-06 20:49:23,608 INFO Accepted socket connection from /127.0.0.1:46780 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:23,608 INFO Processing ruok command from /127.0.0.1:46780 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:23,609 INFO Closed socket connection for client /127.0.0.1:46780 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-7]
2019-08-06 20:49:23,670 INFO Accepted socket connection from /127.0.0.1:46786 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:23,671 WARN Exception causing close of session 0x0: ZooKeeperServer not running (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:23,671 INFO Closed socket connection for client /127.0.0.1:46786 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:24,850 INFO Accepted socket connection from /127.0.0.1:46794 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:24,850 WARN Exception causing close of session 0x0: ZooKeeperServer not running (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:24,851 INFO Closed socket connection for client /127.0.0.1:46794 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:28,601 INFO Accepted socket connection from /127.0.0.1:46812 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:28,601 INFO Processing ruok command from /127.0.0.1:46812 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:28,602 INFO Closed socket connection for client /127.0.0.1:46812 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-8]
2019-08-06 20:49:33,607 INFO Accepted socket connection from /127.0.0.1:46824 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:33,608 INFO Processing ruok command from /127.0.0.1:46824 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:33,609 INFO Closed socket connection for client /127.0.0.1:46824 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-9]
2019-08-06 20:49:33,668 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:49:33,668 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:49:33,669 INFO Notification time out: 51200 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:49:38,577 INFO Accepted socket connection from /127.0.0.1:46844 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:38,577 INFO Processing ruok command from /127.0.0.1:46844 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:38,578 INFO Closed socket connection for client /127.0.0.1:46844 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-10]
2019-08-06 20:49:43,612 INFO Accepted socket connection from /127.0.0.1:46856 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:43,612 INFO Processing ruok command from /127.0.0.1:46856 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06T20:49:43.613+0000: 61.400: [GC pause (G1 Evacuation Pause) (young), 0.0121468 secs]
[Parallel Time: 11.1 ms, GC Workers: 1]
[GC Worker Start (ms): 61399.9]
[Ext Root Scanning (ms): 3.3]
[Update RS (ms): 0.0]
[Processed Buffers: 0]
[Scan RS (ms): 0.0]
[Code Root Scanning (ms): 0.5]
[Object Copy (ms): 7.1]
[Termination (ms): 0.0]
[Termination Attempts: 1]
[GC Worker Other (ms): 0.0]
[GC Worker Total (ms): 11.0]
[GC Worker End (ms): 61410.9]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.0 ms]
[Other: 1.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.8 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.0 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.0 ms]
[Eden: 4096.0K(4096.0K)->0.0B(4096.0K) Survivors: 4096.0K->4096.0K Heap: 7135.5K(128.0M)->4338.5K(128.0M)]
[Times: user=0.01 sys=0.00, real=0.01 secs]
2019-08-06 20:49:43,626 INFO Closed socket connection for client /127.0.0.1:46856 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-11]
2019-08-06 20:49:48,584 INFO Accepted socket connection from /127.0.0.1:46868 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:48,585 INFO Processing ruok command from /127.0.0.1:46868 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:48,586 INFO Closed socket connection for client /127.0.0.1:46868 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-12]
2019-08-06 20:49:53,587 INFO Accepted socket connection from /127.0.0.1:46880 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:53,588 INFO Processing ruok command from /127.0.0.1:46880 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:53,589 INFO Closed socket connection for client /127.0.0.1:46880 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-13]
2019-08-06 20:49:54,270 INFO Accepted socket connection from /127.0.0.1:46886 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:54,272 WARN Exception causing close of session 0x0: ZooKeeperServer not running (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:54,272 INFO Closed socket connection for client /127.0.0.1:46886 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:58,593 INFO Accepted socket connection from /127.0.0.1:46906 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:58,593 INFO Processing ruok command from /127.0.0.1:46906 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:49:58,594 INFO Closed socket connection for client /127.0.0.1:46906 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-14]
2019-08-06 20:50:03,612 INFO Accepted socket connection from /127.0.0.1:46918 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:03,612 INFO Processing ruok command from /127.0.0.1:46918 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:03,613 INFO Closed socket connection for client /127.0.0.1:46918 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-15]
2019-08-06 20:50:08,600 INFO Accepted socket connection from /127.0.0.1:46930 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:08,600 INFO Processing ruok command from /127.0.0.1:46930 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:08,601 INFO Closed socket connection for client /127.0.0.1:46930 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-16]
2019-08-06 20:50:13,596 INFO Accepted socket connection from /127.0.0.1:46942 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:13,597 INFO Processing ruok command from /127.0.0.1:46942 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:13,598 INFO Closed socket connection for client /127.0.0.1:46942 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-17]
2019-08-06 20:50:18,587 INFO Accepted socket connection from /127.0.0.1:46954 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:18,587 INFO Processing ruok command from /127.0.0.1:46954 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:18,588 INFO Closed socket connection for client /127.0.0.1:46954 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-18]
2019-08-06 20:50:23,609 INFO Accepted socket connection from /127.0.0.1:46966 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:23,609 INFO Processing ruok command from /127.0.0.1:46966 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:23,610 INFO Closed socket connection for client /127.0.0.1:46966 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-19]
2019-08-06 20:50:24,869 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:50:24,870 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:50:24,870 INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:50:28,582 INFO Accepted socket connection from /127.0.0.1:46990 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:28,583 INFO Processing ruok command from /127.0.0.1:46990 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:28,583 INFO Closed socket connection for client /127.0.0.1:46990 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-20]
2019-08-06 20:50:33,594 INFO Accepted socket connection from /127.0.0.1:47002 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:33,594 INFO Processing ruok command from /127.0.0.1:47002 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:33,595 INFO Closed socket connection for client /127.0.0.1:47002 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-21]
2019-08-06 20:50:36,061 INFO Accepted socket connection from /127.0.0.1:47008 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:36,062 WARN Exception causing close of session 0x0: ZooKeeperServer not running (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:36,062 INFO Closed socket connection for client /127.0.0.1:47008 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:38,570 INFO Accepted socket connection from /127.0.0.1:47024 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:38,570 INFO Processing ruok command from /127.0.0.1:47024 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:38,571 INFO Closed socket connection for client /127.0.0.1:47024 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-22]
2019-08-06 20:50:43,607 INFO Accepted socket connection from /127.0.0.1:47036 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:43,608 INFO Processing ruok command from /127.0.0.1:47036 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:43,608 INFO Closed socket connection for client /127.0.0.1:47036 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-23]
2019-08-06 20:50:48,589 INFO Accepted socket connection from /127.0.0.1:47048 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:48,590 INFO Processing ruok command from /127.0.0.1:47048 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:48,591 INFO Closed socket connection for client /127.0.0.1:47048 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-24]
2019-08-06 20:50:53,625 INFO Accepted socket connection from /127.0.0.1:47062 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:53,626 INFO Processing ruok command from /127.0.0.1:47062 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:53,627 INFO Closed socket connection for client /127.0.0.1:47062 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-25]
2019-08-06 20:50:58,576 INFO Accepted socket connection from /127.0.0.1:47078 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:58,576 INFO Processing ruok command from /127.0.0.1:47078 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:50:58,577 INFO Closed socket connection for client /127.0.0.1:47078 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-26]
2019-08-06 20:51:03,615 INFO Accepted socket connection from /127.0.0.1:47090 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:03,615 INFO Processing ruok command from /127.0.0.1:47090 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:03,616 INFO Closed socket connection for client /127.0.0.1:47090 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-27]
2019-08-06 20:51:08,587 INFO Accepted socket connection from /127.0.0.1:47102 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:08,588 INFO Processing ruok command from /127.0.0.1:47102 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:08,589 INFO Closed socket connection for client /127.0.0.1:47102 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-28]
2019-08-06 20:51:13,603 INFO Accepted socket connection from /127.0.0.1:47114 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:13,603 INFO Processing ruok command from /127.0.0.1:47114 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:13,604 INFO Closed socket connection for client /127.0.0.1:47114 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-29]
2019-08-06 20:51:18,592 INFO Accepted socket connection from /127.0.0.1:47126 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:18,592 INFO Processing ruok command from /127.0.0.1:47126 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:18,593 INFO Closed socket connection for client /127.0.0.1:47126 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-30]
2019-08-06 20:51:23,605 INFO Accepted socket connection from /127.0.0.1:47138 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:23,606 INFO Processing ruok command from /127.0.0.1:47138 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:23,607 INFO Closed socket connection for client /127.0.0.1:47138 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-31]
2019-08-06 20:51:24,871 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:51:24,871 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:51:24,871 INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:51:28,587 INFO Accepted socket connection from /127.0.0.1:47162 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:28,587 INFO Processing ruok command from /127.0.0.1:47162 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:28,588 INFO Closed socket connection for client /127.0.0.1:47162 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-32]
2019-08-06 20:51:29,192 INFO Accepted socket connection from /127.0.0.1:47168 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:29,193 WARN Exception causing close of session 0x0: ZooKeeperServer not running (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:29,193 INFO Closed socket connection for client /127.0.0.1:47168 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:33,584 INFO Accepted socket connection from /127.0.0.1:47184 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:33,584 INFO Processing ruok command from /127.0.0.1:47184 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:33,585 INFO Closed socket connection for client /127.0.0.1:47184 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-33]
2019-08-06 20:51:38,594 INFO Accepted socket connection from /127.0.0.1:47196 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:38,595 INFO Processing ruok command from /127.0.0.1:47196 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:38,596 INFO Closed socket connection for client /127.0.0.1:47196 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-34]
2019-08-06 20:51:43,615 INFO Accepted socket connection from /127.0.0.1:47208 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:43,615 INFO Processing ruok command from /127.0.0.1:47208 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:43,616 INFO Closed socket connection for client /127.0.0.1:47208 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-35]
2019-08-06 20:51:48,597 INFO Accepted socket connection from /127.0.0.1:47220 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:48,598 INFO Processing ruok command from /127.0.0.1:47220 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:48,598 INFO Closed socket connection for client /127.0.0.1:47220 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-36]
2019-08-06 20:51:53,616 INFO Accepted socket connection from /127.0.0.1:47232 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:53,616 INFO Processing ruok command from /127.0.0.1:47232 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:53,617 INFO Closed socket connection for client /127.0.0.1:47232 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-37]
2019-08-06 20:51:58,605 INFO Accepted socket connection from /127.0.0.1:47248 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:58,606 INFO Processing ruok command from /127.0.0.1:47248 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:51:58,607 INFO Closed socket connection for client /127.0.0.1:47248 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-38]
2019-08-06 20:52:03,597 INFO Accepted socket connection from /127.0.0.1:47260 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:03,598 INFO Processing ruok command from /127.0.0.1:47260 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:03,599 INFO Closed socket connection for client /127.0.0.1:47260 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-39]
2019-08-06 20:52:08,602 INFO Accepted socket connection from /127.0.0.1:47272 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:08,602 INFO Processing ruok command from /127.0.0.1:47272 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:08,603 INFO Closed socket connection for client /127.0.0.1:47272 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-40]
2019-08-06 20:52:13,617 INFO Accepted socket connection from /127.0.0.1:47284 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:13,618 INFO Processing ruok command from /127.0.0.1:47284 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:13,619 INFO Closed socket connection for client /127.0.0.1:47284 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-41]
2019-08-06 20:52:18,591 INFO Accepted socket connection from /127.0.0.1:47296 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:18,591 INFO Processing ruok command from /127.0.0.1:47296 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:18,592 INFO Closed socket connection for client /127.0.0.1:47296 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-42]
2019-08-06 20:52:23,618 INFO Accepted socket connection from /127.0.0.1:47308 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:23,618 INFO Processing ruok command from /127.0.0.1:47308 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:23,619 INFO Closed socket connection for client /127.0.0.1:47308 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-43]
2019-08-06 20:52:24,872 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:52:24,873 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:52:24,873 INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:52:28,598 INFO Accepted socket connection from /127.0.0.1:47332 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:28,599 INFO Processing ruok command from /127.0.0.1:47332 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:28,599 INFO Closed socket connection for client /127.0.0.1:47332 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-44]
2019-08-06 20:52:33,595 INFO Accepted socket connection from /127.0.0.1:47344 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:33,596 INFO Processing ruok command from /127.0.0.1:47344 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:33,597 INFO Closed socket connection for client /127.0.0.1:47344 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-45]
2019-08-06 20:52:38,600 INFO Accepted socket connection from /127.0.0.1:47356 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:38,601 INFO Processing ruok command from /127.0.0.1:47356 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:38,602 INFO Closed socket connection for client /127.0.0.1:47356 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-46]
2019-08-06 20:52:43,606 INFO Accepted socket connection from /127.0.0.1:47368 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:43,606 INFO Processing ruok command from /127.0.0.1:47368 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:43,607 INFO Closed socket connection for client /127.0.0.1:47368 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-47]
2019-08-06 20:52:48,582 INFO Accepted socket connection from /127.0.0.1:47380 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:48,583 INFO Processing ruok command from /127.0.0.1:47380 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:48,584 INFO Closed socket connection for client /127.0.0.1:47380 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-48]
2019-08-06 20:52:53,611 INFO Accepted socket connection from /127.0.0.1:47392 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:53,612 INFO Processing ruok command from /127.0.0.1:47392 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:53,613 INFO Closed socket connection for client /127.0.0.1:47392 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-49]
2019-08-06 20:52:58,583 INFO Accepted socket connection from /127.0.0.1:47410 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:58,583 INFO Processing ruok command from /127.0.0.1:47410 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:52:58,584 INFO Closed socket connection for client /127.0.0.1:47410 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-50]
2019-08-06 20:53:03,606 INFO Accepted socket connection from /127.0.0.1:47422 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:03,607 INFO Processing ruok command from /127.0.0.1:47422 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:03,607 INFO Closed socket connection for client /127.0.0.1:47422 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-51]
2019-08-06 20:53:08,609 INFO Accepted socket connection from /127.0.0.1:47434 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:08,610 INFO Processing ruok command from /127.0.0.1:47434 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:08,610 INFO Closed socket connection for client /127.0.0.1:47434 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-52]
2019-08-06 20:53:13,589 INFO Accepted socket connection from /127.0.0.1:47450 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:13,590 INFO Processing ruok command from /127.0.0.1:47450 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:13,591 INFO Closed socket connection for client /127.0.0.1:47450 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-53]
2019-08-06 20:53:18,595 INFO Accepted socket connection from /127.0.0.1:47462 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:18,596 INFO Processing ruok command from /127.0.0.1:47462 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:18,596 INFO Closed socket connection for client /127.0.0.1:47462 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-54]
2019-08-06 20:53:23,605 INFO Accepted socket connection from /127.0.0.1:47474 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:23,605 INFO Processing ruok command from /127.0.0.1:47474 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:23,606 INFO Closed socket connection for client /127.0.0.1:47474 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-55]
2019-08-06 20:53:24,873 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:53:24,874 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:53:24,874 INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:53:28,588 INFO Accepted socket connection from /127.0.0.1:47498 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:28,588 INFO Processing ruok command from /127.0.0.1:47498 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:28,589 INFO Closed socket connection for client /127.0.0.1:47498 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-56]
2019-08-06 20:53:33,602 INFO Accepted socket connection from /127.0.0.1:47510 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:33,602 INFO Processing ruok command from /127.0.0.1:47510 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:33,603 INFO Closed socket connection for client /127.0.0.1:47510 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-57]
2019-08-06 20:53:38,594 INFO Accepted socket connection from /127.0.0.1:47522 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:38,595 INFO Processing ruok command from /127.0.0.1:47522 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:38,596 INFO Closed socket connection for client /127.0.0.1:47522 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-58]
2019-08-06 20:53:43,585 INFO Accepted socket connection from /127.0.0.1:47534 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:43,585 INFO Processing ruok command from /127.0.0.1:47534 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:43,586 INFO Closed socket connection for client /127.0.0.1:47534 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-59]
2019-08-06 20:53:48,598 INFO Accepted socket connection from /127.0.0.1:47546 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:48,599 INFO Processing ruok command from /127.0.0.1:47546 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:48,600 INFO Closed socket connection for client /127.0.0.1:47546 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-60]
2019-08-06 20:53:53,616 INFO Accepted socket connection from /127.0.0.1:47558 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:53,616 INFO Processing ruok command from /127.0.0.1:47558 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:53,617 INFO Closed socket connection for client /127.0.0.1:47558 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-61]
2019-08-06 20:53:58,577 INFO Accepted socket connection from /127.0.0.1:47574 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:58,578 INFO Processing ruok command from /127.0.0.1:47574 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:53:58,578 INFO Closed socket connection for client /127.0.0.1:47574 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-62]
2019-08-06 20:54:03,614 INFO Accepted socket connection from /127.0.0.1:47586 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:03,614 INFO Processing ruok command from /127.0.0.1:47586 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:03,615 INFO Closed socket connection for client /127.0.0.1:47586 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-63]
2019-08-06 20:54:08,600 INFO Accepted socket connection from /127.0.0.1:47598 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:08,600 INFO Processing ruok command from /127.0.0.1:47598 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:08,601 INFO Closed socket connection for client /127.0.0.1:47598 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-64]
2019-08-06 20:54:13,593 INFO Accepted socket connection from /127.0.0.1:47614 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:13,594 INFO Processing ruok command from /127.0.0.1:47614 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:13,595 INFO Closed socket connection for client /127.0.0.1:47614 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-65]
2019-08-06 20:54:18,595 INFO Accepted socket connection from /127.0.0.1:47626 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:18,595 INFO Processing ruok command from /127.0.0.1:47626 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:18,596 INFO Closed socket connection for client /127.0.0.1:47626 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-66]
2019-08-06 20:54:23,617 INFO Accepted socket connection from /127.0.0.1:47638 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:23,618 INFO Processing ruok command from /127.0.0.1:47638 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:23,619 INFO Closed socket connection for client /127.0.0.1:47638 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-67]
2019-08-06 20:54:24,875 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:54:24,876 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:54:24,876 INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:54:28,571 INFO Accepted socket connection from /127.0.0.1:47662 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:28,571 INFO Processing ruok command from /127.0.0.1:47662 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:28,572 INFO Closed socket connection for client /127.0.0.1:47662 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-68]
2019-08-06 20:54:33,591 INFO Accepted socket connection from /127.0.0.1:47674 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:33,592 INFO Processing ruok command from /127.0.0.1:47674 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:33,593 INFO Closed socket connection for client /127.0.0.1:47674 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-69]
2019-08-06 20:54:38,589 INFO Accepted socket connection from /127.0.0.1:47686 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:38,589 INFO Processing ruok command from /127.0.0.1:47686 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:38,590 INFO Closed socket connection for client /127.0.0.1:47686 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-70]
2019-08-06 20:54:43,600 INFO Accepted socket connection from /127.0.0.1:47698 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:43,601 INFO Processing ruok command from /127.0.0.1:47698 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:43,602 INFO Closed socket connection for client /127.0.0.1:47698 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-71]
2019-08-06 20:54:48,583 INFO Accepted socket connection from /127.0.0.1:47710 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:48,584 INFO Processing ruok command from /127.0.0.1:47710 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:48,585 INFO Closed socket connection for client /127.0.0.1:47710 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-72]
2019-08-06 20:54:53,612 INFO Accepted socket connection from /127.0.0.1:47722 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:53,613 INFO Processing ruok command from /127.0.0.1:47722 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:53,614 INFO Closed socket connection for client /127.0.0.1:47722 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-73]
2019-08-06 20:54:58,591 INFO Accepted socket connection from /127.0.0.1:47738 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:58,591 INFO Processing ruok command from /127.0.0.1:47738 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:54:58,592 INFO Closed socket connection for client /127.0.0.1:47738 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-74]
2019-08-06 20:55:03,731 INFO Accepted socket connection from /127.0.0.1:47752 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:03,732 INFO Processing ruok command from /127.0.0.1:47752 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:03,733 INFO Closed socket connection for client /127.0.0.1:47752 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-75]
2019-08-06 20:55:08,598 INFO Accepted socket connection from /127.0.0.1:47764 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:08,598 INFO Processing ruok command from /127.0.0.1:47764 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:08,599 INFO Closed socket connection for client /127.0.0.1:47764 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-76]
2019-08-06 20:55:13,599 INFO Accepted socket connection from /127.0.0.1:47776 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:13,600 INFO Processing ruok command from /127.0.0.1:47776 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:13,600 INFO Closed socket connection for client /127.0.0.1:47776 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-77]
2019-08-06 20:55:18,582 INFO Accepted socket connection from /127.0.0.1:47788 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:18,582 INFO Processing ruok command from /127.0.0.1:47788 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:18,583 INFO Closed socket connection for client /127.0.0.1:47788 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-78]
2019-08-06 20:55:23,617 INFO Accepted socket connection from /127.0.0.1:47800 (org.apache.zookeeper.server.NIOServerCnxnFactory) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:23,618 INFO Processing ruok command from /127.0.0.1:47800 (org.apache.zookeeper.server.NIOServerCnxn) [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:21810]
2019-08-06 20:55:23,619 INFO Closed socket connection for client /127.0.0.1:47800 (no session established for client) (org.apache.zookeeper.server.NIOServerCnxn) [Thread-79]
2019-08-06 20:55:24,876 INFO Have smaller server identifier, so dropping the connection: (2, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:55:24,877 INFO Have smaller server identifier, so dropping the connection: (3, 1) (org.apache.zookeeper.server.quorum.QuorumCnxManager) [QuorumPeer[myid=1]/0.0.0.0:21810]
2019-08-06 20:55:24,877 INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection) [QuorumPeer[myid=1]/0.0.0.0:21810]
Here is for one of the zookeeper tls-sidecar pods:
Starting Stunnel with configuration:
pid = /usr/local/var/run/stunnel.pid
foreground = yes
debug = notice
[my-cluster-zookeeper-1-2888]
client = yes
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 127.0.0.1:28881
connect = my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local:2888
delay = yes
verify = 2
[my-cluster-zookeeper-2-2888]
client = yes
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 127.0.0.1:28882
connect = my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local:2888
delay = yes
verify = 2
[listener-2888]
client = no
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 2888
connect = 127.0.0.1:28880
verify = 2
[my-cluster-zookeeper-1-3888]
client = yes
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 127.0.0.1:38881
connect = my-cluster-zookeeper-1.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local:3888
delay = yes
verify = 2
[my-cluster-zookeeper-2-3888]
client = yes
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 127.0.0.1:38882
connect = my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local:3888
delay = yes
verify = 2
[listener-3888]
client = no
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 3888
connect = 127.0.0.1:38880
verify = 2
[listener-2181]
client = no
CAfile = /tmp/cluster-ca.crt
cert = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.crt
key = /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
accept = 2181
connect = 127.0.0.1:21810
verify = 2
2019.08.06 20:48:41 LOG5[1:139798742128704]: stunnel 4.56 on x86_64-redhat-linux-gnu platform
2019.08.06 20:48:41 LOG5[1:139798742128704]: Compiled/running with OpenSSL 1.0.1e-fips 11 Feb 2013
2019.08.06 20:48:41 LOG5[1:139798742128704]: Threading:PTHREAD Sockets:POLL,IPv6 SSL:ENGINE,OCSP,FIPS Auth:LIBWRAP
2019.08.06 20:48:41 LOG5[1:139798742128704]: Reading configuration from file /tmp/stunnel.conf
2019.08.06 20:48:41 LOG5[1:139798742128704]: FIPS mode is enabled
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG4[1:139798742128704]: Insecure file permissions on /etc/tls-sidecar/zookeeper-nodes/my-cluster-zookeeper-0.key
2019.08.06 20:48:41 LOG5[1:139798742128704]: Configuration successful
2019.08.06 20:48:42 LOG5[1:139798742124288]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60144
2019.08.06 20:48:42 LOG5[1:139798742013696]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60348
2019.08.06 20:48:42 LOG3[1:139798742013696]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:42 LOG3[1:139798742013696]: No host resolved
2019.08.06 20:48:42 LOG5[1:139798742013696]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:42 LOG5[1:139798742013696]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60156
2019.08.06 20:48:42 LOG5[1:139798741903104]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60360
2019.08.06 20:48:42 LOG3[1:139798741903104]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:42 LOG3[1:139798741903104]: No host resolved
2019.08.06 20:48:42 LOG5[1:139798741903104]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:43 LOG5[1:139798741903104]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60162
2019.08.06 20:48:43 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60366
2019.08.06 20:48:43 LOG3[1:139798741792512]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:43 LOG3[1:139798741792512]: No host resolved
2019.08.06 20:48:43 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:44 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60168
2019.08.06 20:48:44 LOG5[1:139798741681920]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60372
2019.08.06 20:48:44 LOG3[1:139798741681920]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:44 LOG3[1:139798741681920]: No host resolved
2019.08.06 20:48:44 LOG5[1:139798741681920]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:45 LOG5[1:139798741681920]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60176
2019.08.06 20:48:45 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60380
2019.08.06 20:48:45 LOG3[1:139798741571328]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:45 LOG3[1:139798741571328]: No host resolved
2019.08.06 20:48:45 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:48 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60192
2019.08.06 20:48:48 LOG5[1:139798741460736]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60396
2019.08.06 20:48:48 LOG3[1:139798741460736]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:48 LOG3[1:139798741460736]: No host resolved
2019.08.06 20:48:48 LOG5[1:139798741460736]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:52 LOG3[1:139798742124288]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:48:52 LOG5[1:139798742124288]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:52 LOG3[1:139798742013696]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:48:52 LOG5[1:139798742013696]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:53 LOG3[1:139798741903104]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:48:53 LOG5[1:139798741903104]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:54 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:48:54 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:55 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60210
2019.08.06 20:48:55 LOG5[1:139798741903104]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60414
2019.08.06 20:48:55 LOG3[1:139798741903104]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:48:55 LOG3[1:139798741903104]: No host resolved
2019.08.06 20:48:55 LOG5[1:139798741903104]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:55 LOG3[1:139798741681920]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:48:55 LOG5[1:139798741681920]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:48:58 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:48:58 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:05 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:49:05 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:08 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60254
2019.08.06 20:49:08 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60458
2019.08.06 20:49:08 LOG3[1:139798741571328]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:49:08 LOG3[1:139798741571328]: No host resolved
2019.08.06 20:49:08 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:11 LOG5[1:139798741571328]: Service [listener-2181] accepted connection from 192.168.99.66:57914
2019.08.06 20:49:11 LOG5[1:139798741571328]: Certificate accepted: depth=1, /O=io.strimzi/CN=cluster-ca v0
2019.08.06 20:49:11 LOG5[1:139798741571328]: Certificate accepted: depth=0, /O=io.strimzi/CN=my-cluster-kafka
2019.08.06 20:49:11 LOG5[1:139798741571328]: connect_blocking: connected 127.0.0.1:21810
2019.08.06 20:49:11 LOG5[1:139798741571328]: Service [listener-2181] connected remote server from 127.0.0.1:46744
2019.08.06 20:49:11 LOG5[1:139798741571328]: Read socket error: Broken pipe (32)
2019.08.06 20:49:11 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 49 byte(s) sent to socket
2019.08.06 20:49:18 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:49:18 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:23 LOG5[1:139798741792512]: Service [listener-2181] accepted connection from 192.168.99.66:57956
2019.08.06 20:49:23 LOG5[1:139798741792512]: connect_blocking: connected 127.0.0.1:21810
2019.08.06 20:49:23 LOG5[1:139798741792512]: Service [listener-2181] connected remote server from 127.0.0.1:46786
2019.08.06 20:49:23 LOG5[1:139798741792512]: Read socket error: Broken pipe (32)
2019.08.06 20:49:23 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 49 byte(s) sent to socket
2019.08.06 20:49:24 LOG5[1:139798741792512]: Service [listener-2181] accepted connection from 192.168.99.66:57964
2019.08.06 20:49:24 LOG5[1:139798741792512]: connect_blocking: connected 127.0.0.1:21810
2019.08.06 20:49:24 LOG5[1:139798741792512]: Service [listener-2181] connected remote server from 127.0.0.1:46794
2019.08.06 20:49:24 LOG5[1:139798741792512]: Read socket error: Broken pipe (32)
2019.08.06 20:49:24 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 49 byte(s) sent to socket
2019.08.06 20:49:33 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60356
2019.08.06 20:49:33 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60560
2019.08.06 20:49:43 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:49:43 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:43 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:49:43 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:49:54 LOG5[1:139798741571328]: Service [listener-2181] accepted connection from 192.168.99.66:58056
2019.08.06 20:49:54 LOG5[1:139798741571328]: connect_blocking: connected 127.0.0.1:21810
2019.08.06 20:49:54 LOG5[1:139798741571328]: Service [listener-2181] connected remote server from 127.0.0.1:46886
2019.08.06 20:49:54 LOG5[1:139798741571328]: Read socket error: Broken pipe (32)
2019.08.06 20:49:54 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 49 byte(s) sent to socket
2019.08.06 20:50:24 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60500
2019.08.06 20:50:24 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60704
2019.08.06 20:50:34 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:50:34 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:50:34 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:50:34 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:50:36 LOG5[1:139798741571328]: Service [listener-2181] accepted connection from 192.168.99.66:58178
2019.08.06 20:50:36 LOG5[1:139798741571328]: connect_blocking: connected 127.0.0.1:21810
2019.08.06 20:50:36 LOG5[1:139798741571328]: Service [listener-2181] connected remote server from 127.0.0.1:47008
2019.08.06 20:50:36 LOG5[1:139798741571328]: Read socket error: Broken pipe (32)
2019.08.06 20:50:36 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 49 byte(s) sent to socket
2019.08.06 20:51:24 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60672
2019.08.06 20:51:24 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:60876
2019.08.06 20:51:29 LOG5[1:139798741681920]: Service [listener-2181] accepted connection from 192.168.99.66:58338
2019.08.06 20:51:29 LOG5[1:139798741681920]: connect_blocking: connected 127.0.0.1:21810
2019.08.06 20:51:29 LOG5[1:139798741681920]: Service [listener-2181] connected remote server from 127.0.0.1:47168
2019.08.06 20:51:29 LOG5[1:139798741681920]: Read socket error: Broken pipe (32)
2019.08.06 20:51:29 LOG5[1:139798741681920]: Connection reset: 0 byte(s) sent to SSL, 49 byte(s) sent to socket
2019.08.06 20:51:34 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:51:34 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:51:34 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:51:34 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:52:24 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:60842
2019.08.06 20:52:24 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:32814
2019.08.06 20:52:34 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:52:34 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:52:34 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:52:34 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:53:24 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:32776
2019.08.06 20:53:24 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:32980
2019.08.06 20:53:34 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:53:34 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:53:34 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:53:34 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:54:24 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:32940
2019.08.06 20:54:24 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:33144
2019.08.06 20:54:34 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:54:34 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:54:34 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:54:34 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:55:24 LOG5[1:139798741792512]: Service [my-cluster-zookeeper-1-3888] accepted connection from 127.0.0.1:33102
2019.08.06 20:55:24 LOG5[1:139798741571328]: Service [my-cluster-zookeeper-2-3888] accepted connection from 127.0.0.1:33306
2019.08.06 20:55:34 LOG3[1:139798741571328]: connect_blocking: s_poll_wait 10.42.1.21:3888: TIMEOUTconnect exceeded
2019.08.06 20:55:34 LOG5[1:139798741571328]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2019.08.06 20:55:34 LOG3[1:139798741792512]: connect_blocking: s_poll_wait 10.42.2.18:3888: TIMEOUTconnect exceeded
2019.08.06 20:55:34 LOG5[1:139798741792512]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
Just FYI I'm also experiencing the same issue with a similar setup (I'm running it on GKE instead)
Hmm, it looks like this issue got lost among other issues. It seems that the TLS sidecars in Zookeeper have some issue with resolving the DNS names of other Zookeeper nodes:
2019.08.06 20:49:08 LOG3[1:139798741571328]: Error resolving 'my-cluster-zookeeper-2.my-cluster-zookeeper-nodes.strimzi-kafka-operator.svc.cluster.local': Neither nodename nor servname known (EAI_NONAME)
2019.08.06 20:49:08 LOG3[1:139798741571328]: No host resolved
I wonder if the TLS sidecar has outdated DNS metadata or whether there is some issue with the Kube DNS.
Hi, I also encountered the same issue while testing the kafka-ephemeral on 1.13.7-gke.24, with network policy enabled.
I did another test on a new cluster without network policy enabled, and it worked without problems.
I couldn't understand what's wrong because the policy created look correct to me.
Could it be possible to instruct the operator to not create those network policies (at least for testing)?
@carlobongiovanni I use it regularly in environments with network policies enabled without any problem. But that is not GKE - maybe there the policies work differently?
You cannot disable the network policies. But normally if one of the netwrk policies gives access it should be given. So you should be able to add your own policies with your own name to try to figure out which would work on your GKE. And afterwards we can see if this is something what can be incorporated into the operator (i.e. if it would work elsewhere as well).
kubectl get -n kafka-operator pod
NAME READY STATUS RESTARTS AGE
strimzi-topic-operator-6b8849f89d-lgrhh 0/1 CrashLoopBackOff 158 10h
strimzi-user-operator-7478c698bc-s9fhf 0/1 CrashLoopBackOff 129 10h
kubectl logs -f -n kafka-operator strimzi-topic-operator-6b8849f89d-lgrhh
2019-10-22 03:09:11 INFO ClientCnxn:1025 - Opening socket connection to server kafka-cluster-zookeeper-client/172.31.61.238:2181. Will not attempt to authenticate using SASL (unknown error)
2019-10-22 03:09:11 INFO ClientCnxn:879 - Socket connection established to kafka-cluster-zookeeper-client/172.31.61.238:2181, initiating session
2019-10-22 03:09:11 WARN ClientCnxn:1164 - Session 0x0 for server kafka-cluster-zookeeper-client/172.31.61.238:2181, unexpected error, closing socket connection and attempting reconnect
...
2019-10-22 01:52:57 INFO ClientCnxn:879 - Socket connection established to kafka-cluster-zookeeper-client/172.31.61.238:2181, initiating session
2019-10-22 01:52:57 INFO ZooKeeper:693 - Session: 0x0 closed
2019-10-22 01:52:57 INFO ClientCnxn:522 - EventThread shut down for session: 0x0
2019-10-22 01:52:57 ERROR Main:48 - Error deploying Session
org.I0Itec.zkclient.exception.ZkTimeoutException: Unable to connect to zookeeper server 'kafka-cluster-zookeeper-client:2181' with timeout of 20000 ms
kubectl logs -f --tail=20 -n kafka-operator kafka-cluster-zookeeper-1 tls-sidecar
...
2019.10.22 03:06:28 LOG5[1:139780507633408]: Service [listener-2181] accepted connection from 192.168.38.16:34934
2019.10.22 03:06:28 LOG3[1:139780507633408]: SSL_accept: 1408F10B: error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number
2019.10.22 03:06:28 LOG5[1:139780507633408]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
kubectl exec -it -n kafka-operator kafka-cluster-zookeeper-0 -- ./bin/kafka-topics.sh --list --zookeeper localhost:2181
Defaulting container name to zookeeper.
Use 'kubectl describe pod/kafka-cluster-zookeeper-0 -n kafka-operator' to see all of the containers in this pod.
OpenJDK 64-Bit Server VM warning: If the number of processors is expected to increase from one, then you should configure the number of parallel GC threads appropriately using -XX:ParallelGCThreads=N
[2019-10-22 03:23:47,698] WARN Session 0x0 for server localhost/127.0.0.1:2181, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
java.io.IOException: Connection reset by peer
at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
at sun.nio.ch.IOUtil.read(IOUtil.java:192)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)
at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:68)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:366)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1141)
[2019-10-22 03:23:49,283] WARN Session 0x0 for server localhost/127.0.0.1:2181, unexpected error, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
quick update, I was able to start the cluster correctly by applying a networkpolicy to allow all traffic: https://kubernetes.io/docs/concepts/services-networking/network-policies/#default-allow-all-ingress-traffic
There is something weird going on that I'm trying to debug. But I have to admit that our current setup is quite complicated, as we have private gke clusters with calico enabled and with masquerading rules to enable connection to our legacy datacenters. If I will discover anything new I'll update the thread.
@carlobongiovanni That is a bit weird. I use Calico (just the default setup in my case) regularly with Strimzi and never had any network policies issues. :-(
@scholzj I found we had a wrong masquerading configuration in the cluster. that was blocking calico to work properly. After fixing that, strimzi started to work immediately and now it's all fine. Thanks for the hints
@carlobongiovanni Great, thanks for letting us know.
INFO Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL so what cause the problem in redhat linux machines?