Re: Hbase corrupts data after reporting MSG_REPORT_CLOSE to master during compaction and split process

Tue, 02 Sep 2008 12:15:24 -0700 

Thanks for digging in Cosmin.   What version of hbase?

FYI, to repair the table, there is a tool to merge adjacent regions:

$ ./bin/hbase org.apache.hadoop.hbase.util.Merge
Usage: bin/hbase merge <table-name> <region-1> <region-2>

See below for comments inline:

Cosmin Lehene wrote:

...
HMaster 10.131.237.52 log

grep "users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6" 
/usr/local/hbase/logs/hbase-hadoop-master-dev2.log.2008-08-29
2008-08-29 07:58:59,660 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 to 
server 10.131.237.54:60020
2008-08-29 07:59:02,728 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.54:60020
2008-08-29 07:59:02,881 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.54:60020
2008-08-29 07:59:02,881 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 open on 
10.131.237.54:60020
2008-08-29 07:59:02,881 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in region .META.,,1 
with startcode 1220014953935 and server 10.131.237.54:60020
M1 2008-08-29 08:50:18,558 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 to 
server 10.131.237.51:60020
What happened in here to cause the master reassign a region already assigned? It was on 54 then we are asked assign it to 51. Would suggest you run with DEBUG. Would help with the diagnosis (See FAQ for how). 


2008-08-29 08:50:21,935 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
2008-08-29 08:50:25,086 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
...
2008-08-29 08:53:06,020 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
2008-08-29 08:53:06,020 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
M2 2008-08-29 08:53:36,875 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
The multiple instances of MSG_REPORT_PROCESS_OPEN would imply it was taking the redeployment a long time to come up replaying edits (If its replaying edits of a region already deployed, that'll make for a real mess). 



2008-08-29 08:53:36,876 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 open on 
10.131.237.51:60020
M3 2008-08-29 08:53:36,876 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in region .META.,,1 
with startcode 1220014954000 and server 10.131.237.51:60020
2008-08-29 08:54:12,249 INFO org.apache.hadoop.hbase.master.RegionManager: 
Skipping region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because it is already closing.
2008-08-29 08:54:15,525 INFO org.apache.hadoop.hbase.master.RegionManager: 
Skipping region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because it is already closing.
2008-08-29 08:54:18,581 INFO org.apache.hadoop.hbase.master.RegionManager: 
Skipping region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because it is already closing.
M4 2008-08-29 08:54:24,616 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
M5 2008-08-29 08:54:24,937 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 to 
server 10.131.237.55:60020
2008-08-29 08:54:28,133 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.55:60020
Now we are assigning the region to 55. I don't know why the MSG_REPORT_CLOSE happened over on 51. Doesn't say in the regionserver log. Our logging needs improving. Without DEBUG its not possible to know why some of these actions happened. 

St.Ack


2008-08-29 08:54:28,134 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.55:60020
2008-08-29 08:54:28,221 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 open on 
10.131.237.55:60020
M6 2008-08-29 08:54:28,221 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in region .META.,,1 
with startcode 1220014319248 and server 10.131.237.55:60020
M7 2008-08-29 08:54:30,775 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_SPLIT: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774: [EMAIL PROTECTED] 
from 10.131.237.51:60020
M8 2008-08-29 08:54:33,356 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 to 
server 10.131.237.52:60020
2008-08-29 08:54:36,419 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:54:39,498 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
...
2008-08-29 08:55:03,727 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
M9 2008-08-29 08:55:04,835 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_SPLIT: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774: [EMAIL PROTECTED] 
from 10.131.237.55:60020
2008-08-29 08:55:06,898 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
...
2008-08-29 08:56:04,627 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
M10 2008-08-29 08:56:04,627 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:56:04,642 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 open on 
10.131.237.52:60020
M11 2008-08-29 08:56:04,642 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 in region .META.,,1 
with startcode 1220014954468 and server 10.131.237.52:60020
2008-08-29 08:56:10,645 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:56:16,111 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 to 
server 10.131.236.91:60020
2008-08-29 08:56:19,134 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.236.91:60020
2008-08-29 08:56:19,134 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.236.91:60020
2008-08-29 08:56:19,134 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 open on 
10.131.236.91:60020
M12 2008-08-29 08:56:19,134 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 in region .META.,,1 
with startcode 1220014953772 and server 10.131.236.91:60020
2008-08-29 08:56:43,935 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 to 
server 10.131.236.91:60020
2008-08-29 08:56:47,158 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:50,274 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:53,421 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:53,422 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:53,500 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 open on 
10.131.236.91:60020
M13 2008-08-29 08:56:53,500 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 in region .META.,,1 
with startcode 1220014953772 and server 10.131.236.91:60020
2008-08-29 08:57:02,485 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.236.91:60020
2008-08-29 08:57:04,188 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 to 
server 10.131.237.53:60020
2008-08-29 08:57:07,309 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.53:60020
2008-08-29 08:57:07,309 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.53:60020
2008-08-29 08:57:07,309 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 open on 
10.131.237.53:60020
2008-08-29 08:57:07,309 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 in region .META.,,1 
with startcode 1220024985751 and server 10.131.237.53:60020
2008-08-29 09:00:45,252 INFO org.apache.hadoop.hbase.master.BaseScanner: 
Deleting region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because daughter splits no longer hold references
[EMAIL PROTECTED] ~]$ grep "users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6" 
/usr/local/hbase/logs/hbase-hadoop-master-ice-dev2-buc.corp.adobe.com.log.2008-08-29
2008-08-29 07:58:59,660 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 to 
server 10.131.237.54:60020
2008-08-29 07:59:02,728 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.54:60020
2008-08-29 07:59:02,881 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.54:60020
2008-08-29 07:59:02,881 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 open on 
10.131.237.54:60020
2008-08-29 07:59:02,881 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in region .META.,,1 
with startcode 1220014953935 and server 10.131.237.54:60020
2008-08-29 08:50:18,558 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 to 
server 10.131.237.51:60020
2008-08-29 08:50:21,935 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
2008-08-29 08:50:25,086 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
...
2008-08-29 08:53:06,020 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
2008-08-29 08:53:36,875 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
2008-08-29 08:53:36,876 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 open on 
10.131.237.51:60020
2008-08-29 08:53:36,876 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in region .META.,,1 
with startcode 1220014954000 and server 10.131.237.51:60020
2008-08-29 08:54:12,249 INFO org.apache.hadoop.hbase.master.RegionManager: 
Skipping region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because it is already closing.
2008-08-29 08:54:15,525 INFO org.apache.hadoop.hbase.master.RegionManager: 
Skipping region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because it is already closing.
2008-08-29 08:54:18,581 INFO org.apache.hadoop.hbase.master.RegionManager: 
Skipping region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because it is already closing.
2008-08-29 08:54:24,616 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.51:60020
2008-08-29 08:54:24,937 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 to 
server 10.131.237.55:60020
2008-08-29 08:54:28,133 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.55:60020
2008-08-29 08:54:28,134 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 from 
10.131.237.55:60020
2008-08-29 08:54:28,221 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 open on 
10.131.237.55:60020
2008-08-29 08:54:28,221 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in region .META.,,1 
with startcode 1220014319248 and server 10.131.237.55:60020
2008-08-29 08:54:30,775 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_SPLIT: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774: [EMAIL PROTECTED] 
from 10.131.237.51:60020
2008-08-29 08:54:33,356 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 to 
server 10.131.237.52:60020
2008-08-29 08:54:36,419 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:54:39,498 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
...
2008-08-29 08:55:03,727 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:55:04,835 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_SPLIT: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774: [EMAIL PROTECTED] 
from 10.131.237.55:60020
2008-08-29 08:55:06,898 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
...
2008-08-29 08:56:04,627 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:56:04,627 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:56:04,642 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 open on 
10.131.237.52:60020
2008-08-29 08:56:04,642 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 in region .META.,,1 
with startcode 1220014954468 and server 10.131.237.52:60020
2008-08-29 08:56:10,645 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.52:60020
2008-08-29 08:56:16,111 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 to 
server 10.131.236.91:60020
2008-08-29 08:56:19,134 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.236.91:60020
2008-08-29 08:56:19,134 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.236.91:60020
2008-08-29 08:56:19,134 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 open on 
10.131.236.91:60020
2008-08-29 08:56:19,134 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 in region .META.,,1 
with startcode 1220014953772 and server 10.131.236.91:60020
2008-08-29 08:56:43,935 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 to 
server 10.131.236.91:60020
2008-08-29 08:56:47,158 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:50,274 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:53,421 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:53,422 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 from 
10.131.236.91:60020
2008-08-29 08:56:53,500 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 open on 
10.131.236.91:60020
2008-08-29 08:56:53,500 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220024667454 in region .META.,,1 
with startcode 1220014953772 and server 10.131.236.91:60020
2008-08-29 08:57:02,485 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.236.91:60020
2008-08-29 08:57:04,188 INFO org.apache.hadoop.hbase.master.RegionManager: 
assigning region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 to 
server 10.131.237.53:60020
2008-08-29 08:57:07,309 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_PROCESS_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.53:60020
2008-08-29 08:57:07,309 INFO org.apache.hadoop.hbase.master.ServerManager: 
Received MSG_REPORT_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 from 
10.131.237.53:60020
2008-08-29 08:57:07,309 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 open on 
10.131.237.53:60020
2008-08-29 08:57:07,309 INFO 
org.apache.hadoop.hbase.master.ProcessRegionOpen$1: updating row 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231 in region .META.,,1 
with startcode 1220024985751 and server 10.131.237.53:60020
M14 2008-08-29 09:00:45,252 INFO org.apache.hadoop.hbase.master.BaseScanner: 
Deleting region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 
because daughter splits no longer hold references


Region server log 10.131.237.51

grep users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6 
/usr/local/hbase/logs/hbase-hadoop-regionserver-dev1.log.2008-08-29
2008-08-29 08:50:18,868 INFO 
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774
2008-08-29 08:52:52,323 INFO 
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774
R1 2008-08-29 08:53:34,330 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774/62578664 
available
R2 2008-08-29 08:53:34,330 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
starting compaction on region 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774
R3 2008-08-29 08:54:09,035 INFO 
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774: [EMAIL PROTECTED]
R4 2008-08-29 08:54:24,224 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
compaction completed on region 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 in 49sec
R5 2008-08-29 08:54:24,224 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
Starting split of region 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774
R6 2008-08-29 08:54:24,234 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
closed users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774
R7 2008-08-29 08:54:24,393 INFO 
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_CLOSE: 
users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774: [EMAIL PROTECTED]
R8 2008-08-29 08:54:24,393 WARN org.apache.hadoop.hbase.regionserver.HRegion: 
region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774 already closed
R9 2008-08-29 08:54:27,323 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
region users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231/620189721 
available
R10 2008-08-29 08:54:27,324 INFO org.apache.hadoop.hbase.regionserver.HRegion: 
closed users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231
R11 2008-08-29 08:54:27,726 INFO org.apache.hadoop.hbase.regionserver.CompactSplitThread: region split, META updated, and report to master 
all successful. Old region=REGION => {NAME => 'users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220021933774', STARTKEY => 
'27B5C924-6FE4-4484-B131-D5C9E71AF4A6', ENDKEY => '2FB0249D-0A95-47BB-A4F1-6C7600039542', ENCODED => 62578664, OFFLINE => true, 
SPLIT => true, TABLE => {{NAME => 'users', IS_ROOT => 'false', IS_META => 'false', FAMILIES => [{NAME => 'test', 
BLOOMFILTER => 'false', COMPRESSION => 'NONE', VERSIONS => '3', LENGTH => '2147483647', TTL => '-1', IN_MEMORY => 
'false', BLOCKCACHE => 'false'}]}}, new regions: users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6,1220025264231, 
users,2BB6AC25-2EA6-4311-9670-49B68B7BB975,1220025264231. Split took 3sec

Reply via email to