hbase-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gaojinchao <gaojinc...@huawei.com>
Subject Re: a lots of error about Region has been OPEN for too long
Date Sat, 16 Apr 2011 00:52:29 GMT
It reproduces easily. 
In my cluster, It reproduces when balance region. 

Log is:
2011-04-15 14:54:21,885 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.,
src=C4C3.site,60020,1302849920122,

Today , I will open ZK client debug log and keep digging.

I will try to make state chart, then can understand easily for assigning a region.

-----邮件原件-----
发件人: jdcryans@gmail.com [mailto:jdcryans@gmail.com] 代表 Jean-Daniel Cryans
发送时间: 2011年4月16日 1:56
收件人: user@hbase.apache.org
主题: Re: a lots of error about Region has been OPEN for too long

Yeah it's not clear from the logs why it did that, and looking through
my logs I can't see any occurrence. Can you reproduce it easily?

J-D

On Fri, Apr 15, 2011 at 12:46 AM, Gaojinchao <gaojinchao@huawei.com> wrote:
> Thanks for your reply.
>
> Hbase version : 0.90.1
>
> I find other abnormal logs.
> Hmaster receives twice RS_ZK_REGION_OPENED event.
> It reproduces in balance processing.
> But I can't root out what brings on ?
>
> Hmaster logs:
> 2011-04-15 14:54:21,885 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.,
src=C4C3.site,60020,1302849920122, dest=C4C5.site,60020,1302849920117
> 2011-04-15 14:54:21,885 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting
unassignment of region ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
(offlining)
> 2011-04-15 14:54:21,886 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent
CLOSE to serverName=C4C3.site,60020,1302849920122, load=(requests=0, regions=588, usedHeap=122,
maxHeap=8175) for region ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
> 2011-04-15 14:54:25,333 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling
new unassigned node: /hbase/unassigned/89e2c4452de2864bf3362a8f16e758d0 (region=ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.,
server=C4C3.site,60020,1302849920122, state=RS_ZK_REGION_CLOSED)
> 2011-04-15 14:54:25,333 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_CLOSED, server=C4C3.site,60020,1302849920122, region=89e2c4452de2864bf3362a8f16e758d0
> 2011-04-15 14:55:14,364 DEBUG org.apache.hadoop.hbase.master.handler.ClosedRegionHandler:
Handling CLOSED event for 89e2c4452de2864bf3362a8f16e758d0
> 2011-04-15 14:55:14,380 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing
OFFLINE; was=ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0. state=CLOSED,
ts=1302850513941
> 2011-04-15 14:55:14,380 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x2f57e8192e0000
Creating (or updating) unassigned node for 89e2c4452de2864bf3362a8f16e758d0 with OFFLINE state
> 2011-04-15 14:55:14,614 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Using
pre-existing plan for region ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.;
plan=hri=ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0., src=C4C3.site,60020,1302849920122,
dest=C4C5.site,60020,1302849920117
> 2011-04-15 14:55:14,614 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning
region ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0. to C4C5.site,60020,1302849920117
> 2011-04-15 14:55:14,705 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENING, server=C4C5.site,60020,1302849920117, region=89e2c4452de2864bf3362a8f16e758d0
>
> 2011-04-15 14:55:14,714 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENED, server=C4C5.site,60020,1302849920117, region=89e2c4452de2864bf3362a8f16e758d0
>
> //repetition
> 2011-04-15 14:55:14,714 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling
transition=RS_ZK_REGION_OPENED, server=C4C5.site,60020,1302849920117, region=89e2c4452de2864bf3362a8f16e758d0
>
> // Hmaster abnormal logs
> 2011-04-15 14:55:14,715 WARN org.apache.hadoop.hbase.master.AssignmentManager: Received
OPENED for region 89e2c4452de2864bf3362a8f16e758d0 from server C4C5.site,60020,1302849920117
but region was in  the state ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
state=OPEN, ts=1302850514694 and not in expected PENDING_OPEN or OPENING states
>
> 2011-04-15 14:55:42,362 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler:
Handling OPENED event for 89e2c4452de2864bf3362a8f16e758d0; deleting unassigned node
> 2011-04-15 14:55:42,362 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x2f57e8192e0000
Deleting existing unassigned node for 89e2c4452de2864bf3362a8f16e758d0 that is in expected
state RS_ZK_REGION_OPENED
> 2011-04-15 14:55:42,392 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:60000-0x2f57e8192e0000
Successfully deleted unassigned node for region 89e2c4452de2864bf3362a8f16e758d0 in expected
state RS_ZK_REGION_OPENED
> 2011-04-15 14:55:42,411 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler:
Opened region ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0. on C4C5.site,60020,1302849920117
>
>
> Region server logs:
> 2011-04-15 14:55:14,603 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received
request to open region: ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
> 2011-04-15 14:55:14,617 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler:
Processing open of ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
> 2011-04-15 14:55:14,617 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x2f57e8192e0004
Attempting to transition node 89e2c4452de2864bf3362a8f16e758d0 from M_ZK_REGION_OFFLINE to
RS_ZK_REGION_OPENING
> 2011-04-15 14:55:14,644 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x2f57e8192e0004
Successfully transitioned node 89e2c4452de2864bf3362a8f16e758d0 from M_ZK_REGION_OFFLINE to
RS_ZK_REGION_OPENING
> 2011-04-15 14:55:14,644 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region:
REGION => {NAME => 'ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.',
STARTKEY => '1088613823076918', ENDKEY => '1088613826923071', ENCODED => 89e2c4452de2864bf3362a8f16e758d0,
TABLE => {{NAME => 'ufdrA', FAMILIES => [{NAME => 'value', BLOOMFILTER => 'NONE',
REPLICATION_SCOPE => '0', VERSIONS => '3', COMPRESSION => 'GZ', TTL => '86400',
BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}}
> 2011-04-15 14:55:14,644 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated
ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
> 2011-04-15 14:55:14,648 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.;
next sequenceid=1
> 2011-04-15 14:55:14,648 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x2f57e8192e0004
Attempting to transition node 89e2c4452de2864bf3362a8f16e758d0 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENING
> 2011-04-15 14:55:14,677 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x2f57e8192e0004
Successfully transitioned node 89e2c4452de2864bf3362a8f16e758d0 from RS_ZK_REGION_OPENING
to RS_ZK_REGION_OPENING
> 2011-04-15 14:55:14,680 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row
ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0. in region .META.,,1
with server=C4C5.site:60020, startcode=1302849920117
> 2011-04-15 14:55:14,680 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x2f57e8192e0004
Attempting to transition node 89e2c4452de2864bf3362a8f16e758d0 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENED
> 2011-04-15 14:55:14,702 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:60020-0x2f57e8192e0004
Successfully transitioned node 89e2c4452de2864bf3362a8f16e758d0 from RS_ZK_REGION_OPENING
to RS_ZK_REGION_OPENED
> 2011-04-15 14:55:14,702 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler:
Opened ufdrA,1088613823076918,1301646236458.89e2c4452de2864bf3362a8f16e758d0.
Mime
View raw message