Zookeeper statup issue

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Zookeeper statup issue

Daniel Chan
We've a standalone ZK setup. Upon restart, it failed to serve requests.

Here are the logs:
------------------
2017-03-05 17:33:58,888 [myid:] - INFO  [main:QuorumPeerConfig@103] - Reading configuration from: /zookeeper/zookeeper-3.4.6/conf/zoo.1.cfg
2017-03-05 17:33:58,898 [myid:] - WARN  [main:QuorumPeerConfig@293] - No server failure will be tolerated. You need at least 3 servers.
2017-03-05 17:33:58,898 [myid:] - INFO  [main:QuorumPeerConfig@340] - Defaulting to majority quorums
2017-03-05 17:33:58,909 [myid:1] - INFO  [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 10
2017-03-05 17:33:58,910 [myid:1] - INFO  [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 5
2017-03-05 17:33:58,911 [myid:1] - INFO  [PurgeTask:DatadirCleanupManager$PurgeTask@138] - Purge task started.
2017-03-05 17:33:58,946 [myid:1] - INFO  [main:QuorumPeerMain@127] - Starting quorum peer
2017-03-05 17:33:58,966 [myid:1] - INFO  [PurgeTask:DatadirCleanupManager$PurgeTask@144] - Purge task completed.
2017-03-05 17:33:58,991 [myid:1] - INFO  [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181
2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@959] - tickTime set to 2000
2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@979] - minSessionTimeout set to -1
2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@990] - maxSessionTimeout set to -1
2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@1005] - initLimit set to 20
2017-03-05 17:34:01,328 [myid:1] - INFO  [main:QuorumPeer@473] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation
2017-03-05 17:34:01,332 [myid:1] - INFO  [main:QuorumPeer@488] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation
2017-03-05 17:34:01,335 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /10.245.66.147:48198
2017-03-05 17:34:01,339 [myid:1] - INFO  [Thread-4:QuorumCnxManager$Listener@504] - My election bind port: server001-internal/10.245.66.137:3888
2017-03-05 17:34:01,346 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
2017-03-05 17:34:01,346 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /10.245.66.147:48198 (no session established for client)
2017-03-05 17:34:01,346 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /10.245.66.147:48199
2017-03-05 17:34:01,347 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
2017-03-05 17:34:01,347 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /10.245.66.147:48199 (no session established for client)
2017-03-05 17:34:01,347 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /10.245.66.147:48200
2017-03-05 17:34:01,347 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
2017-03-05 17:34:01,348 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /10.245.66.147:48200 (no session established for client)
2017-03-05 17:34:01,348 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /10.245.66.147:48201
2017-03-05 17:34:01,348 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /10.245.66.137:46628
2017-03-05 17:34:01,348 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
------------------

Is it a race issue during startup?
2017-03-05 17:34:01,346 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running

Thanks,
Daniel
Reply | Threaded
Open this post in threaded view
|

Re: Zookeeper statup issue

hanm
Did your ZK server stay in this "not running" state forever - or eventually
it's up and serving requests? If it's the later, then this is not a bug,
because during start up ZK server has to initialize various sub systems
after the server instance is initialized; so if there are client requests
coming in after the server instance initialized but before all subsystems
are initialized, you will see this what's logged here which is expected. If
it's the former, please state the ZK version you use and if possible,
detailed steps on how to reproduce.

On Wed, Mar 8, 2017 at 1:40 PM, Daniel Chan <[hidden email]>
wrote:

> We've a standalone ZK setup. Upon restart, it failed to serve requests.
>
> Here are the logs:
> ------------------
> 2017-03-05 17:33:58,888 [myid:] - INFO  [main:QuorumPeerConfig@103] -
> Reading configuration from: /zookeeper/zookeeper-3.4.6/conf/zoo.1.cfg
> 2017-03-05 17:33:58,898 [myid:] - WARN  [main:QuorumPeerConfig@293] - No
> server failure will be tolerated. You need at least 3 servers.
> 2017-03-05 17:33:58,898 [myid:] - INFO  [main:QuorumPeerConfig@340] -
> Defaulting to majority quorums
> 2017-03-05 17:33:58,909 [myid:1] - INFO  [main:DatadirCleanupManager@78]
> - autopurge.snapRetainCount set to 10
> 2017-03-05 17:33:58,910 [myid:1] - INFO  [main:DatadirCleanupManager@79]
> - autopurge.purgeInterval set to 5
> 2017-03-05 17:33:58,911 [myid:1] - INFO  [PurgeTask:DatadirCleanupManager$
> PurgeTask@138] - Purge task started.
> 2017-03-05 17:33:58,946 [myid:1] - INFO  [main:QuorumPeerMain@127] -
> Starting quorum peer
> 2017-03-05 17:33:58,966 [myid:1] - INFO  [PurgeTask:DatadirCleanupManager$
> PurgeTask@144] - Purge task completed.
> 2017-03-05 17:33:58,991 [myid:1] - INFO  [main:NIOServerCnxnFactory@94] -
> binding to port 0.0.0.0/0.0.0.0:2181
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@959] - tickTime
> set to 2000
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@979] -
> minSessionTimeout set to -1
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@990] -
> maxSessionTimeout set to -1
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@1005] -
> initLimit set to 20
> 2017-03-05 17:34:01,328 [myid:1] - INFO  [main:QuorumPeer@473] -
> currentEpoch not found! Creating with a reasonable default of 0. This
> should only happen when you are upgrading your installation
> 2017-03-05 17:34:01,332 [myid:1] - INFO  [main:QuorumPeer@488] -
> acceptedEpoch not found! Creating with a reasonable default of 0. This
> should only happen when you are upgrading your installation
> 2017-03-05 17:34:01,335 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /
> 10.245.66.147:48198
> 2017-03-05 17:34:01,339 [myid:1] - INFO  [Thread-4:QuorumCnxManager$
> Listener@504] - My election bind port: server001-internal/10.245.66.
> 137:3888
> 2017-03-05 17:34:01,346 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0
> due to java.io.IOException: ZooKeeperServer not running
> 2017-03-05 17:34:01,346 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /
> 10.245.66.147:48198 (no session established for client)
> 2017-03-05 17:34:01,346 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /
> 10.245.66.147:48199
> 2017-03-05 17:34:01,347 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0
> due to java.io.IOException: ZooKeeperServer not running
> 2017-03-05 17:34:01,347 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /
> 10.245.66.147:48199 (no session established for client)
> 2017-03-05 17:34:01,347 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /
> 10.245.66.147:48200
> 2017-03-05 17:34:01,347 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0
> due to java.io.IOException: ZooKeeperServer not running
> 2017-03-05 17:34:01,348 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /
> 10.245.66.147:48200 (no session established for client)
> 2017-03-05 17:34:01,348 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /
> 10.245.66.147:48201
> 2017-03-05 17:34:01,348 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxnFactory@197] - Accepted socket connection from /
> 10.245.66.137:46628
> 2017-03-05 17:34:01,348 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0
> due to java.io.IOException: ZooKeeperServer not running
> ------------------
>
> Is it a race issue during startup?
> 2017-03-05 17:34:01,346 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/
> 0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x0
> due to java.io.IOException: ZooKeeperServer not running
>
> Thanks,
> Daniel
>



--
Cheers
Michael.
Reply | Threaded
Open this post in threaded view
|

RE: Zookeeper statup issue

Daniel Chan
It stays there forever. The ZK version is 3.4.6.

We just use the bin/zkServer.sh script to start up ZK.

It seems not reproducible again.

Also logged a bug https://issues.apache.org/jira/browse/ZOOKEEPER-2714 for the issue.

-----Original Message-----
From: Michael Han [mailto:[hidden email]]
Sent: Wednesday, March 8, 2017 7:23 PM
To: UserZooKeeper
Subject: Re: Zookeeper statup issue

Did your ZK server stay in this "not running" state forever - or eventually it's up and serving requests? If it's the later, then this is not a bug, because during start up ZK server has to initialize various sub systems after the server instance is initialized; so if there are client requests coming in after the server instance initialized but before all subsystems are initialized, you will see this what's logged here which is expected. If it's the former, please state the ZK version you use and if possible, detailed steps on how to reproduce.

On Wed, Mar 8, 2017 at 1:40 PM, Daniel Chan <[hidden email]>
wrote:

> We've a standalone ZK setup. Upon restart, it failed to serve requests.
>
> Here are the logs:
> ------------------
> 2017-03-05 17:33:58,888 [myid:] - INFO  [main:QuorumPeerConfig@103] -
> Reading configuration from: /zookeeper/zookeeper-3.4.6/conf/zoo.1.cfg
> 2017-03-05 17:33:58,898 [myid:] - WARN  [main:QuorumPeerConfig@293] -
> No server failure will be tolerated. You need at least 3 servers.
> 2017-03-05 17:33:58,898 [myid:] - INFO  [main:QuorumPeerConfig@340] -
> Defaulting to majority quorums
> 2017-03-05 17:33:58,909 [myid:1] - INFO  
> [main:DatadirCleanupManager@78]
> - autopurge.snapRetainCount set to 10
> 2017-03-05 17:33:58,910 [myid:1] - INFO  
> [main:DatadirCleanupManager@79]
> - autopurge.purgeInterval set to 5
> 2017-03-05 17:33:58,911 [myid:1] - INFO  
> [PurgeTask:DatadirCleanupManager$ PurgeTask@138] - Purge task started.
> 2017-03-05 17:33:58,946 [myid:1] - INFO  [main:QuorumPeerMain@127] -
> Starting quorum peer
> 2017-03-05 17:33:58,966 [myid:1] - INFO  
> [PurgeTask:DatadirCleanupManager$ PurgeTask@144] - Purge task completed.
> 2017-03-05 17:33:58,991 [myid:1] - INFO  
> [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@959] -
> tickTime set to 2000
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@979] -
> minSessionTimeout set to -1
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@990] -
> maxSessionTimeout set to -1
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@1005] -
> initLimit set to 20
> 2017-03-05 17:34:01,328 [myid:1] - INFO  [main:QuorumPeer@473] -
> currentEpoch not found! Creating with a reasonable default of 0. This
> should only happen when you are upgrading your installation
> 2017-03-05 17:34:01,332 [myid:1] - INFO  [main:QuorumPeer@488] -
> acceptedEpoch not found! Creating with a reasonable default of 0. This
> should only happen when you are upgrading your installation
> 2017-03-05 17:34:01,335 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48198
> 2017-03-05 17:34:01,339 [myid:1] - INFO  [Thread-4:QuorumCnxManager$
> Listener@504] - My election bind port: server001-internal/10.245.66.
> 137:3888
> 2017-03-05 17:34:01,346 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> 2017-03-05 17:34:01,346 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> Closed socket connection for client /
> 10.245.66.147:48198 (no session established for client)
> 2017-03-05 17:34:01,346 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48199
> 2017-03-05 17:34:01,347 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> 2017-03-05 17:34:01,347 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> Closed socket connection for client /
> 10.245.66.147:48199 (no session established for client)
> 2017-03-05 17:34:01,347 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48200
> 2017-03-05 17:34:01,347 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> 2017-03-05 17:34:01,348 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> Closed socket connection for client /
> 10.245.66.147:48200 (no session established for client)
> 2017-03-05 17:34:01,348 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48201
> 2017-03-05 17:34:01,348 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.137:46628
> 2017-03-05 17:34:01,348 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> ------------------
>
> Is it a race issue during startup?
> 2017-03-05 17:34:01,346 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
>
> Thanks,
> Daniel
>



--
Cheers
Michael.
Reply | Threaded
Open this post in threaded view
|

回复:RE: Zookeeper statup issue

KiFile
It looks like your zkServer stays in election status.


Are you sure all your cluster node is acceptable?


And you should run bin/zkServer.sh on every cluster node machine by yourself, zk won't help you to open server automatically.




------------------ 原始邮件 ------------------
发件人: "Daniel Chan";<[hidden email]>;
发送时间: 2017年3月9日(星期四) 中午1:27
收件人: "user"<[hidden email]>;

主题: RE: Zookeeper statup issue



It stays there forever. The ZK version is 3.4.6.

We just use the bin/zkServer.sh script to start up ZK.

It seems not reproducible again.

Also logged a bug https://issues.apache.org/jira/browse/ZOOKEEPER-2714 for the issue.

-----Original Message-----
From: Michael Han [mailto:[hidden email]]
Sent: Wednesday, March 8, 2017 7:23 PM
To: UserZooKeeper
Subject: Re: Zookeeper statup issue

Did your ZK server stay in this "not running" state forever - or eventually it's up and serving requests? If it's the later, then this is not a bug, because during start up ZK server has to initialize various sub systems after the server instance is initialized; so if there are client requests coming in after the server instance initialized but before all subsystems are initialized, you will see this what's logged here which is expected. If it's the former, please state the ZK version you use and if possible, detailed steps on how to reproduce.

On Wed, Mar 8, 2017 at 1:40 PM, Daniel Chan <[hidden email]>
wrote:

> We've a standalone ZK setup. Upon restart, it failed to serve requests.
>
> Here are the logs:
> ------------------
> 2017-03-05 17:33:58,888 [myid:] - INFO  [main:QuorumPeerConfig@103] -
> Reading configuration from: /zookeeper/zookeeper-3.4.6/conf/zoo.1.cfg
> 2017-03-05 17:33:58,898 [myid:] - WARN  [main:QuorumPeerConfig@293] -
> No server failure will be tolerated. You need at least 3 servers.
> 2017-03-05 17:33:58,898 [myid:] - INFO  [main:QuorumPeerConfig@340] -
> Defaulting to majority quorums
> 2017-03-05 17:33:58,909 [myid:1] - INFO  
> [main:DatadirCleanupManager@78]
> - autopurge.snapRetainCount set to 10
> 2017-03-05 17:33:58,910 [myid:1] - INFO  
> [main:DatadirCleanupManager@79]
> - autopurge.purgeInterval set to 5
> 2017-03-05 17:33:58,911 [myid:1] - INFO  
> [PurgeTask:DatadirCleanupManager$ PurgeTask@138] - Purge task started.
> 2017-03-05 17:33:58,946 [myid:1] - INFO  [main:QuorumPeerMain@127] -
> Starting quorum peer
> 2017-03-05 17:33:58,966 [myid:1] - INFO  
> [PurgeTask:DatadirCleanupManager$ PurgeTask@144] - Purge task completed.
> 2017-03-05 17:33:58,991 [myid:1] - INFO  
> [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@959] -
> tickTime set to 2000
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@979] -
> minSessionTimeout set to -1
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@990] -
> maxSessionTimeout set to -1
> 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@1005] -
> initLimit set to 20
> 2017-03-05 17:34:01,328 [myid:1] - INFO  [main:QuorumPeer@473] -
> currentEpoch not found! Creating with a reasonable default of 0. This
> should only happen when you are upgrading your installation
> 2017-03-05 17:34:01,332 [myid:1] - INFO  [main:QuorumPeer@488] -
> acceptedEpoch not found! Creating with a reasonable default of 0. This
> should only happen when you are upgrading your installation
> 2017-03-05 17:34:01,335 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48198
> 2017-03-05 17:34:01,339 [myid:1] - INFO  [Thread-4:QuorumCnxManager$
> Listener@504] - My election bind port: server001-internal/10.245.66.
> 137:3888
> 2017-03-05 17:34:01,346 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> 2017-03-05 17:34:01,346 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> Closed socket connection for client /
> 10.245.66.147:48198 (no session established for client)
> 2017-03-05 17:34:01,346 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48199
> 2017-03-05 17:34:01,347 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> 2017-03-05 17:34:01,347 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> Closed socket connection for client /
> 10.245.66.147:48199 (no session established for client)
> 2017-03-05 17:34:01,347 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48200
> 2017-03-05 17:34:01,347 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> 2017-03-05 17:34:01,348 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> Closed socket connection for client /
> 10.245.66.147:48200 (no session established for client)
> 2017-03-05 17:34:01,348 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.147:48201
> 2017-03-05 17:34:01,348 [myid:1] - INFO  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> - Accepted socket connection from /
> 10.245.66.137:46628
> 2017-03-05 17:34:01,348 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
> ------------------
>
> Is it a race issue during startup?
> 2017-03-05 17:34:01,346 [myid:1] - WARN  
> [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> Exception causing close of session 0x0 due to java.io.IOException:
> ZooKeeperServer not running
>
> Thanks,
> Daniel
>



--
Cheers
Michael.
Reply | Threaded
Open this post in threaded view
|

Re: RE: Zookeeper statup issue

hanm
>> Are you sure all your cluster node is acceptable?

I think OP mentioned that it was a stand alone ZK setup.

>> It seems not reproducible again.

I am closing ZOOKEEPER-2714
<https://issues.apache.org/jira/browse/ZOOKEEPER-2714> since this is not
reproducible, but feel free to comment and reopen the JIRA if this can be
deterministically reproduced.

On Wed, Mar 8, 2017 at 10:21 PM, KiFile <[hidden email]> wrote:

> It looks like your zkServer stays in election status.
>
>
> Are you sure all your cluster node is acceptable?
>
>
> And you should run bin/zkServer.sh on every cluster node machine by
> yourself, zk won't help you to open server automatically.
>
>
>
>
> ------------------ 原始邮件 ------------------
> 发件人: "Daniel Chan";<[hidden email]>;
> 发送时间: 2017年3月9日(星期四) 中午1:27
> 收件人: "user"<[hidden email]>;
>
> 主题: RE: Zookeeper statup issue
>
>
>
> It stays there forever. The ZK version is 3.4.6.
>
> We just use the bin/zkServer.sh script to start up ZK.
>
> It seems not reproducible again.
>
> Also logged a bug https://issues.apache.org/jira/browse/ZOOKEEPER-2714
> for the issue.
>
> -----Original Message-----
> From: Michael Han [mailto:[hidden email]]
> Sent: Wednesday, March 8, 2017 7:23 PM
> To: UserZooKeeper
> Subject: Re: Zookeeper statup issue
>
> Did your ZK server stay in this "not running" state forever - or
> eventually it's up and serving requests? If it's the later, then this is
> not a bug, because during start up ZK server has to initialize various sub
> systems after the server instance is initialized; so if there are client
> requests coming in after the server instance initialized but before all
> subsystems are initialized, you will see this what's logged here which is
> expected. If it's the former, please state the ZK version you use and if
> possible, detailed steps on how to reproduce.
>
> On Wed, Mar 8, 2017 at 1:40 PM, Daniel Chan <[hidden email]>
> wrote:
>
> > We've a standalone ZK setup. Upon restart, it failed to serve requests.
> >
> > Here are the logs:
> > ------------------
> > 2017-03-05 17:33:58,888 [myid:] - INFO  [main:QuorumPeerConfig@103] -
> > Reading configuration from: /zookeeper/zookeeper-3.4.6/conf/zoo.1.cfg
> > 2017-03-05 17:33:58,898 [myid:] - WARN  [main:QuorumPeerConfig@293] -
> > No server failure will be tolerated. You need at least 3 servers.
> > 2017-03-05 17:33:58,898 [myid:] - INFO  [main:QuorumPeerConfig@340] -
> > Defaulting to majority quorums
> > 2017-03-05 17:33:58,909 [myid:1] - INFO
> > [main:DatadirCleanupManager@78]
> > - autopurge.snapRetainCount set to 10
> > 2017-03-05 17:33:58,910 [myid:1] - INFO
> > [main:DatadirCleanupManager@79]
> > - autopurge.purgeInterval set to 5
> > 2017-03-05 17:33:58,911 [myid:1] - INFO
> > [PurgeTask:DatadirCleanupManager$ PurgeTask@138] - Purge task started.
> > 2017-03-05 17:33:58,946 [myid:1] - INFO  [main:QuorumPeerMain@127] -
> > Starting quorum peer
> > 2017-03-05 17:33:58,966 [myid:1] - INFO
> > [PurgeTask:DatadirCleanupManager$ PurgeTask@144] - Purge task completed.
> > 2017-03-05 17:33:58,991 [myid:1] - INFO
> > [main:NIOServerCnxnFactory@94] - binding to port 0.0.0.0/0.0.0.0:2181
> > 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@959] -
> > tickTime set to 2000
> > 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@979] -
> > minSessionTimeout set to -1
> > 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@990] -
> > maxSessionTimeout set to -1
> > 2017-03-05 17:33:59,016 [myid:1] - INFO  [main:QuorumPeer@1005] -
> > initLimit set to 20
> > 2017-03-05 17:34:01,328 [myid:1] - INFO  [main:QuorumPeer@473] -
> > currentEpoch not found! Creating with a reasonable default of 0. This
> > should only happen when you are upgrading your installation
> > 2017-03-05 17:34:01,332 [myid:1] - INFO  [main:QuorumPeer@488] -
> > acceptedEpoch not found! Creating with a reasonable default of 0. This
> > should only happen when you are upgrading your installation
> > 2017-03-05 17:34:01,335 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> > - Accepted socket connection from /
> > 10.245.66.147:48198
> > 2017-03-05 17:34:01,339 [myid:1] - INFO  [Thread-4:QuorumCnxManager$
> > Listener@504] - My election bind port: server001-internal/10.245.66.
> > 137:3888
> > 2017-03-05 17:34:01,346 [myid:1] - WARN
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> > Exception causing close of session 0x0 due to java.io.IOException:
> > ZooKeeperServer not running
> > 2017-03-05 17:34:01,346 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> > Closed socket connection for client /
> > 10.245.66.147:48198 (no session established for client)
> > 2017-03-05 17:34:01,346 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> > - Accepted socket connection from /
> > 10.245.66.147:48199
> > 2017-03-05 17:34:01,347 [myid:1] - WARN
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> > Exception causing close of session 0x0 due to java.io.IOException:
> > ZooKeeperServer not running
> > 2017-03-05 17:34:01,347 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> > Closed socket connection for client /
> > 10.245.66.147:48199 (no session established for client)
> > 2017-03-05 17:34:01,347 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> > - Accepted socket connection from /
> > 10.245.66.147:48200
> > 2017-03-05 17:34:01,347 [myid:1] - WARN
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> > Exception causing close of session 0x0 due to java.io.IOException:
> > ZooKeeperServer not running
> > 2017-03-05 17:34:01,348 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@1007] -
> > Closed socket connection for client /
> > 10.245.66.147:48200 (no session established for client)
> > 2017-03-05 17:34:01,348 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> > - Accepted socket connection from /
> > 10.245.66.147:48201
> > 2017-03-05 17:34:01,348 [myid:1] - INFO
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxnFactory@197]
> > - Accepted socket connection from /
> > 10.245.66.137:46628
> > 2017-03-05 17:34:01,348 [myid:1] - WARN
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> > Exception causing close of session 0x0 due to java.io.IOException:
> > ZooKeeperServer not running
> > ------------------
> >
> > Is it a race issue during startup?
> > 2017-03-05 17:34:01,346 [myid:1] - WARN
> > [NIOServerCxn.Factory:0.0.0.0/ 0.0.0.0:2181:NIOServerCnxn@362] -
> > Exception causing close of session 0x0 due to java.io.IOException:
> > ZooKeeperServer not running
> >
> > Thanks,
> > Daniel
> >
>
>
>
> --
> Cheers
> Michael.
>



--
Cheers
Michael.