hbase-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Cosmin Lehene <cleh...@adobe.com>
Subject Re: Hbase corrupts data after reporting MSG_REPORT_CLOSE to master during compaction and split process
Date Thu, 04 Sep 2008 15:25:32 GMT



On 9/3/08 6:40 PM, "stack" <stack@duboce.net> wrote:

> Cosmin Lehene wrote:
>> Hi,
>>
>> Thanks for explaining things.
>> HBase Version    0.2.0, r690650
>>
>
> Is that the released 0.2.0?
>
It was a build from the 0.2 branch.
>> Hadoop Version    0.17.2, r684969
>>
>> It's hard to reproduce that. Right now HDFS gets corrupted after we start our
>> insertion scripts.  I've enabled DEBUG however. I'll retry fresh with an
>> upgrade  to hadoop 0.18 and Hbase trunk.
>>
>
> I would be interested in seeing logs of a corrupt hbase especially when
> we're under the illusion that we left 'corruption' long behind us.
>> However we might start  digging more in the code to see if we can start
>> patching things.
>> Are there any issues with HDFS as well or it's just Hbase that needs fixing?
>>

I upgraded the cluster to HBase trunk "0.3.0"(I guess this should be  0.18)  and Hadoop 0.18
release. We're still pushing data, but so far it looks better than 0.2.0, however region servers
die with

2008-09-03 10:17:20,457 FATAL org.apache.hadoop.hbase.regionserver.HRegionServer: Ran out
of memory
java.lang.OutOfMemoryError: Java heap space

And the data got corrupted again with debug information only on the master server. Apparently
it started a compaction and failed with NullPointerException leaving the region corrupted.
Unfortunately the CompactSplitThread only logs the exception, not the stack trace.

Most of the problems appear when inserting heavily (between 1000 - 2000 requests/s). Under
light insert rate (<400 requests/s) it behaves better.

I recompiled now with more logging and started to load data again. Hopefully we will cross
the 20M boundary.

Cosmin
>
> Usually its HBase.  But if HDFS is sickly, HBase is too.
>
> St.Ack
>
>> Thanks,
>> Cosmin
>>
>> On 9/2/08 10:14 PM, "stack" <stack@duboce.net> wrote:
>>
>> 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: [B@4861ef74 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: [B@62927d48 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
>>> [hadoop@ice-dev2-buc ~]$ grep "users,27B5C924-6FE4-4484-B131-D5C9E71AF4A6"
>>> /usr/local/hbase/logs/hbase-hadoop-master-ice-dev2-buc.corp.adobe.com.log.20
>>> 08-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: [B@4861ef74 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: [B@62927d48 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: [B@284f4565
>>> 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: [B@284f4565
>>> 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
>>>
>>>
>>>
>>>
>>
>>
>>
>
>

Mime
View raw message