HBase
  1. HBase
  2. HBASE-10005

TestVisibilityLabels fails occasionally

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Blocker Blocker
    • Resolution: Fixed
    • Affects Version/s: 0.98.0
    • Fix Version/s: 0.98.0
    • Component/s: None
    • Labels:
      None

      Description

      I got the following test failures running test suite on hadoop-2 where distributed log replay was turned on :

      testAddVisibilityLabelsOnRSRestart(org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels)  Time elapsed: 0.019 sec  <<< FAILURE!
      java.lang.AssertionError: The count should be 8 expected:<8> but was:<6>
        at org.junit.Assert.fail(Assert.java:88)
        at org.junit.Assert.failNotEquals(Assert.java:743)
        at org.junit.Assert.assertEquals(Assert.java:118)
        at org.junit.Assert.assertEquals(Assert.java:555)
        at org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels.testAddVisibilityLabelsOnRSRestart(TestVisibilityLabels.java:408)
      ...
      testClearUserAuths(org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels)  Time elapsed: 0.002 sec  <<< FAILURE!
      java.lang.AssertionError
        at org.junit.Assert.fail(Assert.java:86)
        at org.junit.Assert.assertTrue(Assert.java:41)
        at org.junit.Assert.assertTrue(Assert.java:52)
        at org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels.testClearUserAuths(TestVisibilityLabels.java:505)
      

      Logs to be attached

        Activity

        Hide
        Ted Yu added a comment -

        The test failure is reproducible on (with jdk 1.6):

        Linux core.net 2.6.32-220.23.1.el6.20120713.x86_64 #1 SMP Fri Jul 13 11:40:51 CDT 2012 x86_64 x86_64 x86_64 GNU/Linux

        Show
        Ted Yu added a comment - The test failure is reproducible on (with jdk 1.6): Linux core.net 2.6.32-220.23.1.el6.20120713.x86_64 #1 SMP Fri Jul 13 11:40:51 CDT 2012 x86_64 x86_64 x86_64 GNU/Linux
        Hide
        Andrew Purtell added a comment -

        Blocker for 0.98

        Show
        Andrew Purtell added a comment - Blocker for 0.98
        Hide
        Anoop Sam John added a comment -

        While doing the clearAuths we get the current Auths for the given user and validate whether removing auth is already present for the user. This get happens from the cache. The cache update happens via zk data changed event and this thread can be bit late some times.
        In test we 1st add auths and immediately clear some of them. When the clearAuths reaches the cache update might not have happened yet!!

        Changed the code so that it gets the current auths for the user from hbase:labels table and not from cache. Any way these admin ops for the labels will not happen frequently.

        Show
        Anoop Sam John added a comment - While doing the clearAuths we get the current Auths for the given user and validate whether removing auth is already present for the user. This get happens from the cache. The cache update happens via zk data changed event and this thread can be bit late some times. In test we 1st add auths and immediately clear some of them. When the clearAuths reaches the cache update might not have happened yet!! Changed the code so that it gets the current auths for the user from hbase:labels table and not from cache. Any way these admin ops for the labels will not happen frequently.
        Hide
        ramkrishna.s.vasudevan added a comment -
        <testcase time="0.011" classname="org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels" name="testClearUserAuths">
            <failure type="java.lang.AssertionError">java.lang.AssertionError
                at org.junit.Assert.fail(Assert.java:86)
                at org.junit.Assert.assertTrue(Assert.java:41)
                at org.junit.Assert.assertTrue(Assert.java:52)
                at org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels.testClearUserAuths(TestVisibilityLabels.java:505)
                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        

        Got this in the latest local test case run. One thing observed from the logs is that there are no enough debug msgs.

        2013-11-28 13:15:05,111 INFO  [pool-1-thread-1] hbase.ResourceChecker(147): before: security.visibility.TestVisibilityLabels#testClearUserAuths Thread=243, OpenFileDescriptor=473, MaxFileDescriptor=327680, SystemLoadAverage=1204, ProcessCount=367, AvailableMemoryMB=1914, ConnectionCount=3
        2013-11-28 13:15:05,227 INFO  [pool-1-thread-1] hbase.ResourceChecker(171): after: security.visibility.TestVisibilityLabels#testClearUserAuths Thread=239 (was 243), OpenFileDescriptor=448 (was 473), MaxFileDescriptor=327680 (was 327680), SystemLoadAverage=1204 (was 1204), ProcessCount=367 (was 367), AvailableMemoryMB=1861 (was 1914), ConnectionCount=3 (was 3)
        2013-11-28 13:15:05,227 INFO  [pool-1-thread-1] hbase.HBaseTestingUtility(943): Shutting down minicluster
        

        We have only these two lines related to that testcase. May be the notification of the zk should be the issue.

        Show
        ramkrishna.s.vasudevan added a comment - <testcase time= "0.011" classname= "org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels" name= "testClearUserAuths" > <failure type= "java.lang.AssertionError" >java.lang.AssertionError at org.junit.Assert.fail(Assert.java:86) at org.junit.Assert.assertTrue(Assert.java:41) at org.junit.Assert.assertTrue(Assert.java:52) at org.apache.hadoop.hbase.security.visibility.TestVisibilityLabels.testClearUserAuths(TestVisibilityLabels.java:505) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) Got this in the latest local test case run. One thing observed from the logs is that there are no enough debug msgs. 2013-11-28 13:15:05,111 INFO [pool-1-thread-1] hbase.ResourceChecker(147): before: security.visibility.TestVisibilityLabels#testClearUserAuths Thread =243, OpenFileDescriptor=473, MaxFileDescriptor=327680, SystemLoadAverage=1204, ProcessCount=367, AvailableMemoryMB=1914, ConnectionCount=3 2013-11-28 13:15:05,227 INFO [pool-1-thread-1] hbase.ResourceChecker(171): after: security.visibility.TestVisibilityLabels#testClearUserAuths Thread =239 (was 243), OpenFileDescriptor=448 (was 473), MaxFileDescriptor=327680 (was 327680), SystemLoadAverage=1204 (was 1204), ProcessCount=367 (was 367), AvailableMemoryMB=1861 (was 1914), ConnectionCount=3 (was 3) 2013-11-28 13:15:05,227 INFO [pool-1-thread-1] hbase.HBaseTestingUtility(943): Shutting down minicluster We have only these two lines related to that testcase. May be the notification of the zk should be the issue.
        Hide
        ramkrishna.s.vasudevan added a comment -

        Okie same comment added by Anoop. Just saw that.

        Show
        ramkrishna.s.vasudevan added a comment - Okie same comment added by Anoop. Just saw that.
        Hide
        Anoop Sam John added a comment -

        Yes I was able to reproduce the issue with break points. Yes I also felt we missed some debug logs. Let me check other areas also and add more debug logs. Will add it in another IA jira. You +1 for this patch Ram? Let us see what QA says

        Show
        Anoop Sam John added a comment - Yes I was able to reproduce the issue with break points. Yes I also felt we missed some debug logs. Let me check other areas also and add more debug logs. Will add it in another IA jira. You +1 for this patch Ram? Let us see what QA says
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12616206/HBASE-10005.patch
        against trunk revision .

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 3 new or modified tests.

        +1 hadoop1.0. The patch compiles against the hadoop 1.0 profile.

        +1 hadoop2.0. The patch compiles against the hadoop 2.0 profile.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        +1 lineLengths. The patch does not introduce lines longer than 100

        -1 site. The patch appears to cause mvn site goal to fail.

        +1 core tests. The patch passed unit tests in .

        Test results: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-prefix-tree.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-client.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-common.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-protocol.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-server.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop1-compat.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-examples.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-thrift.html
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop-compat.html
        Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall . Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12616206/HBASE-10005.patch against trunk revision . +1 @author . The patch does not contain any @author tags. +1 tests included . The patch appears to include 3 new or modified tests. +1 hadoop1.0 . The patch compiles against the hadoop 1.0 profile. +1 hadoop2.0 . The patch compiles against the hadoop 2.0 profile. +1 javadoc . The javadoc tool did not generate any warning messages. +1 javac . The applied patch does not increase the total number of javac compiler warnings. +1 findbugs . The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit . The applied patch does not increase the total number of release audit warnings. +1 lineLengths . The patch does not introduce lines longer than 100 -1 site . The patch appears to cause mvn site goal to fail. +1 core tests . The patch passed unit tests in . Test results: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-prefix-tree.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-client.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-common.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-protocol.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-server.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop1-compat.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-examples.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-thrift.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop-compat.html Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/8020//console This message is automatically generated.
        Hide
        ramkrishna.s.vasudevan added a comment -

        Yes +1 for now. We can see if this happens again. May be after commit we can have this JIRA open for couple of days. If nothing fails close this. +1 for adding some more debug logs.
        I have not checked this failure till now testAddVisibilityLabelsOnRSRestart. Does this also repeat?

        Show
        ramkrishna.s.vasudevan added a comment - Yes +1 for now. We can see if this happens again. May be after commit we can have this JIRA open for couple of days. If nothing fails close this. +1 for adding some more debug logs. I have not checked this failure till now testAddVisibilityLabelsOnRSRestart. Does this also repeat?
        Hide
        Anoop Sam John added a comment -

        Committed the patch to Trunk. Keeping open for some more builds

        Show
        Anoop Sam John added a comment - Committed the patch to Trunk. Keeping open for some more builds
        Hide
        Ted Yu added a comment -

        There seems to be some misspelled method names:

              List<String> labels = getUserAuthsFromLablesTable(user);
          private List<String> getUserAuthsFromLablesTable(byte[] user) throws IOException {
              List<String> currentAuths = this.getUserAuthsFromLablesTable(user);
        hbase-server//src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java
          public void testLablesWithCheckAndPut() throws Throwable {
          public void testLablesWithIncrement() throws Throwable {
          public void testLablesWithAppend() throws Throwable {
        hbase-server//src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
        

        Lable -> Label

        Show
        Ted Yu added a comment - There seems to be some misspelled method names: List< String > labels = getUserAuthsFromLablesTable(user); private List< String > getUserAuthsFromLablesTable( byte [] user) throws IOException { List< String > currentAuths = this .getUserAuthsFromLablesTable(user); hbase-server //src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java public void testLablesWithCheckAndPut() throws Throwable { public void testLablesWithIncrement() throws Throwable { public void testLablesWithAppend() throws Throwable { hbase-server //src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java Lable -> Label
        Hide
        Anoop Sam John added a comment -

        Committed this addendum to correct the spell. Thanks a lot for finding it out Ted!

        Show
        Anoop Sam John added a comment - Committed this addendum to correct the spell. Thanks a lot for finding it out Ted!
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12616294/HBASE-10005_addendum.patch
        against trunk revision .

        +1 @author. The patch does not contain any @author tags.

        +1 tests included. The patch appears to include 3 new or modified tests.

        -1 patch. The patch command could not apply the patch.

        Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/8025//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall . Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12616294/HBASE-10005_addendum.patch against trunk revision . +1 @author . The patch does not contain any @author tags. +1 tests included . The patch appears to include 3 new or modified tests. -1 patch . The patch command could not apply the patch. Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/8025//console This message is automatically generated.
        Hide
        Hudson added a comment -

        SUCCESS: Integrated in HBase-TRUNK #4702 (See https://builds.apache.org/job/HBase-TRUNK/4702/)
        HBASE-10005 TestVisibilityLabels fails occasionally (addendum) (anoopsamjohn: rev 1546408)

        • /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java
        • /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
          HBASE-10005 TestVisibilityLabels fails occasionally (anoopsamjohn: rev 1546396)
        • /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java
        • /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
        Show
        Hudson added a comment - SUCCESS: Integrated in HBase-TRUNK #4702 (See https://builds.apache.org/job/HBase-TRUNK/4702/ ) HBASE-10005 TestVisibilityLabels fails occasionally (addendum) (anoopsamjohn: rev 1546408) /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java HBASE-10005 TestVisibilityLabels fails occasionally (anoopsamjohn: rev 1546396) /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
        Hide
        Hudson added a comment -

        FAILURE: Integrated in HBase-TRUNK-on-Hadoop-2.0.0 #855 (See https://builds.apache.org/job/HBase-TRUNK-on-Hadoop-2.0.0/855/)
        HBASE-10005 TestVisibilityLabels fails occasionally (addendum) (anoopsamjohn: rev 1546408)

        • /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java
        • /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
          HBASE-10005 TestVisibilityLabels fails occasionally (anoopsamjohn: rev 1546396)
        • /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java
        • /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
        Show
        Hudson added a comment - FAILURE: Integrated in HBase-TRUNK-on-Hadoop-2.0.0 #855 (See https://builds.apache.org/job/HBase-TRUNK-on-Hadoop-2.0.0/855/ ) HBASE-10005 TestVisibilityLabels fails occasionally (addendum) (anoopsamjohn: rev 1546408) /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java HBASE-10005 TestVisibilityLabels fails occasionally (anoopsamjohn: rev 1546396) /hbase/trunk/hbase-server/src/main/java/org/apache/hadoop/hbase/security/visibility/VisibilityController.java /hbase/trunk/hbase-server/src/test/java/org/apache/hadoop/hbase/security/visibility/TestVisibilityLabels.java
        Hide
        Andrew Purtell added a comment -

        Committed, resolving

        Show
        Andrew Purtell added a comment - Committed, resolving
        Hide
        Ted Yu added a comment -

        This test still fails on openjdk 1.7.0

        Attached are test output.

        Java: jre-1.7.0-openjdk.x86_64
        Linux: 2.6.18-348.el5 #1 SMP Tue Jan 8 17:53:53 EST 2013 x86_64 x86_64 x86_64 GNU/Linux

        Show
        Ted Yu added a comment - This test still fails on openjdk 1.7.0 Attached are test output. Java: jre-1.7.0-openjdk.x86_64 Linux: 2.6.18-348.el5 #1 SMP Tue Jan 8 17:53:53 EST 2013 x86_64 x86_64 x86_64 GNU/Linux
        Hide
        Ted Yu added a comment -

        Clarification:
        testAddVisibilityLabelsOnRSRestart fails when log replay is turned on.
        I added some debug log:

        2013-12-12 14:53:53,131 DEBUG [RpcServer.handler=2,port=58108] visibility.VisibilityController(1271): The list of auths are [system]
        2013-12-12 14:53:53,133 DEBUG [RpcServer.handler=2,port=58108] visibility.VisibilityController(1046): Adding the label ABC
        2013-12-12 14:53:53,133 DEBUG [RpcServer.handler=2,port=58108] visibility.VisibilityController(1046): Adding the label XYZ2013-12-12 14:53:53,137 ERROR [RpcServer.handler=2,port=58108] visibility.VisibilityController(1074): org.apache.hadoop.hbase.exceptions.RegionInRecoveryException: hbase:labels,,1386888826648.f14a399ba85cbb42c2c3b7547bf17c65. is recovering
        2013-12-12 14:53:53,151 DEBUG [main] visibility.TestVisibilityLabels(405): response from addLabels: result {
          exception {
            name: &quot;org.apache.hadoop.hbase.exceptions.RegionInRecoveryException&quot;
            value: &quot;org.apache.hadoop.hbase.exceptions.RegionInRecoveryException: hbase:labels,,1386888826648.f14a399ba85cbb42c2c3b7547bf17c65. is recovering\n\tat org.apache.hadoop.hbase.regionserver.HRegion.startRegionOperation(HRegion.java:5555)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1763)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1749)\n\tat org.apache.hadoop.hbase.security.visibility.VisibilityController.getExistingLabelsWithAuths(VisibilityController.java:1096)\n\tat org.apache.hadoop.hbase.security.visibility.VisibilityController.postBatchMutate(VisibilityController.java:672)\n\tat org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.postBatchMutate(RegionCoprocessorHost.java:1069)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:2401)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2087)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2037)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2041)\n\tat org.apache.hadoop.hbase.security.visibility.VisibilityController.addLabels(VisibilityController.java:1059)\n\tat org.apache.hadoop.hbase.protobuf.generated.VisibilityLabelsProtos$VisibilityLabelsService$1.addLabels(VisibilityLabelsProtos.java:5014)\n\tat org.apache.hadoop.hbase.protobuf.generated.VisibilityLabelsProtos$VisibilityLabelsService.callMethod(VisibilityLabelsProtos.java:5178)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.execService(HRegion.java:5357)\n\tat org.apache.hadoop.hbase.regionserver.HRegionServer.execService(HRegionServer.java:3275)\n\tat org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:28458)\n\tat org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2008)\n\tat org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:92)\n\tat org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.consumerLoop(SimpleRpcScheduler.java:160)\n\tat org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.access$000(SimpleRpcScheduler.java:38)\n\tat org.apache.hadoop.hbase.ipc.SimpleRpcScheduler$1.run(SimpleRpcScheduler.java:110)\n\tat java.lang.Thread.run(Thread.java:744)\n&quot;
          }
        }
        
        Show
        Ted Yu added a comment - Clarification: testAddVisibilityLabelsOnRSRestart fails when log replay is turned on. I added some debug log: 2013-12-12 14:53:53,131 DEBUG [RpcServer.handler=2,port=58108] visibility.VisibilityController(1271): The list of auths are [system] 2013-12-12 14:53:53,133 DEBUG [RpcServer.handler=2,port=58108] visibility.VisibilityController(1046): Adding the label ABC 2013-12-12 14:53:53,133 DEBUG [RpcServer.handler=2,port=58108] visibility.VisibilityController(1046): Adding the label XYZ2013-12-12 14:53:53,137 ERROR [RpcServer.handler=2,port=58108] visibility.VisibilityController(1074): org.apache.hadoop.hbase.exceptions.RegionInRecoveryException: hbase:labels,,1386888826648.f14a399ba85cbb42c2c3b7547bf17c65. is recovering 2013-12-12 14:53:53,151 DEBUG [main] visibility.TestVisibilityLabels(405): response from addLabels: result { exception { name: &quot;org.apache.hadoop.hbase.exceptions.RegionInRecoveryException&quot; value: &quot;org.apache.hadoop.hbase.exceptions.RegionInRecoveryException: hbase:labels,,1386888826648.f14a399ba85cbb42c2c3b7547bf17c65. is recovering\n\tat org.apache.hadoop.hbase.regionserver.HRegion.startRegionOperation(HRegion.java:5555)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1763)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1749)\n\tat org.apache.hadoop.hbase.security.visibility.VisibilityController.getExistingLabelsWithAuths(VisibilityController.java:1096)\n\tat org.apache.hadoop.hbase.security.visibility.VisibilityController.postBatchMutate(VisibilityController.java:672)\n\tat org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.postBatchMutate(RegionCoprocessorHost.java:1069)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:2401)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2087)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2037)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2041)\n\tat org.apache.hadoop.hbase.security.visibility.VisibilityController.addLabels(VisibilityController.java:1059)\n\tat org.apache.hadoop.hbase.protobuf.generated.VisibilityLabelsProtos$VisibilityLabelsService$1.addLabels(VisibilityLabelsProtos.java:5014)\n\tat org.apache.hadoop.hbase.protobuf.generated.VisibilityLabelsProtos$VisibilityLabelsService.callMethod(VisibilityLabelsProtos.java:5178)\n\tat org.apache.hadoop.hbase.regionserver.HRegion.execService(HRegion.java:5357)\n\tat org.apache.hadoop.hbase.regionserver.HRegionServer.execService(HRegionServer.java:3275)\n\tat org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:28458)\n\tat org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2008)\n\tat org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:92)\n\tat org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.consumerLoop(SimpleRpcScheduler.java:160)\n\tat org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.access$000(SimpleRpcScheduler.java:38)\n\tat org.apache.hadoop.hbase.ipc.SimpleRpcScheduler$1.run(SimpleRpcScheduler.java:110)\n\tat java.lang. Thread .run( Thread .java:744)\n&quot; } }
        Hide
        Andrew Purtell added a comment -

        Java: jre-1.7.0-openjdk.x86_64

        I don't see this failure anywhere, but have Oracle JVMs for 6 and 7 set up, so that could be the difference.

        Ted Yu, do you know anyone running OpenJDK in production?

        Show
        Andrew Purtell added a comment - Java: jre-1.7.0-openjdk.x86_64 I don't see this failure anywhere, but have Oracle JVMs for 6 and 7 set up, so that could be the difference. Ted Yu , do you know anyone running OpenJDK in production?
        Hide
        Andrew Purtell added a comment -

        Clarification: testAddVisibilityLabelsOnRSRestart fails when log replay is turned on.

        Wait. We are crossing comments on JIRA again. Please provide steps for reproducing the problem, I think we are missing some detail there.

        Show
        Andrew Purtell added a comment - Clarification: testAddVisibilityLabelsOnRSRestart fails when log replay is turned on. Wait. We are crossing comments on JIRA again. Please provide steps for reproducing the problem, I think we are missing some detail there.
        Hide
        Ted Yu added a comment -

        Andy:
        Usage of openjdk was redherring.
        You can reproduce the test failure with the following change:

        Index: hbase-common/src/main/java/org/apache/hadoop/hbase/HConstants.java
        ===================================================================
        --- hbase-common/src/main/java/org/apache/hadoop/hbase/HConstants.java	(revision 1550575)
        +++ hbase-common/src/main/java/org/apache/hadoop/hbase/HConstants.java	(working copy)
        @@ -794,7 +794,7 @@
        
           /** Conf key that enables unflushed WAL edits directly being replayed to region servers */
           public static final String DISTRIBUTED_LOG_REPLAY_KEY = "hbase.master.distributed.log.replay";
        -  public static final boolean DEFAULT_DISTRIBUTED_LOG_REPLAY_CONFIG = false;
        +  public static final boolean DEFAULT_DISTRIBUTED_LOG_REPLAY_CONFIG = true;
           public static final String DISALLOW_WRITES_IN_RECOVERING =
               "hbase.regionserver.disallow.writes.when.recovering";
           public static final boolean DEFAULT_DISALLOW_WRITES_IN_RECOVERING_CONFIG = false;
        

        As shown in test output above, when testAddVisibilityLabelsOnRSRestart opens scanner to scan labels table, the region is still in recovery - not ready for scan.

        Show
        Ted Yu added a comment - Andy: Usage of openjdk was redherring. You can reproduce the test failure with the following change: Index: hbase-common/src/main/java/org/apache/hadoop/hbase/HConstants.java =================================================================== --- hbase-common/src/main/java/org/apache/hadoop/hbase/HConstants.java (revision 1550575) +++ hbase-common/src/main/java/org/apache/hadoop/hbase/HConstants.java (working copy) @@ -794,7 +794,7 @@ /** Conf key that enables unflushed WAL edits directly being replayed to region servers */ public static final String DISTRIBUTED_LOG_REPLAY_KEY = "hbase.master.distributed.log.replay" ; - public static final boolean DEFAULT_DISTRIBUTED_LOG_REPLAY_CONFIG = false ; + public static final boolean DEFAULT_DISTRIBUTED_LOG_REPLAY_CONFIG = true ; public static final String DISALLOW_WRITES_IN_RECOVERING = "hbase.regionserver.disallow.writes.when.recovering" ; public static final boolean DEFAULT_DISALLOW_WRITES_IN_RECOVERING_CONFIG = false ; As shown in test output above, when testAddVisibilityLabelsOnRSRestart opens scanner to scan labels table, the region is still in recovery - not ready for scan.
        Hide
        Andrew Purtell added a comment -

        Ok Ted Yu, I opened HBASE-10148

        Show
        Andrew Purtell added a comment - Ok Ted Yu , I opened HBASE-10148

          People

          • Assignee:
            Anoop Sam John
            Reporter:
            Ted Yu
          • Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development