Uploaded image for project: 'HBase'
  1. HBase
  2. HBASE-14018

RegionServer is aborted when flushing memstore.

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Invalid
    • Affects Version/s: 1.0.1.1
    • Fix Version/s: None
    • Component/s: hadoop2
    • Labels:
      None
    • Environment:

      CentOS x64 Server

      Description

      + Pseudo-distributed Hadoop (2.6.0), ZK_HBASE_MANAGE = true (1 master, 1 regionserver).
      + Put data to OpenTSDB, 1000 records / s, for 2000 seconds.
      + RegionServer is aborted.

      === RegionServer logs ===
      2015-07-03 16:37:37,332 INFO [LruBlockCacheStatsExecutor] hfile.LruBlockCache: totalSize=371.27 KB, freeSize=181.41 MB, max=181.78 MB, blockCount=5, accesses=1623, hits=172, hitRatio=10.60%, , cachingAccesses=177, cachingHits=151, cachingHitsRatio=85.31%, evictions=1139, evicted=21, evictedPerRun=0.018437225371599197
      2015-07-03 16:37:37,898 INFO node1:16040Replication Statistics #0 regionserver.Replication: Normal source for cluster 1: Total replicated edits: 2744, currently replicating from: hdfs://node1.vmcluster:9000/hbase/WALs/node1.vmcluster,16040,1435897652505/node1.vmcluster%2C16040%2C1435897652505.default.1435908458590 at position: 19207814

      2015-07-03 16:42:37,331 INFO [LruBlockCacheStatsExecutor] hfile.LruBlockCache: totalSize=371.27 KB, freeSize=181.41 MB, max=181.78 MB, blockCount=5, accesses=1624, hits=173, hitRatio=10.65%, , cachingAccesses=178, cachingHits=152, cachingHitsRatio=85.39%, evictions=1169, evicted=21, evictedPerRun=0.01796407252550125
      2015-07-03 16:42:37,899 INFO node1:16040Replication Statistics #0 regionserver.Replication: Normal source for cluster 1: Total replicated edits: 3049, currently replicating from: hdfs://node1.vmcluster:9000/hbase/WALs/node1.vmcluster,16040,1435897652505/node1.vmcluster%2C16040%2C1435897652505.default.1435908458590 at position: 33026416

      2015-07-03 16:43:27,217 INFO [MemStoreFlusher.1] regionserver.HRegion: Started memstore flush for tsdb,,1435897759785.2d49cd81fb6513f51af58bd0394c4e0d., current region memstore size 128.05 MB
      2015-07-03 16:43:27,899 FATAL [MemStoreFlusher.1] regionserver.HRegionServer: ABORTING region server node1.vmcluster,16040,1435897652505: Replay of WAL required. Forcing server shutdown
      org.apache.hadoop.hbase.DroppedSnapshotException: region: tsdb,,1435897759785.2d49cd81fb6513f51af58bd0394c4e0d.
      at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:2001)
      at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1772)
      at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1704)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:445)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:407)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:69)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:225)
      at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.ArrayIndexOutOfBoundsException: -32743
      at org.apache.hadoop.hbase.CellComparator.getMinimumMidpointArray(CellComparator.java:478)
      at org.apache.hadoop.hbase.CellComparator.getMidpoint(CellComparator.java:448)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.finishBlock(HFileWriterV2.java:165)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.checkBlockBoundary(HFileWriterV2.java:146)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.append(HFileWriterV2.java:263)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV3.append(HFileWriterV3.java:87)
      at org.apache.hadoop.hbase.regionserver.StoreFile$Writer.append(StoreFile.java:932)
      at org.apache.hadoop.hbase.regionserver.StoreFlusher.performFlush(StoreFlusher.java:121)
      at org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:71)
      at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:879)
      at org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:2128)
      at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1955)
      ... 7 more
      2015-07-03 16:43:27,901 FATAL [MemStoreFlusher.1] regionserver.HRegionServer: RegionServer abort: loaded coprocessors are: [org.apache.hadoop.hbase.coprocessor.MultiRowMutationEndpoint]

      === HMaster logs ===
      2015-07-03 13:29:20,671 INFO [RegionOpenAndInitThread-tsdb-meta-1] regionserver.HRegion: creating HRegion tsdb-meta HTD == 'tsdb-meta',

      {NAME => 'name', BLOOMFILTER => 'ROW', VERSIONS => '1', IN_MEMORY => 'false', KEEP_DELETED_CELLS => 'FALSE', DATA_BLOCK_ENCODING => 'NONE', TTL => 'FOREVER', COMPRESSION => 'NONE', MIN_VERSIONS => '0', BLOCKCACHE => 'true', BLOCKSIZE => '65536', REPLICATION_SCOPE => '1'}

      RootDir = hdfs://node1.vmcluster:9000/hbase/.tmp Table name == tsdb-meta
      2015-07-03 13:29:20,696 INFO [RegionOpenAndInitThread-tsdb-meta-1] regionserver.HRegion: Closed tsdb-meta,,1435897760624.0738e3fac8ffe40d656dc91588a47aac.
      2015-07-03 13:29:20,703 INFO [MASTER_TABLE_OPERATIONS-node1:16020-0] hbase.MetaTableAccessor: Added 1
      2015-07-03 13:29:20,704 INFO [MASTER_TABLE_OPERATIONS-node1:16020-0] master.AssignmentManager: Assigning 1 region(s) to node1.vmcluster,16040,1435897652505
      2015-07-03 13:29:20,717 INFO [MASTER_TABLE_OPERATIONS-node1:16020-0] master.RegionStates: Transition

      {0738e3fac8ffe40d656dc91588a47aac state=OFFLINE, ts=1435897760704, server=null}

      to

      {0738e3fac8ffe40d656dc91588a47aac state=PENDING_OPEN, ts=1435897760717, server=node1.vmcluster,16040,1435897652505}
      2015-07-03 13:29:20,729 WARN [MASTER_TABLE_OPERATIONS-node1:16020-0] zookeeper.ZKTableStateManager: Moving table tsdb-meta state from ENABLING to ENABLED
      2015-07-03 13:29:20,734 INFO [AM.ZK.Worker-pool2-t33] master.RegionStates: Transition {0738e3fac8ffe40d656dc91588a47aac state=PENDING_OPEN, ts=1435897760717, server=node1.vmcluster,16040,1435897652505}

      to

      {0738e3fac8ffe40d656dc91588a47aac state=OPENING, ts=1435897760734, server=node1.vmcluster,16040,1435897652505}
      2015-07-03 13:29:20,748 INFO [MASTER_TABLE_OPERATIONS-node1:16020-0] handler.CreateTableHandler: failed. null
      2015-07-03 13:29:20,772 INFO [AM.ZK.Worker-pool2-t35] master.RegionStates: Transition {0738e3fac8ffe40d656dc91588a47aac state=OPENING, ts=1435897760734, server=node1.vmcluster,16040,1435897652505}

      to

      {0738e3fac8ffe40d656dc91588a47aac state=OPEN, ts=1435897760772, server=node1.vmcluster,16040,1435897652505}

      2015-07-03 13:29:20,774 INFO [AM.ZK.Worker-pool2-t35] master.RegionStates: Onlined 0738e3fac8ffe40d656dc91588a47aac on node1.vmcluster,16040,1435897652505
      2015-07-03 16:43:27,970 ERROR [B.defaultRpcServer.handler=15,queue=0,port=16020] master.MasterRpcServices: Region server node1.vmcluster,16040,1435897652505 reported a fatal error:
      ABORTING region server node1.vmcluster,16040,1435897652505: Replay of WAL required. Forcing server shutdown
      Cause:
      org.apache.hadoop.hbase.DroppedSnapshotException: region: tsdb,,1435897759785.2d49cd81fb6513f51af58bd0394c4e0d.
      at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:2001)
      at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1772)
      at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1704)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:445)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:407)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:69)
      at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:225)
      at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.ArrayIndexOutOfBoundsException: -32743
      at org.apache.hadoop.hbase.CellComparator.getMinimumMidpointArray(CellComparator.java:478)
      at org.apache.hadoop.hbase.CellComparator.getMidpoint(CellComparator.java:448)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.finishBlock(HFileWriterV2.java:165)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.checkBlockBoundary(HFileWriterV2.java:146)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.append(HFileWriterV2.java:263)
      at org.apache.hadoop.hbase.io.hfile.HFileWriterV3.append(HFileWriterV3.java:87)
      at org.apache.hadoop.hbase.regionserver.StoreFile$Writer.append(StoreFile.java:932)
      at org.apache.hadoop.hbase.regionserver.StoreFlusher.performFlush(StoreFlusher.java:121)
      at org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:71)
      at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:879)
      at org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:2128)
      at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1955)
      ... 7 more

      2015-07-03 16:43:32,595 INFO [main-EventThread] zookeeper.RegionServerTracker: RegionServer ephemeral node deleted, processing expiration [node1.vmcluster,16040,1435897652505]
      2015-07-03 16:43:32,611 INFO [MASTER_META_SERVER_OPERATIONS-node1:16020-0] handler.MetaServerShutdownHandler: Splitting hbase:meta logs for node1.vmcluster,16040,1435897652505
      2015-07-03 16:43:32,627 INFO [MASTER_META_SERVER_OPERATIONS-node1:16020-0] master.SplitLogManager: dead splitlog workers [node1.vmcluster,16040,1435897652505]
      2015-07-03 16:43:32,630 INFO [MASTER_META_SERVER_OPERATIONS-node1:16020-0] master.SplitLogManager: started splitting 1 logs in [hdfs://node1.vmcluster:9000/hbase/WALs/node1.vmcluster,16040,1435897652505-splitting] for [node1.vmcluster,16040,1435897652505]

        Attachments

        1. hbase-hadoop-master-node1.vmcluster.log
          855 kB
          Dinh Duong Mai
        2. hbase-hadoop-regionserver-node1.vmcluster.log
          243 kB
          Dinh Duong Mai
        3. hbase-hadoop-zookeeper-node1.vmcluster.log
          316 kB
          Dinh Duong Mai

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                duong_dajgja Dinh Duong Mai
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Due:
                  Created:
                  Updated:
                  Resolved: