[ 
https://issues.apache.org/jira/browse/ZOOKEEPER-2439?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15496588#comment-15496588
 ] 

Edward Ribeiro edited comment on ZOOKEEPER-2439 at 9/16/16 3:37 PM:
--------------------------------------------------------------------

Hi [~kazuakibanzai],

I took some time to dig this problem and I *guess* I've found the root cause. 
*Disclaimer: I can be totally wrong on my assumptions, so would love to hear 
from some ZK committers as to deny or confirm my idea (and took the liberty of 
marking them on this message, sorry guys).* /cc [~fpj], [~breed], [~phunt]

First and foremost, *huge thanks* for the patch to simulate the bug, it helped 
a lot. Well, let's start: in a nutshell, the server side ZK is an ordered 
processing pipeline of RequestProcessors, where each processor is handled by a 
different Thread. The one that is interesting to this particular case looks 
like this (I am a newbie, so I may get something wrong):

{code}
request ---------->  PrepRequestProcessor --------> SyncRequestsProcessor  
----------> FinalRequestProcessor ------> [request applied and committed]
{code}

*KEEP THIS IN MIND:* A request is committed to ZK database as well as having 
the logs and snapshots updated if it arrives at the {{FinalRequestProcessor}} 
without any exception.

a. One request can be currently being processed at {{PrepRequestProcessor}} 
while another one is either {{SyncRequestsProcessor}} or 
{{FinalRequestsProcessor}}. In fact, I guess that we can have three requests, 
one in each step of the pipeline under high load, for example.

b. At {{PrepRequestProcessor}} ZK checks if the znode path of the request is 
well formed as well as authorization and ACL permissions (it makes sense as 
SyncRequestProcessor, among other things, saves the log file and we wouldn't 
want to record an invalid request on command log, right?). *KEEP THIS IN MIND 
TOO:* ACL checks are done at the first stage of the pipeline.


*_So, the problem you described can be summarised as such:_*

1. a setACL request that removes access to '/' (let's call it REQ1) is sent 
asynchronously, followed by a create a znode under '/a' request (let's call it 
REQ2). Both are enqueued in order and arrive in this order on the server side.

2. REQ1 passes {{PrepRequestProcessor}}.

3. While REQ1 is at {{SyncRequestsProcessor}}, REQ 2 arrives at 
{{PrepRequestProcessor}}. {{PrepRequestProcessor}} checks ZK DB and see that 
REQ2 has the ACL rights to create the node, because REQ1 was not committed to 
ZK DB yet (it's in the middle of the pipeline).

4. When REQ1 is finally committed on ZK DB, REQ1 is just behind it in the 
pipeline, so it also gets committed to the ZK DB even tough REQ1 would prevent 
REQ2 from being applied! Remember the permission was check on 
{{PrepRequestProcessor}}, the first stage of the pipeline, when REQ1 was still 
ongoing.

*_Now let's see why some scenarios that explain your unit test:_*

Case 1: The sync ACL call is, well, synchronous so, it wait for a response 
before sending the next command (createNode). Therefore, REQ1 completes the 
pipeline before REQ2 even reaches the it and the createNode is rejected as 
expected.

Case 2. If you put a sleep between async setACL and createNode then you gave 
some time to REQ1 finish the pipeline because REQ2 will be inserted into the 
client outgoing queue after the sleep time. Again, this succeeds by rejecting 
the createNode command.

Case 3. If you insert async or sync setACL commands before the createNode you 
are "stuffing" additional commands between setACL and createNode. Again giving 
a chance of setACL finishes before the createdNode reaches the first stage of 
the pipeline. Then again, it works as expected (the createNode is rejected).

Finally, another conjecture I have is that this setACL/createNode behavior 
could happen if with synchronous setACL. If we had two clients, the first one 
could issue a sync setACL and the second one a createNode, and with the right 
timing they would be enqueued as explained above.

Does it make sense?






was (Author: eribeiro):
Hi [~kazuakibanzai],

I took some time to dig this problem and I *guess* I've found the root cause. 
*Disclaimer: I can be totally wrong on my assumptions, so would love to hear 
from some ZK committers as to deny or confirm my idea (and took the liberty of 
marking them on this message, sorry guys).* /cc [~fpj], [~breed], [~phunt]

First and foremost, *huge thanks* for the patch to simulate the bug, it helped 
a lot. Well, let's start: in a nutshell, the server side ZK ordered processing 
pipeline of RequestProcessors. The one that is interesting to this particular 
case looks like this (I am a newbie, so I may get something wrong):

{code}
request ---------->  PrepRequestProcessor --------> SyncRequestsProcessor  
----------> FinalRequestProcessor ------> [request applied and committed]
{code}

*KEEP THIS IN MIND:* A request is committed to ZK database as well as having 
the logs and snapshots updated if it arrives at the {{FinalRequestProcessor}} 
without any exception.

a. One request can be currently being processed at {{PrepRequestProcessor}} 
while another one is either {{SyncRequestsProcessor}} or 
{{FinalRequestsProcessor}}. In fact, I guess that we can have three requests, 
one in each step of the pipeline under high load, for example.

b. At {{PrepRequestProcessor}} ZK checks if the znode path of the request is 
well formed as well as authorization and ACL permissions (it makes sense as 
SyncRequestProcessor, among other things, saves the log file and we wouldn't 
want to record an invalid request on command log, right?). *KEEP THIS IN MIND 
TOO:* ACL checks are done at the first stage of the pipeline.


*_So, the problem you described can be summarised as such:_*

1. a setACL request that removes access to '/' (let's call it REQ1) is sent 
asynchronously, followed by a create a znode under '/a' request (let's call it 
REQ2). Both are enqueued in order and arrive in this order on the server side.

2. REQ1 passes {{PrepRequestProcessor}}.

3. While REQ1 is at {{SyncRequestsProcessor}}, REQ 2 arrives at 
{{PrepRequestProcessor}}. {{PrepRequestProcessor}} checks ZK DB and see that 
REQ2 has the ACL rights to create the node, because REQ1 was not committed to 
ZK DB yet (it's in the middle of the pipeline).

4. When REQ1 is finally committed on ZK DB, REQ1 is just behind it in the 
pipeline, so it also gets committed to the ZK DB even tough REQ1 would prevent 
REQ2 from being applied! Remember the permission was check on 
{{PrepRequestProcessor}}, the first stage of the pipeline, when REQ1 was still 
ongoing.

*_Now let's see why some scenarios that explain your unit test:_*

Case 1: The sync ACL call is, well, synchronous so, it wait for a response 
before sending the next command (createNode). Therefore, REQ1 completes the 
pipeline before REQ2 even reaches the it and the createNode is rejected as 
expected.

Case 2. If you put a sleep between async setACL and createNode then you gave 
some time to REQ1 finish the pipeline because REQ2 will be inserted into the 
client outgoing queue after the sleep time. Again, this succeeds by rejecting 
the createNode command.

Case 3. If you insert async or sync setACL commands before the createNode you 
are "stuffing" additional commands between setACL and createNode. Again giving 
a chance of setACL finishes before the createdNode reaches the first stage of 
the pipeline. Then again, it works as expected (the createNode is rejected).

Finally, another conjecture I have is that this setACL/createNode behavior 
could happen if with synchronous setACL. If we had two clients, the first one 
could issue a sync setACL and the second one a createNode, and with the right 
timing they would be enqueued as explained above.

Does it make sense?





> The order of asynchronous setACL is not correct.
> ------------------------------------------------
>
>                 Key: ZOOKEEPER-2439
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2439
>             Project: ZooKeeper
>          Issue Type: Bug
>    Affects Versions: 3.4.8, 3.5.1
>         Environment: Linux Ubuntu
> Mac OS X
>            Reporter: Kazuaki Banzai
>              Labels: acl
>         Attachments: ZOOKEEPER-2439.patch
>
>
> Within a given client connection, the execution of commands on the ZooKeeper 
> server is always ordered, as both synchronous and asynchronous commands are 
> dispatched through queuePacket (directly or indirectly).
> In other words, Zookeeper guarantees sequential consistency: updates from a 
> client will be applied in the order that they were sent.
> However, the order of asynchronous setACL is not correct on Ubuntu.
> When asynchronous setACL is called BEFORE another API is called, asynchronous 
> setACL is applied AFTER another API.
> For example, if a client calls
> (1) asynchronous setACL to remove all permissions of node "/" and
> (2) synchronous create to create node "/a",
> synchronous create should fail, but it succeeds on Ubuntu.
> (We can see all permissions of node "/" are removed when the client calls 
> getACL to node "/" after (2), so (1) is applied AFTER (2). If we call getACL 
> between (1) and (2), the synchronous case works correctly but the 
> asynchronous case still produces the bug.)
> The attached unit test reproduces this scenario. It fails on Linux Ubuntu but 
> succeeds on Mac OS X. If used on a heavily loaded server on Mac OS, the test 
> sometimes fails as well but only rarely.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to