Is this Curator 2.x or 3.x - the connection handling in the two versions is different.
> Can anyone explain why does my CuratorFramework instance recreate a session > and establish connection again? "When I shutdown my application where I delete some ZNodes” - that’s why, right? You’re trying to do work. Maybe I don’t understand? -Jordan > On Dec 6, 2016, at 6:31 AM, Imesha Sudasingha <[email protected]> wrote: > > Nope. I tried it without ACL and the problem still exists. Here are the logs > of zookeeper with debug enabled, > > INFO MBeanRegistry [ConnnectionExpirer] Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=192.168.1.230,name5=0x20002d381ee0000] > INFO ZooKeeperServer [SessionTracker] Expiring session 0x20002d381ee0000, > timeout of 60000ms exceeded > INFO ZooKeeperServer [SessionTracker] Submitting global closeSession request > for session 0x20002d381ee0000 > INFO NIOServerCnxn [ConnnectionExpirer] Closed socket connection for client > /192.168.1.230:39652 <http://192.168.1.230:39652/> which had sessionid > 0x20002d381ee0000 > INFO PrepRequestProcessor [ProcessThread(sid:2 cport:-1):] Processed session > termination for sessionid: 0x20002d381ee0000 > DEBUG CommitProcessor [ProcessThread(sid:2 cport:-1):] Processing request:: > sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 zxid:0x100000014 > txntype:-11 reqpath:n/a > DEBUG Leader [ProcessThread(sid:2 cport:-1):] Proposing:: > sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 zxid:0x100000014 > txntype:-11 reqpath:n/a > DEBUG CommitProcessor [LearnerHandler-/127.0.0.1:49988 > <http://127.0.0.1:49988/>] Committing request:: sessionid:0x20002d381ee0000 > type:closeSession cxid:0x0 zxid:0x100000014 txntype:-11 reqpath:n/a > DEBUG CommitProcessor > [QuorumPeer[myid=0](plain=/0:0:0:0:0:0:0:0:30155)(secure=disabled)] > Committing request:: sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 > zxid:0x100000014 txntype:-11 reqpath:n/a > DEBUG CommitProcessor > [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:30156)(secure=disabled)] > Committing request:: sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 > zxid:0x100000014 txntype:-11 reqpath:n/a > DEBUG Leader [LearnerHandler-/127.0.0.1:49928 <http://127.0.0.1:49928/>] > outstanding is 0 > DEBUG FinalRequestProcessor [CommitProcWorkThread-1] Processing request:: > sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 zxid:0x100000014 > txntype:-11 reqpath:n/a > DEBUG FinalRequestProcessor [CommitProcWorkThread-1] Processing request:: > sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 zxid:0x100000014 > txntype:-11 reqpath:n/a > DEBUG FinalRequestProcessor [CommitProcWorkThread-1] Processing request:: > sessionid:0x20002d381ee0000 type:closeSession cxid:0x0 zxid:0x100000014 > txntype:-11 reqpath:n/a > DEBUG DataTree [CommitProcWorkThread-1] Deleting ephemeral node > /x/default/failover/strategies/groupFailover/group1/active/kube_master for > session 0x20002d381ee0000 > DEBUG DataTree [CommitProcWorkThread-1] Deleting ephemeral node > /x/default/failover/strategies/groupFailover/group1/active/kube_master for > session 0x20002d381ee0000 > DEBUG DataTree [CommitProcWorkThread-1] Deleting ephemeral node > /x/default/failover/strategies/groupFailover/group1/active/kube_master for > session 0x20002d381ee0000 > DEBUG SessionTrackerImpl [CommitProcWorkThread-1] Removing session > 0x20002d381ee0000 > INFO NIOServerCnxnFactory > [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:30156 > <http://0.0.0.0/0.0.0.0:30156>] Accepted socket connection from > /192.168.1.230:39800 <http://192.168.1.230:39800/> > DEBUG ZooKeeperServer [NIOWorkerThread-1] Session establishment request from > client /192.168.1.230:39800 <http://192.168.1.230:39800/> client's lastZxid > is 0x100000013 > INFO ZooKeeperServer [NIOWorkerThread-1] Client attempting to renew session > 0x20002d381ee0000 at /192.168.1.230:39800 <http://192.168.1.230:39800/> > INFO Learner [NIOWorkerThread-1] Revalidating client: 0x20002d381ee0000 > INFO ZooKeeperServer > [QuorumPeer[myid=1](plain=/0:0:0:0:0:0:0:0:30156)(secure=disabled)] Invalid > session 0x20002d381ee0000 for client /192.168.1.230:39800 > <http://192.168.1.230:39800/>, probably expired > INFO NIOServerCnxn [NIOWorkerThread-2] Closed socket connection for client > /192.168.1.230:39800 <http://192.168.1.230:39800/> which had sessionid > 0x20002d381ee0000 > > As per the logs, first the zookeeper cluster recognize that my client's > session has expired and remove it. Then when I reconnect the client to the > network, client's attempt to renew the session fails and nothing happens > thereafter. > > > On 6 December 2016 at 03:25, Cameron McKenzie <[email protected] > <mailto:[email protected]>> wrote: > hey Imesha, > Does this only happen when you have the ACL set? > cheers > > On Tue, Dec 6, 2016 at 12:38 AM, Imesha Sudasingha <[email protected] > <mailto:[email protected]>> wrote: > Sorry, the question is, > "Can anyone explain why doesn't my CuratorFramework instance recreate a > session and establish connection again?" > > On 5 December 2016 at 18:58, Imesha Sudasingha <[email protected] > <mailto:[email protected]>> wrote: > Hi all, > > I'm using CuratorFramework to connect to ZooKeeper and I also use > authorization with ACL, CREATOR_ALL_ACL. > > In order to test the functionality I deliberately disconnect my client > machine from the network. Then I see the connection state being changed to > SUSPENDED. Then after some time I see connection state change to LOST. (I'm > using connection timeout of 15 seconds and session timeout of 60 seconds). > > Then, I reconnect the client machine to the network. Then I see the following > logs in my zookeeper logs which shows that the client is trying to > re-establish the previous connection. > > INFO MBeanRegistry [ConnnectionExpirer] Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=Connections,name4=192.168.1.230,name5=0x20001dbe1940001] > INFO NIOServerCnxn [ConnnectionExpirer] Closed socket connection for client > /192.168.1.230:56178 <http://192.168.1.230:56178/> which had sessionid > 0x20001dbe1940001 > INFO ZooKeeperServer [SessionTracker] Expiring session 0x20001dbe1940001, > timeout of 60000ms exceeded > INFO ZooKeeperServer [SessionTracker] Submitting global closeSession request > for session 0x20001dbe1940001 > INFO PrepRequestProcessor [ProcessThread(sid:2 cport:-1):] Processed session > termination for sessionid: 0x20001dbe1940001 > INFO NIOServerCnxnFactory > [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:30155 > <http://0.0.0.0/0.0.0.0:30155>] Accepted socket connection from > /192.168.1.230:57834 <http://192.168.1.230:57834/> > INFO ZooKeeperServer [NIOWorkerThread-1] Client attempting to renew session > 0x20001dbe1940001 at /192.168.1.230:57834 <http://192.168.1.230:57834/> > INFO Learner [NIOWorkerThread-1] Revalidating client: 0x20001dbe1940001 > INFO ZooKeeperServer > [QuorumPeer[myid=0](plain=/0:0:0:0:0:0:0:0:30155)(secure=disabled)] Invalid > session 0x20001dbe1940001 for client /192.168.1.230:57834 > <http://192.168.1.230:57834/>, probably expired > INFO NIOServerCnxn [NIOWorkerThread-2] Closed socket connection for client > /192.168.1.230:57834 <http://192.168.1.230:57834/> which had sessionid > 0x20001dbe1940001 > > As expected, resuming the session fails. But, there after nothing happens in > the client's side. No connection state changes, no retry attempts. When I > shutdown my application where I delete some ZNodes, I only see errors saying > "Keeper Error Code = ConnectionLoss" after sometime (which is due to my retry > policy, RetryNTimes(200,1000)). > > Can anyone explain why does my CuratorFramework instance recreate a session > and establish connection again? > > Thanks in advance! > > - Imesha Sudasingha > > -- > Imesha Sudasingha > Undergraduate of Department of Computer Science and Engineering, > University of Moratuwa. > > > > > > -- > Imesha Sudasingha
