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

Region stuck in transition after failed RS_ZK_REGION_FAILED_OPEN

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Closed
    • Major
    • Resolution: Incomplete
    • 0.96.0
    • None
    • Region Assignment
    • None

    Description

      Testing, I just ran into a case where I have a region stuck in transition. We kept trying to open the region but were failing and eventually got stuck. Looks like a block was missing so region may never have been able to open but we likely shouldn't have the region stuck in transition.

      Here is some log snippet from master side only showing lines that mention the region that is failing:

       31 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] master.AssignmentManager: Handling RS_ZK_REGION_FAILED_OPEN, server=c2023.halxg.cloudera.com,60020,1385405351397, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411440853, server=c2023.halxg.cloudera.com,60020,1385405351397}
 30 2013-11-25 12:30:56,111 INFO  [AM.ZK.Worker-pool2-t366] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411440853, server=c2023.halxg.cloudera.com,60020,1385405351397} to {d1485bc64a1a9246908e6af38a89b973 state=CLOSED, ts=1385411456111, server=c2023.halxg.cloudera.com,60020,1385405351397}
 29 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] master.AssignmentManager: Found an existing plan for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973. destination server is c2023.halxg.cloudera.com,60020,1385405351397 accepted as a dest server = false
 28 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] master.AssignmentManager: No previous transition plan found (or ignoring an existing plan) for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.; generated random plan=hri=TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973., src=, dest=c2025.halxg.cloudera.com,60020,1385405351329; 3 (on#
 27 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] handler.ClosedRegionHandler: Handling CLOSED event for d1485bc64a1a9246908e6af38a89b973
 26 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] master.AssignmentManager: Found an existing plan for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973. destination server is c2025.halxg.cloudera.com,60020,1385405351329 accepted as a dest server = true
 25 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] master.AssignmentManager: Using pre-existing plan for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.; plan=hri=TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973., src=, dest=c2025.halxg.cloudera.com,60020,1385405351329
 24 2013-11-25 12:30:56,111 INFO  [AM.ZK.Worker-pool2-t366] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=CLOSED, ts=1385411456111, server=c2023.halxg.cloudera.com,60020,1385405351397} to {d1485bc64a1a9246908e6af38a89b973 state=OFFLINE, ts=1385411456111, server=c2023.halxg.cloudera.com,60020,1385405351397}
 23 2013-11-25 12:30:56,111 DEBUG [AM.ZK.Worker-pool2-t366] zookeeper.ZKAssign: master:60000-0x1429097f3410007, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Creating (or updating) unassigned node d1485bc64a1a9246908e6af38a89b973 with OFFLINE state
 22 2013-11-25 12:30:56,118 INFO  [AM.ZK.Worker-pool2-t366] master.AssignmentManager: Assigning TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973. to c2025.halxg.cloudera.com,60020,1385405351329
 21 2013-11-25 12:30:56,118 INFO  [AM.ZK.Worker-pool2-t366] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=OFFLINE, ts=1385411456111, server=c2023.halxg.cloudera.com,60020,1385405351397} to {d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411456118, server=c2025.halxg.cloudera.com,60020,1385405351329}
 20 2013-11-25 12:30:56,127 DEBUG [AM.ZK.Worker-pool2-t367] master.AssignmentManager: Handling M_ZK_REGION_OFFLINE, server=c2025.halxg.cloudera.com,60020,1385405351329, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411456118, server=c2025.halxg.cloudera.com,60020,1385405351329}
 19 2013-11-25 12:30:56,135 DEBUG [AM.ZK.Worker-pool2-t368] master.AssignmentManager: Handling RS_ZK_REGION_OPENING, server=c2025.halxg.cloudera.com,60020,1385405351329, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411456118, server=c2025.halxg.cloudera.com,60020,1385405351329}
 18 2013-11-25 12:30:56,135 INFO  [AM.ZK.Worker-pool2-t368] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411456118, server=c2025.halxg.cloudera.com,60020,1385405351329} to {d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411456135, server=c2025.halxg.cloudera.com,60020,1385405351329}
 17 2013-11-25 12:31:10,594 DEBUG [c2020.halxg.cloudera.com,60000,1385405460201-BalancerChore] master.HMaster: Not running balancer because 1 region(s) in transition: {d1485bc64a1a9246908e6af38a89b973={d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411456135, server=c2025.halxg.cloudera.com,60020,1385405351329}}
 16 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] master.AssignmentManager: Handling RS_ZK_REGION_FAILED_OPEN, server=c2025.halxg.cloudera.com,60020,1385405351329, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411456135, server=c2025.halxg.cloudera.com,60020,1385405351329}
 15 2013-11-25 12:31:15,368 INFO  [AM.ZK.Worker-pool2-t369] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411456135, server=c2025.halxg.cloudera.com,60020,1385405351329} to {d1485bc64a1a9246908e6af38a89b973 state=CLOSED, ts=1385411475368, server=c2025.halxg.cloudera.com,60020,1385405351329}
 14 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] master.AssignmentManager: Found an existing plan for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973. destination server is c2025.halxg.cloudera.com,60020,1385405351329 accepted as a dest server = false
 13 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] master.AssignmentManager: No previous transition plan found (or ignoring an existing plan) for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.; generated random plan=hri=TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973., src=, dest=c2024.halxg.cloudera.com,60020,1385405351453; 3 (on#
 12 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] handler.ClosedRegionHandler: Handling CLOSED event for d1485bc64a1a9246908e6af38a89b973
 11 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] master.AssignmentManager: Found an existing plan for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973. destination server is c2024.halxg.cloudera.com,60020,1385405351453 accepted as a dest server = true
 10 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] master.AssignmentManager: Using pre-existing plan for TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.; plan=hri=TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973., src=, dest=c2024.halxg.cloudera.com,60020,1385405351453
  9 2013-11-25 12:31:15,368 INFO  [AM.ZK.Worker-pool2-t369] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=CLOSED, ts=1385411475368, server=c2025.halxg.cloudera.com,60020,1385405351329} to {d1485bc64a1a9246908e6af38a89b973 state=OFFLINE, ts=1385411475368, server=c2025.halxg.cloudera.com,60020,1385405351329}
  8 2013-11-25 12:31:15,368 DEBUG [AM.ZK.Worker-pool2-t369] zookeeper.ZKAssign: master:60000-0x1429097f3410007, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Creating (or updating) unassigned node d1485bc64a1a9246908e6af38a89b973 with OFFLINE state
  7 2013-11-25 12:31:15,375 INFO  [AM.ZK.Worker-pool2-t369] master.AssignmentManager: Assigning TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973. to c2024.halxg.cloudera.com,60020,1385405351453
  6 2013-11-25 12:31:15,375 INFO  [AM.ZK.Worker-pool2-t369] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=OFFLINE, ts=1385411475368, server=c2025.halxg.cloudera.com,60020,1385405351329} to {d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411475375, server=c2024.halxg.cloudera.com,60020,1385405351453}
  5 2013-11-25 12:31:15,382 DEBUG [AM.ZK.Worker-pool2-t370] master.AssignmentManager: Handling M_ZK_REGION_OFFLINE, server=c2024.halxg.cloudera.com,60020,1385405351453, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411475375, server=c2024.halxg.cloudera.com,60020,1385405351453}
  4 2013-11-25 12:31:15,392 DEBUG [AM.ZK.Worker-pool2-t371] master.AssignmentManager: Handling RS_ZK_REGION_OPENING, server=c2024.halxg.cloudera.com,60020,1385405351453, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411475375, server=c2024.halxg.cloudera.com,60020,1385405351453}
  3 2013-11-25 12:31:15,393 INFO  [AM.ZK.Worker-pool2-t371] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=PENDING_OPEN, ts=1385411475375, server=c2024.halxg.cloudera.com,60020,1385405351453} to {d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411475393, server=c2024.halxg.cloudera.com,60020,1385405351453}
  2 2013-11-25 12:31:27,436 DEBUG [AM.ZK.Worker-pool2-t372] master.AssignmentManager: Handling RS_ZK_REGION_FAILED_OPEN, server=c2024.halxg.cloudera.com,60020,1385405351453, region=d1485bc64a1a9246908e6af38a89b973, current_state={d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411475393, server=c2024.halxg.cloudera.com,60020,1385405351453}
  1 2013-11-25 12:31:27,436 WARN  [AM.ZK.Worker-pool2-t372] master.RegionStates: Failed to open/close d1485bc64a1a9246908e6af38a89b973 on c2024.halxg.cloudera.com,60020,1385405351453, set to FAILED_OPEN
  0 2013-11-25 12:31:27,436 INFO  [AM.ZK.Worker-pool2-t372] master.RegionStates: Transitioned {d1485bc64a1a9246908e6af38a89b973 state=OPENING, ts=1385411475393, server=c2024.halxg.cloudera.com,60020,1385405351453} to {d1485bc64a1a9246908e6af38a89b973 state=FAILED_OPEN, ts=1385411487436, server=c2024.halxg.cloudera.com,60020,1385405351453}
  1 2013-11-25 12:36:10,595 DEBUG [c2020.halxg.cloudera.com,60000,1385405460201-BalancerChore] master.HMaster: Not running balancer because 1 region(s) in transition: {d1485bc64a1a9246908e6af38a89b973={d1485bc64a1a9246908e6af38a89b973 state=FAILED_OPEN, ts=1385411487436, server=c2024.halxg.cloudera.com,60020,1385405351453}}
  2 2013-11-25 12:41:10,595 DEBUG [c2020.halxg.cloudera.com,60000,1385405460201-BalancerChore] master.HMaster: Not running balancer because 1 region(s) in transition: {d1485bc64a1a9246908e6af38a89b973={d1485bc64a1a9246908e6af38a89b973 state=FAILED_OPEN, ts=1385411487436, server=c2024.halxg.cloudera.com,60020,1385405351453}}
  3 2013-11-25 12:46:10,596 DEBUG [c2020.halxg.cloudera.com,60000,1385405460201-BalancerChore] master.HMaster: Not running balancer because 1 region(s) in transition: {d1485bc64a1a9246908e6af38a89b973={d1485bc64a1a9246908e6af38a89b973 state=FAILED_OPEN, ts=1385411487436, server=c2024.halxg.cloudera.com,60020,1385405351453}}
  4 2013-11-25 12:51:10,595 DEBUG [c2020.halxg.cloudera.com,60000,1385405460201-BalancerChore] master.HMaster: Not running balancer because 1 region(s) in transition: {d1485bc64a1a9246908e6af38a89b973={d1485bc64a1a9246908e6af38a89b973 state=FAILED_OPEN, ts=1385411487436, server=c2024.halxg.cloudera.com,60020,1385405351453}}
  5 2013-11-25 12:56:10,595 DEBUG [c2020.halxg.cloudera.com,60000,1385405460201-BalancerChore] master.HMaster: Not running balancer because 1 region(s) in transition: {d1485bc64a1a9246908e6af38a89b973={d1485bc64a1a9246908e6af38a89b973 state=FAILED_OPEN, ts=1385411487436, server=c2024.halxg.cloudera.com,60020,1385405351453}}

      Here is log from the regionserver side on last open attempt:

      2013-11-25 12:29:40,648 INFO  [RS_OPEN_REGION-c2024:60020-1] handler.OpenRegionHandler: Opening of region {ENCODED => d1485bc64a1a9246908e6af38a89b973, NAME => 'TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.', STARTKEY => '', ENDKEY => '00000000000000000005329216'} failed, transitioning from OPENING to FAILED_OPEN in ZK, expecting version 10
2013-11-25 12:29:40,648 DEBUG [RS_OPEN_REGION-c2024:60020-1] zookeeper.ZKAssign: regionserver:60020-0x1429097f3410003, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Transitioning d1485bc64a1a9246908e6af38a89b973 from RS_ZK_REGION_OPENING to RS_ZK_REGION_FAILED_OPEN
2013-11-25 12:29:40,663 DEBUG [RS_OPEN_REGION-c2024:60020-1] zookeeper.ZKAssign: regionserver:60020-0x1429097f3410003, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Transitioned node d1485bc64a1a9246908e6af38a89b973 from RS_ZK_REGION_OPENING to RS_ZK_REGION_FAILED_OPEN
2013-11-25 12:31:15,376 INFO  [Priority.RpcServer.handler=0,port=60020] regionserver.HRegionServer: Open TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.
2013-11-25 12:31:15,380 DEBUG [RS_OPEN_REGION-c2024:60020-0] zookeeper.ZKAssign: regionserver:60020-0x1429097f3410003, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Transitioning d1485bc64a1a9246908e6af38a89b973 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2013-11-25 12:31:15,390 DEBUG [RS_OPEN_REGION-c2024:60020-0] zookeeper.ZKAssign: regionserver:60020-0x1429097f3410003, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Transitioned node d1485bc64a1a9246908e6af38a89b973 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2013-11-25 12:31:15,390 DEBUG [RS_OPEN_REGION-c2024:60020-0] regionserver.HRegion: Opening region: {ENCODED => d1485bc64a1a9246908e6af38a89b973, NAME => 'TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.', STARTKEY => '', ENDKEY => '00000000000000000005329216'}
2013-11-25 12:31:15,391 DEBUG [RS_OPEN_REGION-c2024:60020-0] regionserver.MetricsRegionSourceImpl: Creating new MetricsRegionSourceImpl for table TestTable d1485bc64a1a9246908e6af38a89b973
2013-11-25 12:31:15,391 DEBUG [RS_OPEN_REGION-c2024:60020-0] regionserver.HRegion: Instantiated TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.
2013-11-25 12:31:15,396 INFO  [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] compactions.CompactionConfiguration: size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000
2013-11-25 12:31:15,410 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/0b11ea6ce17f47269518d8ebdad7317f, isReference=false, isBulkLoadResult=false, seqid=37383, majorCompaction=false
2013-11-25 12:31:15,421 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/1f8d0ce7df434557949e4d6abd007763, isReference=false, isBulkLoadResult=false, seqid=34710, majorCompaction=false
2013-11-25 12:31:15,427 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/3ccc4c67a02745ecbca04f45faf49843, isReference=false, isBulkLoadResult=false, seqid=37300, majorCompaction=false
2013-11-25 12:31:15,434 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/4664bc35374b4a7db7f8920449ac539c, isReference=false, isBulkLoadResult=false, seqid=36624, majorCompaction=false
2013-11-25 12:31:15,441 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/646293ad1fc44ad589bdcb27195d19df, isReference=false, isBulkLoadResult=false, seqid=37227, majorCompaction=false
2013-11-25 12:31:15,444 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: No node available for BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 file=/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
2013-11-25 12:31:15,444 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: Could not obtain BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 from any node: java.io.IOException: No live nodes contain current block. Will get new block locations from namenode and retry...
2013-11-25 12:31:15,444 WARN  [StoreFileOpenerThread-info-1] hdfs.DFSClient: DFS chooseDataNode: got # 1 IOException, will wait for 2303.229529558494 msec.
2013-11-25 12:31:17,749 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: No node available for BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 file=/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
2013-11-25 12:31:17,749 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: Could not obtain BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 from any node: java.io.IOException: No live nodes contain current block. Will get new block locations from namenode and retry...
2013-11-25 12:31:17,749 WARN  [StoreFileOpenerThread-info-1] hdfs.DFSClient: DFS chooseDataNode: got # 2 IOException, will wait for 3539.589126663613 msec.
2013-11-25 12:31:21,290 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: No node available for BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 file=/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
2013-11-25 12:31:21,290 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: Could not obtain BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 from any node: java.io.IOException: No live nodes contain current block. Will get new block locations from namenode and retry...
2013-11-25 12:31:21,290 WARN  [StoreFileOpenerThread-info-1] hdfs.DFSClient: DFS chooseDataNode: got # 3 IOException, will wait for 6005.249913877286 msec.
2013-11-25 12:31:27,298 WARN  [StoreFileOpenerThread-info-1] hdfs.DFSClient: DFS Read
2013-11-25 12:31:21,290 INFO  [StoreFileOpenerThread-info-1] hdfs.DFSClient: Could not obtain BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 from any node: java.io.IOException: No live nodes contain current block. Will get new block locations from namenode and retry...
2013-11-25 12:31:21,290 WARN  [StoreFileOpenerThread-info-1] hdfs.DFSClient: DFS chooseDataNode: got # 3 IOException, will wait for 6005.249913877286 msec.
2013-11-25 12:31:27,298 WARN  [StoreFileOpenerThread-info-1] hdfs.DFSClient: DFS Read
org.apache.hadoop.hdfs.BlockMissingException: Could not obtain block: BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 file=/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
        at org.apache.hadoop.hdfs.DFSInputStream.chooseDataNode(DFSInputStream.java:838)
        at org.apache.hadoop.hdfs.DFSInputStream.blockSeekTo(DFSInputStream.java:526)
        at org.apache.hadoop.hdfs.DFSInputStream.readWithStrategy(DFSInputStream.java:749)
        at org.apache.hadoop.hdfs.DFSInputStream.read(DFSInputStream.java:793)
        at java.io.DataInputStream.readFully(DataInputStream.java:195)
        at org.apache.hadoop.hbase.io.hfile.FixedFileTrailer.readFromStream(FixedFileTrailer.java:415)
        at org.apache.hadoop.hbase.io.hfile.HFile.pickReaderVersion(HFile.java:567)
        at org.apache.hadoop.hbase.io.hfile.HFile.createReader(HFile.java:607)
        at org.apache.hadoop.hbase.regionserver.StoreFile$Reader.<init>(StoreFile.java:1083)
        at org.apache.hadoop.hbase.regionserver.StoreFileInfo.open(StoreFileInfo.java:188)
        at org.apache.hadoop.hbase.regionserver.StoreFile.open(StoreFile.java:351)
        at org.apache.hadoop.hbase.regionserver.StoreFile.createReader(StoreFile.java:446)
        at org.apache.hadoop.hbase.regionserver.HStore.createStoreFileAndReader(HStore.java:472)
        at org.apache.hadoop.hbase.regionserver.HStore.access$000(HStore.java:109)
        at org.apache.hadoop.hbase.regionserver.HStore$1.call(HStore.java:425)
        at org.apache.hadoop.hbase.regionserver.HStore$1.call(HStore.java:422)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)
2013-11-25 12:31:27,306 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/cbbb02d1fe254ec28b28b692247fe2a3, isReference=false, isBulkLoadResult=false, seqid=36367, majorCompaction=false
2013-11-25 12:31:27,330 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/dc4bd223cb6e4e169450aa4dc511b436, isReference=false, isBulkLoadResult=false, seqid=25056, majorCompaction=true
2013-11-25 12:31:27,358 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/e5d87d2d22474c20973543b7009862d3, isReference=false, isBulkLoadResult=false, seqid=28805, majorCompaction=false
2013-11-25 12:31:27,366 DEBUG [StoreOpener-d1485bc64a1a9246908e6af38a89b973-1] regionserver.HStore: loaded hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/f7822308175c4bedbcb8a657ebbebdd1, isReference=false, isBulkLoadResult=false, seqid=36090, majorCompaction=false
2013-11-25 12:31:27,393 ERROR [RS_OPEN_REGION-c2024:60020-0] handler.OpenRegionHandler: Failed open of region=TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973., starting to roll back the global memstore size.
java.io.IOException: java.io.IOException: org.apache.hadoop.hbase.io.hfile.CorruptHFileException: Problem reading HFile Trailer from file hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
        at org.apache.hadoop.hbase.regionserver.HRegion.initializeRegionStores(HRegion.java:700)
        at org.apache.hadoop.hbase.regionserver.HRegion.initializeRegionInternals(HRegion.java:616)
        at org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:587)
        at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4115)
        at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4086)
        at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:4037)
        at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:3988)
        at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:475)
        at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:140)
        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)
Caused by: java.io.IOException: org.apache.hadoop.hbase.io.hfile.CorruptHFileException: Problem reading HFile Trailer from file hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
        at org.apache.hadoop.hbase.regionserver.HStore.loadStoreFiles(HStore.java:450)
        at org.apache.hadoop.hbase.regionserver.HStore.<init>(HStore.java:239)
        at org.apache.hadoop.hbase.regionserver.HRegion.instantiateHStore(HRegion.java:3090)
        at org.apache.hadoop.hbase.regionserver.HRegion$1.call(HRegion.java:673)
        at org.apache.hadoop.hbase.regionserver.HRegion$1.call(HRegion.java:670)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        ... 3 more
Caused by: org.apache.hadoop.hbase.io.hfile.CorruptHFileException: Problem reading HFile Trailer from file hdfs://c2020.halxg.cloudera.com:8020/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
        at org.apache.hadoop.hbase.io.hfile.HFile.pickReaderVersion(HFile.java:581)
        at org.apache.hadoop.hbase.io.hfile.HFile.createReader(HFile.java:607)
        at org.apache.hadoop.hbase.regionserver.StoreFile$Reader.<init>(StoreFile.java:1083)
        at org.apache.hadoop.hbase.regionserver.StoreFileInfo.open(StoreFileInfo.java:188)
        at org.apache.hadoop.hbase.regionserver.StoreFile.open(StoreFile.java:351)
        at org.apache.hadoop.hbase.regionserver.StoreFile.createReader(StoreFile.java:446)
        at org.apache.hadoop.hbase.regionserver.HStore.createStoreFileAndReader(HStore.java:472)
        at org.apache.hadoop.hbase.regionserver.HStore.access$000(HStore.java:109)
        at org.apache.hadoop.hbase.regionserver.HStore$1.call(HStore.java:425)
        at org.apache.hadoop.hbase.regionserver.HStore$1.call(HStore.java:422)
        ... 6 more
Caused by: org.apache.hadoop.hdfs.BlockMissingException: Could not obtain block: BP-1665758641-10.20.84.26-1385096579215:blk_1073772825_32007 file=/hbase_094/data/default/TestTable/d1485bc64a1a9246908e6af38a89b973/info/881468a5db134daaa621661a1edfbb2b
        at org.apache.hadoop.hdfs.DFSInputStream.chooseDataNode(DFSInputStream.java:838)
        at org.apache.hadoop.hdfs.DFSInputStream.blockSeekTo(DFSInputStream.java:526)
        at org.apache.hadoop.hdfs.DFSInputStream.readWithStrategy(DFSInputStream.java:749)
        at org.apache.hadoop.hdfs.DFSInputStream.read(DFSInputStream.java:793)
        at java.io.DataInputStream.readFully(DataInputStream.java:195)
        at org.apache.hadoop.hbase.io.hfile.FixedFileTrailer.readFromStream(FixedFileTrailer.java:415)
        at org.apache.hadoop.hbase.io.hfile.HFile.pickReaderVersion(HFile.java:567)
        ... 15 more
2013-11-25 12:31:27,395 INFO  [RS_OPEN_REGION-c2024:60020-0] handler.OpenRegionHandler: Opening of region {ENCODED => d1485bc64a1a9246908e6af38a89b973, NAME => 'TestTable,,1385406553349.d1485bc64a1a9246908e6af38a89b973.', STARTKEY => '', ENDKEY => '00000000000000000005329216'} failed, transitioning from OPENING to FAILED_OPEN in ZK, expecting version 28
2013-11-25 12:31:27,395 DEBUG [RS_OPEN_REGION-c2024:60020-0] zookeeper.ZKAssign: regionserver:60020-0x1429097f3410003, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Transitioning d1485bc64a1a9246908e6af38a89b973 from RS_ZK_REGION_OPENING to RS_ZK_REGION_FAILED_OPEN
2013-11-25 12:31:27,433 DEBUG [RS_OPEN_REGION-c2024:60020-0] zookeeper.ZKAssign: regionserver:60020-0x1429097f3410003, quorum=c2020.halxg.cloudera.com:2181, baseZNode=/hbase Transitioned node d1485bc64a1a9246908e6af38a89b973 from RS_ZK_REGION_OPENING to RS_ZK_REGION_FAILED_OPEN

      Attachments

        Issue Links

          is related to

          Task - A task that needs to be done. HBASE-14350 Procedure V2 Phase 2: Assignment Manager

          • Blocker - Blocks development and/or testing work, production could not run
          • Closed

          Activity

            People

              Unassigned Unassigned
              stack Michael Stack
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: