Home | About | Sematext search-lucene.com search-hadoop.com
 Search Hadoop and all its subprojects:

Switch to Threaded View
Zookeeper, mail # user - Ephemeral node not getting deleted


Copy link to this message
-
Ephemeral node not getting deleted
Deepa 2012-12-04, 10:53
Hi,

  I have zookeeper cluster of size 3,with the following parameters set
across all the servers:
tickTime=2000
initLimit=10
syncLimit=5

  Session timeout is set to 40sec and using zookeeper 3.4.4. My application
works something like this:
It creates ephemeral nodes if it can grab and serve a range from a list of
ranges . It basically creates 2 ephemerals if its successful in finding a
range. From the zookeeper server logs, I see that only one of the ephemeral
node is getting deleted while bringing down servers randomly and restarting
them.

Please find the log snippet below:

2012-12-03 19:22:52,360 [myid:2] - DEBUG
[FollowerRequestProcessor:2:CommitProcessor@171] - Processing request::
sessionid:0x23b6109f83e0001 type:createSession cxid:0x0
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2012-12-03 19:22:52,362 [myid:2] - DEBUG
[QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2181:CommitProcessor@161] - Committing
request:: sessionid:0x23b6109f83e0001 type:createSession cxid:0x0
zxid:0x3000000013 txntype:-10 reqpath:n/a
2012-12-03 19:22:52,362 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@88] - Processing request::
sessionid:*0x23b6109f83e0001* type:createSession cxid:0x0 zxid:0x3000000013
txntype:-10 reqpath:n/a
2012-12-03 19:22:52,363 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@160] - sessionid:*0x23b6109f83e0001
*type:createSession cxid:0x0 zxid:0x3000000013 txntype:-10 reqpath:n/a
2012-12-03 19:22:52,364 [myid:2] - INFO
[CommitProcessor:2:ZooKeeperServer@595] - Established session
*0x23b6109f83e0001 *with negotiated timeout 40000 for client
/192.168.11.94:3566

2012-12-03 19:23:01,143 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@88] - Processing request::
sessionid:*0x23b6109f83e0001 *type:create cxid:0x50bdb440 zxid:0x300000002d
txntype:1 reqpath:/CONFIGNODE/NP2147483647
2012-12-03 19:23:01,144 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@160] - sessionid:*0x23b6109f83e0001
*type:create cxid:0x50bdb440 zxid:0x300000002d txntype:1
reqpath:*/CONFIGNODE/NP2147483647*

2012-12-03 19:23:01,157 [myid:2] - DEBUG
[FollowerRequestProcessor:2:CommitProcessor@171] - Processing request::
sessionid:*0x23b6109f83e0001 *type:create cxid:0x50bdb444
zxid:0xfffffffffffffffe txntype:unknown reqpath:*/ACTIVE/NP2147483647*
2012-12-03 19:23:01,159 [myid:2] - DEBUG
[QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:2181:CommitProcessor@161] - Committing
request:: sessionid:0x23b6109f83e0001 type:create cxid:0x50bdb444
zxid:0x3000000032 txntype:1 reqpath:n/a
2012-12-03 19:23:01,159 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@88] - Processing request::
sessionid:0x23b6109f83e0001 type:create cxid:0x50bdb444 zxid:0x3000000032
txntype:1 reqpath:/ACTIVE/NP2147483647
2012-12-03 19:23:01,160 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@160] - sessionid:0x23b6109f83e0001
type:create cxid:0x50bdb444 zxid:0x3000000032 txntype:1
reqpath:*/ACTIVE/NP2147483647*
2012-12-03 19:45:16,672 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@88] - Processing request::
sessionid:0x23b6109f83e0001 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a
2012-12-03 19:45:16,672 [myid:2] - DEBUG
[CommitProcessor:2:FinalRequestProcessor@160] - sessionid:0x23b6109f83e0001
type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown
reqpath:n/a
2012-12-03 19:45:26,966 [myid:2] - WARN
[RecvWorker:1:QuorumCnxManager$RecvWorker@762] - Connection broken for id 1,
my id = 2, error =
java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:392)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:747)
2012-12-03 19:45:26,972 [myid:2] - WARN
[RecvWorker:1:QuorumCnxManager$RecvWorker@765] - Interrupting SendWorker
2012-12-03 19:45:26,973 [myid:2] - DEBUG
[RecvWorker:1:QuorumCnxManager$SendWorker@588] - Calling finish for 1
2012-12-03 19:45:26,973 [myid:2] - DEBUG
[RecvWorker:1:QuorumCnxManager$SendWorker@608] - Removing entry from
senderWorkerMap sid=1
2012-12-03 19:45:26,973 [myid:2] - WARN
[SendWorker:1:QuorumCnxManager$SendWorker@679] - Interrupted while waiting
for message on queue
java.lang.InterruptedException
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2094)
at
java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:370)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:831)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:62)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:667)
2012-12-03 19:45:26,974 [myid:2] - DEBUG
[SendWorker:1:QuorumCnxManager$SendWorker@588] - Calling finish for 1
2012-12-03 19:45:26,974 [myid:2] - WARN
[SendWorker:1:QuorumCnxManager$SendWorker@688] - Send worker leaving thread
2012-12-03 19:46:25,059 [myid:] - INFO  [main:QuorumPeerConfig@101] -
Reading configuration from: /usr/zookeeper/bin/../conf/zoo.cfg
2012-12-03 19:46:25,066 [myid:] - INFO  [main:QuorumPeerConfig@334] -
Defaulting to majority quorums
2012-12-03 19:46:25,071 [myid:2] - INFO  [main:DatadirCleanupManager@78] -
autopurge.snapRetainCount set to 3
2012-12-03 19:46:25,072 [myid:2] - INFO  [main:DatadirCleanupManager@79] -
autopurge.purgeInterval set to 0
2012-12-03 19:46:25,073 [myid:2] - INFO  [main:DatadirCleanupManager@101] -
Purge task is not scheduled.
2012-12-03 19:46:25,080 [myid:2] - DEBUG [main:AbstractDynamicMBean@124] -
preRegister called. Server=com.sun.jmx.mbeanserver.JmxMBeanServer@558385e3,
name=log4j:hiearchy=default
2012-12-03 19:46:25,081 [myid:2] - DEBUG [main:HierarchyDynamicMBean@254] -
postRegister is called.
2012-12-03 19:46:25,084 [myid:2] - DEBUG [main:AbstractDynamicMBean@124] -
preRegister called. S