HBase
  1. HBase
  2. HBASE-11017

TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94

    Details

    • Type: Test Test
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.94.19
    • Component/s: None
    • Labels:
      None

      Description

      Have seen a few of these:

      Error Message
      
      Failed clearing memory after 6 attempts on region: testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac.
      
      Stacktrace
      
      org.apache.hadoop.hbase.DroppedSnapshotException: Failed clearing memory after 6 attempts on region: testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac.
      	at org.apache.hadoop.hbase.regionserver.HRegion.doClose(HRegion.java:1087)
      	at org.apache.hadoop.hbase.regionserver.HRegion.close(HRegion.java:1024)
      	at org.apache.hadoop.hbase.regionserver.HRegion.close(HRegion.java:989)
      	at org.apache.hadoop.hbase.regionserver.HRegion.closeHRegion(HRegion.java:4346)
      	at org.apache.hadoop.hbase.regionserver.TestHRegion.testWritesWhileScanning(TestHRegion.java:3406)
      

        Activity

        Hide
        Lars Hofhansl added a comment -

        stack, do you think this is normal? I know we had to fix some other test after this change went it.

        Show
        Lars Hofhansl added a comment - stack , do you think this is normal? I know we had to fix some other test after this change went it.
        Hide
        Lars Hofhansl added a comment -

        This is what I see in the logs:

        2014-04-17 09:41:02,037 INFO  [pool-1-thread-1] regionserver.HRegion(1776): Finished memstore flush of ~9.7m/10168960, currentsize=7.0m/7383120 for region testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. in 278ms, sequenceid=50, compaction requested=true
        2014-04-17 09:41:02,038 INFO  [pool-1-thread-1] regionserver.HRegion(1090): Running extra flush, 1 (carrying snapshot?) testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac.
        2014-04-17 09:41:02,038 DEBUG [pool-1-thread-1] regionserver.HRegion(1636): Started memstore flush for testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., current region memstore size 7.0m
        2014-04-17 09:41:02,038 DEBUG [pool-1-thread-1] regionserver.HRegion(1686): Finished snapshotting testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., syncing WAL and waiting on mvcc, flushsize=0
        2014-04-17 09:41:02,038 DEBUG [pool-1-thread-1] regionserver.HRegion(1702): Finished snapshotting, commencing flushing stores
        2014-04-17 09:41:02,038 INFO  [pool-1-thread-1] regionserver.HRegion(1776): Finished memstore flush of ~0.0/0, currentsize=7.0m/7383120 for region testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. in 0ms, sequenceid=51, compaction requested=false
        2014-04-17 09:41:02,038 INFO  [pool-1-thread-1] regionserver.HRegion(1090): Running extra flush, 2 (carrying snapshot?) testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac.
        2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1636): Started memstore flush for testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., current region memstore size 7.0m
        2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1686): Finished snapshotting testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., syncing WAL and waiting on mvcc, flushsize=0
        2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1702): Finished snapshotting, commencing flushing stores
        2014-04-17 09:41:02,039 INFO  [pool-1-thread-1] regionserver.HRegion(1776): Finished memstore flush of ~0.0/0, currentsize=7.0m/7383120 for region testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. in 1ms, sequenceid=52, compaction requested=false
        2014-04-17 09:41:02,039 INFO  [pool-1-thread-1] regionserver.HRegion(1090): Running extra flush, 3 (carrying snapshot?) testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac.
        2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1636): Started memstore flush for testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., current region memstore size 7.0m
        2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1686): Finished snapshotting testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., syncing WAL and waiting on mvcc, flushsize=0
        

        So somehow it is not making progress once it gets into this state.

        Show
        Lars Hofhansl added a comment - This is what I see in the logs: 2014-04-17 09:41:02,037 INFO [pool-1-thread-1] regionserver.HRegion(1776): Finished memstore flush of ~9.7m/10168960, currentsize=7.0m/7383120 for region testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. in 278ms, sequenceid=50, compaction requested= true 2014-04-17 09:41:02,038 INFO [pool-1-thread-1] regionserver.HRegion(1090): Running extra flush, 1 (carrying snapshot?) testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. 2014-04-17 09:41:02,038 DEBUG [pool-1-thread-1] regionserver.HRegion(1636): Started memstore flush for testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., current region memstore size 7.0m 2014-04-17 09:41:02,038 DEBUG [pool-1-thread-1] regionserver.HRegion(1686): Finished snapshotting testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., syncing WAL and waiting on mvcc, flushsize=0 2014-04-17 09:41:02,038 DEBUG [pool-1-thread-1] regionserver.HRegion(1702): Finished snapshotting, commencing flushing stores 2014-04-17 09:41:02,038 INFO [pool-1-thread-1] regionserver.HRegion(1776): Finished memstore flush of ~0.0/0, currentsize=7.0m/7383120 for region testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. in 0ms, sequenceid=51, compaction requested= false 2014-04-17 09:41:02,038 INFO [pool-1-thread-1] regionserver.HRegion(1090): Running extra flush, 2 (carrying snapshot?) testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. 2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1636): Started memstore flush for testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., current region memstore size 7.0m 2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1686): Finished snapshotting testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., syncing WAL and waiting on mvcc, flushsize=0 2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1702): Finished snapshotting, commencing flushing stores 2014-04-17 09:41:02,039 INFO [pool-1-thread-1] regionserver.HRegion(1776): Finished memstore flush of ~0.0/0, currentsize=7.0m/7383120 for region testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. in 1ms, sequenceid=52, compaction requested= false 2014-04-17 09:41:02,039 INFO [pool-1-thread-1] regionserver.HRegion(1090): Running extra flush, 3 (carrying snapshot?) testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac. 2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1636): Started memstore flush for testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., current region memstore size 7.0m 2014-04-17 09:41:02,039 DEBUG [pool-1-thread-1] regionserver.HRegion(1686): Finished snapshotting testWritesWhileScanning,,1397727647509.2c968a587c4cb7e84a52c7aa8d2afcac., syncing WAL and waiting on mvcc, flushsize=0 So somehow it is not making progress once it gets into this state.
        Hide
        Lars Hofhansl added a comment -

        Is the same as HBASE-10751?

        Show
        Lars Hofhansl added a comment - Is the same as HBASE-10751 ?
        Hide
        stack added a comment -

        It is the same. In HBASE-10751 I claim I backported the patch but must have not.

        "stack added a comment - 14/Mar/14 13:39
        Committed to 0.94 too after HBASE-10514 went in."

        Then if I look on the 0.94 branch I see:

        ------------------------------------------------------------------------
        r1577784 | stack | 2014-03-14 21:30:20 -0700 (Fri, 14 Mar 2014) | 1 line

        HBASE-10751 TestHRegion testWritesWhileScanning occasional fail since HBASE-10514 went in

        But when I look at the commit, it is only the addendum import fix. Sorry about that Lars. Let me fix on this issue.

        Show
        stack added a comment - It is the same. In HBASE-10751 I claim I backported the patch but must have not. "stack added a comment - 14/Mar/14 13:39 Committed to 0.94 too after HBASE-10514 went in." Then if I look on the 0.94 branch I see: ------------------------------------------------------------------------ r1577784 | stack | 2014-03-14 21:30:20 -0700 (Fri, 14 Mar 2014) | 1 line HBASE-10751 TestHRegion testWritesWhileScanning occasional fail since HBASE-10514 went in But when I look at the commit, it is only the addendum import fix. Sorry about that Lars. Let me fix on this issue.
        Hide
        stack added a comment -

        Patch that is backport of HBASE-10751

        Show
        stack added a comment - Patch that is backport of HBASE-10751
        Hide
        stack added a comment -

        Committed to 0.94. Hopefully that does it Lars. Sorry for pain caused.

        Show
        stack added a comment - Committed to 0.94. Hopefully that does it Lars. Sorry for pain caused.
        Hide
        Lars Hofhansl added a comment -

        Thanks stack!

        Show
        Lars Hofhansl added a comment - Thanks stack !
        Hide
        Hudson added a comment -

        SUCCESS: Integrated in HBase-0.94-security #472 (See https://builds.apache.org/job/HBase-0.94-security/472/)
        HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392)

        • /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Show
        Hudson added a comment - SUCCESS: Integrated in HBase-0.94-security #472 (See https://builds.apache.org/job/HBase-0.94-security/472/ ) HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392) /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Hide
        Hudson added a comment -

        FAILURE: Integrated in HBase-0.94-on-Hadoop-2 #75 (See https://builds.apache.org/job/HBase-0.94-on-Hadoop-2/75/)
        HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392)

        • /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Show
        Hudson added a comment - FAILURE: Integrated in HBase-0.94-on-Hadoop-2 #75 (See https://builds.apache.org/job/HBase-0.94-on-Hadoop-2/75/ ) HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392) /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Hide
        Hudson added a comment -

        SUCCESS: Integrated in HBase-0.94 #1353 (See https://builds.apache.org/job/HBase-0.94/1353/)
        HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392)

        • /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Show
        Hudson added a comment - SUCCESS: Integrated in HBase-0.94 #1353 (See https://builds.apache.org/job/HBase-0.94/1353/ ) HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392) /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Hide
        Hudson added a comment -

        SUCCESS: Integrated in HBase-0.94-JDK7 #120 (See https://builds.apache.org/job/HBase-0.94-JDK7/120/)
        HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392)

        • /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java
        Show
        Hudson added a comment - SUCCESS: Integrated in HBase-0.94-JDK7 #120 (See https://builds.apache.org/job/HBase-0.94-JDK7/120/ ) HBASE-11017 TestHRegionBusyWait.testWritesWhileScanning fails frequently in 0.94 (stack: rev 1588392) /hbase/branches/0.94/src/test/java/org/apache/hadoop/hbase/regionserver/TestHRegion.java

          People

          • Assignee:
            stack
            Reporter:
            Lars Hofhansl
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development