hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jerry He (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HBASE-13084) Add labels to VisibilityLabelsCache asynchronously causes TestShell flakey
Date Wed, 25 Feb 2015 06:44:05 GMT

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

Jerry He commented on HBASE-13084:
----------------------------------

FYI. While working on HBASE-12644, I recall seeing ZK events (data changed events) lost (not
captured) by the ZK watcher due to race condition.
See this comment, 
https://issues.apache.org/jira/browse/HBASE-12644?focusedCommentId=14242242&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14242242
It may not be the same issue.
In the test Surefire reports, there should be detailed ZK events debug logging. That will
help to make sure at least no visibility ZK events are lost due to race condition.
One idea is put the wait in Before the addLabels call to make sure all prior ZK events have
been processed and watchs are reset.

On the other hand, in waitLabelAvailable() in the patch, try to use the listLabels() from
the client to see if the labels are really in there.
 
Just threw in some ideas.

> Add labels to VisibilityLabelsCache asynchronously causes TestShell flakey
> --------------------------------------------------------------------------
>
>                 Key: HBASE-13084
>                 URL: https://issues.apache.org/jira/browse/HBASE-13084
>             Project: HBase
>          Issue Type: Bug
>          Components: test
>            Reporter: zhangduo
>            Assignee: zhangduo
>             Fix For: 2.0.0, 1.1.0
>
>         Attachments: HBASE-13084.patch, HBASE-13084_1.patch, HBASE-13084_2.patch, HBASE-13084_2.patch,
HBASE-13084_2.patch, HBASE-13084_2.patch
>
>
> As discussed in HBASE-12953, we found this error in PreCommit log
> https://builds.apache.org/job/PreCommit-HBASE-Build/12918/artifact/hbase-shell/target/surefire-reports/org.apache.hadoop.hbase.client.TestShell-output.txt
> {noformat}
>   1) Error:
> test_The_get/put_methods_should_work_for_data_written_with_Visibility(Hbase::VisibilityLabelsAdminMethodsTest):
> ArgumentError: org.apache.hadoop.hbase.DoNotRetryIOException: org.apache.hadoop.hbase.security.visibility.InvalidLabelException:
Label 'TEST_VISIBILITY' doesn't exists
> 	at org.apache.hadoop.hbase.security.visibility.VisibilityController.setAuths(VisibilityController.java:808)
> 	at org.apache.hadoop.hbase.protobuf.generated.VisibilityLabelsProtos$VisibilityLabelsService$1.setAuths(VisibilityLabelsProtos.java:6036)
> 	at org.apache.hadoop.hbase.protobuf.generated.VisibilityLabelsProtos$VisibilityLabelsService.callMethod(VisibilityLabelsProtos.java:6219)
> 	at org.apache.hadoop.hbase.regionserver.HRegion.execService(HRegion.java:6867)
> 	at org.apache.hadoop.hbase.regionserver.RSRpcServices.execServiceOnRegion(RSRpcServices.java:1707)
> 	at org.apache.hadoop.hbase.regionserver.RSRpcServices.execService(RSRpcServices.java:1689)
> 	at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:31309)
> 	at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2038)
> 	at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:107)
> 	at org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:130)
> 	at org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:107)
> 	at java.lang.Thread.run(Thread.java:744)
>     /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-shell/src/main/ruby/hbase/visibility_labels.rb:84:in
`set_auths'
>     ./src/test/ruby/hbase/visibility_labels_admin_test.rb:77:in `test_The_get/put_methods_should_work_for_data_written_with_Visibility'
>     org/jruby/RubyProc.java:270:in `call'
>     org/jruby/RubyKernel.java:2105:in `send'
>     org/jruby/RubyArray.java:1620:in `each'
>     org/jruby/RubyArray.java:1620:in `each'
>   2) Error:
> test_The_set/clear_methods_should_work_with_authorizations(Hbase::VisibilityLabelsAdminMethodsTest):
> ArgumentError: No authentication set for the given user jenkins
>     /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/hbase-shell/src/main/ruby/hbase/visibility_labels.rb:97:in
`get_auths'
>     ./src/test/ruby/hbase/visibility_labels_admin_test.rb:57:in `test_The_set/clear_methods_should_work_with_authorizations'
>     org/jruby/RubyProc.java:270:in `call'
>     org/jruby/RubyKernel.java:2105:in `send'
>     org/jruby/RubyArray.java:1620:in `each'
>     org/jruby/RubyArray.java:1620:in `each'
> {noformat}
> This is the test code
> {code:title=visibility_labels_admin_test.rb}
>       label = 'TEST_VISIBILITY'
>       user = org.apache.hadoop.hbase.security.User.getCurrent().getName();
>       visibility_admin.add_labels(label)
>       visibility_admin.set_auths(user, label)
> {code}
> It says 'label does not exists' when calling set_auths.
> Then I add some ugly logs in  DefaultVisibilityLabelServiceImpl and VisibilityLabelsCache.
> {code:title=DefaultVisibilityLabelServiceImpl.java}
>   public OperationStatus[] addLabels(List<byte[]> labels) throws IOException {
>     ...
>     if (mutateLabelsRegion(puts, finalOpStatus)) {
>       updateZk(true);
>     }
>     for (byte[] label : labels) {
>       String labelStr = Bytes.toString(label);
>       LOG.info(labelStr + "=====" + this.labelsCache.getLabelOrdinal(labelStr));
>     }
>     ...
>   }
> {code}
> {code:title=VisibilityLabelsCache.java}
>   public void refreshLabelsCache(byte[] data) throws IOException {
>     LOG.info("========refresh", new Exception());
>     ...
>   }
> {code}
> And I modified TestVisibilityLabelsWithCustomVisLabService to use DefaultVisibilityLabelServiceImpl,
then collected the logs of setupBeforeClass
> {noformat}
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
secret=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
topsecret=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
confidential=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
public=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
private=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
©ABC=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
ु=====0
> 2015-02-21 20:39:16,362 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
©ABC"ु\secret"'&\=====0
> 2015-02-21 20:39:16,363 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
'"+=====0
> 2015-02-21 20:39:16,363 INFO  [B.defaultRpcServer.handler=0,queue=0,port=42678] visibility.DefaultVisibilityLabelServiceImpl(236):
-?=====0
> 2015-02-21 20:39:16,363 INFO  [main-EventThread] visibility.VisibilityLabelsCache(115):
========refresh
> java.lang.Exception
> 	at org.apache.hadoop.hbase.security.visibility.VisibilityLabelsCache.refreshLabelsCache(VisibilityLabelsCache.java:115)
> 	at org.apache.hadoop.hbase.security.visibility.ZKVisibilityLabelWatcher.refreshVisibilityLabelsCache(ZKVisibilityLabelWatcher.java:76)
> 	at org.apache.hadoop.hbase.security.visibility.ZKVisibilityLabelWatcher.nodeDataChanged(ZKVisibilityLabelWatcher.java:115)
> 	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:412)
> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
> {noformat}
> We can see that, refresh is triggered from a background zk watcher, and it is possible
that the labels are not in labelsCache after addLabels being called.



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

Mime
View raw message