You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@zookeeper.apache.org by "blb.dev" <bl...@gmail.com> on 2020/05/01 23:36:15 UTC

ZK not starting during upgrade to use 3.6.1 with SSL communication

Hi, during testing upgrade to 3.6.1 version and using secure quorum ssl
communication my zookeeper is not starting up. 

*config file:*
dataDir=/data
dataLogDir=/datalog
tickTime=2000
initLimit=10
syncLimit=5
maxClientCnxns=0
autopurge.snapRetainCount=10
autopurge.purgeInterval=24
admin.enableServer=false
snapshot.trust.empty=true
reconfigEnabled=true
audit.enable=true
clientPort=2181
secureClientPort=2281
sslQuorum=true
portUnification=true
serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
client.portUnification=true
clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
ssl.client.enable=true
clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
ssl.quorum.keyStore.location=/apache-zookeeper-3.6.1-bin/java/node1.ks
ssl.quorum.keyStore.password=<pw>
ssl.quorum.trustStore.location=/apache-zookeeper-3.6.1-bin/java/truststore.ks
ssl.quorum.trustStore.password=<pw>
4lw.commands.whitelist=*
quorumListenOnAllIPs=true
server.2=<fqdn of zoo2>:2888:3888:participant
server.3=<fqdn of zoo2>:2888:3888:participant
server.1=<fqdn of zoo1>:2888:3888:participant

*# bin/zkServer.sh status*
/usr/bin/java
ZooKeeper JMX enabled by default
Using config: /conf/zoo.cfg
Client port found: 2181. Client address: localhost.
Error contacting service. It is probably not running.

*# cat /logs/zookeeper_audit.log  *
2020-05-01 22:06:12,213 INFO audit.Log4jAuditLogger: user=zookeeper
operation=serverStart	result=success
2020-05-01 23:08:30,859 INFO audit.Log4jAuditLogger: user=zookeeper
operation=serverStart	result=success

*# bin/zkCli.sh -server 127.0.0.1:2181*
/usr/bin/java
Connecting to 127.0.0.1:2181
2020-05-01 23:19:20,035 [myid:] - INFO  [main:Environment@98] - Client
environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
built on 04/21/2020 15:01 GMT
2020-05-01 23:19:20,039 [myid:] - INFO  [main:Environment@98] - Client
environment:host.name=zoo1
2020-05-01 23:19:20,039 [myid:] - INFO  [main:Environment@98] - Client
environment:java.version=1.8.0_252
2020-05-01 23:19:20,042 [myid:] - INFO  [main:Environment@98] - Client
environment:java.vendor=Oracle Corporation
2020-05-01 23:19:20,042 [myid:] - INFO  [main:Environment@98] - Client
environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
2020-05-01 23:19:20,042 [myid:] - INFO  [main:Environment@98] - Client
environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:java.io.tmpdir=/tmp
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:java.compiler=<NA>
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:os.name=Linux
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:os.arch=amd64
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:os.version=3.10.0-327.28.3.el7.x86_64
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:user.name=root
2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
environment:user.home=/root
2020-05-01 23:19:20,044 [myid:] - INFO  [main:Environment@98] - Client
environment:user.dir=/apache-zookeeper-3.6.1-bin
2020-05-01 23:19:20,044 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.free=51MB
2020-05-01 23:19:20,046 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.max=228MB
2020-05-01 23:19:20,046 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.total=57MB
2020-05-01 23:19:20,052 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
client connection, connectString=127.0.0.1:2181 sessionTimeout=30000
watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
2020-05-01 23:19:20,059 [myid:] - INFO  [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
TLS renegotiation
2020-05-01 23:19:20,071 [myid:] - INFO  [main:ClientCnxnSocket@239] -
jute.maxbuffer value is 1048575 Bytes
2020-05-01 23:19:20,083 [myid:] - INFO  [main:ClientCnxn@1703] -
zookeeper.request.timeout value is 0. feature enabled=false
2020-05-01 23:19:20,091 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1154] - Opening
socket connection to server localhost/127.0.0.1:2181.
2020-05-01 23:19:20,091 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1156] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
Welcome to ZooKeeper!
JLine support is enabled
2020-05-01 23:19:20,235 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@986] - Socket
connection established, initiating session, client: /127.0.0.1:37360,
server: localhost/127.0.0.1:2181
2020-05-01 23:19:20,259 [myid:127.0.0.1:2181] - WARN 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1272] - Session 0x0
for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
EndOfStreamException: Unable to read additional data from server sessionid
0x0, likely server has closed socket
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
[zk: 127.0.0.1:2181(CONNECTING) 0] 2020-05-01 23:19:21,591
[myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1154] - Opening
socket connection to server localhost/127.0.0.1:2181.
2020-05-01 23:19:21,591 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1156] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
2020-05-01 23:19:21,592 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@986] - Socket
connection established, initiating session, client: /127.0.0.1:37362,
server: localhost/127.0.0.1:2181
2020-05-01 23:19:21,598 [myid:127.0.0.1:2181] - WARN 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1272] - Session 0x0
for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
EndOfStreamException: Unable to read additional data from server sessionid
0x0, likely server has closed socket
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
2020-05-01 23:19:23,303 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1154] - Opening
socket connection to server localhost/127.0.0.1:2181.
2020-05-01 23:19:23,304 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1156] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
2020-05-01 23:19:23,304 [myid:127.0.0.1:2181] - INFO 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@986] - Socket
connection established, initiating session, client: /127.0.0.1:37364,
server: localhost/127.0.0.1:2181
2020-05-01 23:19:23,313 [myid:127.0.0.1:2181] - WARN 
[main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1272] - Session 0x0
for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
EndOfStreamException: Unable to read additional data from server sessionid
0x0, likely server has closed socket
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)


(it continues on like this repeating the same exception)

Don't see /logs/zookeeper.out

*# nc -vz zoo2 2181*
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connected to <fqdn zoo2>:2181.
Ncat: 0 bytes sent, 0 bytes received in 0.01 seconds.
*# nc -vz zoo3 2181*
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connected to <fqdn zoo3>:2181.
Ncat: 0 bytes sent, 0 bytes received in 0.02 seconds.

*# nc -vz zoo2 2182*
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connection refused.
*# nc -vz zoo3 2182*
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connection refused.

*# ps -ef | grep zookeeper*
root        13     1  0 23:08 ?        00:00:00 su -m zookeeper zkServer.sh
start-foreground
zookeep+    14    13  0 23:08 ?        00:00:03 java
-Dzookeeper.log.dir=/logs -Dzookeeper.log.file=zookeeper--server-zoo1.log
-Dzookeeper.root.logger=DEBUG -XX:+HeapDumpOnOutOfMemoryError
-XX:OnOutOfMemoryError=kill -9 %p -cp
/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
-Xmx1000m -Xmx4g -Xms1g -Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.local.only=false
org.apache.zookeeper.server.quorum.QuorumPeerMain /conf/zoo.cfg

I think the issue is around the secureClientPort not taking the connection? 
What else needs to be configured to work or would it be an issue between my
machines?  At a loss for how to proceed. Any debug or configuration guidance
is appreciated. 




--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Upgrading from 3.4.14



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by Enrico Olivelli <eo...@gmail.com>.
Hi,
From which version are you upgrading?
Enrico

Il Sab 2 Mag 2020, 01:39 blb.dev <bl...@gmail.com> ha scritto:

> I also notice that in the /conf/zoo.cfg file the servers are being added
> out
> of order, but the /data/myid files are all correct server id.
>
> For example, it's showing as:
> server.2=<fqdn of zoo2>:2888:3888:participant
> server.3=<fqdn of zoo2>:2888:3888:participant
> server.1=<fqdn of zoo1>:2888:3888:participant
>
> But I would expect it to be:
> server.1=<fqdn of zoo1>:2888:3888:participant
> server.2=<fqdn of zoo2>:2888:3888:participant
> server.3=<fqdn of zoo2>:2888:3888:participant
>
> Is that an indication of an underlying issue?
>
>
>
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/
>

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
I also notice that in the /conf/zoo.cfg file the servers are being added out
of order, but the /data/myid files are all correct server id. 

For example, it's showing as: 
server.2=<fqdn of zoo2>:2888:3888:participant
server.3=<fqdn of zoo2>:2888:3888:participant
server.1=<fqdn of zoo1>:2888:3888:participant

But I would expect it to be: 
server.1=<fqdn of zoo1>:2888:3888:participant
server.2=<fqdn of zoo2>:2888:3888:participant
server.3=<fqdn of zoo2>:2888:3888:participant

Is that an indication of an underlying issue? 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Hi manu31-2, 

Yes, my config remains the same except I added in some params:
- added in extra params recommended by the config that Szalay-Bekő Máté
posted in his last message
- added ssl.quorum.* params which configure server-server SSL

Yes, I have my truststore/keystore params all pointing to the same files
(you can have them configured separately, but for simplicity I used the same
files at first). 

I added all client and server ssl info into zoo.cfg and as system properties
as well. 

I do not set SERVER_JVMFLAGS. I only use JVMFLAGS and CLIENT_JVMFLAGS. 

Hope this helps. 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by manu31 <ha...@yahoo.com.INVALID>.
I have been getting the same error, can you share your zoo.cfg, is it the
same as what you posted before? Also  your ssl.quorum.keyStore/trustStore
and ssl.keyStore/trustStore do they set to the same values? Do you need the
client ssl information in the zoo.cfg? Do you need SERVER_JVMFLAGS set
anywhere? 
Thanks!



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Szalay-Bekő, thank you for sharing your config! It helped me to figure out
what the problem was!

I was only setting "ssl.keyStore" and "ssl.trustStore" options and not
"ssl.quorum.keyStore" and "ssl.quorum. trustStore" - so the quorum SSL was
never working and it gave me all the binding/startup errors because of this.
Once those were set, quorum comes up healthy and quorum SSL works. 

Was then also able to enable mixed mode by setting secureClientPort and
client port unification, so I have quorum ssl, and accept ssl and non-ssl
client connections. 

I do think I have found a bug/issue with the CLI when connecting to a secure
port though. It always gives "JLine support is disabled" and errors out when
trying to do a create with node data. Null creates work fine though. Will
look through current tickets and open an item for it if I don't find one
already. 

Thanks again









--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by Szalay-Bekő Máté <sz...@gmail.com>.
I am not exactly sure where we are now...

Did you managed to setup what you wanted to?
Am I right that you need Quorum SSL and client SSL, while you want to
disable the unsecure Client connection?


I think this case the following config should work, using ZooKeeper 3.6.1:

 -------  zoo.cfg starts here -----
# generic
dataDir=/data
dataLogDir=/datalog
tickTime=2000
initLimit=10
syncLimit=5
maxClientCnxns=0
leaderServes=yes
autopurge.snapRetainCount=10
autopurge.purgeInterval=24
standaloneEnabled=false
admin.enableServer=false
reconfigEnabled=true
audit.enable=true
quorumListenOnAllIPs=true
4lw.commands.whitelist=*
dynamicConfigFile=/conf/zoo.cfg.dynamic

# only after upgrade, until you have at least one snapshot on each ZK server
snapshot.trust.empty=true

# quorum SSL
sslQuorum=true
serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
ssl.quorum.keyStore.location=<keystore file used for Quorum SSL>
ssl.quorum.keyStore.password=<keystore password used for Quorum SSL>
ssl.quorum.trustStore.location=<truststore password used for Quorum SSL>
ssl.quorum.trustStore.password=<truststore file used for Quorum SSL>

# client SSL
secureClientPort=2181
clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
ssl.keyStore.location=<server-side keystore file used for Client SSL>
ssl.keyStore.password=<server-side keystore password used for Client SSL>
ssl.trustStore.location=<server-side trueststore file used for Client SSL>
ssl.trustStore.password=<server-side trueststore password used for Client
SSL>
 -------  end of zoo.cfg -----

and:

 -------  zoo.cfg.dynamic starts here -----
server.1=zoo1:2888:3888:participant
server.2=zoo2:2888:3888:participant
server.3=zoo3:2888:3888:participant
 -------  end of zoo.cfg.dynamic -----


If the above config doesn't work and the cluster can not come up, then I
would assume the problem is related to your keystore / truststore files. Or
something else. Maybe debug logs would help to figure out what is the
problem.

1) please try again with some extra debug logging by setting the following
environment variables before starting zkServer.sh:
export ZOO_LOG4J_PROP="DEBUG,CONSOLE,ROLLINGFILE"
export SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dzookeeper.log.threshold=DEBUG
-Dzookeeper.console.threshold=DEBUG"
(optionally if you want to specify where ZooKeeper should print its
logs: export ZOO_LOG_DIR="/var/logs/zookeeper" )

 2) please create a Jira ticket (
https://issues.apache.org/jira/projects/ZOOKEEPER/) where you attach:
- zoo.cfg
- zoo.cfg.dynamic
- the debug logs for all your ZooKeeper servers

3) please ping me (@symat) on the ticket and I will check the debug logs.

Kind regards,
Mate

On Fri, May 15, 2020 at 2:44 AM blb.dev <bl...@gmail.com> wrote:

> Ashish, thank you for detailing why you chose that parameter! You're right
> we
> wouldn't need that in our config.
>
> Anyone else have any ideas why my zookeeper quorum is not starting up with
> this configuration? I am unfortunately still blocked as it will not start
> up.
>
> I need to configure encrypted quorum and client communication (and also
> accept non ssl client communications while clients update) - guidance on
> how
> to change my config params to help with the startup?
>
>
>
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/
>

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Ashish, thank you for detailing why you chose that parameter! You're right we
wouldn't need that in our config. 

Anyone else have any ideas why my zookeeper quorum is not starting up with
this configuration? I am unfortunately still blocked as it will not start
up. 

I need to configure encrypted quorum and client communication (and also
accept non ssl client communications while clients update) - guidance on how
to change my config params to help with the startup? 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by ashish soni <ai...@gmail.com>.
Hi,

We are using consul for our external service DNS resolution and the
zookeeper is running in a Docker containerized environment. We can not use
a hard IP address in our server config due to containerization. We are
migrating from 3.4.12 to 3.5.5 and I had to introduce the flag (which is
not needed in 3.6.1 thanks to the fix made by Mate Szalay)

From the code, the zookeeper requires IP and port to connect for the socket
connection. We used to have 0.0.0.0 set in our zoo.cfg which was supported
by 3.4.12 (in general 3.4.x). Since 3.5, when the zookeeper server starts
for the very first time, it sends out its "Initial Identification" to its
peers. The ZK server sends out its sid and its address as its
identification. Our zk server list is of the form
server.1=zk.service:2888:3888;2181 The hostname zk.service is not
understood by the zookeeper as it requires InetAddress (as its all internal
communication, our external consul DNS resolution doesn't come into the
picture). What this leads to is that the originating node is never able to
complete its leader election as it cannot bind to the address, to begin
with, and therefore is never able to join the cluster.
Now ** quorumListenOnAllIPs** enables the 0.0.0.0 interface as it allows
the zookeeper to bind on the address 0.0.0.0:3888 and also talk to its
peers during leader election. It will receive the connections from all the
IP's and quorum will be formed.

You don't need to add this if you have a static IP config or using 3.6+ (or
now 3.5.8 as well as it is also released)

On Thu, May 7, 2020 at 6:30 PM blb.dev <bl...@gmail.com> wrote:

> Thanks for sharing -
>
> I wasn't using quorumListenOnAllIPs=true, as it's listed as an Unsafe
> Option
> - any reason why you chose to use it?
>
> The bind issue is fixed by setting either clientPort or secureClientPort
> only and only setting it in zoo.cfg or zoo.cfg.dynamic.
>
> However, my quorum still does not start up!  It gives the following stack
> trace:
>
> # bin/zkCli.sh
> /usr/bin/java
> Connecting to localhost:2181
> 2020-05-08 01:25:54,277 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
> built on 04/21/2020 15:01 GMT
> 2020-05-08 01:25:54,281 [myid:] - INFO  [main:Environment@98] - Client
> environment:host.name=zoo2
> 2020-05-08 01:25:54,281 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.version=1.8.0_252
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.vendor=Oracle Corporation
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.io.tmpdir=/tmp
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.compiler=<NA>
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.name=Linux
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.arch=amd64
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.version=3.10.0-327.28.3.el7.x86_64
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.name=root
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.home=/root
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.dir=/apache-zookeeper-3.6.1-bin
> 2020-05-08 01:25:54,286 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.free=51MB
> 2020-05-08 01:25:54,287 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.max=228MB
> 2020-05-08 01:25:54,287 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.total=57MB
> 2020-05-08 01:25:54,293 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
> client connection, connectString=localhost:2181 sessionTimeout=30000
> watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
> 2020-05-08 01:25:54,298 [myid:] - INFO  [main:X509Util@77] - Setting -D
> jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
> TLS renegotiation
> 2020-05-08 01:25:54,306 [myid:] - INFO  [main:ClientCnxnSocket@239] -
> jute.maxbuffer value is 1048575 Bytes
> 2020-05-08 01:25:54,318 [myid:] - INFO  [main:ClientCnxn@1703] -
> zookeeper.request.timeout value is 0. feature enabled=false
> Welcome to ZooKeeper!
> 2020-05-08 01:25:54,331 [myid:localhost:2181] - INFO
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2181.
> 2020-05-08 01:25:54,333 [myid:localhost:2181] - INFO
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> JLine support is enabled
> 2020-05-08 01:25:54,449 [myid:localhost:2181] - INFO
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:49708,
> server: localhost/127.0.0.1:2181
> 2020-05-08 01:25:54,474 [myid:localhost:2181] - WARN
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
>         at
> org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
>         at
>
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
>         at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
>
> I tried adding multiAddress.reachabilityCheckEnabled=true since that seemed
> to paid with quorumListenOnAllIPs=true, but still the same SessionExpired
> error.
>
> Current config:
>
> dataDir=/data
> dataLogDir=/datalog
> tickTime=2000
> initLimit=10
> syncLimit=5
> maxClientCnxns=0
> autopurge.snapRetainCount=10
> autopurge.purgeInterval=24
> standaloneEnabled=false
> admin.enableServer=false
> snapshot.trust.empty=true
> reconfigEnabled=true
> audit.enable=true
> clientPort=2181
> sslQuorum=true
> ssl.client.enable=true
> portUnification=true
> client.portUnification=true
> serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
> clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
> ssl.quorum.keyStore.location=
> ssl.quorum.keyStore.password=
> ssl.quorum.trustStore.location=
> ssl.quorum.trustStore.password=
> multiAddress.reachabilityCheckEnabled=true
> quorumListenOnAllIPs=true
> 4lw.commands.whitelist=*
> dynamicConfigFile=/conf/zoo.cfg.dynamic
>
> where zoo.cfg.dynamic is:
>
> server.2=zoo2:2888:3888:participant
> server.3=zoo3:2888:3888:participant
> server.1=zoo1:2888:3888:participant
>
>
> Any ideas what this issue is? I'm really at a loss trying to add SSL...
>
>
>
>
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/
>

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Enrico, 

- Before the upgrade were you running SSL client port and SSL Quorum ?

Yes, before the upgrade the config contained clientPort and secureClientPort
and had JVM flags javax.net.debug=ssl:handshake and quorum.ssl.enabled=true
set. 

- If you enable only SSL Quorum, does it run ?

No, if I try and start with sslQuorum=true it always fails to start. 

- if you enable only client SSL port does it run ?

Do you mean only setting the secureClientPort and not the clientPort? No it
fails with exit error in the zkServer.sh, which I see there is a bug for, I
can try and update this code to not exit when clientPort is not set at all
and see. 

It does start up when sslQuorum=false and portUnification=true, but I would
like to have quorum SSL working. 

- is it the problem only when you configure both SSL Quorum and SSL secure
client port ?

Problem is whenever trying to enable ssl quorum at all. 

I tried even in a brand new cluster environment, starting fresh with this
install and face the same issues. 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by Enrico Olivelli <eo...@gmail.com>.
Trying to restart from the beginning...

You are upgrading your cluster.
- Before the upgrade were you running SSL client port and SSL Quorum ?
- If you enable only SSL Quorum, does it run ?
- if you enable only client SSL port does it run ?
- is it the problem only when you configure both SSL Quorum and SSL secure
client port ?

Enrico

Il giorno ven 8 mag 2020 alle ore 03:30 blb.dev <bl...@gmail.com> ha
scritto:

> Thanks for sharing -
>
> I wasn't using quorumListenOnAllIPs=true, as it's listed as an Unsafe
> Option
> - any reason why you chose to use it?
>
> The bind issue is fixed by setting either clientPort or secureClientPort
> only and only setting it in zoo.cfg or zoo.cfg.dynamic.
>
> However, my quorum still does not start up!  It gives the following stack
> trace:
>
> # bin/zkCli.sh
> /usr/bin/java
> Connecting to localhost:2181
> 2020-05-08 01:25:54,277 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
> built on 04/21/2020 15:01 GMT
> 2020-05-08 01:25:54,281 [myid:] - INFO  [main:Environment@98] - Client
> environment:host.name=zoo2
> 2020-05-08 01:25:54,281 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.version=1.8.0_252
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.vendor=Oracle Corporation
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> 2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.io.tmpdir=/tmp
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.compiler=<NA>
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.name=Linux
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.arch=amd64
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.version=3.10.0-327.28.3.el7.x86_64
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.name=root
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.home=/root
> 2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.dir=/apache-zookeeper-3.6.1-bin
> 2020-05-08 01:25:54,286 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.free=51MB
> 2020-05-08 01:25:54,287 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.max=228MB
> 2020-05-08 01:25:54,287 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.total=57MB
> 2020-05-08 01:25:54,293 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
> client connection, connectString=localhost:2181 sessionTimeout=30000
> watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
> 2020-05-08 01:25:54,298 [myid:] - INFO  [main:X509Util@77] - Setting -D
> jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
> TLS renegotiation
> 2020-05-08 01:25:54,306 [myid:] - INFO  [main:ClientCnxnSocket@239] -
> jute.maxbuffer value is 1048575 Bytes
> 2020-05-08 01:25:54,318 [myid:] - INFO  [main:ClientCnxn@1703] -
> zookeeper.request.timeout value is 0. feature enabled=false
> Welcome to ZooKeeper!
> 2020-05-08 01:25:54,331 [myid:localhost:2181] - INFO
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2181.
> 2020-05-08 01:25:54,333 [myid:localhost:2181] - INFO
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> JLine support is enabled
> 2020-05-08 01:25:54,449 [myid:localhost:2181] - INFO
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:49708,
> server: localhost/127.0.0.1:2181
> 2020-05-08 01:25:54,474 [myid:localhost:2181] - WARN
> [main-SendThread(localhost:2181):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
>         at
> org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
>         at
>
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
>         at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
>
> I tried adding multiAddress.reachabilityCheckEnabled=true since that seemed
> to paid with quorumListenOnAllIPs=true, but still the same SessionExpired
> error.
>
> Current config:
>
> dataDir=/data
> dataLogDir=/datalog
> tickTime=2000
> initLimit=10
> syncLimit=5
> maxClientCnxns=0
> autopurge.snapRetainCount=10
> autopurge.purgeInterval=24
> standaloneEnabled=false
> admin.enableServer=false
> snapshot.trust.empty=true
> reconfigEnabled=true
> audit.enable=true
> clientPort=2181
> sslQuorum=true
> ssl.client.enable=true
> portUnification=true
> client.portUnification=true
> serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
> clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
> ssl.quorum.keyStore.location=
> ssl.quorum.keyStore.password=
> ssl.quorum.trustStore.location=
> ssl.quorum.trustStore.password=
> multiAddress.reachabilityCheckEnabled=true
> quorumListenOnAllIPs=true
> 4lw.commands.whitelist=*
> dynamicConfigFile=/conf/zoo.cfg.dynamic
>
> where zoo.cfg.dynamic is:
>
> server.2=zoo2:2888:3888:participant
> server.3=zoo3:2888:3888:participant
> server.1=zoo1:2888:3888:participant
>
>
> Any ideas what this issue is? I'm really at a loss trying to add SSL...
>
>
>
>
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/
>

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Thanks for sharing - 

I wasn't using quorumListenOnAllIPs=true, as it's listed as an Unsafe Option
- any reason why you chose to use it?

The bind issue is fixed by setting either clientPort or secureClientPort
only and only setting it in zoo.cfg or zoo.cfg.dynamic. 

However, my quorum still does not start up!  It gives the following stack
trace: 

# bin/zkCli.sh
/usr/bin/java
Connecting to localhost:2181
2020-05-08 01:25:54,277 [myid:] - INFO  [main:Environment@98] - Client
environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
built on 04/21/2020 15:01 GMT
2020-05-08 01:25:54,281 [myid:] - INFO  [main:Environment@98] - Client
environment:host.name=zoo2
2020-05-08 01:25:54,281 [myid:] - INFO  [main:Environment@98] - Client
environment:java.version=1.8.0_252
2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
environment:java.vendor=Oracle Corporation
2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2020-05-08 01:25:54,284 [myid:] - INFO  [main:Environment@98] - Client
environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:java.io.tmpdir=/tmp
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:java.compiler=<NA>
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:os.name=Linux
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:os.arch=amd64
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:os.version=3.10.0-327.28.3.el7.x86_64
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:user.name=root
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:user.home=/root
2020-05-08 01:25:54,285 [myid:] - INFO  [main:Environment@98] - Client
environment:user.dir=/apache-zookeeper-3.6.1-bin
2020-05-08 01:25:54,286 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.free=51MB
2020-05-08 01:25:54,287 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.max=228MB
2020-05-08 01:25:54,287 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.total=57MB
2020-05-08 01:25:54,293 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
client connection, connectString=localhost:2181 sessionTimeout=30000
watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
2020-05-08 01:25:54,298 [myid:] - INFO  [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
TLS renegotiation
2020-05-08 01:25:54,306 [myid:] - INFO  [main:ClientCnxnSocket@239] -
jute.maxbuffer value is 1048575 Bytes
2020-05-08 01:25:54,318 [myid:] - INFO  [main:ClientCnxn@1703] -
zookeeper.request.timeout value is 0. feature enabled=false
Welcome to ZooKeeper!
2020-05-08 01:25:54,331 [myid:localhost:2181] - INFO 
[main-SendThread(localhost:2181):ClientCnxn$SendThread@1154] - Opening
socket connection to server localhost/127.0.0.1:2181.
2020-05-08 01:25:54,333 [myid:localhost:2181] - INFO 
[main-SendThread(localhost:2181):ClientCnxn$SendThread@1156] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
JLine support is enabled
2020-05-08 01:25:54,449 [myid:localhost:2181] - INFO 
[main-SendThread(localhost:2181):ClientCnxn$SendThread@986] - Socket
connection established, initiating session, client: /127.0.0.1:49708,
server: localhost/127.0.0.1:2181
2020-05-08 01:25:54,474 [myid:localhost:2181] - WARN 
[main-SendThread(localhost:2181):ClientCnxn$SendThread@1272] - Session 0x0
for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
EndOfStreamException: Unable to read additional data from server sessionid
0x0, likely server has closed socket
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)

I tried adding multiAddress.reachabilityCheckEnabled=true since that seemed
to paid with quorumListenOnAllIPs=true, but still the same SessionExpired
error. 

Current config: 

dataDir=/data
dataLogDir=/datalog
tickTime=2000
initLimit=10
syncLimit=5
maxClientCnxns=0
autopurge.snapRetainCount=10
autopurge.purgeInterval=24
standaloneEnabled=false
admin.enableServer=false
snapshot.trust.empty=true
reconfigEnabled=true
audit.enable=true
clientPort=2181
sslQuorum=true
ssl.client.enable=true
portUnification=true
client.portUnification=true
serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
ssl.quorum.keyStore.location=
ssl.quorum.keyStore.password=
ssl.quorum.trustStore.location=
ssl.quorum.trustStore.password=
multiAddress.reachabilityCheckEnabled=true
quorumListenOnAllIPs=true
4lw.commands.whitelist=*
dynamicConfigFile=/conf/zoo.cfg.dynamic

where zoo.cfg.dynamic is:

server.2=zoo2:2888:3888:participant
server.3=zoo3:2888:3888:participant
server.1=zoo1:2888:3888:participant


Any ideas what this issue is? I'm really at a loss trying to add SSL...




--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by ashish soni <ai...@gmail.com>.
this is how my zoo.cfg looks,

# https://zookeeper.apache.org/doc/r3.5.5/zookeeperAdmin.html
# https://zookeeper.apache.org/doc/r3.5.5/zookeeperReconfig.html

# The number of milliseconds of each tick
tickTime=2000
# The number of ticks that the initial synchronization phase can take
initLimit=20
# The number of ticks that can pass between sending a request and
getting an acknowledgement
syncLimit=15
quorumListenOnAllIPs=true

# HA (multi-node) setup
standaloneEnabled=false
dynamicConfigFile=/zookeeper/conf/zoo.cfg.dynamic

# location of in-memory database snapshots
dataDir=/data
# location of the transaction-log
dataLogDir=/data/xnlogs

maxClientCnxns = 1000
# enable regular purging of old data
autopurge.purgeInterval=24
autopurge.snapRetainCount=5

# The maximum session timeout in milliseconds that the server will
allow the client to negotiate
maxSessionTimeout=180000


And I have provided server list in dynamic file without client ports,

eg.
server.1=a.zookeeper.service:2888;3888server.2=b.zookeeper.service:2888;3888
server.3=c.zookeeper.service:2888;3888

I haven't been able to start the service in TLS mode yet as the certs
work is taken care by the infra team. But atleast the app failed at
the handshake and not at port binding.

Regards,
Aishwarya Soni

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Hi, 

I've tried keeping only secureClientPort or clientPort and still receive the
same bind error each time - I tried both leaving portUnification enabled and
disabled and still the same error. 

Could you share what your configuration looked like?  

When I try deploying, my quorum does not start up at all and does not even
configure the dynamic cfg file, it just fails with bind error, yet shows as
successful in audit logs (that might be its own bug). 






--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by ashish soni <ai...@gmail.com>.
Hi,

I got this error some days ago. Can you try keeping only one client port
configuration? Like, set secureClientPort in zoo.cfg and remove the
clientPort config from zoo.cfg and zoo.cfg.dynamic. Keeping at multiple
places will give you the port binding error.

Regards,
Aishwarya Soni

On Wed, May 6, 2020 at 3:24 PM blb.dev <bl...@gmail.com> wrote:

> It looks like others are seeing the same issue as me in recent comments on
> this item: https://issues.apache.org/jira/browse/ZOOKEEPER-2125
>
> I tried following the item and setting SERVER_JVMFLAGS and CLIENT_JVMFLAGS
> as well. Still get the same errors when trying to start ZK on 2181 or 2281:
>
> *# bin/zkCli.sh -server localhost:2281*
> /usr/bin/java
> Connecting to localhost:2281
> 2020-05-06 22:20:14,977 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
> built on 04/21/2020 15:01 GMT
> 2020-05-06 22:20:14,983 [myid:] - INFO  [main:Environment@98] - Client
> environment:host.name=zoo1
> 2020-05-06 22:20:14,983 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.version=1.8.0_252
> 2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.vendor=Oracle Corporation
> 2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
> 2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> 2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
>
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.io.tmpdir=/tmp
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.compiler=<NA>
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.name=Linux
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.arch=amd64
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.version=3.10.0-327.28.3.el7.x86_64
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.name=root
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.home=/root
> 2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.dir=/apache-zookeeper-3.6.1-bin
> 2020-05-06 22:20:14,989 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.free=51MB
> 2020-05-06 22:20:14,992 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.max=228MB
> 2020-05-06 22:20:14,993 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.total=57MB
> 2020-05-06 22:20:15,001 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
> client connection, connectString=localhost:2281 sessionTimeout=30000
> watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
> 2020-05-06 22:20:15,008 [myid:] - INFO  [main:X509Util@77] - Setting -D
> jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
> TLS renegotiation
> 2020-05-06 22:20:15,020 [myid:] - INFO  [main:ClientCnxnSocket@239] -
> jute.maxbuffer value is 1048575 Bytes
> 2020-05-06 22:20:15,033 [myid:] - INFO  [main:ClientCnxn@1703] -
> zookeeper.request.timeout value is 0. feature enabled=false
> Welcome to ZooKeeper!
> 2020-05-06 22:20:15,057 [myid:localhost:2281] - INFO
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2281.
> 2020-05-06 22:20:15,057 [myid:localhost:2281] - INFO
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> JLine support is enabled
> 2020-05-06 22:20:15,310 [myid:localhost:2281] - INFO
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:60688,
> server: localhost/127.0.0.1:2281
> 2020-05-06 22:20:15,337 [myid:localhost:2281] - WARN
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2281, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
>         at
> org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
>         at
>
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
>         at
> org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
> [zk: localhost:2281(CONNECTING) 0] 2020-05-06 22:20:17,130
> [myid:localhost:2281] - INFO
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2281.
> 2020-05-06 22:20:17,130 [myid:localhost:2281] - INFO
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> 2020-05-06 22:20:17,131 [myid:localhost:2281] - INFO
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:60690,
> server: localhost/127.0.0.1:2281
> 2020-05-06 22:20:17,156 [myid:localhost:2281] - WARN
> [main-SendThread(localhost:2281):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2281, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
>
> *# cat /logs/zookeeper.out *
> 2020-05-06 22:21:53,276 [myid:] - INFO  [main:QuorumPeerConfig@173] -
> Reading configuration from: /conf/zoo.cfg
> 2020-05-06 22:21:53,298 [myid:] - INFO  [main:QuorumPeerConfig@459] -
> clientPortAddress is 0.0.0.0:2181
> 2020-05-06 22:21:53,298 [myid:] - INFO  [main:QuorumPeerConfig@472] -
> secureClientPortAddress is 0.0.0.0:2281
> 2020-05-06 22:21:53,303 [myid:] - INFO  [main:X509Util@77] - Setting -D
> jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
> TLS renegotiation
> 2020-05-06 22:21:53,304 [myid:] - INFO  [main:QuorumPeerConfig@479] -
> observerMasterPort is not set
> 2020-05-06 22:21:53,305 [myid:] - INFO  [main:QuorumPeerConfig@496] -
> metricsProvider.className is
> org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
> 2020-05-06 22:21:53,348 [myid:1] - INFO  [main:DatadirCleanupManager@78] -
> autopurge.snapRetainCount set to 10
> 2020-05-06 22:21:53,348 [myid:1] - INFO  [main:DatadirCleanupManager@79] -
> autopurge.purgeInterval set to 24
> 2020-05-06 22:21:53,349 [myid:1] - INFO
> [PurgeTask:DatadirCleanupManager$PurgeTask@139] - Purge task started.
> 2020-05-06 22:21:53,353 [myid:1] - INFO  [PurgeTask:FileTxnSnapLog@124] -
> zookeeper.snapshot.trust.empty : true
> 2020-05-06 22:21:53,358 [myid:1] - INFO  [main:ManagedUtil@44] - Log4j 1.2
> jmx support found and enabled.
> 2020-05-06 22:21:53,362 [myid:1] - INFO  [PurgeTask:SnapStream@61] -
> zookeeper.snapshot.compression.method = CHECKED
> 2020-05-06 22:21:53,365 [myid:1] - INFO
> [PurgeTask:DatadirCleanupManager$PurgeTask@145] - Purge task completed.
> 2020-05-06 22:21:53,370 [myid:1] - INFO  [main:QuorumPeerMain@151] -
> Starting quorum peer
> 2020-05-06 22:21:53,387 [myid:1] - INFO  [main:ServerMetrics@62] -
> ServerMetrics initialized with provider
> org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@3b6eb2ec
> 2020-05-06 22:21:53,508 [myid:1] - INFO  [main:NettyServerCnxnFactory@483]
> -
> zookeeper.client.portUnification=false
> 2020-05-06 22:21:53,510 [myid:1] - INFO  [main:NettyServerCnxnFactory@495]
> -
> zookeeper.netty.advancedFlowControl.enabled = false
> 2020-05-06 22:21:53,510 [myid:1] - INFO  [main:NettyServerCnxnFactory@105]
> -
> handshakeThrottlingEnabled = false,
> zookeeper.netty.server.outstandingHandshake.limit = -1
> 2020-05-06 22:21:53,569 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
> Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
> connection factory
> 2020-05-06 22:21:53,571 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
> maxCnxns is not configured, using default value 0.
> 2020-05-06 22:21:53,571 [myid:1] - INFO  [main:NettyServerCnxnFactory@483]
> -
> zookeeper.client.portUnification=false
> 2020-05-06 22:21:53,572 [myid:1] - INFO  [main:NettyServerCnxnFactory@495]
> -
> zookeeper.netty.advancedFlowControl.enabled = false
> 2020-05-06 22:21:53,572 [myid:1] - INFO  [main:NettyServerCnxnFactory@105]
> -
> handshakeThrottlingEnabled = false,
> zookeeper.netty.server.outstandingHandshake.limit = -1
> 2020-05-06 22:21:53,573 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
> Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
> connection factory
> 2020-05-06 22:21:53,573 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
> maxCnxns is not configured, using default value 0.
> 2020-05-06 22:21:53,582 [myid:1] - INFO  [main:QuorumPeer@752] -
> zookeeper.quorumCnxnTimeoutMs=-1
> 2020-05-06 22:21:53,585 [myid:1] - INFO  [main:FileTxnSnapLog@124] -
> zookeeper.snapshot.trust.empty : true
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1680] - Local
> sessions disabled
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1691] - Local
> session upgrading disabled
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1658] - tickTime
> set to 2000
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1702] -
> minSessionTimeout set to 4000
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1713] -
> maxSessionTimeout set to 40000
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1738] -
> initLimit
> set to 10
> 2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1920] -
> syncLimit
> set to 5
> 2020-05-06 22:21:53,587 [myid:1] - INFO  [main:QuorumPeer@1935] -
> connectToLearnerMasterLimit set to 0
> 2020-05-06 22:21:53,603 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> ______                  _
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> |___
> /                 | |
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
>  / /
> ___     ___   | | __   ___    ___   _ __     ___   _ __
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -    /
> /
> / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -   /
> /__
> | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
>
> | |
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
>
> |_|
> 2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> 2020-05-06 22:21:53,606 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
> built on 04/21/2020 15:01 GMT
> 2020-05-06 22:21:53,606 [myid:1] - INFO  [main:Environment@98] - Server
> environment:host.name=zoo1
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.version=1.8.0_252
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.vendor=Oracle Corporation
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.io.tmpdir=/tmp
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.compiler=<NA>
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.name=Linux
> 2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.arch=amd64
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.version=3.10.0-327.28.3.el7.x86_64
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:user.name=root
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:user.home=/root
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:user.dir=/apache-zookeeper-3.6.1-bin
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.memory.free=47MB
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.memory.max=889MB
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.memory.total=57MB
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:ZooKeeperServer@128] -
> zookeeper.enableEagerACLCheck = false
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:ZooKeeperServer@136] -
> zookeeper.digest.enabled = true
> 2020-05-06 22:21:53,608 [myid:1] - INFO  [main:ZooKeeperServer@140] -
> zookeeper.closeSessionTxn.enabled = true
> 2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@1434] -
> zookeeper.flushDelay=0
> 2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@1443] -
> zookeeper.maxWriteQueuePollTime=0
> 2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@1452] -
> zookeeper.maxBatchSize=1000
> 2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@241] -
> zookeeper.intBufferStartingSizeBytes = 1024
> 2020-05-06 22:21:53,620 [myid:1] - INFO  [main:WatchManagerFactory@42] -
> Using org.apache.zookeeper.server.watch.WatchManager as watch manager
> 2020-05-06 22:21:53,621 [myid:1] - INFO  [main:WatchManagerFactory@42] -
> Using org.apache.zookeeper.server.watch.WatchManager as watch manager
> 2020-05-06 22:21:53,621 [myid:1] - INFO  [main:ZKDatabase@132] -
> zookeeper.snapshotSizeFactor = 0.33
> 2020-05-06 22:21:53,621 [myid:1] - INFO  [main:ZKDatabase@152] -
> zookeeper.commitLogCount=500
> 2020-05-06 22:21:53,653 [myid:1] - INFO  [main:QuorumPeer@1999] - Using
> TLS
> encrypted quorum communication
> 2020-05-06 22:21:53,653 [myid:1] - INFO  [main:QuorumPeer@2007] - Port
> unification disabled
> 2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@174] -
> multiAddress.enabled set to false
> 2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@199] -
> multiAddress.reachabilityCheckEnabled set to true
> 2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@186] -
> multiAddress.reachabilityCheckTimeoutMs set to 1000
> 2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@2461] -
> QuorumPeer
> communication is not secured! (SASL auth disabled)
> 2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@2486] -
> quorum.cnxn.threads.size set to 20
> 2020-05-06 22:21:53,655 [myid:1] - INFO  [main:FileSnap@85] - Reading
> snapshot /data/version-2/snapshot.2df600000002
> 2020-05-06 22:21:53,675 [myid:1] - INFO  [main:DataTree@1730] - The digest
> in the snapshot has digest version of 2, , with zxid as 0x2df600000002, and
> digest value as 352305768550
> 2020-05-06 22:21:53,692 [myid:1] - INFO  [main:FileTxnSnapLog@363] - 2
> txns
> loaded in 6 ms
> 2020-05-06 22:21:53,692 [myid:1] - INFO  [main:ZKDatabase@289] - Snapshot
> loaded in 37 ms, highest zxid is 0x2df700000002, digest is 352305768550
> 2020-05-06 22:21:53,693 [myid:1] - INFO  [main:NettyServerCnxnFactory@670]
> -
> binding to port 0.0.0.0/0.0.0.0:2181
> 2020-05-06 22:21:53,808 [myid:1] - ERROR [main:QuorumPeerMain@113] -
> Unexpected exception, exiting abnormally
> java.net.BindException: Address already in use
>         at sun.nio.ch.Net.bind0(Native Method)
>         at sun.nio.ch.Net.bind(Net.java:433)
>         at sun.nio.ch.Net.bind(Net.java:425)
>         at
> sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
>         at
>
> io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:134)
>         at
>
> io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:550)
>         at
>
> io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334)
>         at
>
> io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506)
>         at
>
> io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:491)
>         at
>
> io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973)
>         at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:248)
>         at
> io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356)
>         at
>
> io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
>         at
>
> io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
>         at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
>         at
>
> io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
>         at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
>         at
>
> io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
>         at java.lang.Thread.run(Thread.java:748)
> 2020-05-06 22:21:53,812 [myid:1] - INFO  [main:ZKAuditProvider@40] -
> ZooKeeper audit is enabled.
> 2020-05-06 22:21:53,816 [myid:1] - ERROR [main:ServiceUtils@42] - Exiting
> JVM with code 1
>
> What is the workaround here? Every time I set sslQuorum=true the ZK quorum
> will not start because the bind issue.
>
> Need guidance on how to proceed - I'm at a loss and upgrading is blocked.
> At
> a minimum I need secured client and server side communication.
>
>
>
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/
>

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
It looks like others are seeing the same issue as me in recent comments on
this item: https://issues.apache.org/jira/browse/ZOOKEEPER-2125

I tried following the item and setting SERVER_JVMFLAGS and CLIENT_JVMFLAGS
as well. Still get the same errors when trying to start ZK on 2181 or 2281:

*# bin/zkCli.sh -server localhost:2281*
/usr/bin/java
Connecting to localhost:2281
2020-05-06 22:20:14,977 [myid:] - INFO  [main:Environment@98] - Client
environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
built on 04/21/2020 15:01 GMT
2020-05-06 22:20:14,983 [myid:] - INFO  [main:Environment@98] - Client
environment:host.name=zoo1
2020-05-06 22:20:14,983 [myid:] - INFO  [main:Environment@98] - Client
environment:java.version=1.8.0_252
2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
environment:java.vendor=Oracle Corporation
2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2020-05-06 22:20:14,987 [myid:] - INFO  [main:Environment@98] - Client
environment:java.io.tmpdir=/tmp
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:java.compiler=<NA>
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:os.name=Linux
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:os.arch=amd64
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:os.version=3.10.0-327.28.3.el7.x86_64
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:user.name=root
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:user.home=/root
2020-05-06 22:20:14,988 [myid:] - INFO  [main:Environment@98] - Client
environment:user.dir=/apache-zookeeper-3.6.1-bin
2020-05-06 22:20:14,989 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.free=51MB
2020-05-06 22:20:14,992 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.max=228MB
2020-05-06 22:20:14,993 [myid:] - INFO  [main:Environment@98] - Client
environment:os.memory.total=57MB
2020-05-06 22:20:15,001 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
client connection, connectString=localhost:2281 sessionTimeout=30000
watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
2020-05-06 22:20:15,008 [myid:] - INFO  [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
TLS renegotiation
2020-05-06 22:20:15,020 [myid:] - INFO  [main:ClientCnxnSocket@239] -
jute.maxbuffer value is 1048575 Bytes
2020-05-06 22:20:15,033 [myid:] - INFO  [main:ClientCnxn@1703] -
zookeeper.request.timeout value is 0. feature enabled=false
Welcome to ZooKeeper!
2020-05-06 22:20:15,057 [myid:localhost:2281] - INFO 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@1154] - Opening
socket connection to server localhost/127.0.0.1:2281.
2020-05-06 22:20:15,057 [myid:localhost:2281] - INFO 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@1156] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
JLine support is enabled
2020-05-06 22:20:15,310 [myid:localhost:2281] - INFO 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@986] - Socket
connection established, initiating session, client: /127.0.0.1:60688,
server: localhost/127.0.0.1:2281
2020-05-06 22:20:15,337 [myid:localhost:2281] - WARN 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@1272] - Session 0x0
for sever localhost/127.0.0.1:2281, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
EndOfStreamException: Unable to read additional data from server sessionid
0x0, likely server has closed socket
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
	at
org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
[zk: localhost:2281(CONNECTING) 0] 2020-05-06 22:20:17,130
[myid:localhost:2281] - INFO 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@1154] - Opening
socket connection to server localhost/127.0.0.1:2281.
2020-05-06 22:20:17,130 [myid:localhost:2281] - INFO 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@1156] - SASL config
status: Will not attempt to authenticate using SASL (unknown error)
2020-05-06 22:20:17,131 [myid:localhost:2281] - INFO 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@986] - Socket
connection established, initiating session, client: /127.0.0.1:60690,
server: localhost/127.0.0.1:2281
2020-05-06 22:20:17,156 [myid:localhost:2281] - WARN 
[main-SendThread(localhost:2281):ClientCnxn$SendThread@1272] - Session 0x0
for sever localhost/127.0.0.1:2281, Closing socket connection. Attempting
reconnect except it is a SessionExpiredException.
EndOfStreamException: Unable to read additional data from server sessionid
0x0, likely server has closed socket

*# cat /logs/zookeeper.out *
2020-05-06 22:21:53,276 [myid:] - INFO  [main:QuorumPeerConfig@173] -
Reading configuration from: /conf/zoo.cfg
2020-05-06 22:21:53,298 [myid:] - INFO  [main:QuorumPeerConfig@459] -
clientPortAddress is 0.0.0.0:2181
2020-05-06 22:21:53,298 [myid:] - INFO  [main:QuorumPeerConfig@472] -
secureClientPortAddress is 0.0.0.0:2281
2020-05-06 22:21:53,303 [myid:] - INFO  [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
TLS renegotiation
2020-05-06 22:21:53,304 [myid:] - INFO  [main:QuorumPeerConfig@479] -
observerMasterPort is not set
2020-05-06 22:21:53,305 [myid:] - INFO  [main:QuorumPeerConfig@496] -
metricsProvider.className is
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
2020-05-06 22:21:53,348 [myid:1] - INFO  [main:DatadirCleanupManager@78] -
autopurge.snapRetainCount set to 10
2020-05-06 22:21:53,348 [myid:1] - INFO  [main:DatadirCleanupManager@79] -
autopurge.purgeInterval set to 24
2020-05-06 22:21:53,349 [myid:1] - INFO 
[PurgeTask:DatadirCleanupManager$PurgeTask@139] - Purge task started.
2020-05-06 22:21:53,353 [myid:1] - INFO  [PurgeTask:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : true
2020-05-06 22:21:53,358 [myid:1] - INFO  [main:ManagedUtil@44] - Log4j 1.2
jmx support found and enabled.
2020-05-06 22:21:53,362 [myid:1] - INFO  [PurgeTask:SnapStream@61] -
zookeeper.snapshot.compression.method = CHECKED
2020-05-06 22:21:53,365 [myid:1] - INFO 
[PurgeTask:DatadirCleanupManager$PurgeTask@145] - Purge task completed.
2020-05-06 22:21:53,370 [myid:1] - INFO  [main:QuorumPeerMain@151] -
Starting quorum peer
2020-05-06 22:21:53,387 [myid:1] - INFO  [main:ServerMetrics@62] -
ServerMetrics initialized with provider
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@3b6eb2ec
2020-05-06 22:21:53,508 [myid:1] - INFO  [main:NettyServerCnxnFactory@483] -
zookeeper.client.portUnification=false
2020-05-06 22:21:53,510 [myid:1] - INFO  [main:NettyServerCnxnFactory@495] -
zookeeper.netty.advancedFlowControl.enabled = false
2020-05-06 22:21:53,510 [myid:1] - INFO  [main:NettyServerCnxnFactory@105] -
handshakeThrottlingEnabled = false,
zookeeper.netty.server.outstandingHandshake.limit = -1
2020-05-06 22:21:53,569 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
connection factory
2020-05-06 22:21:53,571 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
maxCnxns is not configured, using default value 0.
2020-05-06 22:21:53,571 [myid:1] - INFO  [main:NettyServerCnxnFactory@483] -
zookeeper.client.portUnification=false
2020-05-06 22:21:53,572 [myid:1] - INFO  [main:NettyServerCnxnFactory@495] -
zookeeper.netty.advancedFlowControl.enabled = false
2020-05-06 22:21:53,572 [myid:1] - INFO  [main:NettyServerCnxnFactory@105] -
handshakeThrottlingEnabled = false,
zookeeper.netty.server.outstandingHandshake.limit = -1
2020-05-06 22:21:53,573 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
connection factory
2020-05-06 22:21:53,573 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
maxCnxns is not configured, using default value 0.
2020-05-06 22:21:53,582 [myid:1] - INFO  [main:QuorumPeer@752] -
zookeeper.quorumCnxnTimeoutMs=-1
2020-05-06 22:21:53,585 [myid:1] - INFO  [main:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : true
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1680] - Local
sessions disabled
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1691] - Local
session upgrading disabled
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1658] - tickTime
set to 2000
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1702] -
minSessionTimeout set to 4000
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1713] -
maxSessionTimeout set to 40000
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1738] - initLimit
set to 10
2020-05-06 22:21:53,586 [myid:1] - INFO  [main:QuorumPeer@1920] - syncLimit
set to 5
2020-05-06 22:21:53,587 [myid:1] - INFO  [main:QuorumPeer@1935] -
connectToLearnerMasterLimit set to 0
2020-05-06 22:21:53,603 [myid:1] - INFO  [main:ZookeeperBanner@42] - 
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -  
______                  _                                          
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -  |___ 
/                 | |                                         
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -     / /   
___     ___   | | __   ___    ___   _ __     ___   _ __   
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -    / /   
/ _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -   / /__ 
| (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |    
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] - 
/_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -                                              
| |                     
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] -                                              
|_|                     
2020-05-06 22:21:53,604 [myid:1] - INFO  [main:ZookeeperBanner@42] - 
2020-05-06 22:21:53,606 [myid:1] - INFO  [main:Environment@98] - Server
environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
built on 04/21/2020 15:01 GMT
2020-05-06 22:21:53,606 [myid:1] - INFO  [main:Environment@98] - Server
environment:host.name=zoo1
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.version=1.8.0_252
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.vendor=Oracle Corporation
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.io.tmpdir=/tmp
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.compiler=<NA>
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.name=Linux
2020-05-06 22:21:53,607 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.arch=amd64
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.version=3.10.0-327.28.3.el7.x86_64
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:user.name=root
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:user.home=/root
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:user.dir=/apache-zookeeper-3.6.1-bin
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.memory.free=47MB
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.memory.max=889MB
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.memory.total=57MB
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:ZooKeeperServer@128] -
zookeeper.enableEagerACLCheck = false
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:ZooKeeperServer@136] -
zookeeper.digest.enabled = true
2020-05-06 22:21:53,608 [myid:1] - INFO  [main:ZooKeeperServer@140] -
zookeeper.closeSessionTxn.enabled = true
2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@1434] -
zookeeper.flushDelay=0
2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@1443] -
zookeeper.maxWriteQueuePollTime=0
2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@1452] -
zookeeper.maxBatchSize=1000
2020-05-06 22:21:53,609 [myid:1] - INFO  [main:ZooKeeperServer@241] -
zookeeper.intBufferStartingSizeBytes = 1024
2020-05-06 22:21:53,620 [myid:1] - INFO  [main:WatchManagerFactory@42] -
Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2020-05-06 22:21:53,621 [myid:1] - INFO  [main:WatchManagerFactory@42] -
Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2020-05-06 22:21:53,621 [myid:1] - INFO  [main:ZKDatabase@132] -
zookeeper.snapshotSizeFactor = 0.33
2020-05-06 22:21:53,621 [myid:1] - INFO  [main:ZKDatabase@152] -
zookeeper.commitLogCount=500
2020-05-06 22:21:53,653 [myid:1] - INFO  [main:QuorumPeer@1999] - Using TLS
encrypted quorum communication
2020-05-06 22:21:53,653 [myid:1] - INFO  [main:QuorumPeer@2007] - Port
unification disabled
2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@174] -
multiAddress.enabled set to false
2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@199] -
multiAddress.reachabilityCheckEnabled set to true
2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@186] -
multiAddress.reachabilityCheckTimeoutMs set to 1000
2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@2461] - QuorumPeer
communication is not secured! (SASL auth disabled)
2020-05-06 22:21:53,654 [myid:1] - INFO  [main:QuorumPeer@2486] -
quorum.cnxn.threads.size set to 20
2020-05-06 22:21:53,655 [myid:1] - INFO  [main:FileSnap@85] - Reading
snapshot /data/version-2/snapshot.2df600000002
2020-05-06 22:21:53,675 [myid:1] - INFO  [main:DataTree@1730] - The digest
in the snapshot has digest version of 2, , with zxid as 0x2df600000002, and
digest value as 352305768550
2020-05-06 22:21:53,692 [myid:1] - INFO  [main:FileTxnSnapLog@363] - 2 txns
loaded in 6 ms
2020-05-06 22:21:53,692 [myid:1] - INFO  [main:ZKDatabase@289] - Snapshot
loaded in 37 ms, highest zxid is 0x2df700000002, digest is 352305768550
2020-05-06 22:21:53,693 [myid:1] - INFO  [main:NettyServerCnxnFactory@670] -
binding to port 0.0.0.0/0.0.0.0:2181
2020-05-06 22:21:53,808 [myid:1] - ERROR [main:QuorumPeerMain@113] -
Unexpected exception, exiting abnormally
java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:433)
	at sun.nio.ch.Net.bind(Net.java:425)
	at
sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
	at
io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:134)
	at
io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:550)
	at
io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334)
	at
io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506)
	at
io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:491)
	at
io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973)
	at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:248)
	at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356)
	at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
2020-05-06 22:21:53,812 [myid:1] - INFO  [main:ZKAuditProvider@40] -
ZooKeeper audit is enabled.
2020-05-06 22:21:53,816 [myid:1] - ERROR [main:ServiceUtils@42] - Exiting
JVM with code 1

What is the workaround here? Every time I set sslQuorum=true the ZK quorum
will not start because the bind issue. 

Need guidance on how to proceed - I'm at a loss and upgrading is blocked. At
a minimum I need secured client and server side communication. 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Enrico, 

Yes, we would like client- and server-side SSL/TLS. 

I thought to do so I would need to keep the following in the config: 
secureClientPort=2281
sslQuorum=true
portUnification=false
ssl.client.enable=true
clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
ssl.quorum.trustStore.location=
ssl.quorum.trustStore.password=
ssl.quorum.keyStore.location=
ssl.quorum.keyStore.password=

When I try starting the quorum like this then it does not start up and gives
the bind error for the ports. When I try by enabling portUnification and
disabling sslQuorum, then it starts up. 

What configuration do I need to have only TLS client and server side
connections? Do you mean to do something different than what I am trying in
zoo.cfg currently? 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by Enrico Olivelli <eo...@gmail.com>.
from the stacktrace is looks like the error is on Netty and Netty is only
for the communication port to the client,
so the quorum communication should not be affected but this error.

So you have SSL clients and SSL quorum communication ?
With portUnification you r using only one single port that serves both
plain and ssl protocols so you do not need to
start the secureClientPort
if you want only TLS then you can disable port unification and configure
the secureClientPort

I hope that helps

Enrico

Il giorno lun 4 mag 2020 alle ore 20:44 blb.dev <bl...@gmail.com> ha
scritto:

> So reading through the section on Upgrading existing non-TLS cluster with
> no
> downtime in the zookeeper admin guide, it says when upgrading from 3.4
> branch I need to start with /sslQuorum=false portUnification=true/.
>
> I tried this and ZK finally came up successfully. However, when I updated
> the config files to /sslQuorum=true portUnification=true/ and did rolling
> restart, then they do not pick up the changes giving the same port bind
> error as noted.
>
> *What do I need to do differently to get a healthy zk when sslQuorum
> communication is enabled? *
>
>
>
> *# cat /logs/zookeeper.out    *
> 2020-05-04 18:15:06,565 [myid:] - INFO  [main:QuorumPeerConfig@173] -
> Reading configuration from: /conf/zoo.cfg
> 2020-05-04 18:15:06,584 [myid:] - INFO  [main:QuorumPeerConfig@459] -
> clientPortAddress is 0.0.0.0:2181
> 2020-05-04 18:15:06,584 [myid:] - INFO  [main:QuorumPeerConfig@472] -
> secureClientPortAddress is 0.0.0.0:2281
> 2020-05-04 18:15:06,588 [myid:] - INFO  [main:X509Util@77] - Setting -D
> jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
> TLS renegotiation
> 2020-05-04 18:15:06,589 [myid:] - INFO  [main:QuorumPeerConfig@479] -
> observerMasterPort is not set
> 2020-05-04 18:15:06,590 [myid:] - INFO  [main:QuorumPeerConfig@496] -
> metricsProvider.className is
> org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
> 2020-05-04 18:15:06,605 [myid:1] - INFO  [main:DatadirCleanupManager@78] -
> autopurge.snapRetainCount set to 10
> 2020-05-04 18:15:06,606 [myid:1] - INFO  [main:DatadirCleanupManager@79] -
> autopurge.purgeInterval set to 24
> 2020-05-04 18:15:06,610 [myid:1] - INFO  [main:ManagedUtil@44] - Log4j 1.2
> jmx support found and enabled.
> 2020-05-04 18:15:06,614 [myid:1] - INFO
> [PurgeTask:DatadirCleanupManager$PurgeTask@139] - Purge task started.
> 2020-05-04 18:15:06,618 [myid:1] - INFO  [PurgeTask:FileTxnSnapLog@124] -
> zookeeper.snapshot.trust.empty : true
> 2020-05-04 18:15:06,629 [myid:1] - INFO  [main:QuorumPeerMain@151] -
> Starting quorum peer
> 2020-05-04 18:15:06,654 [myid:1] - INFO  [PurgeTask:SnapStream@61] -
> zookeeper.snapshot.compression.method = CHECKED
> 2020-05-04 18:15:06,656 [myid:1] - INFO
> [PurgeTask:DatadirCleanupManager$PurgeTask@145] - Purge task completed.
> 2020-05-04 18:15:06,662 [myid:1] - INFO  [main:ServerMetrics@62] -
> ServerMetrics initialized with provider
> org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@1d251891
> 2020-05-04 18:15:06,780 [myid:1] - INFO  [main:NettyServerCnxnFactory@483]
> -
> zookeeper.client.portUnification=true
> 2020-05-04 18:15:06,781 [myid:1] - INFO  [main:NettyServerCnxnFactory@495]
> -
> zookeeper.netty.advancedFlowControl.enabled = false
> 2020-05-04 18:15:06,782 [myid:1] - INFO  [main:NettyServerCnxnFactory@105]
> -
> handshakeThrottlingEnabled = false,
> zookeeper.netty.server.outstandingHandshake.limit = -1
> 2020-05-04 18:15:06,840 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
> Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
> connection factory
> 2020-05-04 18:15:06,841 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
> maxCnxns is not configured, using default value 0.
> 2020-05-04 18:15:06,841 [myid:1] - INFO  [main:NettyServerCnxnFactory@483]
> -
> zookeeper.client.portUnification=true
> 2020-05-04 18:15:06,842 [myid:1] - INFO  [main:NettyServerCnxnFactory@495]
> -
> zookeeper.netty.advancedFlowControl.enabled = false
> 2020-05-04 18:15:06,842 [myid:1] - INFO  [main:NettyServerCnxnFactory@105]
> -
> handshakeThrottlingEnabled = false,
> zookeeper.netty.server.outstandingHandshake.limit = -1
> 2020-05-04 18:15:06,843 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
> Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
> connection factory
> 2020-05-04 18:15:06,843 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
> maxCnxns is not configured, using default value 0.
> 2020-05-04 18:15:06,852 [myid:1] - INFO  [main:QuorumPeer@752] -
> zookeeper.quorumCnxnTimeoutMs=-1
> 2020-05-04 18:15:06,856 [myid:1] - INFO  [main:FileTxnSnapLog@124] -
> zookeeper.snapshot.trust.empty : true
> 2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1680] - Local
> sessions disabled
> 2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1691] - Local
> session upgrading disabled
> 2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1658] - tickTime
> set to 2000
> 2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1702] -
> minSessionTimeout set to 4000
> 2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1713] -
> maxSessionTimeout set to 40000
> 2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1738] -
> initLimit
> set to 10
> 2020-05-04 18:15:06,858 [myid:1] - INFO  [main:QuorumPeer@1920] -
> syncLimit
> set to 5
> 2020-05-04 18:15:06,858 [myid:1] - INFO  [main:QuorumPeer@1935] -
> connectToLearnerMasterLimit set to 0
> 2020-05-04 18:15:06,877 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> 2020-05-04 18:15:06,877 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> ______                  _
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> |___
> /                 | |
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -
>  / /
> ___     ___   | | __   ___    ___   _ __     ___   _ __
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -    /
> /
> / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -   /
> /__
> | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -
>
> | |
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -
>
> |_|
> 2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -
> 2020-05-04 18:15:06,880 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
> built on 04/21/2020 15:01 GMT
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
> environment:host.name=zoo1
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.version=1.8.0_252
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.vendor=Oracle Corporation
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
>
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.io.tmpdir=/tmp
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:java.compiler=<NA>
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.name=Linux
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.arch=amd64
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.version=3.10.0-327.28.3.el7.x86_64
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:user.name=root
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:user.home=/root
> 2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
> environment:user.dir=/apache-zookeeper-3.6.1-bin
> 2020-05-04 18:15:06,883 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.memory.free=47MB
> 2020-05-04 18:15:06,883 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.memory.max=889MB
> 2020-05-04 18:15:06,883 [myid:1] - INFO  [main:Environment@98] - Server
> environment:os.memory.total=57MB
> 2020-05-04 18:15:06,883 [myid:1] - INFO  [main:ZooKeeperServer@128] -
> zookeeper.enableEagerACLCheck = false
> 2020-05-04 18:15:06,883 [myid:1] - INFO  [main:ZooKeeperServer@136] -
> zookeeper.digest.enabled = true
> 2020-05-04 18:15:06,883 [myid:1] - INFO  [main:ZooKeeperServer@140] -
> zookeeper.closeSessionTxn.enabled = true
> 2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@1434] -
> zookeeper.flushDelay=0
> 2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@1443] -
> zookeeper.maxWriteQueuePollTime=0
> 2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@1452] -
> zookeeper.maxBatchSize=1000
> 2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@241] -
> zookeeper.intBufferStartingSizeBytes = 1024
> 2020-05-04 18:15:06,892 [myid:1] - INFO  [main:WatchManagerFactory@42] -
> Using org.apache.zookeeper.server.watch.WatchManager as watch manager
> 2020-05-04 18:15:06,893 [myid:1] - INFO  [main:WatchManagerFactory@42] -
> Using org.apache.zookeeper.server.watch.WatchManager as watch manager
> 2020-05-04 18:15:06,893 [myid:1] - INFO  [main:ZKDatabase@132] -
> zookeeper.snapshotSizeFactor = 0.33
> 2020-05-04 18:15:06,893 [myid:1] - INFO  [main:ZKDatabase@152] -
> zookeeper.commitLogCount=500
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@1999] - Using
> TLS
> encrypted quorum communication
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@2007] - Port
> unification enabled
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@174] -
> multiAddress.enabled set to false
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@199] -
> multiAddress.reachabilityCheckEnabled set to true
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@186] -
> multiAddress.reachabilityCheckTimeoutMs set to 1000
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@2461] -
> QuorumPeer
> communication is not secured! (SASL auth disabled)
> 2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@2486] -
> quorum.cnxn.threads.size set to 20
> 2020-05-04 18:15:06,929 [myid:1] - INFO  [main:FileSnap@85] - Reading
> snapshot /data/version-2/snapshot.2df500000000
> 2020-05-04 18:15:06,948 [myid:1] - INFO  [main:DataTree@1737] - The digest
> value is empty in snapshot
> 2020-05-04 18:15:06,983 [myid:1] - INFO  [main:FileTxnSnapLog@363] - 16
> txns
> loaded in 22 ms
> 2020-05-04 18:15:06,983 [myid:1] - INFO  [main:ZKDatabase@289] - Snapshot
> loaded in 55 ms, highest zxid is 0x2df700000008, digest is 354107731533
> 2020-05-04 18:15:06,984 [myid:1] - INFO  [main:NettyServerCnxnFactory@670]
> -
> binding to port 0.0.0.0/0.0.0.0:2181
> 2020-05-04 18:15:07,088 [myid:1] - ERROR [main:QuorumPeerMain@113] -
> Unexpected exception, exiting abnormally
> java.net.BindException: Address already in use
>         at sun.nio.ch.Net.bind0(Native Method)
>         at sun.nio.ch.Net.bind(Net.java:433)
>         at sun.nio.ch.Net.bind(Net.java:425)
>         at
> sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
>         at
>
> io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:134)
>         at
>
> io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:550)
>         at
>
> io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334)
>         at
>
> io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506)
>         at
>
> io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:491)
>         at
>
> io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973)
>         at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:248)
>         at
> io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356)
>         at
>
> io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
>         at
>
> io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
>         at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
>         at
>
> io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
>         at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
>         at
>
> io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
>         at java.lang.Thread.run(Thread.java:748)
> 2020-05-04 18:15:07,091 [myid:1] - INFO  [main:ZKAuditProvider@40] -
> ZooKeeper audit is enabled.
> 2020-05-04 18:15:07,094 [myid:1] - ERROR [main:ServiceUtils@42] - Exiting
> JVM with code 1
>
>
>
> */conf/zoo.cfg:*
>
> ssl.quorum.trustStore.location=/apache-zookeeper-3.6.1-bin/java/truststore.ks
> 4lw.commands.whitelist=*
> ssl.quorum.trustStore.password=ApolloStore
> clientPort=2181
> ssl.client.enable=true
> autopurge.snapRetainCount=10
> dataLogDir=/datalog
> snapshot.trust.empty=true
> clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
> admin.enableServer=false
> syncLimit=5
> tickTime=2000
> sslQuorum=true
> serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
> ssl.quorum.keyStore.location=/apache-zookeeper-3.6.1-bin/java/node1.ks
> ssl.quorum.keyStore.password=ApolloCert1
> initLimit=10
> secureClientPort=2281
> maxClientCnxns=0
> client.portUnification=true
> reconfigEnabled=true
> portUnification=true
> dataDir=/data
> autopurge.purgeInterval=24
> audit.enable=true
> dynamicConfigFile=/conf/zoo.cfg.dynamic.2df700000000
>
>
>
>
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/
>

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
So reading through the section on Upgrading existing non-TLS cluster with no
downtime in the zookeeper admin guide, it says when upgrading from 3.4
branch I need to start with /sslQuorum=false portUnification=true/. 

I tried this and ZK finally came up successfully. However, when I updated
the config files to /sslQuorum=true portUnification=true/ and did rolling
restart, then they do not pick up the changes giving the same port bind
error as noted.  

*What do I need to do differently to get a healthy zk when sslQuorum
communication is enabled? *



*# cat /logs/zookeeper.out    *   
2020-05-04 18:15:06,565 [myid:] - INFO  [main:QuorumPeerConfig@173] -
Reading configuration from: /conf/zoo.cfg
2020-05-04 18:15:06,584 [myid:] - INFO  [main:QuorumPeerConfig@459] -
clientPortAddress is 0.0.0.0:2181
2020-05-04 18:15:06,584 [myid:] - INFO  [main:QuorumPeerConfig@472] -
secureClientPortAddress is 0.0.0.0:2281
2020-05-04 18:15:06,588 [myid:] - INFO  [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
TLS renegotiation
2020-05-04 18:15:06,589 [myid:] - INFO  [main:QuorumPeerConfig@479] -
observerMasterPort is not set
2020-05-04 18:15:06,590 [myid:] - INFO  [main:QuorumPeerConfig@496] -
metricsProvider.className is
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
2020-05-04 18:15:06,605 [myid:1] - INFO  [main:DatadirCleanupManager@78] -
autopurge.snapRetainCount set to 10
2020-05-04 18:15:06,606 [myid:1] - INFO  [main:DatadirCleanupManager@79] -
autopurge.purgeInterval set to 24
2020-05-04 18:15:06,610 [myid:1] - INFO  [main:ManagedUtil@44] - Log4j 1.2
jmx support found and enabled.
2020-05-04 18:15:06,614 [myid:1] - INFO 
[PurgeTask:DatadirCleanupManager$PurgeTask@139] - Purge task started.
2020-05-04 18:15:06,618 [myid:1] - INFO  [PurgeTask:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : true
2020-05-04 18:15:06,629 [myid:1] - INFO  [main:QuorumPeerMain@151] -
Starting quorum peer
2020-05-04 18:15:06,654 [myid:1] - INFO  [PurgeTask:SnapStream@61] -
zookeeper.snapshot.compression.method = CHECKED
2020-05-04 18:15:06,656 [myid:1] - INFO 
[PurgeTask:DatadirCleanupManager$PurgeTask@145] - Purge task completed.
2020-05-04 18:15:06,662 [myid:1] - INFO  [main:ServerMetrics@62] -
ServerMetrics initialized with provider
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@1d251891
2020-05-04 18:15:06,780 [myid:1] - INFO  [main:NettyServerCnxnFactory@483] -
zookeeper.client.portUnification=true
2020-05-04 18:15:06,781 [myid:1] - INFO  [main:NettyServerCnxnFactory@495] -
zookeeper.netty.advancedFlowControl.enabled = false
2020-05-04 18:15:06,782 [myid:1] - INFO  [main:NettyServerCnxnFactory@105] -
handshakeThrottlingEnabled = false,
zookeeper.netty.server.outstandingHandshake.limit = -1
2020-05-04 18:15:06,840 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
connection factory
2020-05-04 18:15:06,841 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
maxCnxns is not configured, using default value 0.
2020-05-04 18:15:06,841 [myid:1] - INFO  [main:NettyServerCnxnFactory@483] -
zookeeper.client.portUnification=true
2020-05-04 18:15:06,842 [myid:1] - INFO  [main:NettyServerCnxnFactory@495] -
zookeeper.netty.advancedFlowControl.enabled = false
2020-05-04 18:15:06,842 [myid:1] - INFO  [main:NettyServerCnxnFactory@105] -
handshakeThrottlingEnabled = false,
zookeeper.netty.server.outstandingHandshake.limit = -1
2020-05-04 18:15:06,843 [myid:1] - INFO  [main:ServerCnxnFactory@169] -
Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
connection factory
2020-05-04 18:15:06,843 [myid:1] - WARN  [main:ServerCnxnFactory@309] -
maxCnxns is not configured, using default value 0.
2020-05-04 18:15:06,852 [myid:1] - INFO  [main:QuorumPeer@752] -
zookeeper.quorumCnxnTimeoutMs=-1
2020-05-04 18:15:06,856 [myid:1] - INFO  [main:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : true
2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1680] - Local
sessions disabled
2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1691] - Local
session upgrading disabled
2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1658] - tickTime
set to 2000
2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1702] -
minSessionTimeout set to 4000
2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1713] -
maxSessionTimeout set to 40000
2020-05-04 18:15:06,857 [myid:1] - INFO  [main:QuorumPeer@1738] - initLimit
set to 10
2020-05-04 18:15:06,858 [myid:1] - INFO  [main:QuorumPeer@1920] - syncLimit
set to 5
2020-05-04 18:15:06,858 [myid:1] - INFO  [main:QuorumPeer@1935] -
connectToLearnerMasterLimit set to 0
2020-05-04 18:15:06,877 [myid:1] - INFO  [main:ZookeeperBanner@42] - 
2020-05-04 18:15:06,877 [myid:1] - INFO  [main:ZookeeperBanner@42] -  
______                  _                                          
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -  |___ 
/                 | |                                         
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -     / /   
___     ___   | | __   ___    ___   _ __     ___   _ __   
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -    / /   
/ _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -   / /__ 
| (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |    
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] - 
/_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -                                              
| |                     
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] -                                              
|_|                     
2020-05-04 18:15:06,878 [myid:1] - INFO  [main:ZookeeperBanner@42] - 
2020-05-04 18:15:06,880 [myid:1] - INFO  [main:Environment@98] - Server
environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
built on 04/21/2020 15:01 GMT
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:host.name=zoo1
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.version=1.8.0_252
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.vendor=Oracle Corporation
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2020-05-04 18:15:06,881 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.io.tmpdir=/tmp
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:java.compiler=<NA>
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.name=Linux
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.arch=amd64
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.version=3.10.0-327.28.3.el7.x86_64
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:user.name=root
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:user.home=/root
2020-05-04 18:15:06,882 [myid:1] - INFO  [main:Environment@98] - Server
environment:user.dir=/apache-zookeeper-3.6.1-bin
2020-05-04 18:15:06,883 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.memory.free=47MB
2020-05-04 18:15:06,883 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.memory.max=889MB
2020-05-04 18:15:06,883 [myid:1] - INFO  [main:Environment@98] - Server
environment:os.memory.total=57MB
2020-05-04 18:15:06,883 [myid:1] - INFO  [main:ZooKeeperServer@128] -
zookeeper.enableEagerACLCheck = false
2020-05-04 18:15:06,883 [myid:1] - INFO  [main:ZooKeeperServer@136] -
zookeeper.digest.enabled = true
2020-05-04 18:15:06,883 [myid:1] - INFO  [main:ZooKeeperServer@140] -
zookeeper.closeSessionTxn.enabled = true
2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@1434] -
zookeeper.flushDelay=0
2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@1443] -
zookeeper.maxWriteQueuePollTime=0
2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@1452] -
zookeeper.maxBatchSize=1000
2020-05-04 18:15:06,884 [myid:1] - INFO  [main:ZooKeeperServer@241] -
zookeeper.intBufferStartingSizeBytes = 1024
2020-05-04 18:15:06,892 [myid:1] - INFO  [main:WatchManagerFactory@42] -
Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2020-05-04 18:15:06,893 [myid:1] - INFO  [main:WatchManagerFactory@42] -
Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2020-05-04 18:15:06,893 [myid:1] - INFO  [main:ZKDatabase@132] -
zookeeper.snapshotSizeFactor = 0.33
2020-05-04 18:15:06,893 [myid:1] - INFO  [main:ZKDatabase@152] -
zookeeper.commitLogCount=500
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@1999] - Using TLS
encrypted quorum communication
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@2007] - Port
unification enabled
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@174] -
multiAddress.enabled set to false
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@199] -
multiAddress.reachabilityCheckEnabled set to true
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@186] -
multiAddress.reachabilityCheckTimeoutMs set to 1000
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@2461] - QuorumPeer
communication is not secured! (SASL auth disabled)
2020-05-04 18:15:06,927 [myid:1] - INFO  [main:QuorumPeer@2486] -
quorum.cnxn.threads.size set to 20
2020-05-04 18:15:06,929 [myid:1] - INFO  [main:FileSnap@85] - Reading
snapshot /data/version-2/snapshot.2df500000000
2020-05-04 18:15:06,948 [myid:1] - INFO  [main:DataTree@1737] - The digest
value is empty in snapshot
2020-05-04 18:15:06,983 [myid:1] - INFO  [main:FileTxnSnapLog@363] - 16 txns
loaded in 22 ms
2020-05-04 18:15:06,983 [myid:1] - INFO  [main:ZKDatabase@289] - Snapshot
loaded in 55 ms, highest zxid is 0x2df700000008, digest is 354107731533
2020-05-04 18:15:06,984 [myid:1] - INFO  [main:NettyServerCnxnFactory@670] -
binding to port 0.0.0.0/0.0.0.0:2181
2020-05-04 18:15:07,088 [myid:1] - ERROR [main:QuorumPeerMain@113] -
Unexpected exception, exiting abnormally
java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:433)
	at sun.nio.ch.Net.bind(Net.java:425)
	at
sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
	at
io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:134)
	at
io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:550)
	at
io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334)
	at
io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506)
	at
io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:491)
	at
io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973)
	at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:248)
	at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356)
	at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
2020-05-04 18:15:07,091 [myid:1] - INFO  [main:ZKAuditProvider@40] -
ZooKeeper audit is enabled.
2020-05-04 18:15:07,094 [myid:1] - ERROR [main:ServiceUtils@42] - Exiting
JVM with code 1



*/conf/zoo.cfg:*
ssl.quorum.trustStore.location=/apache-zookeeper-3.6.1-bin/java/truststore.ks
4lw.commands.whitelist=*
ssl.quorum.trustStore.password=ApolloStore
clientPort=2181
ssl.client.enable=true
autopurge.snapRetainCount=10
dataLogDir=/datalog
snapshot.trust.empty=true
clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
admin.enableServer=false
syncLimit=5
tickTime=2000
sslQuorum=true
serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
ssl.quorum.keyStore.location=/apache-zookeeper-3.6.1-bin/java/node1.ks
ssl.quorum.keyStore.password=ApolloCert1
initLimit=10
secureClientPort=2281
maxClientCnxns=0
client.portUnification=true
reconfigEnabled=true
portUnification=true
dataDir=/data
autopurge.purgeInterval=24
audit.enable=true
dynamicConfigFile=/conf/zoo.cfg.dynamic.2df700000000




--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
I tried manually stopping/starting the zk with zkServer.sh stop/start and
then the zookeeper.out started showing logs again. 

*# cat /logs/zookeeper.out  *     
2020-05-04 16:05:53,186 [myid:] - INFO  [main:QuorumPeerConfig@173] -
Reading configuration from: /conf/zoo.cfg
2020-05-04 16:05:53,199 [myid:] - INFO  [main:QuorumPeerConfig@459] -
clientPortAddress is 0.0.0.0:2181
2020-05-04 16:05:53,200 [myid:] - INFO  [main:QuorumPeerConfig@472] -
secureClientPortAddress is 0.0.0.0:2281
2020-05-04 16:05:53,203 [myid:] - INFO  [main:X509Util@77] - Setting -D
jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
TLS renegotiation
2020-05-04 16:05:53,204 [myid:] - INFO  [main:QuorumPeerConfig@479] -
observerMasterPort is not set
2020-05-04 16:05:53,204 [myid:] - INFO  [main:QuorumPeerConfig@496] -
metricsProvider.className is
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
2020-05-04 16:05:53,264 [myid:2] - INFO  [main:DatadirCleanupManager@78] -
autopurge.snapRetainCount set to 10
2020-05-04 16:05:53,265 [myid:2] - INFO  [main:DatadirCleanupManager@79] -
autopurge.purgeInterval set to 24
2020-05-04 16:05:53,266 [myid:2] - INFO 
[PurgeTask:DatadirCleanupManager$PurgeTask@139] - Purge task started.
2020-05-04 16:05:53,271 [myid:2] - INFO  [main:ManagedUtil@44] - Log4j 1.2
jmx support found and enabled.
2020-05-04 16:05:53,274 [myid:2] - INFO  [PurgeTask:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : true
2020-05-04 16:05:53,282 [myid:2] - INFO  [main:QuorumPeerMain@151] -
Starting quorum peer
2020-05-04 16:05:53,292 [myid:2] - INFO  [PurgeTask:SnapStream@61] -
zookeeper.snapshot.compression.method = CHECKED
2020-05-04 16:05:53,309 [myid:2] - INFO  [main:ServerMetrics@62] -
ServerMetrics initialized with provider
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@5594a1b5
2020-05-04 16:05:53,321 [myid:2] - INFO 
[PurgeTask:DatadirCleanupManager$PurgeTask@145] - Purge task completed.
2020-05-04 16:05:53,425 [myid:2] - INFO  [main:NettyServerCnxnFactory@483] -
zookeeper.client.portUnification=true
2020-05-04 16:05:53,427 [myid:2] - INFO  [main:NettyServerCnxnFactory@495] -
zookeeper.netty.advancedFlowControl.enabled = false
2020-05-04 16:05:53,427 [myid:2] - INFO  [main:NettyServerCnxnFactory@105] -
handshakeThrottlingEnabled = false,
zookeeper.netty.server.outstandingHandshake.limit = -1
2020-05-04 16:05:53,485 [myid:2] - INFO  [main:ServerCnxnFactory@169] -
Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
connection factory
2020-05-04 16:05:53,487 [myid:2] - WARN  [main:ServerCnxnFactory@309] -
maxCnxns is not configured, using default value 0.
2020-05-04 16:05:53,487 [myid:2] - INFO  [main:NettyServerCnxnFactory@483] -
zookeeper.client.portUnification=true
2020-05-04 16:05:53,488 [myid:2] - INFO  [main:NettyServerCnxnFactory@495] -
zookeeper.netty.advancedFlowControl.enabled = false
2020-05-04 16:05:53,488 [myid:2] - INFO  [main:NettyServerCnxnFactory@105] -
handshakeThrottlingEnabled = false,
zookeeper.netty.server.outstandingHandshake.limit = -1
2020-05-04 16:05:53,489 [myid:2] - INFO  [main:ServerCnxnFactory@169] -
Using org.apache.zookeeper.server.NettyServerCnxnFactory as server
connection factory
2020-05-04 16:05:53,489 [myid:2] - WARN  [main:ServerCnxnFactory@309] -
maxCnxns is not configured, using default value 0.
2020-05-04 16:05:53,495 [myid:2] - INFO  [main:QuorumPeer@752] -
zookeeper.quorumCnxnTimeoutMs=-1
2020-05-04 16:05:53,498 [myid:2] - INFO  [main:FileTxnSnapLog@124] -
zookeeper.snapshot.trust.empty : true
2020-05-04 16:05:53,498 [myid:2] - INFO  [main:QuorumPeer@1680] - Local
sessions disabled
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1691] - Local
session upgrading disabled
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1658] - tickTime
set to 2000
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1702] -
minSessionTimeout set to 4000
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1713] -
maxSessionTimeout set to 40000
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1738] - initLimit
set to 10
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1920] - syncLimit
set to 5
2020-05-04 16:05:53,499 [myid:2] - INFO  [main:QuorumPeer@1935] -
connectToLearnerMasterLimit set to 0
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] - 
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] -  
______                  _                                          
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] -  |___ 
/                 | |                                         
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] -     / /   
___     ___   | | __   ___    ___   _ __     ___   _ __   
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] -    / /   
/ _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] -   / /__ 
| (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |    
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] - 
/_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
2020-05-04 16:05:53,513 [myid:2] - INFO  [main:ZookeeperBanner@42] -                                              
| |                     
2020-05-04 16:05:53,514 [myid:2] - INFO  [main:ZookeeperBanner@42] -                                              
|_|                     
2020-05-04 16:05:53,514 [myid:2] - INFO  [main:ZookeeperBanner@42] - 
2020-05-04 16:05:53,515 [myid:2] - INFO  [main:Environment@98] - Server
environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
built on 04/21/2020 15:01 GMT
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:host.name=zoo2
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.version=1.8.0_252
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.vendor=Oracle Corporation
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.io.tmpdir=/tmp
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:java.compiler=<NA>
2020-05-04 16:05:53,516 [myid:2] - INFO  [main:Environment@98] - Server
environment:os.name=Linux
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:os.arch=amd64
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:os.version=3.10.0-327.28.3.el7.x86_64
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:user.name=root
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:user.home=/root
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:user.dir=/apache-zookeeper-3.6.1-bin
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:os.memory.free=47MB
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:os.memory.max=889MB
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:Environment@98] - Server
environment:os.memory.total=57MB
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:ZooKeeperServer@128] -
zookeeper.enableEagerACLCheck = false
2020-05-04 16:05:53,517 [myid:2] - INFO  [main:ZooKeeperServer@136] -
zookeeper.digest.enabled = true
2020-05-04 16:05:53,518 [myid:2] - INFO  [main:ZooKeeperServer@140] -
zookeeper.closeSessionTxn.enabled = true
2020-05-04 16:05:53,518 [myid:2] - INFO  [main:ZooKeeperServer@1434] -
zookeeper.flushDelay=0
2020-05-04 16:05:53,518 [myid:2] - INFO  [main:ZooKeeperServer@1443] -
zookeeper.maxWriteQueuePollTime=0
2020-05-04 16:05:53,518 [myid:2] - INFO  [main:ZooKeeperServer@1452] -
zookeeper.maxBatchSize=1000
2020-05-04 16:05:53,518 [myid:2] - INFO  [main:ZooKeeperServer@241] -
zookeeper.intBufferStartingSizeBytes = 1024
2020-05-04 16:05:53,523 [myid:2] - INFO  [main:WatchManagerFactory@42] -
Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2020-05-04 16:05:53,523 [myid:2] - INFO  [main:WatchManagerFactory@42] -
Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2020-05-04 16:05:53,524 [myid:2] - INFO  [main:ZKDatabase@132] -
zookeeper.snapshotSizeFactor = 0.33
2020-05-04 16:05:53,524 [myid:2] - INFO  [main:ZKDatabase@152] -
zookeeper.commitLogCount=500
2020-05-04 16:05:53,559 [myid:2] - INFO  [main:QuorumPeer@1999] - Using TLS
encrypted quorum communication
2020-05-04 16:05:53,559 [myid:2] - INFO  [main:QuorumPeer@2007] - Port
unification enabled
2020-05-04 16:05:53,559 [myid:2] - INFO  [main:QuorumPeer@174] -
multiAddress.enabled set to false
2020-05-04 16:05:53,559 [myid:2] - INFO  [main:QuorumPeer@199] -
multiAddress.reachabilityCheckEnabled set to true
2020-05-04 16:05:53,560 [myid:2] - INFO  [main:QuorumPeer@186] -
multiAddress.reachabilityCheckTimeoutMs set to 1000
2020-05-04 16:05:53,560 [myid:2] - INFO  [main:QuorumPeer@2461] - QuorumPeer
communication is not secured! (SASL auth disabled)
2020-05-04 16:05:53,560 [myid:2] - INFO  [main:QuorumPeer@2486] -
quorum.cnxn.threads.size set to 20
2020-05-04 16:05:53,562 [myid:2] - INFO  [main:FileSnap@85] - Reading
snapshot /data/version-2/snapshot.75000000a2
2020-05-04 16:05:53,582 [myid:2] - INFO  [main:DataTree@1737] - The digest
value is empty in snapshot
2020-05-04 16:05:53,604 [myid:2] - INFO  [main:FileTxnSnapLog@363] - 10 txns
loaded in 6 ms
2020-05-04 16:05:53,604 [myid:2] - INFO  [main:ZKDatabase@289] - Snapshot
loaded in 45 ms, highest zxid is 0x2df700000002, digest is 352305768550
2020-05-04 16:05:53,605 [myid:2] - INFO  [main:NettyServerCnxnFactory@670] -
binding to port 0.0.0.0/0.0.0.0:2181
2020-05-04 16:05:53,688 [myid:2] - ERROR [main:QuorumPeerMain@113] -
Unexpected exception, exiting abnormally
java.net.BindException: Address already in use
	at sun.nio.ch.Net.bind0(Native Method)
	at sun.nio.ch.Net.bind(Net.java:433)
	at sun.nio.ch.Net.bind(Net.java:425)
	at
sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:220)
	at
io.netty.channel.socket.nio.NioServerSocketChannel.doBind(NioServerSocketChannel.java:134)
	at
io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:550)
	at
io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1334)
	at
io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506)
	at
io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:491)
	at
io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:973)
	at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:248)
	at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:356)
	at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500)
	at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
2020-05-04 16:05:53,692 [myid:2] - INFO  [main:ZKAuditProvider@40] -
ZooKeeper audit is enabled.
2020-05-04 16:05:53,696 [myid:2] - ERROR [main:ServiceUtils@42] - Exiting
JVM with code 1


*# nc -vz 0.0.0.0 2181*
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connected to 0.0.0.0:2181.
Ncat: 0 bytes sent, 0 bytes received in 0.01 seconds.

*# nc -vz 0.0.0.0 2281*
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connected to 0.0.0.0:2281.
Ncat: 0 bytes sent, 0 bytes received in 0.01 seconds.



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by "blb.dev" <bl...@gmail.com>.
Hi Andor, I have included the only logs I can find. There was nothing
generated in /logs/zookeeper.out and the included logs are the only ones
generated when running bin/zkCLi.sh -server command. Is there something else
I can do to find more logging? 



--
Sent from: http://zookeeper-user.578899.n2.nabble.com/

Re: ZK not starting during upgrade to use 3.6.1 with SSL communication

Posted by Andor Molnar <an...@apache.org>.
Please include server logs.

Andor



> On 2020. May 2., at 1:36, blb.dev <bl...@gmail.com> wrote:
> 
> Hi, during testing upgrade to 3.6.1 version and using secure quorum ssl
> communication my zookeeper is not starting up. 
> 
> *config file:*
> dataDir=/data
> dataLogDir=/datalog
> tickTime=2000
> initLimit=10
> syncLimit=5
> maxClientCnxns=0
> autopurge.snapRetainCount=10
> autopurge.purgeInterval=24
> admin.enableServer=false
> snapshot.trust.empty=true
> reconfigEnabled=true
> audit.enable=true
> clientPort=2181
> secureClientPort=2281
> sslQuorum=true
> portUnification=true
> serverCnxnFactory=org.apache.zookeeper.server.NettyServerCnxnFactory
> client.portUnification=true
> clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
> ssl.client.enable=true
> clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
> ssl.quorum.keyStore.location=/apache-zookeeper-3.6.1-bin/java/node1.ks
> ssl.quorum.keyStore.password=<pw>
> ssl.quorum.trustStore.location=/apache-zookeeper-3.6.1-bin/java/truststore.ks
> ssl.quorum.trustStore.password=<pw>
> 4lw.commands.whitelist=*
> quorumListenOnAllIPs=true
> server.2=<fqdn of zoo2>:2888:3888:participant
> server.3=<fqdn of zoo2>:2888:3888:participant
> server.1=<fqdn of zoo1>:2888:3888:participant
> 
> *# bin/zkServer.sh status*
> /usr/bin/java
> ZooKeeper JMX enabled by default
> Using config: /conf/zoo.cfg
> Client port found: 2181. Client address: localhost.
> Error contacting service. It is probably not running.
> 
> *# cat /logs/zookeeper_audit.log  *
> 2020-05-01 22:06:12,213 INFO audit.Log4jAuditLogger: user=zookeeper
> operation=serverStart	result=success
> 2020-05-01 23:08:30,859 INFO audit.Log4jAuditLogger: user=zookeeper
> operation=serverStart	result=success
> 
> *# bin/zkCli.sh -server 127.0.0.1:2181*
> /usr/bin/java
> Connecting to 127.0.0.1:2181
> 2020-05-01 23:19:20,035 [myid:] - INFO  [main:Environment@98] - Client
> environment:zookeeper.version=3.6.1--104dcb3e3fb464b30c5186d229e00af9f332524b,
> built on 04/21/2020 15:01 GMT
> 2020-05-01 23:19:20,039 [myid:] - INFO  [main:Environment@98] - Client
> environment:host.name=zoo1
> 2020-05-01 23:19:20,039 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.version=1.8.0_252
> 2020-05-01 23:19:20,042 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.vendor=Oracle Corporation
> 2020-05-01 23:19:20,042 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.home=/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.252.b09-2.el7_8.x86_64/jre
> 2020-05-01 23:19:20,042 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.class.path=/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.io.tmpdir=/tmp
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:java.compiler=<NA>
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.name=Linux
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.arch=amd64
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.version=3.10.0-327.28.3.el7.x86_64
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.name=root
> 2020-05-01 23:19:20,043 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.home=/root
> 2020-05-01 23:19:20,044 [myid:] - INFO  [main:Environment@98] - Client
> environment:user.dir=/apache-zookeeper-3.6.1-bin
> 2020-05-01 23:19:20,044 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.free=51MB
> 2020-05-01 23:19:20,046 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.max=228MB
> 2020-05-01 23:19:20,046 [myid:] - INFO  [main:Environment@98] - Client
> environment:os.memory.total=57MB
> 2020-05-01 23:19:20,052 [myid:] - INFO  [main:ZooKeeper@1005] - Initiating
> client connection, connectString=127.0.0.1:2181 sessionTimeout=30000
> watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@5e265ba4
> 2020-05-01 23:19:20,059 [myid:] - INFO  [main:X509Util@77] - Setting -D
> jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated
> TLS renegotiation
> 2020-05-01 23:19:20,071 [myid:] - INFO  [main:ClientCnxnSocket@239] -
> jute.maxbuffer value is 1048575 Bytes
> 2020-05-01 23:19:20,083 [myid:] - INFO  [main:ClientCnxn@1703] -
> zookeeper.request.timeout value is 0. feature enabled=false
> 2020-05-01 23:19:20,091 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2181.
> 2020-05-01 23:19:20,091 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> Welcome to ZooKeeper!
> JLine support is enabled
> 2020-05-01 23:19:20,235 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:37360,
> server: localhost/127.0.0.1:2181
> 2020-05-01 23:19:20,259 [myid:127.0.0.1:2181] - WARN 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
> 	at
> org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
> 	at
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
> [zk: 127.0.0.1:2181(CONNECTING) 0] 2020-05-01 23:19:21,591
> [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2181.
> 2020-05-01 23:19:21,591 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> 2020-05-01 23:19:21,592 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:37362,
> server: localhost/127.0.0.1:2181
> 2020-05-01 23:19:21,598 [myid:127.0.0.1:2181] - WARN 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
> 	at
> org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
> 	at
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
> 2020-05-01 23:19:23,303 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1154] - Opening
> socket connection to server localhost/127.0.0.1:2181.
> 2020-05-01 23:19:23,304 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1156] - SASL config
> status: Will not attempt to authenticate using SASL (unknown error)
> 2020-05-01 23:19:23,304 [myid:127.0.0.1:2181] - INFO 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@986] - Socket
> connection established, initiating session, client: /127.0.0.1:37364,
> server: localhost/127.0.0.1:2181
> 2020-05-01 23:19:23,313 [myid:127.0.0.1:2181] - WARN 
> [main-SendThread(127.0.0.1:2181):ClientCnxn$SendThread@1272] - Session 0x0
> for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting
> reconnect except it is a SessionExpiredException.
> EndOfStreamException: Unable to read additional data from server sessionid
> 0x0, likely server has closed socket
> 	at
> org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:75)
> 	at
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:348)
> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1262)
> 
> 
> (it continues on like this repeating the same exception)
> 
> Don't see /logs/zookeeper.out
> 
> *# nc -vz zoo2 2181*
> Ncat: Version 7.50 ( https://nmap.org/ncat )
> Ncat: Connected to <fqdn zoo2>:2181.
> Ncat: 0 bytes sent, 0 bytes received in 0.01 seconds.
> *# nc -vz zoo3 2181*
> Ncat: Version 7.50 ( https://nmap.org/ncat )
> Ncat: Connected to <fqdn zoo3>:2181.
> Ncat: 0 bytes sent, 0 bytes received in 0.02 seconds.
> 
> *# nc -vz zoo2 2182*
> Ncat: Version 7.50 ( https://nmap.org/ncat )
> Ncat: Connection refused.
> *# nc -vz zoo3 2182*
> Ncat: Version 7.50 ( https://nmap.org/ncat )
> Ncat: Connection refused.
> 
> *# ps -ef | grep zookeeper*
> root        13     1  0 23:08 ?        00:00:00 su -m zookeeper zkServer.sh
> start-foreground
> zookeep+    14    13  0 23:08 ?        00:00:03 java
> -Dzookeeper.log.dir=/logs -Dzookeeper.log.file=zookeeper--server-zoo1.log
> -Dzookeeper.root.logger=DEBUG -XX:+HeapDumpOnOutOfMemoryError
> -XX:OnOutOfMemoryError=kill -9 %p -cp
> /apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.6.1-bin/bin/../build/classes:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-prometheus-metrics-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-jute-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/snappy-java-1.1.7.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-log4j12-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/slf4j-api-1.7.25.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_servlet-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_hotspot-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient_common-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/simpleclient-0.6.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-unix-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-native-epoll-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-transport-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-resolver-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-handler-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-common-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-codec-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/netty-buffer-4.1.48.Final.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/metrics-core-3.2.5.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/log4j-1.2.17.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/json-simple-1.1.1.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jline-2.11.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-util-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-servlet-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-server-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-security-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-io-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jetty-http-9.4.24.v20191120.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-databind-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-core-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/jackson-annotations-2.10.3.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-lang-2.6.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/commons-cli-1.2.jar:/apache-zookeeper-3.6.1-bin/bin/../lib/audience-annotations-0.5.0.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-3.6.1.jar:/apache-zookeeper-3.6.1-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
> -Xmx1000m -Xmx4g -Xms1g -Dcom.sun.management.jmxremote
> -Dcom.sun.management.jmxremote.local.only=false
> org.apache.zookeeper.server.quorum.QuorumPeerMain /conf/zoo.cfg
> 
> I think the issue is around the secureClientPort not taking the connection? 
> What else needs to be configured to work or would it be an issue between my
> machines?  At a loss for how to proceed. Any debug or configuration guidance
> is appreciated. 
> 
> 
> 
> 
> --
> Sent from: http://zookeeper-user.578899.n2.nabble.com/