[
https://issues.apache.org/jira/browse/HBASE-3741?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13021826#comment-13021826
]
Jean-Daniel Cryans commented on HBASE-3741:
-------------------------------------------
We think we had that bug in another flavor yesterday. Some region was opened on
a region server, timed out, then the master asked the same region server to
reopen it. Turns out that first thread that was opening stalled for a minute
and the second was able to finish before the first, so the region was opened,
but then the first thread woke up, finished opening and failed when it saw the
znode was gone thus closing the region. In the end, the region wasn't assigned
anywhere.
We think this bug is a lot more prone to happen on smaller clusters than on
larger ones since the master has less choice when randomly selecting a region
server so it has more chances of choosing the same one that timed out.
Here's the log:
{quote}
2011-04-18 12:09:27,962 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
region:
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:09:38,990 DEBUG
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open
of
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:09:38,990 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Attempting to transition node
1e69940524196d9779cade4495105800 from M_ZK_REGION_OFFLINE to
RS_ZK_REGION_OPENING
2011-04-18 12:09:39,038 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
regionserver:60020-0x32ec2cece909e73 Retrieved 117 byte(s) of data from znode
/hbase/unassigned/1e69940524196d9779cade4495105800;
data=region=url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.,
server=sv4borg9:60000, state=M_ZK_REGION_OFFLINE
2011-04-18 12:09:39,088 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher:
regionserver:60020-0x32ec2cece909e73 Received ZooKeeper Event,
type=NodeDataChanged, state=SyncConnected,
path=/hbase/unassigned/1e69940524196d9779cade4495105800
2011-04-18 12:09:39,088 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Successfully transitioned node
1e69940524196d9779cade4495105800 from M_ZK_REGION_OFFLINE to
RS_ZK_REGION_OPENING
2011-04-18 12:09:39,088 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Opening region: REGION => {NAME
'url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.'
2011-04-18 12:09:39,089 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Instantiated
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:09:42,292 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/alchemy/547205562891052551,
isReference=false, isBulkLoadResult=false, seqid=171490555075,
majorCompaction=false
2011-04-18 12:09:42,340 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/alchemy/5566830009625920336,
isReference=false, isBulkLoadResult=false, seqid=171419489345,
majorCompaction=true
2011-04-18 12:09:42,397 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/content/4047626416531823546,
isReference=false, isBulkLoadResult=false, seqid=171262790396,
majorCompaction=true
2011-04-18 12:10:41,246 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
region:
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:10:41,246 DEBUG
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open
of
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:10:41,246 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Attempting to transition node
1e69940524196d9779cade4495105800 from M_ZK_REGION_OFFLINE to
RS_ZK_REGION_OPENING
2011-04-18 12:10:41,272 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
regionserver:60020-0x32ec2cece909e73 Retrieved 117 byte(s) of data from znode
/hbase/unassigned/1e69940524196d9779cade4495105800;
data=region=url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.,
server=sv4borg9:60000, state=M_ZK_REGION_OFFLINE
2011-04-18 12:10:41,344 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher:
regionserver:60020-0x32ec2cece909e73 Received ZooKeeper Event,
type=NodeDataChanged, state=SyncConnected,
path=/hbase/unassigned/1e69940524196d9779cade4495105800
2011-04-18 12:10:41,344 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Successfully transitioned node
1e69940524196d9779cade4495105800 from M_ZK_REGION_OFFLINE to
RS_ZK_REGION_OPENING
2011-04-18 12:10:41,345 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Opening region: REGION => {NAME
'url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.'
2011-04-18 12:10:41,345 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Instantiated
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:10:41,363 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/alchemy/547205562891052551,
isReference=false, isBulkLoadResult=false, seqid=171490555075,
majorCompaction=false
2011-04-18 12:10:41,370 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/alchemy/5566830009625920336,
isReference=false, isBulkLoadResult=false, seqid=171419489345,
majorCompaction=true
2011-04-18 12:10:41,384 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/content/4047626416531823546,
isReference=false, isBulkLoadResult=false, seqid=171262790396,
majorCompaction=true
2011-04-18 12:10:41,415 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/content/481403044422440052,
isReference=false, isBulkLoadResult=false, seqid=171526888010,
majorCompaction=false
2011-04-18 12:10:41,444 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/content/6337634596599064186,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=false
2011-04-18 12:10:41,467 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/meta/7668161505043413619,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=false
2011-04-18 12:10:41,506 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/meta/8886420161768514108,
isReference=false, isBulkLoadResult=false, seqid=171526888010,
majorCompaction=true
2011-04-18 12:10:41,553 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/similar/9062208744007970818,
isReference=false, isBulkLoadResult=false, seqid=165218679815,
majorCompaction=true
2011-04-18 12:10:41,605 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/su/2124185357260769643,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=true
2011-04-18 12:10:41,640 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/tags/4274262420188290568,
isReference=false, isBulkLoadResult=false, seqid=171419489345,
majorCompaction=true
2011-04-18 12:10:41,662 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/tags/6251775080838762671,
isReference=false, isBulkLoadResult=false, seqid=171490555075,
majorCompaction=false
2011-04-18 12:10:41,681 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/youtube/3640658911874339377,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=true
2011-04-18 12:10:41,683 INFO org.apache.hadoop.hbase.regionserver.HRegion:
Onlined
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.;
next sequenceid=171538296509
2011-04-18 12:10:41,683 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Attempting to transition node
1e69940524196d9779cade4495105800 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENING
2011-04-18 12:10:41,684 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
regionserver:60020-0x32ec2cece909e73 Retrieved 132 byte(s) of data from znode
/hbase/unassigned/1e69940524196d9779cade4495105800;
data=region=url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.,
server=sv4borg24,60020,1302856880721, state=RS_ZK_REGION_OPENING
2011-04-18 12:10:41,706 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher:
regionserver:60020-0x32ec2cece909e73 Received ZooKeeper Event,
type=NodeDataChanged, state=SyncConnected,
path=/hbase/unassigned/1e69940524196d9779cade4495105800
2011-04-18 12:10:41,707 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Successfully transitioned node
1e69940524196d9779cade4495105800 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENING
2011-04-18 12:10:41,711 INFO org.apache.hadoop.hbase.catalog.MetaEditor:
Updated row
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
in region .META.,,1 with server=sv4borg24:60020, startcode=1302856880721
2011-04-18 12:10:41,711 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Attempting to transition node
1e69940524196d9779cade4495105800 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENED
2011-04-18 12:10:41,716 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
regionserver:60020-0x32ec2cece909e73 Retrieved 132 byte(s) of data from znode
/hbase/unassigned/1e69940524196d9779cade4495105800;
data=region=url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.,
server=sv4borg24,60020,1302856880721, state=RS_ZK_REGION_OPENING
2011-04-18 12:10:41,746 DEBUG
org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher:
regionserver:60020-0x32ec2cece909e73 Received ZooKeeper Event,
type=NodeDataChanged, state=SyncConnected,
path=/hbase/unassigned/1e69940524196d9779cade4495105800
2011-04-18 12:10:41,746 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Successfully transitioned node
1e69940524196d9779cade4495105800 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENED
2011-04-18 12:10:41,746 DEBUG
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:10:42,408 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/content/481403044422440052,
isReference=false, isBulkLoadResult=false, seqid=171526888010,
majorCompaction=false
2011-04-18 12:11:03,425 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/content/6337634596599064186,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=false
2011-04-18 12:11:03,454 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/meta/7668161505043413619,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=false
2011-04-18 12:11:03,504 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/meta/8886420161768514108,
isReference=false, isBulkLoadResult=false, seqid=171526888010,
majorCompaction=true
2011-04-18 12:11:03,515 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/similar/9062208744007970818,
isReference=false, isBulkLoadResult=false, seqid=165218679815,
majorCompaction=true
2011-04-18 12:11:03,523 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/su/2124185357260769643,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=true
2011-04-18 12:11:03,529 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/tags/4274262420188290568,
isReference=false, isBulkLoadResult=false, seqid=171419489345,
majorCompaction=true
2011-04-18 12:11:03,541 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/tags/6251775080838762671,
isReference=false, isBulkLoadResult=false, seqid=171490555075,
majorCompaction=false
2011-04-18 12:11:03,621 DEBUG org.apache.hadoop.hbase.regionserver.Store:
loaded
hdfs://sv4borg9:9000/hbase/url_data/1e69940524196d9779cade4495105800/youtube/3640658911874339377,
isReference=false, isBulkLoadResult=false, seqid=171538296508,
majorCompaction=true
2011-04-18 12:11:03,624 INFO org.apache.hadoop.hbase.regionserver.HRegion:
Onlined
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.;
next sequenceid=171538296509
2011-04-18 12:11:03,624 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
regionserver:60020-0x32ec2cece909e73 Attempting to transition node
1e69940524196d9779cade4495105800 from RS_ZK_REGION_OPENING to
RS_ZK_REGION_OPENING
2011-04-18 12:11:03,627 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
regionserver:60020-0x32ec2cece909e73 Unable to get data of znode
/hbase/unassigned/1e69940524196d9779cade4495105800 because node does not exist
(not necessarily an error)
2011-04-18 12:11:03,627 WARN
org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Failed
refreshing OPENING; region=1e69940524196d9779cade4495105800,
context=post_region_open
2011-04-18 12:11:03,627 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Closing
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.:
disabling compactions & flushes
2011-04-18 12:11:03,627 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Updates disabled for region
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
2011-04-18 12:11:03,628 INFO org.apache.hadoop.hbase.regionserver.HRegion:
Closed
url_data,c60e0ff2d7bcee723758e8bd60450cac,1302090326155.1e69940524196d9779cade4495105800.
{quote}
> OpenRegionHandler and CloseRegionHandler are possibly racing
> ------------------------------------------------------------
>
> Key: HBASE-3741
> URL: https://issues.apache.org/jira/browse/HBASE-3741
> Project: HBase
> Issue Type: Bug
> Affects Versions: 0.90.1
> Reporter: Jean-Daniel Cryans
> Priority: Blocker
> Fix For: 0.90.3
>
>
> This is a serious issue about a race between regions being opened and closed
> in region servers. We had this situation where the master tried to unassign a
> region for balancing, failed, force unassigned it, force assigned it
> somewhere else, failed to open it on another region server (took too long),
> and then reassigned it back to the original region server. A few seconds
> later, the region server processed the first closed and the region was left
> unassigned.
> This is from the master log:
> {quote}
> 11-04-05 15:11:17,758 DEBUG org.apache.hadoop.hbase.master.AssignmentManager:
> Sent CLOSE to serverName=sv4borg42,60020,1300920459477, load=(requests=187,
> regions=574, usedHeap=3918, maxHeap=6973) for region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:12:10,021 INFO
> org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition timed
> out:
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> state=PENDING_CLOSE, ts=1302041477758
> 2011-04-05 15:12:10,021 INFO
> org.apache.hadoop.hbase.master.AssignmentManager: Region has been
> PENDING_CLOSE for too long, running forced unassign again on
> region=stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> ...
> 2011-04-05 15:14:45,783 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE;
> was=stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> state=CLOSED, ts=1302041685733
> 2011-04-05 15:14:45,783 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:60000-0x42ec2cece810b68 Creating (or updating) unassigned node for
> 1470298961 with OFFLINE state
> ...
> 2011-04-05 15:14:45,885 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Using pre-existing plan for
> region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961;
>
> plan=hri=stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961,
> src=sv4borg42,60020,1300920459477, dest=sv4borg40,60020,1302041218196
> 2011-04-05 15:14:45,885 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> to sv4borg40,60020,1302041218196
> 2011-04-05 15:15:39,410 INFO
> org.apache.hadoop.hbase.master.AssignmentManager: Regions in transition timed
> out:
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> state=PENDING_OPEN, ts=1302041700944
> 2011-04-05 15:15:39,410 INFO
> org.apache.hadoop.hbase.master.AssignmentManager: Region has been
> PENDING_OPEN for too long, reassigning
> region=stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:39,410 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE;
> was=stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> state=PENDING_OPEN, ts=1302041700944
> ...
> 2011-04-05 15:15:39,410 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan
> was found (or we are ignoring an existing plan) for
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> so generated a random one;
> hri=stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961,
> src=, dest=sv4borg42,60020,1300920459477; 19 (online=19, exclude=null)
> available servers
> 2011-04-05 15:15:39,410 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> to sv4borg42,60020,1300920459477
> 2011-04-05 15:15:40,951 DEBUG
> org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher:
> master:60000-0x42ec2cece810b68 Received ZooKeeper Event,
> type=NodeDataChanged, state=SyncConnected,
> path=/prodjobs/unassigned/1470298961
> 2011-04-05 15:15:40,952 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
> master:60000-0x42ec2cece810b68 Retrieved 93 byte(s) of data from znode
> /prodjobs/unassigned/1470298961 and set watcher;
> region=stumbles_by_userid2,'����穗���6,1266566087256,
> server=sv4borg42,60020,1300920459477, state=RS_ZK_REGION_OPENED
> 2011-04-05 15:15:40,952 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED, server=sv4borg42,60020,1300920459477,
> region=1470298961
> 2011-04-05 15:15:42,222 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
> event for 1470298961; deleting unassigned node
> ...
> 2011-04-05 15:15:55,812 DEBUG org.apache.hadoop.hbase.zookeeper.ZKUtil:
> master:60000-0x42ec2cece810b68 Retrieved 93 byte(s) of data from znode
> /prodjobs/unassigned/1470298961 and set watcher;
> region=stumbles_by_userid2,'����穗���6,1266566087256,
> server=sv4borg42,60020,1300920459477, state=RS_ZK_REGION_CLOSING
> 2011-04-05 15:15:55,812 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling new unassigned
> node: /prodjobs/unassigned/1470298961
> (region=stumbles_by_userid2,'����穗���6,1266566087256,
> server=sv4borg42,60020,1300920459477, state=RS_ZK_REGION_CLOSING)
> 2011-04-05 15:15:55,812 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_CLOSING, server=sv4borg42,60020,1300920459477,
> region=1470298961
> 2011-04-05 15:15:55,812 WARN
> org.apache.hadoop.hbase.master.AssignmentManager: Received CLOSING for region
> 1470298961 from server sv4borg42,60020,1300920459477 but region was in the
> state null and not in expected PENDING_CLOSE or CLOSING states
> {quote}
> And from sv4borg42:
> {quote}
> 2011-04-05 15:09:58,755 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received close region:
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:11:17,757 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received close region:
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:12:10,021 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received close region:
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:14:45,675 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler: Processing
> close of
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:14:45,700 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Closing
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961:
> disabling compactions & flushes
> 2011-04-05 15:14:45,701 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Updates disabled for region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:14:45,701 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Closed
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:14:45,758 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler: Closed
> region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:39,410 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
> region:
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:39,410 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
> open of
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:39,486 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Opening region: REGION => {NAME =>
> 'stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256',
> STARTKEY => '\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6',
> ENDKEY => '\x00'\x9AU\x7F\xFF\xFE\xEBQ\xB0\xC3\xEF\x00Jr\xF2', ENCODED =>
> 1470298961, TABLE => ...
> 2011-04-05 15:15:39,487 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Instantiated
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:40,399 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961;
> next sequenceid=37627407247
> 2011-04-05 15:15:40,488 INFO org.apache.hadoop.hbase.catalog.MetaEditor:
> Updated row
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> in region .META.,,1 with server=sv4borg42:60020, startcode=1300920459477
> 2011-04-05 15:15:40,582 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:55,776 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler: Processing
> close of
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:55,809 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Closing
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961:
> disabling compactions & flushes
> 2011-04-05 15:15:55,809 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Updates disabled for region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:55,809 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Closed
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:55,842 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler: Closed
> region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:55,943 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler: Processing
> close of
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> 2011-04-05 15:15:55,943 WARN
> org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler: Received
> CLOSE for region
> stumbles_by_userid2,\x00'\x8E\xE8\x7F\xFF\xFE\xE7\xA9\x97\xFC\xDF\x01\x10\xCC6,1266566087256.1470298961
> but currently not serving
> {quote}
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
