stack created HBASE-10025:
-----------------------------
Summary: 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: stack
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
(v6.1#6144)
