You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by "stack (JIRA)" <ji...@apache.org> on 2009/07/02 05:32:47 UTC
[jira] Created: (HBASE-1603) MR failed "RetriesExhaustedException:
Trying to contact region server Some server for region TestTable..."
MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
----------------------------------------------------------------------------------------------------------
Key: HBASE-1603
URL: https://issues.apache.org/jira/browse/HBASE-1603
Project: Hadoop HBase
Issue Type: Bug
Reporter: stack
Fix For: 0.20.0
Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
{code}
2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
Exceptions:
...
{code}
Why after ten attempts did the client not find the region?
{code}
2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
{code}
Here is over on the regionserver:
{code}
2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
{code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12727817#action_12727817 ]
stack commented on HBASE-1603:
------------------------------
Looks like we are making incorrect splits:
{code}
2009-07-06 21:29:00,591 [regionserver/208.76.44.141:60020.compactor] INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread: region split, META updated, and report to master all successful. Old region=REGION => {NAME => 'TestTable,\x00\x04\x05\x02\x01\x04\x09
\x09\x05\x03,1246915671694', STARTKEY => '\x00\x04\x05\x02\x01\x04\x09\x09\x05\x03', ENDKEY => '', ENCODED => 532846028, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', COMPRESSION => 'NONE', VERSIONS => '3', TTL => '21
47483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, new regions: TestTable,\x00\x04\x05\x02\x01\x04\x09\x09\x05\x03,1246915729181, TestTable,\x00\x03\x09\x02\x04\x09\x04\x08\x01\x04,1246915729181. Split took 11sec
{code}
It would seem we're making split with a key that is less than that of the parent region (if the binary output can be trusted);
TestTable,\x00\x03\x09\x02\x04\x09\x04\x08\x01\x04,1246915729181 is <
TestTable,\x00\x04\x05\x02\x01\x04\x09\x09\x05\x03,1246915671694
@Andrew -- I'm looking for Andrew Lee issue...
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12727135#action_12727135 ]
stack commented on HBASE-1603:
------------------------------
This seems pretty easy to manufacture on our small test cluster. I even seen it local doing PE up into standalone cluster.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (HBASE-1603) MR failed "RetriesExhaustedException:
Trying to contact region server Some server for region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack updated HBASE-1603:
-------------------------
Attachment: debugging-v4.patch
Debugs and better reporting of binary in exceptions. Helpful debugging this issue so far.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
> Attachments: debugging-v4.patch
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12727713#action_12727713 ]
stack commented on HBASE-1603:
------------------------------
Added debugging to regionserver. I see WrongRegionException: "Requested row out of range for ..." doing batch Puts. Trying to figure if this issue in client cache of regions.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "mikhail (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12751141#action_12751141 ]
mikhail commented on HBASE-1603:
--------------------------------
I am getting what looks like a reappearance of this issue. I am trying to insert approximately 70 million pieces into an HBase instance (trunk version 808546 checked out in late August, so I assume it contains the fix from 1615). My mappers fail on flushCommit with the following:
org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server, retryOnlyOne=true, index=0, islastrow=false, tries=9, numtries=10, i=234, listsize=1504, location=address: 172.18.56.122:60020, regioninfo: REGION => {NAME => 'dailies__exact_dup_stats.PER_SRC_ENTITY_TS,\x0DDennis\x20Bonnen,1251999874064', STARTKEY => '\x0DDennis\x20Bonnen', ENDKEY => '\x0ECHARITY\x20BASKET', ENCODED => 535563176, TABLE => {{NAME => 'dailies__exact_dup_stats.PER_SRC_ENTITY_TS', FAMILIES => [{NAME => 'd', VERSIONS => '1', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'date_ranges', VERSIONS => '1', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, region=dailies__exact_dup_stats.PER_SRC_ENTITY_TS,\x0DDennis\x20Bonnen,1251999874064 for region dailies__exact_dup_stats.PER_SRC_ENTITY_TS,\x0DDennis\x20Bonnen,1251999874064, row '\x0DWalt\x20Stanfill', but failed after 10 attempts.
Exceptions:
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.processBatchOfRows(HConnectionManager.java:1040)
at org.apache.hadoop.hbase.client.HTable.flushCommits(HTable.java:582)
at org.apache.hadoop.hbase.client.HTable.put(HTable.java:448)
at com.textmap.freedonia.db.hbase.ArtifactHBaseExporter$HBaseArtifactExportMapper.map(ArtifactHBaseExporter.java:172)
at com.textmap.freedonia.db.hbase.ArtifactHBaseExporter$HBaseArtifactExportMapper.map(ArtifactHBaseExporter.java:120)
at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:356)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:305)
at org.apache.hadoop.mapred.Child.main(Child.java:170)
On the master, I'm getting the following:
2009-09-03 16:23:28,331 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner scanning meta region {server: 172.18.56.115:60020, regionname: -ROOT-,,0, startKey:
<>}
2009-09-03 16:23:38,583 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner scan of 1 row(s) of meta region {server: 172.18.56.115:60020, regionname: -ROOT-,,0,
startKey: <>} complete
2009-09-03 16:24:28,147 INFO org.apache.hadoop.hbase.master.ServerManager: 14 region servers, 0 dead, average load 1.2
2009-09-03 16:24:28,257 INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner scanning meta region {server: 172.18.56.107:60020, regionname: .META.,,1, startKey:
<>}
2009-09-03 16:24:28,261 WARN org.apache.hadoop.hbase.master.BaseScanner: Scan one META region: {server: 172.18.56.107:60020, regionname: .META.,,1, startKey: <>}
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
at sun.reflect.GeneratedConstructorAccessor15.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at org.apache.hadoop.hbase.RemoteExceptionHandler.decodeRemoteException(RemoteExceptionHandler.java:94)
at org.apache.hadoop.hbase.master.BaseScanner.scanRegion(BaseScanner.java:191)
at org.apache.hadoop.hbase.master.MetaScanner.scanOneMetaRegion(MetaScanner.java:73)
at org.apache.hadoop.hbase.master.MetaScanner.maintenanceScan(MetaScanner.java:129)
at org.apache.hadoop.hbase.master.BaseScanner.chore(BaseScanner.java:135)
at org.apache.hadoop.hbase.Chore.run(Chore.java:68)
On some regionservers, the following repeats in the logs:
2009-09-03 16:25:28,255 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 5 on 60020, call openScanner([B@ef0bc8a, startRow=, stopRow=, maxVersions=1, caching=-1, timeRange=[0,9223372036854775807), families={(family=info, columns={}}) from 172.18.56.105:35045: error: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
2009-09-03 16:25:30,371 DEBUG org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: Total=3.2688217MB (3427608), Free=395.06866MB (414259528), Max=398.3375MB (417687136), Counts: Blocks=0, Access=0, Hit=0, Miss=0, Evictions=0, Evicted=0, Ratios: Hit Ratio=NaN%, Miss Ratio=NaN%, Evicted/Run=NaN
On other regionservers, there are no exceptions, only messages like this:
2009-09-03 16:26:36,647 DEBUG org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes: Total=3.2688217MB (3427608), Free=395.06866MB (414259528), Max=398.3375MB (417687136)
, Counts: Blocks=0, Access=0, Hit=0, Miss=0, Evictions=0, Evicted=0, Ratios: Hit Ratio=NaN%, Miss Ratio=NaN%, Evicted/Run=NaN
The web UI also goes down when the job fails -- master.jsp gives me the following:
Trying to contact region server 172.18.56.107:60020 for region .META.,,1, row '', but failed after 3 attempts.
Exceptions:
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
RequestURI=/master.jsp
Caused by:
org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server 172.18.56.107:60020 for region .META.,,1, row '', but failed after 3 attempts.
Exceptions:
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hbase.NotServingRegionException: .META.,,1
at org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2261)
at org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1877)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:650)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.getRegionServerWithRetries(HConnectionManager.java:936)
at org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:54)
at org.apache.hadoop.hbase.client.MetaScanner.metaScan(MetaScanner.java:28)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.listTables(HConnectionManager.java:369)
at org.apache.hadoop.hbase.client.HBaseAdmin.listTables(HBaseAdmin.java:127)
at org.apache.hadoop.hbase.generated.master.master_jsp._jspService(master_jsp.java:125)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:97)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:363)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:324)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:864)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:533)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:207)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:403)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:522)
Please let me know if this looks like the same problem or a different problem / API misuse on my part.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Attachments: debugging-v4.patch
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12729795#action_12729795 ]
stack commented on HBASE-1603:
------------------------------
I committed this debugging patch. Will help if we see this issue again. Also had fix up for when exceptions throw with messages that have binary data in it and some small javadoc fixes.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
> Attachments: debugging-v4.patch
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12727729#action_12727729 ]
stack commented on HBASE-1603:
------------------------------
The .meta. table is all wonky:
{code}
2009-07-06 18:54:30,763 [RegionManager.metaScanner] INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner scanning meta region {server: X.X.X.140:60020, regionname: .META.,,1, startKey: <>}
2009-07-06 18:54:30,768 [RegionManager.rootScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', MEMSTORE_FLUSHSIZE => '16384', FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}, serverName=X.X.X.140:60020, startCode=1246905530242
2009-07-06 18:54:30,769 [RegionManager.rootScanner] INFO org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner scan of 1 row(s) of meta region {server: X.X.X.142:60020, regionname: -ROOT-,,0, startKey: <>} complete
2009-07-06 18:54:30,771 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,,1246905732395', STARTKEY => '', ENDKEY => '\x00\x03\x02\x04\x07\x03\x07\x08\x00\x06', ENCODED => 340516641, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.142:60020, startCode=1246905530240
2009-07-06 18:54:30,773 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,,1246905998094', STARTKEY => '', ENDKEY => '\x00\x02\x03\x08\x09\x06\x05\x04\x03\x00', ENCODED => 815443872, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.142:60020, startCode=1246905530240
2009-07-06 18:54:30,775 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,,1246906356948', STARTKEY => '', ENDKEY => '\x00\x02\x03\x04\x09\x03\x03\x08\x01\x06', ENCODED => 660737141, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.142:60020, startCode=1246905530240
2009-07-06 18:54:30,776 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x02\x03\x04\x09\x03\x03\x08\x01\x06,1246906356948', STARTKEY => '\x00\x02\x03\x04\x09\x03\x03\x08\x01\x06', ENDKEY => '\x00\x02\x03\x08\x09\x06\x05\x04\x03\x00', ENCODED => 215524477, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.142:60020, startCode=1246905530240
2009-07-06 18:54:30,778 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x02\x03\x08\x09\x06\x05\x04\x03\x00,1246905998094', STARTKEY => '\x00\x02\x03\x08\x09\x06\x05\x04\x03\x00', ENDKEY => '\x00\x03\x02\x04\x07\x03\x07\x08\x00\x06', ENCODED => 1847085961, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.142:60020, startCode=1246905530240
2009-07-06 18:54:30,779 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x02\x04\x06\x09\x01\x09\x05\x04,1246905800311', STARTKEY => '\x00\x03\x02\x04\x06\x09\x01\x09\x05\x04', ENDKEY => '\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03', ENCODED => 2063095684, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.140:60020, startCode=1246905530242
2009-07-06 18:54:30,781 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x02\x04\x07\x03\x07\x08\x00\x06,1246905800311', STARTKEY => '\x00\x03\x02\x04\x07\x03\x07\x08\x00\x06', ENDKEY => '\x00\x03\x02\x04\x06\x09\x01\x09\x05\x04', ENCODED => 398435244, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.140:60020, startCode=1246905530242
2009-07-06 18:54:30,782 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x06\x05\x00\x09\x03\x03\x06\x07,1246905805297', STARTKEY => '\x00\x03\x06\x05\x00\x09\x03\x03\x06\x07', ENDKEY => '\x00\x03\x09\x02\x04\x09\x01\x01\x06\x07', ENCODED => 568573022, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
2009-07-06 18:54:30,784 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x07\x00\x03\x05\x09\x07\x03\x05,1246906209734', STARTKEY => '\x00\x03\x07\x00\x03\x05\x09\x07\x03\x05', ENDKEY => '\x00\x03\x06\x05\x00\x09\x03\x03\x06\x07', ENCODED => 1135953828, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.142:60020, startCode=1246905530240
2009-07-06 18:54:30,786 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03,1246905647779', STARTKEY => '\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03', ENDKEY => '\x00\x03\x09\x02\x04\x09\x01\x01\x06\x07', ENCODED => 1638479249, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
2009-07-06 18:54:30,787 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03,1246905805297', STARTKEY => '\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03', ENDKEY => '\x00\x03\x06\x05\x00\x09\x03\x03\x06\x07', ENCODED => 585504103, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.140:60020, startCode=1246905530242
2009-07-06 18:54:30,788 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03,1246906209734', STARTKEY => '\x00\x03\x07\x00\x03\x08\x04\x09\x09\x03', ENDKEY => '\x00\x03\x07\x00\x03\x05\x09\x07\x03\x05', ENCODED => 1683674128, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.140:60020, startCode=1246905530242
2009-07-06 18:54:30,790 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x09\x02\x04\x09\x01\x01\x06\x07,1246905589105', STARTKEY => '\x00\x03\x09\x02\x04\x09\x01\x01\x06\x07', ENDKEY => '', ENCODED => 1426901695, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
2009-07-06 18:54:30,791 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x03\x09\x02\x04\x09\x01\x01\x06\x07,1246905703044', STARTKEY => '\x00\x03\x09\x02\x04\x09\x01\x01\x06\x07', ENDKEY => '\x00\x04\x05\x02\x01\x09\x04\x09\x04\x07', ENCODED => 442661090, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
2009-07-06 18:54:30,792 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x04\x05\x02\x01\x09\x04\x09\x04\x07,1246905703044', STARTKEY => '\x00\x04\x05\x02\x01\x09\x04\x09\x04\x07', ENDKEY => '', ENCODED => 1183734620, OFFLINE => true, SPLIT => true, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
2009-07-06 18:54:30,793 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x04\x05\x02\x01\x09\x04\x09\x04\x07,1246906206915', STARTKEY => '\x00\x04\x05\x02\x01\x09\x04\x09\x04\x07', ENDKEY => '\x00\x06\x05\x01\x05\x04\x07\x08\x05\x07', ENCODED => 1552614533, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
2009-07-06 18:54:30,794 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: ROW hri=REGION => {NAME => 'TestTable,\x00\x06\x05\x01\x05\x04\x07\x08\x05\x07,1246906206915', STARTKEY => '\x00\x06\x05\x01\x05\x04\x07\x08\x05\x07', ENDKEY => '', ENCODED => 373711036, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, serverName=X.X.X.141:60020, startCode=1246905530271
{code}
End keys on one region do not match the start keys no next.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (HBASE-1603) MR failed "RetriesExhaustedException:
Trying to contact region server Some server for region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
stack updated HBASE-1603:
-------------------------
Fix Version/s: (was: 0.20.0)
Moving out of 0.20.0. Root cause seems to have been fixed by 1615. Meantime have better debugging in case this arises again.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Attachments: debugging-v4.patch
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "Andrew Purtell (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12727769#action_12727769 ]
Andrew Purtell commented on HBASE-1603:
---------------------------------------
Great (in a way). This is a reproduction of the issue that Andrew Lee reported last month.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12751205#action_12751205 ]
stack commented on HBASE-1603:
------------------------------
Mikhail: I doubt very much its you. Its a pity you don't have a timestamp for when you saw the RetriesExhaustedException issue. It seems like you are having the issue originally described here and another, the missing .META. region.
I just saw this issue again myself with RC3.
First, the client-side up in the MR task. The task fails because of TestTable,0254895141,1251965526935. It says retries exhausted but it doesn't look like it was trying very had... we timed out too fast it would seem.
{code}
2009-09-03 09:04:05,509 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Removed .META.,,1 for tableName=.META. from cache because of TestTable,0256167115,99999999999999
2009-09-03 09:04:05,512 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Cached location address: XX.XX.44.140:60020, regioninfo: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', MEMSTORE_FLUSHSIZE => '16384', FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
2009-09-03 09:04:07,724 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: locateRegionInMeta attempt 1 of 10 failed; retrying after sleep of 2000
org.apache.hadoop.hbase.client.NoServerForRegionException: No server address listed in .META. for region TestTable,0255035045,1251968451499
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionInMeta(HConnectionManager.java:660)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:586)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.relocateRegion(HConnectionManager.java:555)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.getRegionLocation(HConnectionManager.java:401)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.getRegionLocationForRowWithRetries(HConnectionManager.java:1036)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.processBatchOfRows(HConnectionManager.java:1122)
at org.apache.hadoop.hbase.client.HTable.flushCommits(HTable.java:586)
at org.apache.hadoop.hbase.PerformanceEvaluation$Test.testTakedown(PerformanceEvaluation.java:390)
at org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluation.java:413)
at org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvaluation.java:639)
at org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(PerformanceEvaluation.java:194)
at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:358)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:307)
at org.apache.hadoop.mapred.Child.main(Child.java:170)
2009-09-03 09:04:07,725 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Removed .META.,,1 for tableName=.META. from cache because of TestTable,0256167115,99999999999999
2009-09-03 09:04:07,728 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Cached location address: XX.XX.44.140:60020, regioninfo: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', MEMSTORE_FLUSHSIZE => '16384', FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
2009-09-03 09:04:09,994 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: locateRegionInMeta attempt 2 of 10 failed; retrying after sleep of 2000
org.apache.hadoop.hbase.client.NoServerForRegionException: No server address listed in .META. for region TestTable,0255035045,1251968451499
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionInMeta(HConnectionManager.java:660)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:586)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.relocateRegion(HConnectionManager.java:555)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.getRegionLocation(HConnectionManager.java:401)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.getRegionLocationForRowWithRetries(HConnectionManager.java:1036)
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.processBatchOfRows(HConnectionManager.java:1122)
at org.apache.hadoop.hbase.client.HTable.flushCommits(HTable.java:586)
at org.apache.hadoop.hbase.PerformanceEvaluation$Test.testTakedown(PerformanceEvaluation.java:390)
at org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluation.java:413)
at org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvaluation.java:639)
at org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(PerformanceEvaluation.java:194)
at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:358)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:307)
at org.apache.hadoop.mapred.Child.main(Child.java:170)
2009-09-03 09:04:09,995 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Removed .META.,,1 for tableName=.META. from cache because of TestTable,0256167115,99999999999999
2009-09-03 09:04:09,997 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Cached location address: XX.XX.44.140:60020, regioninfo: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', MEMSTORE_FLUSHSIZE => '16384', FAMILIES => [{NAME => 'historian', VERSIONS => '2147483647', COMPRESSION => 'NONE', TTL => '604800', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}, {NAME => 'info', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'false', BLOCKCACHE => 'false'}]}}
2009-09-03 09:04:12,050 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$TableServers: Cached location address: XX.XX.44.142:60020, regioninfo: REGION => {NAME => 'TestTable,0255035045,1251968451499', STARTKEY => '0255035045', ENDKEY => '0257612642', ENCODED => 2088805037, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}
2009-09-03 09:04:12,816 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server, retryOnlyOne=true, index=0, islastrow=false, tries=9, numtries=10, i=0, listsize=8643, location=address: XX.XX.44.142:60020, regioninfo: REGION => {NAME => 'TestTable,0254895141,1251965526935', STARTKEY => '0254895141', ENDKEY => '0257612642', ENCODED => 1579891142, TABLE => {{NAME => 'TestTable', FAMILIES => [{NAME => 'info', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}, region=TestTable,0254895141,1251965526935 for region TestTable,0254895141,1251965526935, row '0256167115', but failed after 10 attempts.
Exceptions:
at org.apache.hadoop.hbase.client.HConnectionManager$TableServers.processBatchOfRows(HConnectionManager.java:1099)
at org.apache.hadoop.hbase.client.HTable.flushCommits(HTable.java:586)
at org.apache.hadoop.hbase.client.HTable.put(HTable.java:451)
at org.apache.hadoop.hbase.PerformanceEvaluation$SequentialWriteTest.testRow(PerformanceEvaluation.java:571)
at org.apache.hadoop.hbase.PerformanceEvaluation$Test.test(PerformanceEvaluation.java:406)
at org.apache.hadoop.hbase.PerformanceEvaluation.runOneClient(PerformanceEvaluation.java:639)
at org.apache.hadoop.hbase.PerformanceEvaluation$EvaluationMapTask.map(PerformanceEvaluation.java:194)
at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:50)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:358)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:307)
at org.apache.hadoop.mapred.Child.main(Child.java:170)
2009-09-03 09:04:12,819 INFO org.apache.hadoop.mapred.TaskRunner: Runnning cleanup for the task
{code}
At the time, the region in question was being split so I'd expect some timeout finding region:
{code}
2009-09-03 08:12:11,569 [IPC Server handler 15 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Processing MSG_REPORT_SPLIT: TestTable,0254895141,1251963952531: Daughters; TestTable,0254895141,1251965526935, TestTab
le,0257612642,1251965526935 from aa0-000-15.u.powerset.com,60020,1251958693334; 5 of 7
2009-09-03 08:12:11,653 [IPC Server handler 15 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,0254895141,1251965526935 to aa0-000-15.u.powerset.com,60020,1251958693334
2009-09-03 08:12:14,691 [IPC Server handler 12 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Processing MSG_REPORT_PROCESS_OPEN: TestTable,0254895141,1251965526935 from aa0-000-15.u.powerset.com,60020,12519586933
34; 2 of 4
2009-09-03 08:12:14,691 [IPC Server handler 12 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Processing MSG_REPORT_OPEN: TestTable,0254895141,1251965526935 from aa0-000-15.u.powerset.com,60020,1251958693334; 4 of
4
2009-09-03 08:12:14,697 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,0254895141,1251965526935 open on XX.XX.44.142:60020
2009-09-03 08:12:14,698 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: Updated row TestTable,0254895141,1251965526935 in region .META.,,1 with startcode=1251958693334, server=XX.XX.44.142:60020
2009-09-03 08:23:03,610 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: TestTable,0254895141,1251965526935/1579891142 no longer has references to TestTable,0254895141,1251963952531
2009-09-03 09:04:01,712 [IPC Server handler 3 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Processing MSG_REPORT_SPLIT: TestTable,0254895141,1251965526935: Daughters; TestTable,0254895141,1251968451499, TestTabl
e,0255035045,1251968451499 from aa0-000-15.u.powerset.com,60020,1251958693334; 1 of 3
2009-09-03 09:20:03,376 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: TestTable,0254895141,1251968451499/906753129 no longer has references to TestTable,0254895141,1251965526935
2009-09-03 09:20:03,378 [RegionManager.metaScanner] DEBUG org.apache.hadoop.hbase.master.BaseScanner: TestTable,0255035045,1251968451499/2088805037 no longer has references to TestTable,0254895141,1251965526935
2009-09-03 09:20:03,380 [RegionManager.metaScanner] INFO org.apache.hadoop.hbase.master.BaseScanner: Deleting region TestTable,0254895141,1251965526935 (encoded=1579891142) because daughter splits no longer hold references
{code}
The daughters came on line promptly...
Why is the client giving up so quickly?
I forgot to check why the other 3 attempts falied on this task.
I can get rows from the daughter regions without issue.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Attachments: debugging-v4.patch
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12727904#action_12727904 ]
stack commented on HBASE-1603:
------------------------------
So, the above wonky table and split keys outside of Region range was because of HBASE-1615.
Let me see if still have original complaint still exists now 1615 has been applied.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Fix For: 0.20.0
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (HBASE-1603) MR failed
"RetriesExhaustedException: Trying to contact region server Some server for
region TestTable..."
Posted by "stack (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/HBASE-1603?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12751206#action_12751206 ]
stack commented on HBASE-1603:
------------------------------
On retry, all is running fine this time around. Will keep an eye on it.
> MR failed "RetriesExhaustedException: Trying to contact region server Some server for region TestTable..."
> ----------------------------------------------------------------------------------------------------------
>
> Key: HBASE-1603
> URL: https://issues.apache.org/jira/browse/HBASE-1603
> Project: Hadoop HBase
> Issue Type: Bug
> Reporter: stack
> Attachments: debugging-v4.patch
>
>
> Here is the master. Region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358 was split at 16:11:42,865. My MR job failed at 18:12:26,462 with this:
> {code}
> 2009-07-01 18:12:26,462 WARN org.apache.hadoop.mapred.TaskTracker: Error running child
> org.apache.hadoop.hbase.client.RetriesExhaustedException: Trying to contact region server Some server for region TestTable,�,1246464670313, row '�� ', but failed after 10 attempts.
> Exceptions:
> ...
> {code}
> Why after ten attempts did the client not find the region?
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on 208.76.44.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server 208.76.44.142:60020
> 2009-07-01 17:46:42,670 [IPC Server handler 0 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246470379467, TestTable,\x00\x00\x08\x04\x05\x07\x02\x05\x04\x08,1246470379467 from aa0-000-15.u.powerset.com,60020,1246461673026; 5 of 7
> {code}
> Here is over on the regionserver:
> {code}
> 2009-07-01 16:11:42,865 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_SPLIT: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246462685358: Daughters; TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313, TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:42,866 [IPC Server handler 2 on 60001] INFO org.apache.hadoop.hbase.master.RegionManager: Assigning region TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 to aa0-000-15.u.powerset.com,60020,1246461673026
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_PROCESS_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 1 of 3
> 2009-07-01 16:11:45,905 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 2 of 3
> 2009-07-01 16:11:45,906 [IPC Server handler 8 on 60001] INFO org.apache.hadoop.hbase.master.ServerManager: Received MSG_REPORT_OPEN: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 from aa0-000-15.u.powerset.com,60020,1246461673026; 3 of 3
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,906 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x00\x06\x05\x01\x05\x07\x09\x08\x00,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X4.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 open on X.X.X.142:60020
> 2009-07-01 16:11:45,908 [HMaster] INFO org.apache.hadoop.hbase.master.RegionServerOperation: updating row TestTable,\x00\x01\x01\x04\x04\x07\x02\x08\x08\x03,1246464670313 in region .META.,,1 with startcode 1246461673026 and server X.X.X.142:60020
> {code}
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.