Home | About | Sematext search-lucene.com search-hadoop.com
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB
 Search Hadoop and all its subprojects:

Switch to Threaded View
Zookeeper >> mail # user >> Random unexpected exception in followers every so often


Copy link to this message
-
Re: Random unexpected exception in followers every so often
Hi Steve, is there any indication what the problem is? The log code
looks like this in Follower.java

            } catch (IOException e) {
                LOG.warn("Exception when following the leader", e);

However I don't see any exception text in log you provided, which is odd.

Patrick
On Thu, Jul 25, 2013 at 10:58 AM, Stephen Tyree <[EMAIL PROTECTED]> wrote:
> Hello all,
>
> In our development Zookeeper cluster, about once a week we've started
> seeing two of the followers have an Unexpected Exception with Zookeeper
> 3.4.5. Looking at the metrics from the mntr four letter word, there is no
> particular amount of load or number of sessions that leads to this
> behavior, it just seems totally out of the blue. Here is a snippet of INFO
> level logs from that period of time (IP addresses have been scrubbed):
>
> 2013-07-25 04:19:20,066 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:NIOServerCnxnFactory@197] - Accepted socket
> connection from /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,066 - WARN  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@793] - Connection request
> from old client /xxx.xxx.xxx.xxx:xxxxx; will be dropped if server is in r-o
> mode
> 2013-07-25 04:19:20,067 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@839] - Client attempting to
> establish new session at /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,068 - INFO  [CommitProcessor:6:ZooKeeperServer@595] -
> Established session 0x63ffea596ee912b with negotiated timeout 30000 for
> client /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,068 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@863] - got auth packet
> /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,068 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@897] - auth success
> /xxx.xxx.xxx.xxx:xxxxx
> (--------lots of normal activity----------)
> 2013-07-25 04:19:20,317 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@839] - Client attempting to
> establish new session at /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,318 - INFO  [CommitProcessor:6:ZooKeeperServer@595] -
> Established session 0x63ffea596ee912c with negotiated timeout 10000 for
> client /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,318 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@863] - got auth packet
> /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,318 - INFO  [NIOServerCxn.Factory:
> 0.0.0.0/xxx.xxx.xxx.xxx:xxxxx:ZooKeeperServer@897] - auth success
> /xxx.xxx.xxx.xxx:xxxxx
> 2013-07-25 04:19:20,319 - WARN
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:Follower@89] - Exception when
> following the leader
> 2013-07-25 04:19:20,319 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:Follower@166] - shutdown called
> 2013-07-25 04:19:20,319 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:NIOServerCnxn@1001] - Closed
> socket connection for client /xxx.xxx.xxx.xxx:xxxxx which had sessionid
> 0x63ffea596ee8bab
> (-----------One of these for each active session it seems-----------------))
> 2013-07-25 04:19:20,375 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:NIOServerCnxn@1001] - Closed
> socket connection for client /xxx.xxx.xxx.xxx:xxxxx which had sessionid
> 0x83fdf0b85832d61
> 2013-07-25 04:19:20,376 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:FollowerZooKeeperServer@139] -
> Shutting down
> 2013-07-25 04:19:20,376 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@419] - shutting
> down
> 2013-07-25 04:19:20,376 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:FollowerRequestProcessor@105] -
> Shutting down
> 2013-07-25 04:19:20,376 - INFO
>  [QuorumPeer[myid=6]/0:0:0:0:0:0:0:0:2181:CommitProcessor@181] - Shutting
> down
> 2013-07-25 04:19:20,376 - INFO
>  [FollowerRequestProcessor:6:FollowerRequestProcessor@95] -
> FollowerRequestProcessor exited loop!
> 2013-07-25 04:19:20,376 - INFO  [CommitProcessor:6:CommitProcessor@150] -
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB