You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by "Andrew Kyle Purtell (Jira)" <ji...@apache.org> on 2022/06/17 15:29:00 UTC
[jira] [Resolved] (HBASE-10025) Region stuck in transition after failed RS_ZK_REGION_FAILED_OPEN
[ https://issues.apache.org/jira/browse/HBASE-10025?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Andrew Kyle Purtell resolved HBASE-10025.
-----------------------------------------
Resolution: Incomplete
> Region stuck in transition after failed RS_ZK_REGION_FAILED_OPEN
> ----------------------------------------------------------------
>
> Key: HBASE-10025
> URL: https://issues.apache.org/jira/browse/HBASE-10025
> Project: HBase
> Issue Type: Bug
> Components: Region Assignment
> Affects Versions: 0.96.0
> Reporter: Michael Stack
> Priority: Major
>
> 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:
> {code}
> 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}}
> {code}
> Here is log from the regionserver side on last open attempt:
> {code}
> 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
> {code}
--
This message was sent by Atlassian Jira
(v8.20.7#820007)