Details

    • Type: Sub-task Sub-task
    • Status: Closed
    • Priority: Critical Critical
    • Resolution: Invalid
    • Affects Version/s: 0.99.0
    • Fix Version/s: 0.99.0
    • Component/s: wal
    • Labels:
      None

      Description

      This was found by Jeffrey Zhong See parent issue. We have this issue since we put the ring buffer/disrupter into the WAL (HBASE-10156).

      An edits region sequence id is set only after the edit has traversed the ring buffer. Flushing, we just up whatever the current region sequence id is. Crossing the ring buffer may take some time and is done by background threads. The flusher may be taking the region sequence id though edits have not yet made it across the ringbuffer: i.e. edits that are actually scoped by the flush may have region sequence ids in excess of that of the flush sequence id reported.

      The consequences are not exactly clear. Would rather not have to find out so lets fix this here.

      1. 11109.txt
        6 kB
        stack
      2. 11109v2.txt
        28 kB
        stack
      3. 11109v2.txt
        28 kB
        stack

        Issue Links

          Activity

          Transition Time In Source Status Execution Times Last Executer Last Execution Date
          Open Open Patch Available Patch Available
          19h 34m 1 stack 03/May/14 00:55
          Patch Available Patch Available Resolved Resolved
          10d 19h 43m 1 stack 13/May/14 20:39
          Resolved Resolved Closed Closed
          284d 3h 52m 1 Enis Soztutar 21/Feb/15 23:31
          Enis Soztutar made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Hide
          Enis Soztutar added a comment -

          Closing this issue after 0.99.0 release.

          Show
          Enis Soztutar added a comment - Closing this issue after 0.99.0 release.
          stack made changes -
          Status Patch Available [ 10002 ] Resolved [ 5 ]
          Resolution Invalid [ 6 ]
          Hide
          stack added a comment -

          This has been subsumed by HBASE-11135. The tests that are in this patch went in as part of HBASE-11135. The 'sync' fix under the update lock while flushing was replaced by an append+wait+on+sequenceid+update which should be less onerous.

          Show
          stack added a comment - This has been subsumed by HBASE-11135 . The tests that are in this patch went in as part of HBASE-11135 . The 'sync' fix under the update lock while flushing was replaced by an append+wait+on+sequenceid+update which should be less onerous.
          stack made changes -
          Link This issue is superceded by HBASE-11135 [ HBASE-11135 ]
          Hide
          stack added a comment -

          The failure is legit. The new call to sync is causing a fail in TestLogRolling in testLogRollOnPipelineRestart on the end when we flush the regions. I get this:

          testLogRollOnPipelineRestart(org.apache.hadoop.hbase.regionserver.wal.TestLogRolling)  Time elapsed: 57.241 sec  <<< ERROR!
          org.apache.hadoop.ipc.RemoteException(java.io.IOException): BP-267694901-127.0.0.1-1399501363598:blk_1073741839_1019 does not exist or is not under Constructionblk_1073741839_1019{blockUCState=UNDER_RECOVERY, primaryNodeIndex=1, replicas=[ReplicaUnderConstruction[[DISK]DS-5c7295aa-1c02-4f51-91ec-61a087a04969:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-0c75895e-620b-4f6b-8999-699f3b6aa614:NORMAL|RBW]]}
                  at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkUCBlock(FSNamesystem.java:5857)
                  at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.updateBlockForPipeline(FSNamesystem.java:5924)
                  at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.updateBlockForPipeline(NameNodeRpcServer.java:658)
                  at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.updateBlockForPipeline(ClientNamenodeProtocolServerSideTranslatorPB.java:873)
                  at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java)
                  at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:585)
                  at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:928)
                  at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2013)
                  at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2009)
                  at java.security.AccessController.doPrivileged(Native Method)
                  at javax.security.auth.Subject.doAs(Subject.java:415)
          ...
          

          Putting this aside for the moment. Will instead work on changing our region sequenceid to be early-binding rather than late-binding and then I think this is no longer an issue. Will be back.

          Show
          stack added a comment - The failure is legit. The new call to sync is causing a fail in TestLogRolling in testLogRollOnPipelineRestart on the end when we flush the regions. I get this: testLogRollOnPipelineRestart(org.apache.hadoop.hbase.regionserver.wal.TestLogRolling) Time elapsed: 57.241 sec <<< ERROR! org.apache.hadoop.ipc.RemoteException(java.io.IOException): BP-267694901-127.0.0.1-1399501363598:blk_1073741839_1019 does not exist or is not under Constructionblk_1073741839_1019{blockUCState=UNDER_RECOVERY, primaryNodeIndex=1, replicas=[ReplicaUnderConstruction[[DISK]DS-5c7295aa-1c02-4f51-91ec-61a087a04969:NORMAL|RBW], ReplicaUnderConstruction[[DISK]DS-0c75895e-620b-4f6b-8999-699f3b6aa614:NORMAL|RBW]]} at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.checkUCBlock(FSNamesystem.java:5857) at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.updateBlockForPipeline(FSNamesystem.java:5924) at org.apache.hadoop.hdfs.server.namenode.NameNodeRpcServer.updateBlockForPipeline(NameNodeRpcServer.java:658) at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolServerSideTranslatorPB.updateBlockForPipeline(ClientNamenodeProtocolServerSideTranslatorPB.java:873) at org.apache.hadoop.hdfs.protocol.proto.ClientNamenodeProtocolProtos$ClientNamenodeProtocol$2.callBlockingMethod(ClientNamenodeProtocolProtos.java) at org.apache.hadoop.ipc.ProtobufRpcEngine$Server$ProtoBufRpcInvoker.call(ProtobufRpcEngine.java:585) at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:928) at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2013) at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:2009) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAs(Subject.java:415) ... Putting this aside for the moment. Will instead work on changing our region sequenceid to be early-binding rather than late-binding and then I think this is no longer an issue. Will be back.
          Hide
          Hadoop QA added a comment -

          -1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12643243/11109v2.txt
          against trunk revision .
          ATTACHMENT ID: 12643243

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

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

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

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

          +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 mvn site goal succeeds with this patch.

          -1 core tests. The patch failed these unit tests:
          org.apache.hadoop.hbase.regionserver.wal.TestLogRolling

          Test results: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//testReport/
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-protocol.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-thrift.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-client.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop2-compat.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-examples.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-prefix-tree.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-common.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-server.html
          Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop-compat.html
          Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//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/12643243/11109v2.txt against trunk revision . ATTACHMENT ID: 12643243 +1 @author . The patch does not contain any @author tags. +1 tests included . The patch appears to include 9 new or modified tests. +1 javac . The applied patch does not increase the total number of javac compiler warnings. +1 javadoc . The javadoc tool did not generate any warning messages. +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 mvn site goal succeeds with this patch. -1 core tests . The patch failed these unit tests: org.apache.hadoop.hbase.regionserver.wal.TestLogRolling Test results: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-protocol.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-thrift.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-client.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop2-compat.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-examples.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-prefix-tree.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-common.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-server.html Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//artifact/trunk/patchprocess/newPatchFindbugsWarningshbase-hadoop-compat.html Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/9458//console This message is automatically generated.
          Hide
          Mikhail Antonov added a comment -

          hadoopqa is gone? retry

          Probably. I tried cancelling/resubmitting consensus patches multiples time over past few days, didn't get any builds kicked in..

          Show
          Mikhail Antonov added a comment - hadoopqa is gone? retry Probably. I tried cancelling/resubmitting consensus patches multiples time over past few days, didn't get any builds kicked in..
          stack made changes -
          Attachment 11109v2.txt [ 12643243 ]
          Hide
          stack added a comment -

          hadoopqa is gone? retry

          Show
          stack added a comment - hadoopqa is gone? retry
          Hide
          stack added a comment -

          Ok. Pass on my suggested optimization above. I was going to make a hack appendNoSync just to get back the highest sequence number outstanding on the WAL and after getting this, sync to that point only (not all edits). It might help in some light cases but would be no good for real hotspotitng so put it aside as a hack. Let me commit this patch because it 'correct' if hadoopqa says it good and lets come back here after we mesh region sequenceid and mvcc. More fun ahead.

          Show
          stack added a comment - Ok. Pass on my suggested optimization above. I was going to make a hack appendNoSync just to get back the highest sequence number outstanding on the WAL and after getting this, sync to that point only (not all edits). It might help in some light cases but would be no good for real hotspotitng so put it aside as a hack. Let me commit this patch because it 'correct' if hadoopqa says it good and lets come back here after we mesh region sequenceid and mvcc. More fun ahead.
          Hide
          stack added a comment -

          Jeffrey Zhong Thank you for pushing back. Thinking on it, there may be a less burdensome soln., one that will not require us sync in the majority of cases using facility @nkeywal made us restore. Let me play.

          On revisit after uniting seqid and mvcc, yes, it will change the lay of the land. Lets revisit after this patch goes in ('correct' but likely with some small cost) and after your grand unification gets committed. Thanks for review.

          Show
          stack added a comment - Jeffrey Zhong Thank you for pushing back. Thinking on it, there may be a less burdensome soln., one that will not require us sync in the majority of cases using facility @nkeywal made us restore. Let me play. On revisit after uniting seqid and mvcc, yes, it will change the lay of the land. Lets revisit after this patch goes in ('correct' but likely with some small cost) and after your grand unification gets committed. Thanks for review.
          Hide
          Jeffrey Zhong added a comment -

          Yeah, doesn't the comment say that? In testing, I see us doing 4 or 5 syncs a ms so when we flush there'd be some hiccup of some portion of a millisecond for this region only

          I c. +1 on your current patch. Thanks.

          It's possible we can move out the sync when mvcc and seqid is combined. Because it will be the readpoint(largest sequence number) before the WriteEntry w inserted with mvcc.beginMemstoreInsert(); when we are holding the updatesLock.

          Show
          Jeffrey Zhong added a comment - Yeah, doesn't the comment say that? In testing, I see us doing 4 or 5 syncs a ms so when we flush there'd be some hiccup of some portion of a millisecond for this region only I c. +1 on your current patch. Thanks. It's possible we can move out the sync when mvcc and seqid is combined. Because it will be the readpoint(largest sequence number) before the WriteEntry w inserted with mvcc.beginMemstoreInsert(); when we are holding the updatesLock.
          stack made changes -
          Status Open [ 1 ] Patch Available [ 10002 ]
          Hide
          stack added a comment -

          Jeffrey Zhong What you think of the patch? You think the sync is not on? If so, I can go back to the drawing board. At the moment I am having trouble figuring a solution that doesn't have me changing the HLog#append to return a 'token' or else inside in FSHLog, adding more per region accounting and exposing that w/ new APIs to HRegion.

          Show
          stack added a comment - Jeffrey Zhong What you think of the patch? You think the sync is not on? If so, I can go back to the drawing board. At the moment I am having trouble figuring a solution that doesn't have me changing the HLog#append to return a 'token' or else inside in FSHLog, adding more per region accounting and exposing that w/ new APIs to HRegion.
          stack made changes -
          Attachment 11109v2.txt [ 12643162 ]
          Hide
          stack added a comment -

          Add a test.

          Add a bunch of doc on how sequenceid is used. Removed stale doc (this is why patch is big).

          Fix is adding of the sync to push out all edits in the ring buffer. Comment out the sync and the test fails.

          Removed the below:

          • // sync unflushed WAL changes when deferred log sync is enabled
          • // see HBASE-8208 for details
          • if (wal != null && !shouldSyncLog()) { - wal.sync(); - }

          No need of conditional sync now we sync always.

          Narrowed the number of references to sequenceId. Only updated in FSHLog and in internal flush now.

          Show
          stack added a comment - Add a test. Add a bunch of doc on how sequenceid is used. Removed stale doc (this is why patch is big). Fix is adding of the sync to push out all edits in the ring buffer. Comment out the sync and the test fails. Removed the below: // sync unflushed WAL changes when deferred log sync is enabled // see HBASE-8208 for details if (wal != null && !shouldSyncLog()) { - wal.sync(); - } No need of conditional sync now we sync always. Narrowed the number of references to sequenceId. Only updated in FSHLog and in internal flush now.
          Hide
          stack added a comment -

          Jeffrey Zhong Yeah, doesn't the comment say that? In testing, I see us doing 4 or 5 syncs a ms so when we flush there'd be some hiccup of some portion of a millisecond for this region only. If you have an alternate strategy, I'd be interested.

          Show
          stack added a comment - Jeffrey Zhong Yeah, doesn't the comment say that? In testing, I see us doing 4 or 5 syncs a ms so when we flush there'd be some hiccup of some portion of a millisecond for this region only. If you have an alternate strategy, I'd be interested.
          Hide
          Jeffrey Zhong added a comment -

          Stack The following change:

                 if (wal != null) {
          +        wal.sync();
          

          has performance impact as we do a WAL sync while holding updatesLock. This may cause intermittent response time spike.

          Show
          Jeffrey Zhong added a comment - Stack The following change: if (wal != null ) { + wal.sync(); has performance impact as we do a WAL sync while holding updatesLock. This may cause intermittent response time spike.
          stack made changes -
          Field Original Value New Value
          Attachment 11109.txt [ 12642998 ]
          Hide
          stack added a comment -

          WIP. Working on unit test.

          Show
          stack added a comment - WIP. Working on unit test.
          stack created issue -

            People

            • Assignee:
              stack
              Reporter:
              stack
            • Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development