Hello all!
I'm fairly new to ZooKeeper, been testing it now for a few days and I have one
question (hopefuly simple).
I've implemented exclusive lock recipe and it seems to be working. So to test
it, I made a counter application.
Using simple mechanism:
- get_xlock(myLock)
- get_node_value(counter)
- increment counter by 1
- set_node_value(counter)
- free_xlock
Program is linked with zookeeper_mt library, zookeeper version:
zookeeper.version=3.4.6-1569965, built on 02/20/2014 09:09 GMT built on Debian
7.7.
I run this application two times, each incrementing counter 1000 times. So, if
everything is OK (no timeouts etc), the final value should be 2000. Instead, it
comes out like something in 300-400. But final version is 2000.
I may not understand ZooKeeper underhood, but ...
I see that version of the "counter" node is increasing correctly. But the value
is not. How come? Do I need to call any function so that it will wait for the
value to get written to the node?!
This is the node after both counter applications finished:
---
[zk: localhost:2181(CONNECTED) 0] get /test/MyLock/counter
386
cZxid = 0xa
ctime = Fri Oct 24 14:53:46 CEST 2014
mZxid = 0x177d
mtime = Fri Oct 24 14:54:14 CEST 2014
pZxid = 0xa
cversion = 0
dataVersion = 2000
aclVersion = 0
ephemeralOwner = 0x0
dataLength = 3
numChildren = 0
---
Any hints on what's going on?
Thank you and kind regards,
Dejan Markic
ADDITIONAL INFORMATION (TL;DR)
Here's a little snippet from my simple logging of what's going on in two
parallel running counter applications:
#1: App#1 is running alone, incrementing the counter to 246, version 246
#1.1: App#1 is trying to obtain lock
#1.2: App#2 successfuly obtained the lock
#2.1: App#2 Reads the value counter=246, version=246. Increments the value and
writes it. It's expected to be: counter=247 version=247
#2.2: App#1 Obtains the lock
#3.1: App#1 Reads the counter node value and ... counter=246, version=247 !??!
... the rest is history ...
Output snippets:
----
...
[1414155244.397642]: [244]: bzk_xlock
[1414155244.400405]: [244]: Lock obtained
[1414155244.400801]: [244]: Counter node value: 244 version: 244
[1414155244.400807]: [244]: Counter node value increased: 245
[1414155244.401794]: [244]: Counter value set successfuly: 245
[1414155244.403844]: [244]: bzk_xunlock
[1414155244.403863]: [245]: bzk_xlock
[1414155244.411246]: [245]: Lock obtained
[1414155244.411938]: [245]: Counter node value: 245 version: 245
[1414155244.411944]: [245]: Counter node value increased: 246
[1414155244.414031]: [245]: Counter value set successfuly: 246
[1414155244.415146]: [245]: bzk_xunlock
[1414155244.415150]: [246]: bzk_xlock
<!-- #1.1 This is where App#2 joined in and obtained the lock.
Counter=246 Version=246
[1414155244.432014]: [246]: Lock obtained
<!-- #2.2 Obtains the lock
[1414155244.432397]: [246]: Counter node value: 246 version: 247 <!-- #3.1
?!# Node value is 246, version is 247 .... WHY?!
[1414155244.432403]: [246]: Counter node value increased: 247
[1414155244.433707]: [246]: Counter value set successfuly: 247
[1414155244.434569]: [246]: bzk_xunlock
<!--#3.2 Writes and unlocks. Counter=247 Version=248 ?!
...
App#2:
----
[1414155244.410774]: [0]: bzk_xlock
[1414155244.416875]: [0]: Lock obtained
[1414155244.417620]: [0]: Counter node value: 246rsion: 246 <!--
#1.2 It receives the correct version and value
[1414155244.417650]: [0]: Counter node value increased: 247
[1414155244.419856]: [0]: Counter value set successfuly: 247
[1414155244.420961]: [0]: bzk_xunlock
<!-- #2.1 Writes and unlocks the lock Counter=247 Version=247
[1414155244.420966]: [1]: bzk_xlock
[1414155244.435151]: [1]: Lock obtained
<!-- #3.3 Obtains the lock and reads value
[1414155244.435624]: [1]: Counter node value: 247 version: 248 <!-- #3.4 !?
...
