You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by "ajay.gov" <ag...@yahoo.com> on 2011/04/07 04:10:09 UTC

HTable.put hangs on bulk loading

I am doing a load test for which I need to load a table with many rows.  I
have a small java program that has a for loop and calls HTable.put.  I am
inserting a map of 2 items into a table that has one column family. The
limit of the for loop is currently 20000. However after 15876 rows the call
to Put hangs. I am using autoFlush on the HTable. Any ideas why this may
happen? 

The table configuration:
DESCRIPTION                                          ENABLED                    
 {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true                       
 1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'                            
 , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2                            
 147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal                            
 se', BLOCKCACHE => 'true'}]}

The HBase config on the client is the one in the hbase-default.xml. Some
values:
hbase.client.write.buffer=2097152
hbase.client.pause=1000
hbase.client.retries.number=10

If i use another client I am able to put items to the table. I am also able
to scan items from the table using the hbase shell.

I have attached the server configuratio
I don't see anything in the region server or master logs. I have them here.

The master server log:
2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scanning meta region {server:
184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.rootScanner scan of 1 row(s) of meta region {server:
184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>} complete
2011-04-06 19:02:40,157 INFO org.apache.hadoop.hbase.master.ServerManager: 1
region servers, 0 dead, average load 42.0
2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scanning meta region {server:
184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
RegionManager.metaScanner scan of 40 row(s) of meta region {server:
184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
complete
2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner: All
1 .META. region(s) scanned


The region server logs:
2011-04-06 19:02:21,294 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
Creating region TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
2011-04-06 19:02:21,295 INFO org.apache.hadoop.hbase.regionserver.HRegion:
Onlined TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
sequenceid=1

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31338874.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Jean-Daniel Cryans <jd...@apache.org>.
There's nothing of use in the pasted logs unfortunately, and the log
didn't get attached to your mail (happens often). Consider putting on
a web server or pastebin.

Also I see you are on an older version, upgrading isn't going to fix
your issue (which is probably related to your environment or
configuration) but at least it's gonna be easier for us to support
you.

J-D

On Wed, Apr 6, 2011 at 7:10 PM, ajay.gov <ag...@yahoo.com> wrote:
>
> I am doing a load test for which I need to load a table with many rows.  I
> have a small java program that has a for loop and calls HTable.put.  I am
> inserting a map of 2 items into a table that has one column family. The
> limit of the for loop is currently 20000. However after 15876 rows the call
> to Put hangs. I am using autoFlush on the HTable. Any ideas why this may
> happen?
>
> The table configuration:
> DESCRIPTION                                          ENABLED
>  {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true
>  1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'
>  , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2
>  147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal
>  se', BLOCKCACHE => 'true'}]}
>
> The HBase config on the client is the one in the hbase-default.xml. Some
> values:
> hbase.client.write.buffer=2097152
> hbase.client.pause=1000
> hbase.client.retries.number=10
>
> If i use another client I am able to put items to the table. I am also able
> to scan items from the table using the hbase shell.
>
> I have attached the server configuratio
> I don't see anything in the region server or master logs. I have them here.
>
> The master server log:
> 2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.rootScanner scanning meta region {server:
> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
> 2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.rootScanner scan of 1 row(s) of meta region {server:
> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>} complete
> 2011-04-06 19:02:40,157 INFO org.apache.hadoop.hbase.master.ServerManager: 1
> region servers, 0 dead, average load 42.0
> 2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.metaScanner scanning meta region {server:
> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
> 2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.metaScanner scan of 40 row(s) of meta region {server:
> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
> complete
> 2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner: All
> 1 .META. region(s) scanned
>
>
> The region server logs:
> 2011-04-06 19:02:21,294 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Creating region TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
> 2011-04-06 19:02:21,295 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
> sequenceid=1
>
> --
> View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31338874.html
> Sent from the HBase User mailing list archive at Nabble.com.
>
>

Re: HTable.put hangs on bulk loading

Posted by Michel Segel <mi...@hotmail.com>.
How many regions on a region server?
Table splits? GC tuning parameters?
HBase heap size?

All of these qustions could be important...

Sent from a remote device. Please excuse any typos...

Mike Segel

On Apr 26, 2011, at 5:25 AM, Stan Barton <ba...@gmail.com> wrote:

> 
> I am running into similar problem with HBase 0.90.2. My setting is 6 RSs one
> master server, 3 ZK servers and about 20 clients (on different servers)
> feeding the database with inserts. After few hours and around 2.5 millions
> rows inserted the process simply hangs with no what so ever error indication
> (neither by ZK, master, regionservers nor the clients). All the inserting
> clients stop virtually at the same moment, but HBase it self is not down and
> can be queried. 
> 
> In fact, the clients not even crash on time out exception for its
> connection. I have ran into such problem always when I attempted to run such
> importing progress with the new HBase versions (even 0.90.1). Can anybody
> address this problem? Does other have similar problems?
> 
> I can provide further info about the configuration if needed.
> 
> Stan Barton
> 
> 
> 
> 
> ajay.gov wrote:
>> 
>> Sorry, my server config was not attached. Its here:
>> http://pastebin.com/U41QZGiq
>> 
>> thanks
>> -ajay
>> 
>> 
>> 
>> ajay.gov wrote:
>>> 
>>> I am doing a load test for which I need to load a table with many rows. 
>>> I have a small java program that has a for loop and calls HTable.put.  I
>>> am inserting a map of 2 items into a table that has one column family.
>>> The limit of the for loop is currently 20000. However after 15876 rows
>>> the call to Put hangs. I am using autoFlush on the HTable. Any ideas why
>>> this may happen? 
>>> 
>>> The table configuration:
>>> DESCRIPTION                                          ENABLED                    
>>> {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true                       
>>> 1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'                            
>>> , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2                            
>>> 147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal                            
>>> se', BLOCKCACHE => 'true'}]}
>>> 
>>> The HBase config on the client is the one in the hbase-default.xml. Some
>>> values:
>>> hbase.client.write.buffer=2097152
>>> hbase.client.pause=1000
>>> hbase.client.retries.number=10
>>> 
>>> If i use another client I am able to put items to the table. I am also
>>> able to scan items from the table using the hbase shell.
>>> 
>>> I have attached the server configuratio
>>> I don't see anything in the region server or master logs. I have them
>>> here.
>>> 
>>> The master server log:
>>> 2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.rootScanner scanning meta region {server:
>>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
>>> 2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.rootScanner scan of 1 row(s) of meta region {server:
>>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
>>> complete
>>> 2011-04-06 19:02:40,157 INFO
>>> org.apache.hadoop.hbase.master.ServerManager: 1 region servers, 0 dead,
>>> average load 42.0
>>> 2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.metaScanner scanning meta region {server:
>>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
>>> 2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.metaScanner scan of 40 row(s) of meta region {server:
>>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
>>> complete
>>> 2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> All 1 .META. region(s) scanned
>>> 
>>> 
>>> The region server logs:
>>> 2011-04-06 19:02:21,294 DEBUG
>>> org.apache.hadoop.hbase.regionserver.HRegion: Creating region
>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
>>> 2011-04-06 19:02:21,295 INFO
>>> org.apache.hadoop.hbase.regionserver.HRegion: Onlined
>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
>>> sequenceid=1
>>> 
>>> 
>> 
>> 
> 
> -- 
> View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31477194.html
> Sent from the HBase User mailing list archive at Nabble.com.
> 
> 

Re: Hmaster is OutOfMemory

Posted by Gaojinchao <ga...@huawei.com>.
If the cluster has 100K regions , restart cluster, Master will need a lot of memory.


-----邮件原件-----
发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
发送时间: 2011年5月10日 13:58
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

2011/5/9 Gaojinchao <ga...@huawei.com>:
> Hbase version : 0.90.3RC0
>
> It happened when creating table with Regions
> I find master started needs so much memory when the cluster has 100K regions

Do you need to have 100k regions in the cluster Gao?  Or, you are just
testing how we do w/ 100k regions?


> It seems likes zkclientcnxn.
>
> It seems master assigned region need improve.
>
>
> top -c | grep 5834
> 5834 root      20   0 8875m 7.9g  11m S    2 50.5  33:53.19 /opt/jdk1.6.0_22/bin/java -Xmx8192m -ea -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode
>

You probably don't need CMSIncrementalMode if your hardware has >= 4 CPUs.

Where do you see heap used in the below?  I just see stats on your
heap config. and a snapshot of what is currently in use.  Seems to be
5G of your 8G heap (~60%).   If you do a full GC, does this go down?

In 0.90.x, HBase Master keeps an 'image' of the cluster in HMaster
RAM.  I'd doubt this takes up 5G but I haven't measured it so perhaps
it could.  Is this a problem for you Gao?  You do have a 100k regions.

St.Ack

> Heap Configuration:
>   MinHeapFreeRatio = 40
>   MaxHeapFreeRatio = 70
>   MaxHeapSize      = 8589934592 (8192.0MB)
>   NewSize          = 21757952 (20.75MB)
>   MaxNewSize       = 174456832 (166.375MB)
>   OldSize          = 65404928 (62.375MB)
>   NewRatio         = 7
>   SurvivorRatio    = 8
>   PermSize         = 21757952 (20.75MB)
>   MaxPermSize      = 88080384 (84.0MB)
>
> Heap Usage:
> New Generation (Eden + 1 Survivor Space):
>   capacity = 100335616 (95.6875MB)
>   used     = 47094720 (44.91302490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   46.93719127612671% used
> Eden Space:
>   capacity = 89194496 (85.0625MB)
>   used     = 35953600 (34.28802490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   40.30921369856723% used
> From Space:
>   capacity = 11141120 (10.625MB)
>   used     = 11141120 (10.625MB)
>   free     = 0 (0.0MB)
>   100.0% used
> To Space:
>   capacity = 11141120 (10.625MB)
>   used     = 0 (0.0MB)
>   free     = 11141120 (10.625MB)
>   0.0% used
> concurrent mark-sweep generation:
>   capacity = 8415477760 (8025.625MB)
>   used     = 5107249280 (4870.6524658203125MB)
>   free     = 3308228480 (3154.9725341796875MB)
>   60.68876213155128% used
> Perm Generation:
>   capacity = 31199232 (29.75390625MB)
>   used     = 18681784 (17.81633758544922MB)
>   free     = 12517448 (11.937568664550781MB)
>   59.87898676480241% used
>
>
> -----邮件原件-----
> 发件人: jdcryans@gmail.com [mailto:jdcryans@gmail.com] 代表 Jean-Daniel Cryans
> 发送时间: 2011年5月10日 1:20
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
>
> It looks like the master entered a GC loop of death (since there are a
> lot of "We slept 76166ms" messages) and finally died. Was it splitting
> logs? Did you get a heap dump? Did you inspect it and can you tell
> what was using all that space?
>
> Thx,
>
> J-D
>
> 2011/5/8 Gaojinchao <ga...@huawei.com>:
>> Hbase version 0.90.2:
>> Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)
>>
>> Other issue. Log is error:
>> see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8
>>
>> Hmaster logs:
>>
>> 2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
>> 2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900
>>
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
>> 2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
>> java.lang.OutOfMemoryError: Java heap space
>>        at java.util.HashMap.addEntry(HashMap.java:753)
>>        at java.util.HashMap.put(HashMap.java:385)
>>        at java.util.HashMap.putAll(HashMap.java:524)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
>>        at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
>>        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
>> 2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
>> 2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
>> 2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
>> 2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
>> 2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
>> org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
>>        at sun.reflect.GeneratedMethodAccessor31.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:570)
>>        at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)
>>
>>        at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
>>        at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
>>        at $Proxy6.next(Unknown Source)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
>>        at org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>>
>

答复: 答复: Hmaster is OutOfMemory

Posted by "Jack Zhang(jian)" <ja...@huawei.com>.
Ok, I try to do it.

Jian Zhang(Jack)

-----邮件原件-----
发件人: Stack [mailto:saint.ack@gmail.com] 
发送时间: 2011年5月13日 9:48
收件人: user@hbase.apache.org
抄送: user@hbase.apache.org
主题: Re: 答复: Hmaster is OutOfMemory

Have a go at fixing it.  If you do it there is some hope it will make it into the code base soon.

My English isn't too good either but it's better than my Chinese 

Stack



On May 12, 2011, at 18:04, "Jack Zhang(jian)" <ja...@huawei.com> wrote:

> Maybe I didn't descript the issue clearly(I hate English ^_^).Yes, we need on branch. I don't have a patch yet, but if need I can try my best to fix this issue.
> 
> -----邮件原件-----
> 发件人: Stack [mailto:saint.ack@gmail.com] 
> 发送时间: 2011年5月13日 8:46
> 收件人: user@hbase.apache.org
> 抄送: user@hbase.apache.org; Chenjian
> 主题: Re: Hmaster is OutOfMemory
> 
> Pardon my being slow but I think I now understand what you are getting at.  I took a look at a heap dump on one of our production servers which is carrying 10k regions.  I see retention of an hserverload per online region.  The count of hserverload hregionload instances retained can be regions * regions.   On my cluster I see retention of about .5 gigs.   On a cluster of 100k regions it would be a good bit worse.   This should be fixed in trunk.  Do you need a fix on branch?   Maybe you have a patch that mulls out load when hsi is added to online regions.  Would need to make sure we did not break balancer if we did this
> 
> Thanks for digging in here
> 
> Stack
> 
> 
> 
> On May 12, 2011, at 5:44, "Jack Zhang(jian)" <ja...@huawei.com> wrote:
> 
>> In our test cluster, 1 hmaster, 3 regionserver, but there are 1,481 HServerInfo instance.
>> So in hbase 0.90.2 , I think there are memory leak in hmaster.
>> 1. Regionsever reports it's load to hmaster period, so the corresponding Hserverinfo will be changed in ServerManager.onlineServers(line 244, 337 in ServerManager) .
>> 2. When hbase cluster start up, AssignmentManager will receive RS_ZK_REGION_OPENED event, then it will construct OpenedRegionHandler(line 431 in AssignmentManager) by the corresponding Hserverinfo instance refreshed by the Regionserver latest.
>> 3. Then OpenedRegionHandler will store this Hserverinfo into assignmentManager.regionOnline(line 97 in OpenedRegionHandler).
>> 
>> After regionserver reported load, hmaster always store the new hserverinfo instance to assignmentManager.regionOnline if region opened meanwhile.
>> So the more the region opened, the more memory will leak.
>> 
>> -----邮件原件-----
>> 发件人: Gaojinchao [mailto:gaojinchao@huawei.com] 
>> 发送时间: 2011年5月12日 15:24
>> 收件人: user@hbase.apache.org
>> 主题: Re: Hmaster is OutOfMemory
>> 
>> Thanks, Stack.
>> The heap dump is so big. I try to dig it and share the result. 
>> Then ,you can give me some suggestion.
>> 
>> 
>> Do you give me more suggestion about my cluster?
>> 
>> My application:
>> write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
>> read opreation is rarely, but the latency time demands lower than 5s
>> 
>> machine:
>> cpu:    8 core 2.GHz
>> memory: 24G, Hbase use 8G
>> Disk:   2T*8 = 16T
>> 
>> node number: 13 nodes
>> 
>> dfs configure:
>> 
>> dfs.block.size 256M 
>> dfs.datanode.handler.count 10 
>> dfs.namenode.handler.count 30 
>> dfs.datanode.max.xcievers 2047 
>> dfs.support.append True 
>> 
>> hbase configure:
>> 
>> hbase.regionserver.handler.count 50 
>> hbase.regionserver.global.memstore.upperLimit 0.4 
>> hbase.regionserver.global.memstore.lowerLimit 0.35 
>> hbase.hregion.memstore.flush.size 128M 
>> hbase.hregion.max.filesize 512M 
>> hbase.client.scanner.caching 1 
>> hfile.block.cache.size 0.2 
>> hbase.hregion.memstore.block.multiplier 3 
>> hbase.hstore.blockingStoreFiles 10 
>> hbase.hstore.compaction.min.size 64M 
>> 
>> compress: gz
>> 
>> I am afraid of some problem:
>> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
>> 2, If a region server crashed, It could bring on the other region server crashed?
>> 
>> Can you give some suggestion about the hbase parameter and my cluster ?
>> 
>> -----邮件原件-----
>> 发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
>> 发送时间: 2011年5月10日 23:21
>> 收件人: user@hbase.apache.org
>> 主题: Re: Hmaster is OutOfMemory
>> 
>> 2011/5/9 Gaojinchao <ga...@huawei.com>:
>>> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
>>> In the future, If store several PB, It will more regions.
>> 
>> You might want to up the size of your regions to 4G (FB run w/ big
>> regions IIUC).
>> 
>> Do you want to put up a heap dump for me to take a look at.  That'd be
>> easier than me figuring time to try and replicate your scenario.
>> 
>> Thanks Gao,
>> St.Ack

Re: 答复: Hmaster is OutOfMemory

Posted by Stack <sa...@gmail.com>.
Have a go at fixing it.  If you do it there is some hope it will make it into the code base soon.

My English isn't too good either but it's better than my Chinese 

Stack



On May 12, 2011, at 18:04, "Jack Zhang(jian)" <ja...@huawei.com> wrote:

> Maybe I didn't descript the issue clearly(I hate English ^_^).Yes, we need on branch. I don't have a patch yet, but if need I can try my best to fix this issue.
> 
> -----邮件原件-----
> 发件人: Stack [mailto:saint.ack@gmail.com] 
> 发送时间: 2011年5月13日 8:46
> 收件人: user@hbase.apache.org
> 抄送: user@hbase.apache.org; Chenjian
> 主题: Re: Hmaster is OutOfMemory
> 
> Pardon my being slow but I think I now understand what you are getting at.  I took a look at a heap dump on one of our production servers which is carrying 10k regions.  I see retention of an hserverload per online region.  The count of hserverload hregionload instances retained can be regions * regions.   On my cluster I see retention of about .5 gigs.   On a cluster of 100k regions it would be a good bit worse.   This should be fixed in trunk.  Do you need a fix on branch?   Maybe you have a patch that mulls out load when hsi is added to online regions.  Would need to make sure we did not break balancer if we did this
> 
> Thanks for digging in here
> 
> Stack
> 
> 
> 
> On May 12, 2011, at 5:44, "Jack Zhang(jian)" <ja...@huawei.com> wrote:
> 
>> In our test cluster, 1 hmaster, 3 regionserver, but there are 1,481 HServerInfo instance.
>> So in hbase 0.90.2 , I think there are memory leak in hmaster.
>> 1. Regionsever reports it's load to hmaster period, so the corresponding Hserverinfo will be changed in ServerManager.onlineServers(line 244, 337 in ServerManager) .
>> 2. When hbase cluster start up, AssignmentManager will receive RS_ZK_REGION_OPENED event, then it will construct OpenedRegionHandler(line 431 in AssignmentManager) by the corresponding Hserverinfo instance refreshed by the Regionserver latest.
>> 3. Then OpenedRegionHandler will store this Hserverinfo into assignmentManager.regionOnline(line 97 in OpenedRegionHandler).
>> 
>> After regionserver reported load, hmaster always store the new hserverinfo instance to assignmentManager.regionOnline if region opened meanwhile.
>> So the more the region opened, the more memory will leak.
>> 
>> -----邮件原件-----
>> 发件人: Gaojinchao [mailto:gaojinchao@huawei.com] 
>> 发送时间: 2011年5月12日 15:24
>> 收件人: user@hbase.apache.org
>> 主题: Re: Hmaster is OutOfMemory
>> 
>> Thanks, Stack.
>> The heap dump is so big. I try to dig it and share the result. 
>> Then ,you can give me some suggestion.
>> 
>> 
>> Do you give me more suggestion about my cluster?
>> 
>> My application:
>> write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
>> read opreation is rarely, but the latency time demands lower than 5s
>> 
>> machine:
>> cpu:    8 core 2.GHz
>> memory: 24G, Hbase use 8G
>> Disk:   2T*8 = 16T
>> 
>> node number: 13 nodes
>> 
>> dfs configure:
>> 
>> dfs.block.size 256M 
>> dfs.datanode.handler.count 10 
>> dfs.namenode.handler.count 30 
>> dfs.datanode.max.xcievers 2047 
>> dfs.support.append True 
>> 
>> hbase configure:
>> 
>> hbase.regionserver.handler.count 50 
>> hbase.regionserver.global.memstore.upperLimit 0.4 
>> hbase.regionserver.global.memstore.lowerLimit 0.35 
>> hbase.hregion.memstore.flush.size 128M 
>> hbase.hregion.max.filesize 512M 
>> hbase.client.scanner.caching 1 
>> hfile.block.cache.size 0.2 
>> hbase.hregion.memstore.block.multiplier 3 
>> hbase.hstore.blockingStoreFiles 10 
>> hbase.hstore.compaction.min.size 64M 
>> 
>> compress: gz
>> 
>> I am afraid of some problem:
>> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
>> 2, If a region server crashed, It could bring on the other region server crashed?
>> 
>> Can you give some suggestion about the hbase parameter and my cluster ?
>> 
>> -----邮件原件-----
>> 发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
>> 发送时间: 2011年5月10日 23:21
>> 收件人: user@hbase.apache.org
>> 主题: Re: Hmaster is OutOfMemory
>> 
>> 2011/5/9 Gaojinchao <ga...@huawei.com>:
>>> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
>>> In the future, If store several PB, It will more regions.
>> 
>> You might want to up the size of your regions to 4G (FB run w/ big
>> regions IIUC).
>> 
>> Do you want to put up a heap dump for me to take a look at.  That'd be
>> easier than me figuring time to try and replicate your scenario.
>> 
>> Thanks Gao,
>> St.Ack

答复: Hmaster is OutOfMemory

Posted by "Jack Zhang(jian)" <ja...@huawei.com>.
Maybe I didn't descript the issue clearly(I hate English ^_^).Yes, we need on branch. I don't have a patch yet, but if need I can try my best to fix this issue.

-----邮件原件-----
发件人: Stack [mailto:saint.ack@gmail.com] 
发送时间: 2011年5月13日 8:46
收件人: user@hbase.apache.org
抄送: user@hbase.apache.org; Chenjian
主题: Re: Hmaster is OutOfMemory

Pardon my being slow but I think I now understand what you are getting at.  I took a look at a heap dump on one of our production servers which is carrying 10k regions.  I see retention of an hserverload per online region.  The count of hserverload hregionload instances retained can be regions * regions.   On my cluster I see retention of about .5 gigs.   On a cluster of 100k regions it would be a good bit worse.   This should be fixed in trunk.  Do you need a fix on branch?   Maybe you have a patch that mulls out load when hsi is added to online regions.  Would need to make sure we did not break balancer if we did this

Thanks for digging in here

Stack



On May 12, 2011, at 5:44, "Jack Zhang(jian)" <ja...@huawei.com> wrote:

> In our test cluster, 1 hmaster, 3 regionserver, but there are 1,481 HServerInfo instance.
> So in hbase 0.90.2 , I think there are memory leak in hmaster.
> 1. Regionsever reports it's load to hmaster period, so the corresponding Hserverinfo will be changed in ServerManager.onlineServers(line 244, 337 in ServerManager) .
> 2. When hbase cluster start up, AssignmentManager will receive RS_ZK_REGION_OPENED event, then it will construct OpenedRegionHandler(line 431 in AssignmentManager) by the corresponding Hserverinfo instance refreshed by the Regionserver latest.
> 3. Then OpenedRegionHandler will store this Hserverinfo into assignmentManager.regionOnline(line 97 in OpenedRegionHandler).
> 
> After regionserver reported load, hmaster always store the new hserverinfo instance to assignmentManager.regionOnline if region opened meanwhile.
> So the more the region opened, the more memory will leak.
> 
> -----邮件原件-----
> 发件人: Gaojinchao [mailto:gaojinchao@huawei.com] 
> 发送时间: 2011年5月12日 15:24
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
> 
> Thanks, Stack.
> The heap dump is so big. I try to dig it and share the result. 
> Then ,you can give me some suggestion.
> 
> 
> Do you give me more suggestion about my cluster?
> 
> My application:
> write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
> read opreation is rarely, but the latency time demands lower than 5s
> 
> machine:
> cpu:    8 core 2.GHz
> memory: 24G, Hbase use 8G
> Disk:   2T*8 = 16T
> 
> node number: 13 nodes
> 
> dfs configure:
> 
> dfs.block.size 256M 
> dfs.datanode.handler.count 10 
> dfs.namenode.handler.count 30 
> dfs.datanode.max.xcievers 2047 
> dfs.support.append True 
> 
> hbase configure:
> 
> hbase.regionserver.handler.count 50 
> hbase.regionserver.global.memstore.upperLimit 0.4 
> hbase.regionserver.global.memstore.lowerLimit 0.35 
> hbase.hregion.memstore.flush.size 128M 
> hbase.hregion.max.filesize 512M 
> hbase.client.scanner.caching 1 
> hfile.block.cache.size 0.2 
> hbase.hregion.memstore.block.multiplier 3 
> hbase.hstore.blockingStoreFiles 10 
> hbase.hstore.compaction.min.size 64M 
> 
> compress: gz
> 
> I am afraid of some problem:
> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
> 2, If a region server crashed, It could bring on the other region server crashed?
> 
> Can you give some suggestion about the hbase parameter and my cluster ?
> 
> -----邮件原件-----
> 发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
> 发送时间: 2011年5月10日 23:21
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
> 
> 2011/5/9 Gaojinchao <ga...@huawei.com>:
>> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
>> In the future, If store several PB, It will more regions.
> 
> You might want to up the size of your regions to 4G (FB run w/ big
> regions IIUC).
> 
> Do you want to put up a heap dump for me to take a look at.  That'd be
> easier than me figuring time to try and replicate your scenario.
> 
> Thanks Gao,
> St.Ack

Re: Hmaster is OutOfMemory

Posted by Stack <sa...@gmail.com>.
Pardon my being slow but I think I now understand what you are getting at.  I took a look at a heap dump on one of our production servers which is carrying 10k regions.  I see retention of an hserverload per online region.  The count of hserverload hregionload instances retained can be regions * regions.   On my cluster I see retention of about .5 gigs.   On a cluster of 100k regions it would be a good bit worse.   This should be fixed in trunk.  Do you need a fix on branch?   Maybe you have a patch that mulls out load when hsi is added to online regions.  Would need to make sure we did not break balancer if we did this

Thanks for digging in here

Stack



On May 12, 2011, at 5:44, "Jack Zhang(jian)" <ja...@huawei.com> wrote:

> In our test cluster, 1 hmaster, 3 regionserver, but there are 1,481 HServerInfo instance.
> So in hbase 0.90.2 , I think there are memory leak in hmaster.
> 1. Regionsever reports it's load to hmaster period, so the corresponding Hserverinfo will be changed in ServerManager.onlineServers(line 244, 337 in ServerManager) .
> 2. When hbase cluster start up, AssignmentManager will receive RS_ZK_REGION_OPENED event, then it will construct OpenedRegionHandler(line 431 in AssignmentManager) by the corresponding Hserverinfo instance refreshed by the Regionserver latest.
> 3. Then OpenedRegionHandler will store this Hserverinfo into assignmentManager.regionOnline(line 97 in OpenedRegionHandler).
> 
> After regionserver reported load, hmaster always store the new hserverinfo instance to assignmentManager.regionOnline if region opened meanwhile.
> So the more the region opened, the more memory will leak.
> 
> -----邮件原件-----
> 发件人: Gaojinchao [mailto:gaojinchao@huawei.com] 
> 发送时间: 2011年5月12日 15:24
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
> 
> Thanks, Stack.
> The heap dump is so big. I try to dig it and share the result. 
> Then ,you can give me some suggestion.
> 
> 
> Do you give me more suggestion about my cluster?
> 
> My application:
> write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
> read opreation is rarely, but the latency time demands lower than 5s
> 
> machine:
> cpu:    8 core 2.GHz
> memory: 24G, Hbase use 8G
> Disk:   2T*8 = 16T
> 
> node number: 13 nodes
> 
> dfs configure:
> 
> dfs.block.size 256M 
> dfs.datanode.handler.count 10 
> dfs.namenode.handler.count 30 
> dfs.datanode.max.xcievers 2047 
> dfs.support.append True 
> 
> hbase configure:
> 
> hbase.regionserver.handler.count 50 
> hbase.regionserver.global.memstore.upperLimit 0.4 
> hbase.regionserver.global.memstore.lowerLimit 0.35 
> hbase.hregion.memstore.flush.size 128M 
> hbase.hregion.max.filesize 512M 
> hbase.client.scanner.caching 1 
> hfile.block.cache.size 0.2 
> hbase.hregion.memstore.block.multiplier 3 
> hbase.hstore.blockingStoreFiles 10 
> hbase.hstore.compaction.min.size 64M 
> 
> compress: gz
> 
> I am afraid of some problem:
> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
> 2, If a region server crashed, It could bring on the other region server crashed?
> 
> Can you give some suggestion about the hbase parameter and my cluster ?
> 
> -----邮件原件-----
> 发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
> 发送时间: 2011年5月10日 23:21
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
> 
> 2011/5/9 Gaojinchao <ga...@huawei.com>:
>> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
>> In the future, If store several PB, It will more regions.
> 
> You might want to up the size of your regions to 4G (FB run w/ big
> regions IIUC).
> 
> Do you want to put up a heap dump for me to take a look at.  That'd be
> easier than me figuring time to try and replicate your scenario.
> 
> Thanks Gao,
> St.Ack

Re: Hmaster is OutOfMemory

Posted by Stack <st...@duboce.net>.
As far as I can tell, what you describe below is the expected
behavior.  What would you suggest we do otherwise?  Do you find that
these HServerInfo instances are consuming lots of memory?

FYI, HServerInfo is purged from TRUNK.

Thanks Jean,
St.Ack

2011/5/12 Jack Zhang(jian) <ja...@huawei.com>:
> In our test cluster, 1 hmaster, 3 regionserver, but there are 1,481 HServerInfo instance.
> So in hbase 0.90.2 , I think there are memory leak in hmaster.
> 1. Regionsever reports it's load to hmaster period, so the corresponding Hserverinfo will be changed in ServerManager.onlineServers(line 244, 337 in ServerManager) .
> 2. When hbase cluster start up, AssignmentManager will receive RS_ZK_REGION_OPENED event, then it will construct OpenedRegionHandler(line 431 in AssignmentManager) by the corresponding Hserverinfo instance refreshed by the Regionserver latest.
> 3. Then OpenedRegionHandler will store this Hserverinfo into assignmentManager.regionOnline(line 97 in OpenedRegionHandler).
>
> After regionserver reported load, hmaster always store the new hserverinfo instance to assignmentManager.regionOnline if region opened meanwhile.
> So the more the region opened, the more memory will leak.
>
> -----邮件原件-----
> 发件人: Gaojinchao [mailto:gaojinchao@huawei.com]
> 发送时间: 2011年5月12日 15:24
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
>
> Thanks, Stack.
> The heap dump is so big. I try to dig it and share the result.
> Then ,you can give me some suggestion.
>
>
> Do you give me more suggestion about my cluster?
>
> My application:
> write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
> read opreation is rarely, but the latency time demands lower than 5s
>
> machine:
> cpu:    8 core 2.GHz
> memory: 24G, Hbase use 8G
> Disk:   2T*8 = 16T
>
> node number: 13 nodes
>
> dfs configure:
>
> dfs.block.size 256M
> dfs.datanode.handler.count 10
> dfs.namenode.handler.count 30
> dfs.datanode.max.xcievers 2047
> dfs.support.append True
>
> hbase configure:
>
> hbase.regionserver.handler.count 50
> hbase.regionserver.global.memstore.upperLimit 0.4
> hbase.regionserver.global.memstore.lowerLimit 0.35
> hbase.hregion.memstore.flush.size 128M
> hbase.hregion.max.filesize 512M
> hbase.client.scanner.caching 1
> hfile.block.cache.size 0.2
> hbase.hregion.memstore.block.multiplier 3
> hbase.hstore.blockingStoreFiles 10
> hbase.hstore.compaction.min.size 64M
>
> compress: gz
>
> I am afraid of some problem:
> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
> 2, If a region server crashed, It could bring on the other region server crashed?
>
> Can you give some suggestion about the hbase parameter and my cluster ?
>
> -----邮件原件-----
> 发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
> 发送时间: 2011年5月10日 23:21
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
>
> 2011/5/9 Gaojinchao <ga...@huawei.com>:
>> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
>> In the future, If store several PB, It will more regions.
>
> You might want to up the size of your regions to 4G (FB run w/ big
> regions IIUC).
>
> Do you want to put up a heap dump for me to take a look at.  That'd be
> easier than me figuring time to try and replicate your scenario.
>
> Thanks Gao,
> St.Ack
>

re: Hmaster is OutOfMemory

Posted by "Jack Zhang(jian)" <ja...@huawei.com>.
In our test cluster, 1 hmaster, 3 regionserver, but there are 1,481 HServerInfo instance.
So in hbase 0.90.2 , I think there are memory leak in hmaster.
1. Regionsever reports it's load to hmaster period, so the corresponding Hserverinfo will be changed in ServerManager.onlineServers(line 244, 337 in ServerManager) .
2. When hbase cluster start up, AssignmentManager will receive RS_ZK_REGION_OPENED event, then it will construct OpenedRegionHandler(line 431 in AssignmentManager) by the corresponding Hserverinfo instance refreshed by the Regionserver latest.
3. Then OpenedRegionHandler will store this Hserverinfo into assignmentManager.regionOnline(line 97 in OpenedRegionHandler).

After regionserver reported load, hmaster always store the new hserverinfo instance to assignmentManager.regionOnline if region opened meanwhile.
So the more the region opened, the more memory will leak.

-----邮件原件-----
发件人: Gaojinchao [mailto:gaojinchao@huawei.com] 
发送时间: 2011年5月12日 15:24
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

Thanks, Stack.
The heap dump is so big. I try to dig it and share the result. 
Then ,you can give me some suggestion.


Do you give me more suggestion about my cluster?

My application:
write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
read opreation is rarely, but the latency time demands lower than 5s

machine:
cpu:    8 core 2.GHz
memory: 24G, Hbase use 8G
Disk:   2T*8 = 16T

node number: 13 nodes

dfs configure:

dfs.block.size 256M 
dfs.datanode.handler.count 10 
dfs.namenode.handler.count 30 
dfs.datanode.max.xcievers 2047 
dfs.support.append True 
 
hbase configure:

hbase.regionserver.handler.count 50 
hbase.regionserver.global.memstore.upperLimit 0.4 
hbase.regionserver.global.memstore.lowerLimit 0.35 
hbase.hregion.memstore.flush.size 128M 
hbase.hregion.max.filesize 512M 
hbase.client.scanner.caching 1 
hfile.block.cache.size 0.2 
hbase.hregion.memstore.block.multiplier 3 
hbase.hstore.blockingStoreFiles 10 
hbase.hstore.compaction.min.size 64M 

compress: gz

I am afraid of some problem:
1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
2, If a region server crashed, It could bring on the other region server crashed?

Can you give some suggestion about the hbase parameter and my cluster ?

-----邮件原件-----
发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
发送时间: 2011年5月10日 23:21
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

2011/5/9 Gaojinchao <ga...@huawei.com>:
> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
> In the future, If store several PB, It will more regions.

You might want to up the size of your regions to 4G (FB run w/ big
regions IIUC).

Do you want to put up a heap dump for me to take a look at.  That'd be
easier than me figuring time to try and replicate your scenario.

Thanks Gao,
St.Ack

Re: Hmaster is OutOfMemory

Posted by Gaojinchao <ga...@huawei.com>.
Hi , Thanks for your share.
In my machine, The disk has 14T~16T. We need use all disks.
So I want to solve it by Key design.
eg: 
A region server has 14T capability ( more than 14K regions )
So, I can make 1000 or less active regions for certain time.
First day: 0~1000
Second day: 1001~2000
..............

It seems some issues for region server restart.
The regions will be resigned. So, the balance is very importance

Other issue is cluster restart, How can these regions be resigned quickly.
I change the parameter hbase.regionserver.executor.openregion.threads and hbase.master.executor.openregion.threads.
I am testing it.

Do you think my scheme solution is feasibility? Thanks.


-----邮件原件-----
发件人: im_gumby@hotmail.com [mailto:im_gumby@hotmail.com] 代表 Michel Segel
发送时间: 2011年5月12日 18:47
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

> 
> On May 12, 2011, at 2:24 AM, Gaojinchao <ga...@huawei.com> wrote:
> 
> I am afraid of some problem:
> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
> 2, If a region server crashed, It could bring on the other region server crashed?
> 
> Can you give some suggestion about the hbase parameter and my cluster ?


Hi,

From what everyone I've talked with, a rule of thumb is to have no more than 1000 regions per region server.
You can set this on a per table basis...

If you do the math, a 2GB max file size would mean that each node would then be able to have 2TB of hbase storage within 1000 regions per region server.

I'm testing this... But it takes a while to generate the data for the test...
The goal is to see how 4GB files work and to see the impact on the cluster.
At 4GB max files... 1000 regions would be 4 TB per node ... 

Note YMMV and I'm still testing. I'm sure someone with more experience has some better advice...


Sent from a remote device. Please excuse any typos...

Mike Segel


Re: Hmaster is OutOfMemory

Posted by Michel Segel <mi...@hotmail.com>.
> 
> On May 12, 2011, at 2:24 AM, Gaojinchao <ga...@huawei.com> wrote:
> 
> I am afraid of some problem:
> 1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
> 2, If a region server crashed, It could bring on the other region server crashed?
> 
> Can you give some suggestion about the hbase parameter and my cluster ?


Hi,

From what everyone I've talked with, a rule of thumb is to have no more than 1000 regions per region server.
You can set this on a per table basis...

If you do the math, a 2GB max file size would mean that each node would then be able to have 2TB of hbase storage within 1000 regions per region server.

I'm testing this... But it takes a while to generate the data for the test...
The goal is to see how 4GB files work and to see the impact on the cluster.
At 4GB max files... 1000 regions would be 4 TB per node ... 

Note YMMV and I'm still testing. I'm sure someone with more experience has some better advice...


Sent from a remote device. Please excuse any typos...

Mike Segel


Re: Hmaster is OutOfMemory

Posted by Gaojinchao <ga...@huawei.com>.
Thanks, Stack.
The heap dump is so big. I try to dig it and share the result. 
Then ,you can give me some suggestion.


Do you give me more suggestion about my cluster?

My application:
write operation with api put<list> is about 75k Puts/s( one put about 400 Bytes)
read opreation is rarely, but the latency time demands lower than 5s

machine:
cpu:    8 core 2.GHz
memory: 24G, Hbase use 8G
Disk:   2T*8 = 16T

node number: 13 nodes

dfs configure:

dfs.block.size 256M 
dfs.datanode.handler.count 10 
dfs.namenode.handler.count 30 
dfs.datanode.max.xcievers 2047 
dfs.support.append True 
 
hbase configure:

hbase.regionserver.handler.count 50 
hbase.regionserver.global.memstore.upperLimit 0.4 
hbase.regionserver.global.memstore.lowerLimit 0.35 
hbase.hregion.memstore.flush.size 128M 
hbase.hregion.max.filesize 512M 
hbase.client.scanner.caching 1 
hfile.block.cache.size 0.2 
hbase.hregion.memstore.block.multiplier 3 
hbase.hstore.blockingStoreFiles 10 
hbase.hstore.compaction.min.size 64M 

compress: gz

I am afraid of some problem:
1, One region server has about 12k reigons or more, if up the hregion.max.filesize , parallel scalability will be low and affect scan latency .
2, If a region server crashed, It could bring on the other region server crashed?

Can you give some suggestion about the hbase parameter and my cluster ?

-----邮件原件-----
发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
发送时间: 2011年5月10日 23:21
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

2011/5/9 Gaojinchao <ga...@huawei.com>:
> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
> In the future, If store several PB, It will more regions.

You might want to up the size of your regions to 4G (FB run w/ big
regions IIUC).

Do you want to put up a heap dump for me to take a look at.  That'd be
easier than me figuring time to try and replicate your scenario.

Thanks Gao,
St.Ack

Re: Hmaster is OutOfMemory

Posted by Stack <st...@duboce.net>.
2011/5/9 Gaojinchao <ga...@huawei.com>:
> My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
> In the future, If store several PB, It will more regions.

You might want to up the size of your regions to 4G (FB run w/ big
regions IIUC).

Do you want to put up a heap dump for me to take a look at.  That'd be
easier than me figuring time to try and replicate your scenario.

Thanks Gao,
St.Ack

Re: Hmaster is OutOfMemory

Posted by Gaojinchao <ga...@huawei.com>.
My first cluster needs save 147 TB data. If one region has 512M or 1 GB, It will be 300 K regions or 147K regions.
In the future, If store several PB, It will more regions.
I have a silly question.
how do it in Facebook? 

-----邮件原件-----
发件人: saint.ack@gmail.com [mailto:saint.ack@gmail.com] 代表 Stack
发送时间: 2011年5月10日 13:58
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

2011/5/9 Gaojinchao <ga...@huawei.com>:
> Hbase version : 0.90.3RC0
>
> It happened when creating table with Regions
> I find master started needs so much memory when the cluster has 100K regions

Do you need to have 100k regions in the cluster Gao?  Or, you are just
testing how we do w/ 100k regions?


> It seems likes zkclientcnxn.
>
> It seems master assigned region need improve.
>
>
> top -c | grep 5834
> 5834 root      20   0 8875m 7.9g  11m S    2 50.5  33:53.19 /opt/jdk1.6.0_22/bin/java -Xmx8192m -ea -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode
>

You probably don't need CMSIncrementalMode if your hardware has >= 4 CPUs.

Where do you see heap used in the below?  I just see stats on your
heap config. and a snapshot of what is currently in use.  Seems to be
5G of your 8G heap (~60%).   If you do a full GC, does this go down?

In 0.90.x, HBase Master keeps an 'image' of the cluster in HMaster
RAM.  I'd doubt this takes up 5G but I haven't measured it so perhaps
it could.  Is this a problem for you Gao?  You do have a 100k regions.

St.Ack

> Heap Configuration:
>   MinHeapFreeRatio = 40
>   MaxHeapFreeRatio = 70
>   MaxHeapSize      = 8589934592 (8192.0MB)
>   NewSize          = 21757952 (20.75MB)
>   MaxNewSize       = 174456832 (166.375MB)
>   OldSize          = 65404928 (62.375MB)
>   NewRatio         = 7
>   SurvivorRatio    = 8
>   PermSize         = 21757952 (20.75MB)
>   MaxPermSize      = 88080384 (84.0MB)
>
> Heap Usage:
> New Generation (Eden + 1 Survivor Space):
>   capacity = 100335616 (95.6875MB)
>   used     = 47094720 (44.91302490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   46.93719127612671% used
> Eden Space:
>   capacity = 89194496 (85.0625MB)
>   used     = 35953600 (34.28802490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   40.30921369856723% used
> From Space:
>   capacity = 11141120 (10.625MB)
>   used     = 11141120 (10.625MB)
>   free     = 0 (0.0MB)
>   100.0% used
> To Space:
>   capacity = 11141120 (10.625MB)
>   used     = 0 (0.0MB)
>   free     = 11141120 (10.625MB)
>   0.0% used
> concurrent mark-sweep generation:
>   capacity = 8415477760 (8025.625MB)
>   used     = 5107249280 (4870.6524658203125MB)
>   free     = 3308228480 (3154.9725341796875MB)
>   60.68876213155128% used
> Perm Generation:
>   capacity = 31199232 (29.75390625MB)
>   used     = 18681784 (17.81633758544922MB)
>   free     = 12517448 (11.937568664550781MB)
>   59.87898676480241% used
>
>
> -----邮件原件-----
> 发件人: jdcryans@gmail.com [mailto:jdcryans@gmail.com] 代表 Jean-Daniel Cryans
> 发送时间: 2011年5月10日 1:20
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
>
> It looks like the master entered a GC loop of death (since there are a
> lot of "We slept 76166ms" messages) and finally died. Was it splitting
> logs? Did you get a heap dump? Did you inspect it and can you tell
> what was using all that space?
>
> Thx,
>
> J-D
>
> 2011/5/8 Gaojinchao <ga...@huawei.com>:
>> Hbase version 0.90.2:
>> Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)
>>
>> Other issue. Log is error:
>> see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8
>>
>> Hmaster logs:
>>
>> 2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
>> 2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900
>>
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
>> 2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
>> java.lang.OutOfMemoryError: Java heap space
>>        at java.util.HashMap.addEntry(HashMap.java:753)
>>        at java.util.HashMap.put(HashMap.java:385)
>>        at java.util.HashMap.putAll(HashMap.java:524)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
>>        at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
>>        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
>> 2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
>> 2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
>> 2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
>> 2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
>> 2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
>> org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
>>        at sun.reflect.GeneratedMethodAccessor31.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:570)
>>        at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)
>>
>>        at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
>>        at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
>>        at $Proxy6.next(Unknown Source)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
>>        at org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>>
>

Re: Hmaster is OutOfMemory

Posted by Stack <st...@duboce.net>.
2011/5/9 Gaojinchao <ga...@huawei.com>:
> Hbase version : 0.90.3RC0
>
> It happened when creating table with Regions
> I find master started needs so much memory when the cluster has 100K regions

Do you need to have 100k regions in the cluster Gao?  Or, you are just
testing how we do w/ 100k regions?


> It seems likes zkclientcnxn.
>
> It seems master assigned region need improve.
>
>
> top -c | grep 5834
> 5834 root      20   0 8875m 7.9g  11m S    2 50.5  33:53.19 /opt/jdk1.6.0_22/bin/java -Xmx8192m -ea -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode
>

You probably don't need CMSIncrementalMode if your hardware has >= 4 CPUs.

Where do you see heap used in the below?  I just see stats on your
heap config. and a snapshot of what is currently in use.  Seems to be
5G of your 8G heap (~60%).   If you do a full GC, does this go down?

In 0.90.x, HBase Master keeps an 'image' of the cluster in HMaster
RAM.  I'd doubt this takes up 5G but I haven't measured it so perhaps
it could.  Is this a problem for you Gao?  You do have a 100k regions.

St.Ack

> Heap Configuration:
>   MinHeapFreeRatio = 40
>   MaxHeapFreeRatio = 70
>   MaxHeapSize      = 8589934592 (8192.0MB)
>   NewSize          = 21757952 (20.75MB)
>   MaxNewSize       = 174456832 (166.375MB)
>   OldSize          = 65404928 (62.375MB)
>   NewRatio         = 7
>   SurvivorRatio    = 8
>   PermSize         = 21757952 (20.75MB)
>   MaxPermSize      = 88080384 (84.0MB)
>
> Heap Usage:
> New Generation (Eden + 1 Survivor Space):
>   capacity = 100335616 (95.6875MB)
>   used     = 47094720 (44.91302490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   46.93719127612671% used
> Eden Space:
>   capacity = 89194496 (85.0625MB)
>   used     = 35953600 (34.28802490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   40.30921369856723% used
> From Space:
>   capacity = 11141120 (10.625MB)
>   used     = 11141120 (10.625MB)
>   free     = 0 (0.0MB)
>   100.0% used
> To Space:
>   capacity = 11141120 (10.625MB)
>   used     = 0 (0.0MB)
>   free     = 11141120 (10.625MB)
>   0.0% used
> concurrent mark-sweep generation:
>   capacity = 8415477760 (8025.625MB)
>   used     = 5107249280 (4870.6524658203125MB)
>   free     = 3308228480 (3154.9725341796875MB)
>   60.68876213155128% used
> Perm Generation:
>   capacity = 31199232 (29.75390625MB)
>   used     = 18681784 (17.81633758544922MB)
>   free     = 12517448 (11.937568664550781MB)
>   59.87898676480241% used
>
>
> -----邮件原件-----
> 发件人: jdcryans@gmail.com [mailto:jdcryans@gmail.com] 代表 Jean-Daniel Cryans
> 发送时间: 2011年5月10日 1:20
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
>
> It looks like the master entered a GC loop of death (since there are a
> lot of "We slept 76166ms" messages) and finally died. Was it splitting
> logs? Did you get a heap dump? Did you inspect it and can you tell
> what was using all that space?
>
> Thx,
>
> J-D
>
> 2011/5/8 Gaojinchao <ga...@huawei.com>:
>> Hbase version 0.90.2:
>> Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)
>>
>> Other issue. Log is error:
>> see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8
>>
>> Hmaster logs:
>>
>> 2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
>> 2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900
>>
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
>> 2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
>> java.lang.OutOfMemoryError: Java heap space
>>        at java.util.HashMap.addEntry(HashMap.java:753)
>>        at java.util.HashMap.put(HashMap.java:385)
>>        at java.util.HashMap.putAll(HashMap.java:524)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
>>        at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
>>        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
>> 2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
>> 2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
>> 2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
>> 2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
>> 2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
>> org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
>>        at sun.reflect.GeneratedMethodAccessor31.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:570)
>>        at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)
>>
>>        at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
>>        at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
>>        at $Proxy6.next(Unknown Source)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
>>        at org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>>
>

Re: Hmaster is OutOfMemory

Posted by Stack <st...@duboce.net>.
Want to dump the heap and put it somewhere so we can pull it and take
a look Gao?
St.Ack

2011/5/9 Gaojinchao <ga...@huawei.com>:
> Hbase version : 0.90.3RC0
>
> It happened when creating table with Regions
> I find master started needs so much memory when the cluster has 100K regions
> It seems likes zkclientcnxn.
>
> It seems master assigned region need improve.
>
>
> top -c | grep 5834
> 5834 root      20   0 8875m 7.9g  11m S    2 50.5  33:53.19 /opt/jdk1.6.0_22/bin/java -Xmx8192m -ea -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode
>
> Attaching to process ID 5834, please wait...
> Debugger attached successfully.
> Server compiler detected.
> JVM version is 17.1-b03
>
> using parallel threads in the new generation.
> using thread-local object allocation.
> Concurrent Mark-Sweep GC
>
> Heap Configuration:
>   MinHeapFreeRatio = 40
>   MaxHeapFreeRatio = 70
>   MaxHeapSize      = 8589934592 (8192.0MB)
>   NewSize          = 21757952 (20.75MB)
>   MaxNewSize       = 174456832 (166.375MB)
>   OldSize          = 65404928 (62.375MB)
>   NewRatio         = 7
>   SurvivorRatio    = 8
>   PermSize         = 21757952 (20.75MB)
>   MaxPermSize      = 88080384 (84.0MB)
>
> Heap Usage:
> New Generation (Eden + 1 Survivor Space):
>   capacity = 100335616 (95.6875MB)
>   used     = 47094720 (44.91302490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   46.93719127612671% used
> Eden Space:
>   capacity = 89194496 (85.0625MB)
>   used     = 35953600 (34.28802490234375MB)
>   free     = 53240896 (50.77447509765625MB)
>   40.30921369856723% used
> From Space:
>   capacity = 11141120 (10.625MB)
>   used     = 11141120 (10.625MB)
>   free     = 0 (0.0MB)
>   100.0% used
> To Space:
>   capacity = 11141120 (10.625MB)
>   used     = 0 (0.0MB)
>   free     = 11141120 (10.625MB)
>   0.0% used
> concurrent mark-sweep generation:
>   capacity = 8415477760 (8025.625MB)
>   used     = 5107249280 (4870.6524658203125MB)
>   free     = 3308228480 (3154.9725341796875MB)
>   60.68876213155128% used
> Perm Generation:
>   capacity = 31199232 (29.75390625MB)
>   used     = 18681784 (17.81633758544922MB)
>   free     = 12517448 (11.937568664550781MB)
>   59.87898676480241% used
>
>
> -----邮件原件-----
> 发件人: jdcryans@gmail.com [mailto:jdcryans@gmail.com] 代表 Jean-Daniel Cryans
> 发送时间: 2011年5月10日 1:20
> 收件人: user@hbase.apache.org
> 主题: Re: Hmaster is OutOfMemory
>
> It looks like the master entered a GC loop of death (since there are a
> lot of "We slept 76166ms" messages) and finally died. Was it splitting
> logs? Did you get a heap dump? Did you inspect it and can you tell
> what was using all that space?
>
> Thx,
>
> J-D
>
> 2011/5/8 Gaojinchao <ga...@huawei.com>:
>> Hbase version 0.90.2:
>> Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)
>>
>> Other issue. Log is error:
>> see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8
>>
>> Hmaster logs:
>>
>> 2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
>> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
>> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
>> 2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900
>>
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
>> 2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
>> java.lang.OutOfMemoryError: Java heap space
>>        at java.util.HashMap.addEntry(HashMap.java:753)
>>        at java.util.HashMap.put(HashMap.java:385)
>>        at java.util.HashMap.putAll(HashMap.java:524)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
>>        at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
>>        at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
>>        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>        at java.lang.Thread.run(Thread.java:662)
>> 2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
>> 2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
>> 2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
>> 2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
>> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
>> 2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
>> 2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
>> 2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
>> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
>> 2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
>> 2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
>> 2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
>> org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
>>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
>>        at sun.reflect.GeneratedMethodAccessor31.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:570)
>>        at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)
>>
>>        at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
>>        at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
>>        at $Proxy6.next(Unknown Source)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
>>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
>>        at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
>>        at org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>>
>

Re: Hmaster is OutOfMemory

Posted by Gaojinchao <ga...@huawei.com>.
Hbase version : 0.90.3RC0

It happened when creating table with Regions
I find master started needs so much memory when the cluster has 100K regions
It seems likes zkclientcnxn.

It seems master assigned region need improve.


top -c | grep 5834
5834 root      20   0 8875m 7.9g  11m S    2 50.5  33:53.19 /opt/jdk1.6.0_22/bin/java -Xmx8192m -ea -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode

Attaching to process ID 5834, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 17.1-b03

using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GC

Heap Configuration:
   MinHeapFreeRatio = 40
   MaxHeapFreeRatio = 70
   MaxHeapSize      = 8589934592 (8192.0MB)
   NewSize          = 21757952 (20.75MB)
   MaxNewSize       = 174456832 (166.375MB)
   OldSize          = 65404928 (62.375MB)
   NewRatio         = 7
   SurvivorRatio    = 8
   PermSize         = 21757952 (20.75MB)
   MaxPermSize      = 88080384 (84.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 100335616 (95.6875MB)
   used     = 47094720 (44.91302490234375MB)
   free     = 53240896 (50.77447509765625MB)
   46.93719127612671% used
Eden Space:
   capacity = 89194496 (85.0625MB)
   used     = 35953600 (34.28802490234375MB)
   free     = 53240896 (50.77447509765625MB)
   40.30921369856723% used
From Space:
   capacity = 11141120 (10.625MB)
   used     = 11141120 (10.625MB)
   free     = 0 (0.0MB)
   100.0% used
To Space:
   capacity = 11141120 (10.625MB)
   used     = 0 (0.0MB)
   free     = 11141120 (10.625MB)
   0.0% used
concurrent mark-sweep generation:
   capacity = 8415477760 (8025.625MB)
   used     = 5107249280 (4870.6524658203125MB)
   free     = 3308228480 (3154.9725341796875MB)
   60.68876213155128% used
Perm Generation:
   capacity = 31199232 (29.75390625MB)
   used     = 18681784 (17.81633758544922MB)
   free     = 12517448 (11.937568664550781MB)
   59.87898676480241% used


-----邮件原件-----
发件人: jdcryans@gmail.com [mailto:jdcryans@gmail.com] 代表 Jean-Daniel Cryans
发送时间: 2011年5月10日 1:20
收件人: user@hbase.apache.org
主题: Re: Hmaster is OutOfMemory

It looks like the master entered a GC loop of death (since there are a
lot of "We slept 76166ms" messages) and finally died. Was it splitting
logs? Did you get a heap dump? Did you inspect it and can you tell
what was using all that space?

Thx,

J-D

2011/5/8 Gaojinchao <ga...@huawei.com>:
> Hbase version 0.90.2:
> Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)
>
> Other issue. Log is error:
> see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8
>
> Hmaster logs:
>
> 2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
> 2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
> 2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900
>
> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
> 2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
> 2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
> java.lang.OutOfMemoryError: Java heap space
>        at java.util.HashMap.addEntry(HashMap.java:753)
>        at java.util.HashMap.put(HashMap.java:385)
>        at java.util.HashMap.putAll(HashMap.java:524)
>        at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
>        at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
>        at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
>        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>        at java.lang.Thread.run(Thread.java:662)
> 2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
> 2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
> 2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
> 2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
> 2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
> 2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
> 2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
> 2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
> 2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
> 2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
> 2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
> org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
>        at sun.reflect.GeneratedMethodAccessor31.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:570)
>        at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)
>
>        at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
>        at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
>        at $Proxy6.next(Unknown Source)
>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
>        at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
>        at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
>        at org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>

Re: Hmaster is OutOfMemory

Posted by Jean-Daniel Cryans <jd...@apache.org>.
It looks like the master entered a GC loop of death (since there are a
lot of "We slept 76166ms" messages) and finally died. Was it splitting
logs? Did you get a heap dump? Did you inspect it and can you tell
what was using all that space?

Thx,

J-D

2011/5/8 Gaojinchao <ga...@huawei.com>:
> Hbase version 0.90.2:
> Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)
>
> Other issue. Log is error:
> see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8
>
> Hmaster logs:
>
> 2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
> 2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
> 2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
> 2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
> 2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900
>
> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
> 2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
> 2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
> java.lang.OutOfMemoryError: Java heap space
>        at java.util.HashMap.addEntry(HashMap.java:753)
>        at java.util.HashMap.put(HashMap.java:385)
>        at java.util.HashMap.putAll(HashMap.java:524)
>        at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
>        at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
>        at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
>        at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>        at java.lang.Thread.run(Thread.java:662)
> 2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
> 2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
> 2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
> 2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
> 2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
> 2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
> 2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
> 2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
> 2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
>        at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
>        at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
>        at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
>        at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
>        at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
>        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
> 2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
> 2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
> 2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
> org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
>        at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
>        at sun.reflect.GeneratedMethodAccessor31.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:570)
>        at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)
>
>        at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
>        at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
>        at $Proxy6.next(Unknown Source)
>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
>        at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
>        at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
>        at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
>        at org.apache.hadoop.hbase.Chore.run(Chore.java:66)
>

Hmaster is OutOfMemory

Posted by Gaojinchao <ga...@huawei.com>.
Hbase version 0.90.2:
Hmaster has 8G memory,  It seems like not enough ? why it needs so much memory?(50K region)

Other issue. Log is error:
see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9 should be see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A8

Hmaster logs:

2011-05-06 19:31:09,924 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 2f19f33ae3f21ac4cb681f1662767d0c with OFFLINE state
2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 76166ms instead of 60000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:31:09,924 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16697ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Forcing OFFLINE; was=ufdr,211007,1304669377398.696f124cc6ff82302f735c8413c6ac0b. state=CLOSED, ts=1304681364406
2011-05-06 19:31:09,932 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Creating (or updating) unassigned node for 696f124cc6ff82302f735c8413c6ac0b with OFFLINE state
2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region ufdr,071415,1304668656420.aa026fbb27a25b0fe54039c00108dad6. on 157-5-100-9,20020,1304678135900
2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 7a75bac2028fba1529075225a3755c4c; deleting unassigned node
2011-05-06 19:31:22,942 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for 7a75bac2028fba1529075225a3755c4c that is in expected state RS_ZK_REGION_OPENED
2011-05-06 19:31:38,986 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 12948ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:31:39,059 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Sent CLOSE to serverName=158-1-91-101,20020,1304663941215, load=(requests=0, regions=5374, usedHeap=79, maxHeap=8165) for region ufdr,082288,1304668716520.144efd9c886f5567abc9a229eb380c76.
2011-05-06 19:31:39,059 INFO org.apache.hadoop.hbase.master.HMaster: balance hri=ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22., src=158-1-91-101,20020,1304663941215, dest=157-5-100-9,20020,1304678135900

2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-2011-05-06 19:31:54,741 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15681ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:32:11,419 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16574ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:32:23,176 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 11756ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:32:23,245 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x12fc3a17c070054, likely server has closed socket, closing socket connection and attempting reconnect
2011-05-06 19:32:36,902 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 13657ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:35:44,084 WARN org.apache.hadoop.hbase.zookeeper.ZKUtil: hconnection-0x12fc3a17c070054 Unable to set watcher on znode /hbase/root-region-server
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
2011-05-06 19:35:44,096 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 78032ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:35:44,095 ERROR org.apache.hadoop.hbase.executor.EventHandler: Caught throwable while processing event RS_ZK_REGION_OPENED
java.lang.OutOfMemoryError: Java heap space
	at java.util.HashMap.addEntry(HashMap.java:753)
	at java.util.HashMap.put(HashMap.java:385)
	at java.util.HashMap.putAll(HashMap.java:524)
	at org.apache.hadoop.hbase.master.AssignmentManager.updateTimers(AssignmentManager.java:630)
	at org.apache.hadoop.hbase.master.AssignmentManager.regionOnline(AssignmentManager.java:607)
	at org.apache.hadoop.hbase.master.handler.OpenedRegionHandler.process(OpenedRegionHandler.java:97)
	at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)
2011-05-06 19:35:59,981 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for accac1bddaa4bf102bcfa6506b19839d; deleting unassigned node
2011-05-06 19:35:44,093 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Starting unassignment of region ufdr,050142,1304668531330.2d56755e7138a93b243a7c5363d1ac22. (offlining)
2011-05-06 19:35:59,981 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server /157.5.100.11:2181
2011-05-06 19:35:59,981 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 15884ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:35:44,097 ERROR org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher: hconnection-0x12fc3a17c070054 Received unexpected KeeperException, re-throwing exception
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)5-100-11/157.5.100.11:2181, initiating session
2011-05-06 19:36:16,570 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 16488ms instead of 1000ms, this is likely due to a long garbage collecting pause and it's usually bad, see http://wiki.apache.org/hadoop/Hbase/Troubleshooting#A9
2011-05-06 19:36:16,570 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to 157-5-100-11/157.5.100.11:2181, initiating session
2011-05-06 19:36:16,571 INFO org.apache.zookeeper.ClientCnxn: Client session timed out, have not heard from server in 16489ms for sessionid 0x12fc3a17c070054, closing socket connection and attempting reconnect
2011-05-06 19:36:00,082 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:20000-0x12fc3a17c070022 Deleting existing unassigned node for accac1bddaa4bf102bcfa6506b19839d that is in expected state RS_ZK_REGION_OPENED
2011-05-06 19:36:16,570 FATAL org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Unexpected exception during initialization, aborting
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/root-region-server
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:90)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:819)
	at org.apache.hadoop.hbase.zookeeper.ZKUtil.watchAndCheckExists(ZKUtil.java:232)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperNodeTracker.start(ZooKeeperNodeTracker.java:72)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.setupZookeeperTrackers(HConnectionManager.java:308)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.resetZooKeeperTrackers(HConnectionManager.java:319)
	at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.abort(HConnectionManager.java:1333)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.connectionEvent(ZooKeeperWatcher.java:328)
	at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:246)
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:541)
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:517)
2011-05-06 19:36:16,572 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Reconnected successfully. This disconnect could have been caused by a network partition or a long-running GC pause, either way it's recommended that you verify your environment.
2011-05-06 19:36:16,572 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
2011-05-06 19:36:16,572 WARN org.apache.hadoop.hbase.master.CatalogJanitor: Failed scan of catalog table
org.apache.hadoop.ipc.RemoteException: org.apache.hadoop.hbase.UnknownScannerException: Name: 3135625757230134514
	at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1794)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.next(HRegionServer.java:1782)
	at sun.reflect.GeneratedMethodAccessor31.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:570)
	at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039)

	at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771)
	at org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257)
	at $Proxy6.next(Unknown Source)
	at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:264)
	at org.apache.hadoop.hbase.catalog.MetaReader.fullScan(MetaReader.java:237)
	at org.apache.hadoop.hbase.master.CatalogJanitor.scan(CatalogJanitor.java:116)
	at org.apache.hadoop.hbase.master.CatalogJanitor.chore(CatalogJanitor.java:85)
	at org.apache.hadoop.hbase.Chore.run(Chore.java:66)

Re: HTable.put hangs on bulk loading

Posted by Ted Yu <yu...@gmail.com>.
>> when the number of the regions in this table rises (more than 100), they
are spread all over the cluster (good)
Can you clarify the above a bit more ?
If you use stock version 0.90.2, random selector wouldn't guarantee to
distribute the regions of this table.

On Fri, May 13, 2011 at 7:44 AM, Stan Barton <ba...@gmail.com> wrote:

>
>
> stack-3 wrote:
> >
> > On Thu, Apr 28, 2011 at 6:54 AM, Stan Barton <ba...@gmail.com> wrote:
> >>
> >> Yes, these high limits are for the user running the hadoop/hbase
> >> processes.
> >>
> >> The systems are ran on a cluster of 7 machines (1 master, 6 slaves). One
> >> processor, two cores and 3.5GB of memory. I am using about 800MB for
> >> hadoop
> >> (version CDH3B2) and 2.1GB for HBase (version 0.90.2). There is 6TB on
> >> four
> >> disks per machine. Three zookeepers. The database contains more than
> 3500
> >> regions and the table that was fed was already about 300 regions. The
> >> table
> >> was fed incrementally using HTable.put().  The data are documents with
> >> size
> >> ranging from few bytes to megabytes where the upper limit is set to 10MB
> >> per
> >> inserted doc.
> >>
> >
> > Are you swapping Stan?  You are close to the edge with your RAM
> > allocations.  What do you have swappyness set to?  Is it default?
> >
> > Writing you don't need that much memory usually but you do have a lot
> > of regions so you could be flushing a bunch, a bunch of small files.
> >
>
> Due to various problems with swap, the swap was turned off and the
> overcommitment of the memory was turned on.
>
>
> stack-3 wrote:
> >
> >> The configuration files:
> >>
> >> hadoop/core-site.xml http://pastebin.ca/2051527
> >> hadoop/hadoop-env.sh http://pastebin.ca/2051528
> >
> > Your HADOOP_CLASSPATH is a little odd.  You are doing * on jar
> > directories.  Does that work?
> >
> > This CLASSPATH  mentions nutch and a bunch of other stuff.  Are you
> > running just datanodes on these machines or tasktracers and mapreduce
> > too?
> >
> > These are old IA stock machines?  Do they have ECC RAM?  (IIRC, they
> > used to not have ECC RAM).
> >
>
> Strangely, on the machines and the debian installed, only this (star * )
> approach works. Originally, I was running the DB on the same cluster as the
> processing took place - mostly mapreduce jobs reading the data and doing
> some analysis. But when I started using nutchwax on the same cluster I
> started running out of memory (on the mapreduce side) and since the
> machines
> are so sensitive (no swap and overcommitment) that became a nightmare. So
> right now the nutch is being ran on a separate cluster - I have tweaked
> nutchwax to work with recent Hadoop apis and also to take the hbase stored
> content on as the input (instead of ARC files).
>
> The machines are somehow renovated old red boxes (I dont know what
> configuration they were originally). The RAM is not an ECC as far as I
> know,
> because the chipset on the motherboards does not support that technology.
>
>
> stack-3 wrote:
> >
> >> hadoop/hdfs-site.xml http://pastebin.ca/2051529
> >>
> >
> > Did you change the dfs block size?   Looks like its 256M rather than
> > usual 64M.  Any reason for that?  Would suggest going w/ defaults at
> > first.
> >
> > Remove dfs.datanode.socket.write.timeout == 0.  Thats an old config.
> > recommendation that should no longer be necessary and is likely
> > corrosive.
> >
>
> I have changed the size of the block, to diminish the overall number of
> blocks. I was following some advices regarding managing that large amount
> of
> data in HDFS that I found in the fora.
>
> As for the dfs.datanode.socket.write.timeout, that was set up because I was
> observing quite often timeouts on the DFS sockets, and by digging around, I
> have found out, that for some reason the internal java times were not
> aligned of the connecting machines (even though the hw clock were), I think
> there was a JIRA for that.
>
>
> stack-3 wrote:
> >
> >> hbase/hbase-site.xml http://pastebin.ca/2051532
> >
> > You are letting major compactions run every 24 hours.  You might want
> > to turn them off and then manage the major compactions to happen
> > during downtimes.  They have a knack of cutting in just when you don't
> > want them too; e.g. when you are under peak loading.
> >
> > You have upped the flush size above default; i.e.
> > hbase.hregion.memstore.flush.size.  This will put more pressure on RAM
> > when I'd think you would want to have less since you are poor where it
> > comes to RAM.
> >
> > You have upped your regionsize above default.   That is good I'd say.
> > You might want to 4x -- go to 4G -- since you are doing relatively big
> > stuff.
> >
> > You should send me the metrics that show on the top of the
> > regionserver UI when you are under load.  I'd like to see things like
> > how much of your RAM is given over to indices for these storefiles.
> >
> > I see you hdfs.block.size specified in here at 256M.  So stuff written
> > by hbase into hdfs will have a block size of 256M.  Any reason to do
> > this?  I'd say leave it at default unless you have a really good
> > reason to do otherwise (Remove this config. from this file).
> >
> >
> Again, the reason to upper the block size was motivated by the assumption
> of
> lowering the overall number of blocks. If it imposes stress on the RAM it
> makes sense to leave it on the defaults. I guess it also helps the
> parallelization.
>
>
>
> stack-3 wrote:
> >
> >
> >
> >> hbase/hbase-env.sh http://pastebin.ca/2051535
> >>
> >
> > Remove this:
> >
> > -XX:+HeapDumpOnOutOfMemoryError
> >
> > Means it will dump heap if JVM crashes.  This is probably of no
> > interest to you and could actually cause you pain if you have small
> > root file system if the heap dump causes you to fill.
> >
> > The -XX:CMSInitiatingOccupancyFraction=90 is probably near useless
> > (default is 92% or 88% -- I don't remember which).  Set it down to 80%
> > or 75% if you want it to actually make a difference.
> >
> > Are you having issues w/ GC'ing?  I see you have mslab enabled.
> >
> >
> On the version 0.20.6 I have seen long pauses during the importing phase
> and
> also when querying. I was measuring the how many queries were processed per
> second and could see pauses in the throughput. The only culprit I could
> find
> was the gc, but still could not figure out why it pauses the whole DB.
> Therefore I gave it a shot with mslab with 0.90, but I do still see those
> pauses in the throughput.
>
>
> stack-3 wrote:
> >
> >
> >> Because the nproc was high I had inspected the out files of the RSs' and
> >> found one which indicated that all the IPCs OOMEd, unfortunately I dont
> >> have
> >> those because they got overwritten after a cluster restart.
> >
> > This may have been because of  HBASE-3813 .  See if 0.90.3 helps
> > (There is an improvement here).
> >
> > Next time, let us see them.
> >
> >> So that means
> >> that it was OK on the client side. Funny is that all RS processes were
> up
> >> and running, only that one with OOMEd IPCs did not really communicate
> >> (after
> >> trying to restart the importing process no inserts went through).
> >
> > An OOME'd process goes wonky thereafter and acts in irrational ways.
> > Perhaps this was why it stopped taking on requests.
> >
> >> So the
> >> cluster seemed OK - I was storing statistics that were apparently served
> >> by
> >> another RS and those were also listed OK. As I mentioned, the log of the
> >> bad
> >> RS did not mention that anything wrong happened.
> >>
> >> My observation was: the regions were spread on all RSs but the crashed
> RS
> >> served most of them about a half more than any other, therefore was
> >> accessed
> >> the more than others. I have discussed the load balancing in HBase
> 0.90.2
> >> with Ted Yu already.
> >>
> >> The balancer needs to be tuned I guess because when the table is created
> >> and
> >> loaded from scratch, the regions of the table are not balanced equally
> >> (in
> >> terms of numbers) in the cluster and I guess the RS that hosted the very
> >> first region is serving the majority of servers as they are being split.
> >> It
> >> imposes larger load on that RS which is more prone to failures (like
> mine
> >> OOME) and kill performance.
> >>
> >
> > OK.  Yeah, Ted has been arguing that the balancer should be
> > table-conscious in that it should try and spread tables across the
> > cluster.  Currently its not.  All regions are equal in the balancer's
> > eyes.  0.90.2 didn't help?  (Others have since reported that they
> > think as Ted that the region a table comes from should be considered
> > when balancing).
> >
> >
> In fact, what I still see in 0.90.2 is that when I start inserting to empty
> table, when the number of the regions in this table rises (more than 100),
> they are spread all over the cluster (good) but one RS (the holding the
> first region) serves remarkably more regions than the rest of the RSs,
> which
> kills performance of the whole cluster and puts a lot of stress on this one
> RS (there was no RS downtime, and the overall region numbers are even on
> all
> RS).
>
>
> stack-3 wrote:
> >
> >
> >
> >> I have resumed the process with rebalancing the regions beforehand and
> >> was
> >> achieving higher data ingestion rate and also did not ran into the OOME
> >> with
> >> one RS. Right now I am trying to replay the incident.
> >>
> >> I know that my scenario would require better machines, but those are
> what
> >> I
> >> have now and am before production running stress tests. In comparison
> >> with
> >> 0.20.6 the 0.90.2 is less stable regarding the insertion but it scales
> >> sub-linearily (v0.20.6 did not scale on my data) in terms of random
> >> access
> >> queries (including multi-versioned data) - have done extensive
> comparison
> >> regarding this.
> >>
> >
> > 0.90.2 scales sub-linearly?  You mean its not linear but more machines
> > helps?
> >
> > Are you random reads truly random (I'd guess they are).  Would cache
> help?
> >
> > Have you tried hdfs-237 patch?  There is a version that should work
> > for you version of cdh.  It could a big difference (though, beware,
> > the latest posted patch does not do checksuming and if your hardware
> > does not have ECC, it could be a problem).
> >
> >
> I have done some test using random access queries and multiversioned data
> (10 to 50 different timestamps per data) and that the random access in
> v0.20.6 is degrading linearly with the number of versions, in the case of
> 0.90, some slow down was recorded but in sub-linear speed. Still while
> using
> the same amount of machines.
>
> The reads were random, I pre-selected the rows from the whole collection.
> The cache helped, I could see in the pattern the time it took to serve a
> query's answer from disk and from cache.
>
> Are you sure that you have suggested the right patch (hdfs-237)? It
> mentions
> dfsadmin... And no the machines do not have ECC enabled ram.
>
>
>
> stack-3 wrote:
> >
> >
> >
> > St.Ack
> >
> >
>
> Stan
> --
> View this message in context:
> http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31612028.html
> Sent from the HBase User mailing list archive at Nabble.com.
>
>

Re: HTable.put hangs on bulk loading

Posted by Stan Barton <ba...@gmail.com>.


stack-3 wrote:
> 
> On Mon, May 16, 2011 at 4:55 AM, Stan Barton <ba...@gmail.com> wrote:
>>> Sorry.  How do you enable overcommitment of memory, or do you mean to
>>> say that your processes add up to more than the RAM you have?
>>>
>>
>> The memory overcommitment is needed because in order to let java still
>> "allocate" the memory for executing external bash commands like "du" when
>> the RAM is nearly filled up. I have the swap turned off and have turned
>> the
>> overcommitment using sysctl and setting vm.overcommit_memory=0 (i.e. the
>> option when any memory allocation attempt will succeed no matter the
>> resting
>> free RAM). I was encountering RS crashed caused by the
>> "java.io.IOException:
>> Cannot run program "bash": java.io.IOException: error=12, Cannot allocate
>> memory". However, my processes should never add up more than the
>> available
>> RAM-the minimum for OS.
>>
> If it happens again, can I see stack trace for the above?
> 
> 
>> How would these manifest? I guess that is not related but on the same
>> note,
>> I am encountering a quite high disk failure on machines running
>> HBase/HDFS.
>>
> 
> 
> If all worked as designed, you'd not see anything.  A corrupted block
> would be put aside and a new replica made from a good replica would
> take its place.  But IIRC, corruption rate was really high on these
> machines.  Do you ever run into files missing blocks?
> 
> Yeah, the disks were cheapies.
> 
> Any chance of different hardware?
> 
Yes, the HW changed I guess, the disks right now are 4xSATA seagates 1.5TB
and the RAM was added (3.5GB total) and the motherboards are supermicro
x7sla. The disks are still no enterprise entry level 7.2k rpm. 

Sometimes I am running into block not available when doing distCp, but the
block is there, it is ok but is just not available for some reason - when
doing exactly the same copy second time, the errors appear on different
blocks.


stack-3 wrote:
> 
>> In general, the HDFS contains only HBase files, so at this point the
>> memory
>> consumption on NN is not an issue, so I have lowered that back to the
>> defaults and will observe.
>>
> 
> Yeah, this is probably better.  You are now like most others on this list.
> 
>> For the import I can understand, but when I am evaluating the querying
>> performance, almost no writes (besides small statistics data) are going
>> on
>> and the HBase pauses as a whole, not only one RS (which I would believe
>> is
>> the case when writes were flushed in the statistics table having one
>> region).
>>
> 
> Lets try and dig in on this.  This shouldn't be happening.  Anything
> in regionserver logs at the time of the pause?
> 
> 

I replayed the query tests, the query throughput is depicted in the
following figure:

http://old.nabble.com/file/p31646631/query_throughput_agg.jpg 

the green line denotes the number of simultaneously querying clients, the
red columns for queries processed in the particular second. The x-axis is
the number of seconds from start of the experiment. Gaps in the throughput
denote the problems. I have looked in the logs and it seems that the culprit
is the HDFS:

snippets of the logs of RS1 and RS2 where I found errors around one of the
gaps:
http://pastebin.ca/2063454

I have included also snippets of logs to datanodes to where the RS errors
pointed. 


stack-3 wrote:
> 
> St.Ack
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31646631.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Stack <st...@duboce.net>.
On Mon, May 16, 2011 at 4:55 AM, Stan Barton <ba...@gmail.com> wrote:
>> Sorry.  How do you enable overcommitment of memory, or do you mean to
>> say that your processes add up to more than the RAM you have?
>>
>
> The memory overcommitment is needed because in order to let java still
> "allocate" the memory for executing external bash commands like "du" when
> the RAM is nearly filled up. I have the swap turned off and have turned the
> overcommitment using sysctl and setting vm.overcommit_memory=0 (i.e. the
> option when any memory allocation attempt will succeed no matter the resting
> free RAM). I was encountering RS crashed caused by the "java.io.IOException:
> Cannot run program "bash": java.io.IOException: error=12, Cannot allocate
> memory". However, my processes should never add up more than the available
> RAM-the minimum for OS.
>
If it happens again, can I see stack trace for the above?


> How would these manifest? I guess that is not related but on the same note,
> I am encountering a quite high disk failure on machines running HBase/HDFS.
>


If all worked as designed, you'd not see anything.  A corrupted block
would be put aside and a new replica made from a good replica would
take its place.  But IIRC, corruption rate was really high on these
machines.  Do you ever run into files missing blocks?

Yeah, the disks were cheapies.

Any chance of different hardware?


> In general, the HDFS contains only HBase files, so at this point the memory
> consumption on NN is not an issue, so I have lowered that back to the
> defaults and will observe.
>

Yeah, this is probably better.  You are now like most others on this list.

> For the import I can understand, but when I am evaluating the querying
> performance, almost no writes (besides small statistics data) are going on
> and the HBase pauses as a whole, not only one RS (which I would believe is
> the case when writes were flushed in the statistics table having one
> region).
>

Lets try and dig in on this.  This shouldn't be happening.  Anything
in regionserver logs at the time of the pause?

St.Ack

Re: HTable.put hangs on bulk loading

Posted by Stan Barton <ba...@gmail.com>.


stack-3 wrote:
> 
> On Fri, May 13, 2011 at 7:44 AM, Stan Barton <ba...@gmail.com> wrote:
>> stack-3 wrote:
>>>
>>> On Thu, Apr 28, 2011 at 6:54 AM, Stan Barton <ba...@gmail.com> wrote:
>>> Are you swapping Stan?  You are close to the edge with your RAM
>>> allocations.  What do you have swappyness set to?  Is it default?
>>>
>>> Writing you don't need that much memory usually but you do have a lot
>>> of regions so you could be flushing a bunch, a bunch of small files.
>>>
>>
>> Due to various problems with swap, the swap was turned off and the
>> overcommitment of the memory was turned on.
>>
> 
> Sorry.  How do you enable overcommitment of memory, or do you mean to
> say that your processes add up to more than the RAM you have?
> 

The memory overcommitment is needed because in order to let java still
"allocate" the memory for executing external bash commands like "du" when
the RAM is nearly filled up. I have the swap turned off and have turned the
overcommitment using sysctl and setting vm.overcommit_memory=0 (i.e. the
option when any memory allocation attempt will succeed no matter the resting
free RAM). I was encountering RS crashed caused by the "java.io.IOException:
Cannot run program "bash": java.io.IOException: error=12, Cannot allocate
memory". However, my processes should never add up more than the available
RAM-the minimum for OS.


stack-3 wrote:
> 
>> stack-3 wrote:
>>> These are old IA stock machines?  Do they have ECC RAM?  (IIRC, they
>>> used to not have ECC RAM).
>>>
>>
>> Strangely, on the machines and the debian installed, only this (star * )
>> approach works.
> 
> OK.  New to me, but hey, what do I know!
> 
> 
>> Originally, I was running the DB on the same cluster as the
>> processing took place - mostly mapreduce jobs reading the data and doing
>> some analysis. But when I started using nutchwax on the same cluster I
>> started running out of memory (on the mapreduce side) and since the
>> machines
>> are so sensitive (no swap and overcommitment) that became a nightmare. So
>> right now the nutch is being ran on a separate cluster - I have tweaked
>> nutchwax to work with recent Hadoop apis and also to take the hbase
>> stored
>> content on as the input (instead of ARC files).
>>
> 
> Good stuff
> 
>> The machines are somehow renovated old red boxes (I dont know what
>> configuration they were originally). The RAM is not an ECC as far as I
>> know,
>> because the chipset on the motherboards does not support that technology.
>>
> 
> OK.  You seeing any issues arising because of checksum issues?  (BTW,
> IIRC, these non-ECC red boxes are the reason HDFS is a checksummed
> filesystem)
> 
> 
How would these manifest? I guess that is not related but on the same note,
I am encountering a quite high disk failure on machines running HBase/HDFS.


stack-3 wrote:
> 
> 
>> stack-3 wrote:
>>>
>>>> hadoop/hdfs-site.xml http://pastebin.ca/2051529
>>>>
>>>
>>> Did you change the dfs block size?   Looks like its 256M rather than
>>> usual 64M.  Any reason for that?  Would suggest going w/ defaults at
>>> first.
>>>
>>> Remove dfs.datanode.socket.write.timeout == 0.  Thats an old config.
>>> recommendation that should no longer be necessary and is likely
>>> corrosive.
>>>
>>
>> I have changed the size of the block, to diminish the overall number of
>> blocks. I was following some advices regarding managing that large amount
>> of
>> data in HDFS that I found in the fora.
>>
> 
> Yeah, I suppose, bigger blocksizes would make it so you need less RAM
> in your namenode.  You have lots of files on here?  On the other side,
> bigger blocks are harder for hbase to sling.
> 
> 

In general, the HDFS contains only HBase files, so at this point the memory
consumption on NN is not an issue, so I have lowered that back to the
defaults and will observe.


stack-3 wrote:
> 
> 
>> As for the dfs.datanode.socket.write.timeout, that was set up because I
>> was
>> observing quite often timeouts on the DFS sockets, and by digging around,
>> I
>> have found out, that for some reason the internal java times were not
>> aligned of the connecting machines (even though the hw clock were), I
>> think
>> there was a JIRA for that.
>>
> 
> Not sure what this one is about.  The
> dfs.datanode.socket.write.timeout=0 is old lore by this stage I think
> you'll find.
> 
> 
I should have noted the cause of the problem better, I will remove that and
observe whether will be getting the socket exceptions again.


stack-3 wrote:
> 
> 
>>
> 
>> Again, the reason to upper the block size was motivated by the assumption
>> of
>> lowering the overall number of blocks. If it imposes stress on the RAM it
>> makes sense to leave it on the defaults. I guess it also helps the
>> parallelization.
>>
> 
> Yeah, would suggest you run w/ default sizes.
> 
> 
>> stack-3 wrote:
>>>
>>>
>>>
>>>> hbase/hbase-env.sh http://pastebin.ca/2051535
>>>>
>>>
>>> Remove this:
>>>
>>> -XX:+HeapDumpOnOutOfMemoryError
>>>
>>> Means it will dump heap if JVM crashes.  This is probably of no
>>> interest to you and could actually cause you pain if you have small
>>> root file system if the heap dump causes you to fill.
>>>
>>> The -XX:CMSInitiatingOccupancyFraction=90 is probably near useless
>>> (default is 92% or 88% -- I don't remember which).  Set it down to 80%
>>> or 75% if you want it to actually make a difference.
>>>
>>> Are you having issues w/ GC'ing?  I see you have mslab enabled.
>>>
>>>
>> On the version 0.20.6 I have seen long pauses during the importing phase
>> and
>> also when querying. I was measuring the how many queries were processed
>> per
>> second and could see pauses in the throughput. The only culprit I could
>> find
>> was the gc, but still could not figure out why it pauses the whole DB.
>> Therefore I gave it a shot with mslab with 0.90, but I do still see those
>> pauses in the throughput.
>>
> 
> Importing, yeah, you are probably running into the 'gate' that a
> regionserver puts up when it has filled its memstore while waiting on
> flush to complete.  Check regionserver logs at about this time.  You
> should see 'blocking' messages followed soon after by unblocking after
> the flush runs.
> 
> 

For the import I can understand, but when I am evaluating the querying
performance, almost no writes (besides small statistics data) are going on
and the HBase pauses as a whole, not only one RS (which I would believe is
the case when writes were flushed in the statistics table having one
region).


stack-3 wrote:
> 
> St.Ack
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31628188.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Stack <st...@duboce.net>.
On Fri, May 13, 2011 at 7:44 AM, Stan Barton <ba...@gmail.com> wrote:
> stack-3 wrote:
>>
>> On Thu, Apr 28, 2011 at 6:54 AM, Stan Barton <ba...@gmail.com> wrote:
>> Are you swapping Stan?  You are close to the edge with your RAM
>> allocations.  What do you have swappyness set to?  Is it default?
>>
>> Writing you don't need that much memory usually but you do have a lot
>> of regions so you could be flushing a bunch, a bunch of small files.
>>
>
> Due to various problems with swap, the swap was turned off and the
> overcommitment of the memory was turned on.
>

Sorry.  How do you enable overcommitment of memory, or do you mean to
say that your processes add up to more than the RAM you have?


> stack-3 wrote:
>> These are old IA stock machines?  Do they have ECC RAM?  (IIRC, they
>> used to not have ECC RAM).
>>
>
> Strangely, on the machines and the debian installed, only this (star * )
> approach works.

OK.  New to me, but hey, what do I know!


> Originally, I was running the DB on the same cluster as the
> processing took place - mostly mapreduce jobs reading the data and doing
> some analysis. But when I started using nutchwax on the same cluster I
> started running out of memory (on the mapreduce side) and since the machines
> are so sensitive (no swap and overcommitment) that became a nightmare. So
> right now the nutch is being ran on a separate cluster - I have tweaked
> nutchwax to work with recent Hadoop apis and also to take the hbase stored
> content on as the input (instead of ARC files).
>

Good stuff

> The machines are somehow renovated old red boxes (I dont know what
> configuration they were originally). The RAM is not an ECC as far as I know,
> because the chipset on the motherboards does not support that technology.
>

OK.  You seeing any issues arising because of checksum issues?  (BTW,
IIRC, these non-ECC red boxes are the reason HDFS is a checksummed
filesystem)


> stack-3 wrote:
>>
>>> hadoop/hdfs-site.xml http://pastebin.ca/2051529
>>>
>>
>> Did you change the dfs block size?   Looks like its 256M rather than
>> usual 64M.  Any reason for that?  Would suggest going w/ defaults at
>> first.
>>
>> Remove dfs.datanode.socket.write.timeout == 0.  Thats an old config.
>> recommendation that should no longer be necessary and is likely
>> corrosive.
>>
>
> I have changed the size of the block, to diminish the overall number of
> blocks. I was following some advices regarding managing that large amount of
> data in HDFS that I found in the fora.
>

Yeah, I suppose, bigger blocksizes would make it so you need less RAM
in your namenode.  You have lots of files on here?  On the other side,
bigger blocks are harder for hbase to sling.


> As for the dfs.datanode.socket.write.timeout, that was set up because I was
> observing quite often timeouts on the DFS sockets, and by digging around, I
> have found out, that for some reason the internal java times were not
> aligned of the connecting machines (even though the hw clock were), I think
> there was a JIRA for that.
>

Not sure what this one is about.  The
dfs.datanode.socket.write.timeout=0 is old lore by this stage I think
you'll find.

>

> Again, the reason to upper the block size was motivated by the assumption of
> lowering the overall number of blocks. If it imposes stress on the RAM it
> makes sense to leave it on the defaults. I guess it also helps the
> parallelization.
>

Yeah, would suggest you run w/ default sizes.


> stack-3 wrote:
>>
>>
>>
>>> hbase/hbase-env.sh http://pastebin.ca/2051535
>>>
>>
>> Remove this:
>>
>> -XX:+HeapDumpOnOutOfMemoryError
>>
>> Means it will dump heap if JVM crashes.  This is probably of no
>> interest to you and could actually cause you pain if you have small
>> root file system if the heap dump causes you to fill.
>>
>> The -XX:CMSInitiatingOccupancyFraction=90 is probably near useless
>> (default is 92% or 88% -- I don't remember which).  Set it down to 80%
>> or 75% if you want it to actually make a difference.
>>
>> Are you having issues w/ GC'ing?  I see you have mslab enabled.
>>
>>
> On the version 0.20.6 I have seen long pauses during the importing phase and
> also when querying. I was measuring the how many queries were processed per
> second and could see pauses in the throughput. The only culprit I could find
> was the gc, but still could not figure out why it pauses the whole DB.
> Therefore I gave it a shot with mslab with 0.90, but I do still see those
> pauses in the throughput.
>

Importing, yeah, you are probably running into the 'gate' that a
regionserver puts up when it has filled its memstore while waiting on
flush to complete.  Check regionserver logs at about this time.  You
should see 'blocking' messages followed soon after by unblocking after
the flush runs.

St.Ack

Re: HTable.put hangs on bulk loading

Posted by Stan Barton <ba...@gmail.com>.

stack-3 wrote:
> 
> On Thu, Apr 28, 2011 at 6:54 AM, Stan Barton <ba...@gmail.com> wrote:
>>
>> Yes, these high limits are for the user running the hadoop/hbase
>> processes.
>>
>> The systems are ran on a cluster of 7 machines (1 master, 6 slaves). One
>> processor, two cores and 3.5GB of memory. I am using about 800MB for
>> hadoop
>> (version CDH3B2) and 2.1GB for HBase (version 0.90.2). There is 6TB on
>> four
>> disks per machine. Three zookeepers. The database contains more than 3500
>> regions and the table that was fed was already about 300 regions. The
>> table
>> was fed incrementally using HTable.put().  The data are documents with
>> size
>> ranging from few bytes to megabytes where the upper limit is set to 10MB
>> per
>> inserted doc.
>>
> 
> Are you swapping Stan?  You are close to the edge with your RAM
> allocations.  What do you have swappyness set to?  Is it default?
> 
> Writing you don't need that much memory usually but you do have a lot
> of regions so you could be flushing a bunch, a bunch of small files.
> 

Due to various problems with swap, the swap was turned off and the
overcommitment of the memory was turned on. 


stack-3 wrote:
> 
>> The configuration files:
>>
>> hadoop/core-site.xml http://pastebin.ca/2051527
>> hadoop/hadoop-env.sh http://pastebin.ca/2051528
> 
> Your HADOOP_CLASSPATH is a little odd.  You are doing * on jar
> directories.  Does that work?
> 
> This CLASSPATH  mentions nutch and a bunch of other stuff.  Are you
> running just datanodes on these machines or tasktracers and mapreduce
> too?
> 
> These are old IA stock machines?  Do they have ECC RAM?  (IIRC, they
> used to not have ECC RAM).
> 

Strangely, on the machines and the debian installed, only this (star * )
approach works. Originally, I was running the DB on the same cluster as the
processing took place - mostly mapreduce jobs reading the data and doing
some analysis. But when I started using nutchwax on the same cluster I
started running out of memory (on the mapreduce side) and since the machines
are so sensitive (no swap and overcommitment) that became a nightmare. So
right now the nutch is being ran on a separate cluster - I have tweaked
nutchwax to work with recent Hadoop apis and also to take the hbase stored
content on as the input (instead of ARC files).

The machines are somehow renovated old red boxes (I dont know what
configuration they were originally). The RAM is not an ECC as far as I know,
because the chipset on the motherboards does not support that technology.


stack-3 wrote:
> 
>> hadoop/hdfs-site.xml http://pastebin.ca/2051529
>>
> 
> Did you change the dfs block size?   Looks like its 256M rather than
> usual 64M.  Any reason for that?  Would suggest going w/ defaults at
> first.
> 
> Remove dfs.datanode.socket.write.timeout == 0.  Thats an old config.
> recommendation that should no longer be necessary and is likely
> corrosive.
> 

I have changed the size of the block, to diminish the overall number of
blocks. I was following some advices regarding managing that large amount of
data in HDFS that I found in the fora. 

As for the dfs.datanode.socket.write.timeout, that was set up because I was
observing quite often timeouts on the DFS sockets, and by digging around, I
have found out, that for some reason the internal java times were not
aligned of the connecting machines (even though the hw clock were), I think
there was a JIRA for that. 


stack-3 wrote:
> 
>> hbase/hbase-site.xml http://pastebin.ca/2051532
> 
> You are letting major compactions run every 24 hours.  You might want
> to turn them off and then manage the major compactions to happen
> during downtimes.  They have a knack of cutting in just when you don't
> want them too; e.g. when you are under peak loading.
> 
> You have upped the flush size above default; i.e.
> hbase.hregion.memstore.flush.size.  This will put more pressure on RAM
> when I'd think you would want to have less since you are poor where it
> comes to RAM.
> 
> You have upped your regionsize above default.   That is good I'd say.
> You might want to 4x -- go to 4G -- since you are doing relatively big
> stuff.
> 
> You should send me the metrics that show on the top of the
> regionserver UI when you are under load.  I'd like to see things like
> how much of your RAM is given over to indices for these storefiles.
> 
> I see you hdfs.block.size specified in here at 256M.  So stuff written
> by hbase into hdfs will have a block size of 256M.  Any reason to do
> this?  I'd say leave it at default unless you have a really good
> reason to do otherwise (Remove this config. from this file).
> 
> 
Again, the reason to upper the block size was motivated by the assumption of
lowering the overall number of blocks. If it imposes stress on the RAM it
makes sense to leave it on the defaults. I guess it also helps the
parallelization.



stack-3 wrote:
> 
> 
> 
>> hbase/hbase-env.sh http://pastebin.ca/2051535
>>
> 
> Remove this:
> 
> -XX:+HeapDumpOnOutOfMemoryError
> 
> Means it will dump heap if JVM crashes.  This is probably of no
> interest to you and could actually cause you pain if you have small
> root file system if the heap dump causes you to fill.
> 
> The -XX:CMSInitiatingOccupancyFraction=90 is probably near useless
> (default is 92% or 88% -- I don't remember which).  Set it down to 80%
> or 75% if you want it to actually make a difference.
> 
> Are you having issues w/ GC'ing?  I see you have mslab enabled.
> 
> 
On the version 0.20.6 I have seen long pauses during the importing phase and
also when querying. I was measuring the how many queries were processed per
second and could see pauses in the throughput. The only culprit I could find
was the gc, but still could not figure out why it pauses the whole DB.
Therefore I gave it a shot with mslab with 0.90, but I do still see those
pauses in the throughput.


stack-3 wrote:
> 
> 
>> Because the nproc was high I had inspected the out files of the RSs' and
>> found one which indicated that all the IPCs OOMEd, unfortunately I dont
>> have
>> those because they got overwritten after a cluster restart.
> 
> This may have been because of  HBASE-3813 .  See if 0.90.3 helps
> (There is an improvement here).
> 
> Next time, let us see them.
> 
>> So that means
>> that it was OK on the client side. Funny is that all RS processes were up
>> and running, only that one with OOMEd IPCs did not really communicate
>> (after
>> trying to restart the importing process no inserts went through).
> 
> An OOME'd process goes wonky thereafter and acts in irrational ways.
> Perhaps this was why it stopped taking on requests.
> 
>> So the
>> cluster seemed OK - I was storing statistics that were apparently served
>> by
>> another RS and those were also listed OK. As I mentioned, the log of the
>> bad
>> RS did not mention that anything wrong happened.
>>
>> My observation was: the regions were spread on all RSs but the crashed RS
>> served most of them about a half more than any other, therefore was
>> accessed
>> the more than others. I have discussed the load balancing in HBase 0.90.2
>> with Ted Yu already.
>>
>> The balancer needs to be tuned I guess because when the table is created
>> and
>> loaded from scratch, the regions of the table are not balanced equally
>> (in
>> terms of numbers) in the cluster and I guess the RS that hosted the very
>> first region is serving the majority of servers as they are being split.
>> It
>> imposes larger load on that RS which is more prone to failures (like mine
>> OOME) and kill performance.
>>
> 
> OK.  Yeah, Ted has been arguing that the balancer should be
> table-conscious in that it should try and spread tables across the
> cluster.  Currently its not.  All regions are equal in the balancer's
> eyes.  0.90.2 didn't help?  (Others have since reported that they
> think as Ted that the region a table comes from should be considered
> when balancing).
> 
> 
In fact, what I still see in 0.90.2 is that when I start inserting to empty
table, when the number of the regions in this table rises (more than 100),
they are spread all over the cluster (good) but one RS (the holding the
first region) serves remarkably more regions than the rest of the RSs, which
kills performance of the whole cluster and puts a lot of stress on this one
RS (there was no RS downtime, and the overall region numbers are even on all
RS).


stack-3 wrote:
> 
> 
> 
>> I have resumed the process with rebalancing the regions beforehand and
>> was
>> achieving higher data ingestion rate and also did not ran into the OOME
>> with
>> one RS. Right now I am trying to replay the incident.
>>
>> I know that my scenario would require better machines, but those are what
>> I
>> have now and am before production running stress tests. In comparison
>> with
>> 0.20.6 the 0.90.2 is less stable regarding the insertion but it scales
>> sub-linearily (v0.20.6 did not scale on my data) in terms of random
>> access
>> queries (including multi-versioned data) - have done extensive comparison
>> regarding this.
>>
> 
> 0.90.2 scales sub-linearly?  You mean its not linear but more machines
> helps?
> 
> Are you random reads truly random (I'd guess they are).  Would cache help?
> 
> Have you tried hdfs-237 patch?  There is a version that should work
> for you version of cdh.  It could a big difference (though, beware,
> the latest posted patch does not do checksuming and if your hardware
> does not have ECC, it could be a problem).
> 
> 
I have done some test using random access queries and multiversioned data
(10 to 50 different timestamps per data) and that the random access in
v0.20.6 is degrading linearly with the number of versions, in the case of
0.90, some slow down was recorded but in sub-linear speed. Still while using
the same amount of machines.

The reads were random, I pre-selected the rows from the whole collection.
The cache helped, I could see in the pattern the time it took to serve a
query's answer from disk and from cache.

Are you sure that you have suggested the right patch (hdfs-237)? It mentions
dfsadmin... And no the machines do not have ECC enabled ram.



stack-3 wrote:
> 
> 
> 
> St.Ack
> 
> 

Stan
-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31612028.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Stack <st...@duboce.net>.
On Thu, Apr 28, 2011 at 6:54 AM, Stan Barton <ba...@gmail.com> wrote:
>
> Yes, these high limits are for the user running the hadoop/hbase processes.
>
> The systems are ran on a cluster of 7 machines (1 master, 6 slaves). One
> processor, two cores and 3.5GB of memory. I am using about 800MB for hadoop
> (version CDH3B2) and 2.1GB for HBase (version 0.90.2). There is 6TB on four
> disks per machine. Three zookeepers. The database contains more than 3500
> regions and the table that was fed was already about 300 regions. The table
> was fed incrementally using HTable.put().  The data are documents with size
> ranging from few bytes to megabytes where the upper limit is set to 10MB per
> inserted doc.
>

Are you swapping Stan?  You are close to the edge with your RAM
allocations.  What do you have swappyness set to?  Is it default?

Writing you don't need that much memory usually but you do have a lot
of regions so you could be flushing a bunch, a bunch of small files.




> The configuration files:
>
> hadoop/core-site.xml http://pastebin.ca/2051527
> hadoop/hadoop-env.sh http://pastebin.ca/2051528

Your HADOOP_CLASSPATH is a little odd.  You are doing * on jar
directories.  Does that work?

This CLASSPATH  mentions nutch and a bunch of other stuff.  Are you
running just datanodes on these machines or tasktracers and mapreduce
too?

These are old IA stock machines?  Do they have ECC RAM?  (IIRC, they
used to not have ECC RAM).


> hadoop/hdfs-site.xml http://pastebin.ca/2051529
>

Did you change the dfs block size?   Looks like its 256M rather than
usual 64M.  Any reason for that?  Would suggest going w/ defaults at
first.

Remove dfs.datanode.socket.write.timeout == 0.  Thats an old config.
recommendation that should no longer be necessary and is likely
corrosive.


> hbase/hbase-site.xml http://pastebin.ca/2051532

You are letting major compactions run every 24 hours.  You might want
to turn them off and then manage the major compactions to happen
during downtimes.  They have a knack of cutting in just when you don't
want them too; e.g. when you are under peak loading.

You have upped the flush size above default; i.e.
hbase.hregion.memstore.flush.size.  This will put more pressure on RAM
when I'd think you would want to have less since you are poor where it
comes to RAM.

You have upped your regionsize above default.   That is good I'd say.
You might want to 4x -- go to 4G -- since you are doing relatively big
stuff.

You should send me the metrics that show on the top of the
regionserver UI when you are under load.  I'd like to see things like
how much of your RAM is given over to indices for these storefiles.

I see you hdfs.block.size specified in here at 256M.  So stuff written
by hbase into hdfs will have a block size of 256M.  Any reason to do
this?  I'd say leave it at default unless you have a really good
reason to do otherwise (Remove this config. from this file).



> hbase/hbase-env.sh http://pastebin.ca/2051535
>

Remove this:

-XX:+HeapDumpOnOutOfMemoryError

Means it will dump heap if JVM crashes.  This is probably of no
interest to you and could actually cause you pain if you have small
root file system if the heap dump causes you to fill.

The -XX:CMSInitiatingOccupancyFraction=90 is probably near useless
(default is 92% or 88% -- I don't remember which).  Set it down to 80%
or 75% if you want it to actually make a difference.

Are you having issues w/ GC'ing?  I see you have mslab enabled.


> Because the nproc was high I had inspected the out files of the RSs' and
> found one which indicated that all the IPCs OOMEd, unfortunately I dont have
> those because they got overwritten after a cluster restart.

This may have been because of  HBASE-3813 .  See if 0.90.3 helps
(There is an improvement here).

Next time, let us see them.

> So that means
> that it was OK on the client side. Funny is that all RS processes were up
> and running, only that one with OOMEd IPCs did not really communicate (after
> trying to restart the importing process no inserts went through).

An OOME'd process goes wonky thereafter and acts in irrational ways.
Perhaps this was why it stopped taking on requests.

> So the
> cluster seemed OK - I was storing statistics that were apparently served by
> another RS and those were also listed OK. As I mentioned, the log of the bad
> RS did not mention that anything wrong happened.
>
> My observation was: the regions were spread on all RSs but the crashed RS
> served most of them about a half more than any other, therefore was accessed
> the more than others. I have discussed the load balancing in HBase 0.90.2
> with Ted Yu already.
>
> The balancer needs to be tuned I guess because when the table is created and
> loaded from scratch, the regions of the table are not balanced equally (in
> terms of numbers) in the cluster and I guess the RS that hosted the very
> first region is serving the majority of servers as they are being split. It
> imposes larger load on that RS which is more prone to failures (like mine
> OOME) and kill performance.
>

OK.  Yeah, Ted has been arguing that the balancer should be
table-conscious in that it should try and spread tables across the
cluster.  Currently its not.  All regions are equal in the balancer's
eyes.  0.90.2 didn't help?  (Others have since reported that they
think as Ted that the region a table comes from should be considered
when balancing).

> I have resumed the process with rebalancing the regions beforehand and was
> achieving higher data ingestion rate and also did not ran into the OOME with
> one RS. Right now I am trying to replay the incident.
>
> I know that my scenario would require better machines, but those are what I
> have now and am before production running stress tests. In comparison with
> 0.20.6 the 0.90.2 is less stable regarding the insertion but it scales
> sub-linearily (v0.20.6 did not scale on my data) in terms of random access
> queries (including multi-versioned data) - have done extensive comparison
> regarding this.
>

0.90.2 scales sub-linearly?  You mean its not linear but more machines helps?

Are you random reads truly random (I'd guess they are).  Would cache help?

Have you tried hdfs-237 patch?  There is a version that should work
for you version of cdh.  It could a big difference (though, beware,
the latest posted patch does not do checksuming and if your hardware
does not have ECC, it could be a problem).

St.Ack

Re: HTable.put hangs on bulk loading

Posted by Stan Barton <ba...@gmail.com>.
Yes, these high limits are for the user running the hadoop/hbase processes.

The systems are ran on a cluster of 7 machines (1 master, 6 slaves). One
processor, two cores and 3.5GB of memory. I am using about 800MB for hadoop
(version CDH3B2) and 2.1GB for HBase (version 0.90.2). There is 6TB on four
disks per machine. Three zookeepers. The database contains more than 3500
regions and the table that was fed was already about 300 regions. The table
was fed incrementally using HTable.put().  The data are documents with size
ranging from few bytes to megabytes where the upper limit is set to 10MB per
inserted doc.

The configuration files:

hadoop/core-site.xml http://pastebin.ca/2051527
hadoop/hadoop-env.sh http://pastebin.ca/2051528
hadoop/hdfs-site.xml http://pastebin.ca/2051529

hbase/hbase-site.xml http://pastebin.ca/2051532
hbase/hbase-env.sh http://pastebin.ca/2051535

Because the nproc was high I had inspected the out files of the RSs' and
found one which indicated that all the IPCs OOMEd, unfortunately I dont have
those because they got overwritten after a cluster restart. So that means
that it was OK on the client side. Funny is that all RS processes were up
and running, only that one with OOMEd IPCs did not really communicate (after
trying to restart the importing process no inserts went through). So the
cluster seemed OK - I was storing statistics that were apparently served by
another RS and those were also listed OK. As I mentioned, the log of the bad
RS did not mention that anything wrong happened. 

My observation was: the regions were spread on all RSs but the crashed RS
served most of them about a half more than any other, therefore was accessed
the more than others. I have discussed the load balancing in HBase 0.90.2
with Ted Yu already. 

The balancer needs to be tuned I guess because when the table is created and
loaded from scratch, the regions of the table are not balanced equally (in
terms of numbers) in the cluster and I guess the RS that hosted the very
first region is serving the majority of servers as they are being split. It
imposes larger load on that RS which is more prone to failures (like mine
OOME) and kill performance.

I have resumed the process with rebalancing the regions beforehand and was
achieving higher data ingestion rate and also did not ran into the OOME with
one RS. Right now I am trying to replay the incident.

I know that my scenario would require better machines, but those are what I
have now and am before production running stress tests. In comparison with
0.20.6 the 0.90.2 is less stable regarding the insertion but it scales
sub-linearily (v0.20.6 did not scale on my data) in terms of random access
queries (including multi-versioned data) - have done extensive comparison
regarding this.

Stan


stack-3 wrote:
> 
> On Wed, Apr 27, 2011 at 2:30 AM, Stan Barton <ba...@gmail.com> wrote:
>>
>> Hi,
>>
>> what means increase? I checked on the client machines and the nproc limit
>> is
>> around 26k, that seems to be as sufficient. The same limit applies on the
>> db
>> machines...
>>
> 
> The nproc and ulimits are 26k for the user who is running the
> hadoop/hbase processes?
> 
> You checked the .out files?   You can pastebin your configuration and
> we'll take a look at them.
> 
> Sounds like the hang is in the client if you can still get to the
> cluster from a new shell....
> 
> As Mike says, tell us more about your context.  How many regions on
> each server.  What is your payload like?
> 
> Thanks,
> St.Ack
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31496726.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Stack <st...@duboce.net>.
On Wed, Apr 27, 2011 at 2:30 AM, Stan Barton <ba...@gmail.com> wrote:
>
> Hi,
>
> what means increase? I checked on the client machines and the nproc limit is
> around 26k, that seems to be as sufficient. The same limit applies on the db
> machines...
>

The nproc and ulimits are 26k for the user who is running the
hadoop/hbase processes?

You checked the .out files?   You can pastebin your configuration and
we'll take a look at them.

Sounds like the hang is in the client if you can still get to the
cluster from a new shell....

As Mike says, tell us more about your context.  How many regions on
each server.  What is your payload like?

Thanks,
St.Ack

Re: HTable.put hangs on bulk loading

Posted by Stan Barton <ba...@gmail.com>.
Hi,

what means increase? I checked on the client machines and the nproc limit is
around 26k, that seems to be as sufficient. The same limit applies on the db
machines...

Stan



ajay.gov wrote:
> 
> Hi,
> 
> I posted the same message on the user@hbase.apache.org mailing list and
> Jean-Daniel Cryans suggested i increase the nproc limit on the client
> machines. I did it and it fixed the problem.
> 
> -ajay
> 
> 
> 
> Stan Barton wrote:
>> 
>> I am running into similar problem with HBase 0.90.2. My setting is 6 RSs
>> one master server, 3 ZK servers and about 20 clients (on different
>> servers) feeding the database with inserts. After few hours and around
>> 2.5 millions rows inserted the process simply hangs with no what so ever
>> error indication (neither by ZK, master, regionservers nor the clients).
>> All the inserting clients stop virtually at the same moment, but HBase it
>> self is not down and can be queried. 
>> 
>> In fact, the clients not even crash on time out exception for its
>> connection. I have ran into such problem always when I attempted to run
>> such importing progress with the new HBase versions (even 0.90.1). Can
>> anybody address this problem? Does other have similar problems?
>> 
>> I can provide further info about the configuration if needed.
>> 
>> Stan Barton
>> 
>> 
>> 
>> 
>> ajay.gov wrote:
>>> 
>>> Sorry, my server config was not attached. Its here:
>>> http://pastebin.com/U41QZGiq
>>> 
>>> thanks
>>> -ajay
>>> 
>>> 
>>> 
>>> ajay.gov wrote:
>>>> 
>>>> I am doing a load test for which I need to load a table with many rows. 
>>>> I have a small java program that has a for loop and calls HTable.put. 
>>>> I am inserting a map of 2 items into a table that has one column
>>>> family. The limit of the for loop is currently 20000. However after
>>>> 15876 rows the call to Put hangs. I am using autoFlush on the HTable.
>>>> Any ideas why this may happen? 
>>>> 
>>>> The table configuration:
>>>> DESCRIPTION                                          ENABLED                    
>>>>  {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true                       
>>>>  1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'                            
>>>>  , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2                            
>>>>  147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal                            
>>>>  se', BLOCKCACHE => 'true'}]}
>>>> 
>>>> The HBase config on the client is the one in the hbase-default.xml.
>>>> Some values:
>>>> hbase.client.write.buffer=2097152
>>>> hbase.client.pause=1000
>>>> hbase.client.retries.number=10
>>>> 
>>>> If i use another client I am able to put items to the table. I am also
>>>> able to scan items from the table using the hbase shell.
>>>> 
>>>> I have attached the server configuratio
>>>> I don't see anything in the region server or master logs. I have them
>>>> here.
>>>> 
>>>> The master server log:
>>>> 2011-04-06 19:02:40,149 INFO
>>>> org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner
>>>> scanning meta region {server: 184.106.69.238:60020, regionname:
>>>> -ROOT-,,0.70236052, startKey: <>}
>>>> 2011-04-06 19:02:40,152 INFO
>>>> org.apache.hadoop.hbase.master.BaseScanner: RegionManager.rootScanner
>>>> scan of 1 row(s) of meta region {server: 184.106.69.238:60020,
>>>> regionname: -ROOT-,,0.70236052, startKey: <>} complete
>>>> 2011-04-06 19:02:40,157 INFO
>>>> org.apache.hadoop.hbase.master.ServerManager: 1 region servers, 0 dead,
>>>> average load 42.0
>>>> 2011-04-06 19:03:15,252 INFO
>>>> org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner
>>>> scanning meta region {server: 184.106.69.238:60020, regionname:
>>>> .META.,,1.1028785192, startKey: <>}
>>>> 2011-04-06 19:03:15,265 INFO
>>>> org.apache.hadoop.hbase.master.BaseScanner: RegionManager.metaScanner
>>>> scan of 40 row(s) of meta region {server: 184.106.69.238:60020,
>>>> regionname: .META.,,1.1028785192, startKey: <>} complete
>>>> 2011-04-06 19:03:15,266 INFO
>>>> org.apache.hadoop.hbase.master.BaseScanner: All 1 .META. region(s)
>>>> scanned
>>>> 
>>>> 
>>>> The region server logs:
>>>> 2011-04-06 19:02:21,294 DEBUG
>>>> org.apache.hadoop.hbase.regionserver.HRegion: Creating region
>>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
>>>> 2011-04-06 19:02:21,295 INFO
>>>> org.apache.hadoop.hbase.regionserver.HRegion: Onlined
>>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
>>>> sequenceid=1
>>>> 
>>>> 
>>> 
>>> 
>> 
>> 
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31485864.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Stack <st...@duboce.net>.
On Tue, Apr 26, 2011 at 11:36 AM, Jeff Whiting <je...@qualtrics.com> wrote:
> Would it make sense to do some kind of sanity check on these various
> configuration parameters when a region or master server starts?  It seems
> like there is a lot of them and when they aren't right, it can cause big
> problems.  Just have it check the configuration parameters and output a
> warning in the log.  E.g. log.warn("Warning, OS setting may be too low:
> ulimit should be at least X.  Considering changing it.");
>
> Also if that were to show up in the Master.jsp it would be even better.
>

We output ulimit seen by HBase as first thing in the log (We recently
changed it so it lists all ulimits so we now show nprocs).  But
obviously, this is not enough given the frequency with which these
configs are missed though they are first thing in our requirements
list.  Lets add a warning to the UI as you suggest Jeff (We have ones
already for when you are running on jdk 1.6.0 u18 -- we can extend
this code).  Mind filing an issue Jeff?  Mark it against 0.92.0 though
no reason it shouldn't be added to 0.90.3.

Thanks,
St.Ack

Re: HTable.put hangs on bulk loading

Posted by Jeff Whiting <je...@qualtrics.com>.
Would it make sense to do some kind of sanity check on these various configuration parameters when a 
region or master server starts?  It seems like there is a lot of them and when they aren't right, it 
can cause big problems.  Just have it check the configuration parameters and output a warning in the 
log.  E.g. log.warn("Warning, OS setting may be too low: ulimit should be at least X.  Considering 
changing it.");

Also if that were to show up in the Master.jsp it would be even better.

~Jeff

On 4/26/2011 11:17 AM, ajay.gov wrote:
> Hi,
>
> I posted the same message on the user@hbase.apache.org mailing list and
> Jean-Daniel Cryans suggested i increase the nproc limit on the client
> machines. I did it and it fixed the problem.
>
> -ajay
>
>
>
> Stan Barton wrote:
>> I am running into similar problem with HBase 0.90.2. My setting is 6 RSs
>> one master server, 3 ZK servers and about 20 clients (on different
>> servers) feeding the database with inserts. After few hours and around 2.5
>> millions rows inserted the process simply hangs with no what so ever error
>> indication (neither by ZK, master, regionservers nor the clients). All the
>> inserting clients stop virtually at the same moment, but HBase it self is
>> not down and can be queried.
>>
>> In fact, the clients not even crash on time out exception for its
>> connection. I have ran into such problem always when I attempted to run
>> such importing progress with the new HBase versions (even 0.90.1). Can
>> anybody address this problem? Does other have similar problems?
>>
>> I can provide further info about the configuration if needed.
>>
>> Stan Barton
>>
>>
>>
>>
>> ajay.gov wrote:
>>> Sorry, my server config was not attached. Its here:
>>> http://pastebin.com/U41QZGiq
>>>
>>> thanks
>>> -ajay
>>>
>>>
>>>
>>> ajay.gov wrote:
>>>> I am doing a load test for which I need to load a table with many rows.
>>>> I have a small java program that has a for loop and calls HTable.put.  I
>>>> am inserting a map of 2 items into a table that has one column family.
>>>> The limit of the for loop is currently 20000. However after 15876 rows
>>>> the call to Put hangs. I am using autoFlush on the HTable. Any ideas why
>>>> this may happen?
>>>>
>>>> The table configuration:
>>>> DESCRIPTION                                          ENABLED
>>>>   {NAME =>  'TABLE2', FAMILIES =>  [{NAME =>  'TABLE2_CF true
>>>>   1', BLOOMFILTER =>  'NONE', REPLICATION_SCOPE =>  '0'
>>>>   , COMPRESSION =>  'NONE', VERSIONS =>  '3', TTL =>  '2
>>>>   147483647', BLOCKSIZE =>  '65536', IN_MEMORY =>  'fal
>>>>   se', BLOCKCACHE =>  'true'}]}
>>>>
>>>> The HBase config on the client is the one in the hbase-default.xml. Some
>>>> values:
>>>> hbase.client.write.buffer=2097152
>>>> hbase.client.pause=1000
>>>> hbase.client.retries.number=10
>>>>
>>>> If i use another client I am able to put items to the table. I am also
>>>> able to scan items from the table using the hbase shell.
>>>>
>>>> I have attached the server configuratio
>>>> I don't see anything in the region server or master logs. I have them
>>>> here.
>>>>
>>>> The master server log:
>>>> 2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>>> RegionManager.rootScanner scanning meta region {server:
>>>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey:<>}
>>>> 2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>>> RegionManager.rootScanner scan of 1 row(s) of meta region {server:
>>>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey:<>}
>>>> complete
>>>> 2011-04-06 19:02:40,157 INFO
>>>> org.apache.hadoop.hbase.master.ServerManager: 1 region servers, 0 dead,
>>>> average load 42.0
>>>> 2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>>> RegionManager.metaScanner scanning meta region {server:
>>>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey:<>}
>>>> 2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>>> RegionManager.metaScanner scan of 40 row(s) of meta region {server:
>>>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey:<>}
>>>> complete
>>>> 2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>>> All 1 .META. region(s) scanned
>>>>
>>>>
>>>> The region server logs:
>>>> 2011-04-06 19:02:21,294 DEBUG
>>>> org.apache.hadoop.hbase.regionserver.HRegion: Creating region
>>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
>>>> 2011-04-06 19:02:21,295 INFO
>>>> org.apache.hadoop.hbase.regionserver.HRegion: Onlined
>>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
>>>> sequenceid=1
>>>>
>>>>
>>>
>>

-- 
Jeff Whiting
Qualtrics Senior Software Engineer
jeffw@qualtrics.com


Re: HTable.put hangs on bulk loading

Posted by "ajay.gov" <ag...@yahoo.com>.
Hi,

I posted the same message on the user@hbase.apache.org mailing list and
Jean-Daniel Cryans suggested i increase the nproc limit on the client
machines. I did it and it fixed the problem.

-ajay



Stan Barton wrote:
> 
> I am running into similar problem with HBase 0.90.2. My setting is 6 RSs
> one master server, 3 ZK servers and about 20 clients (on different
> servers) feeding the database with inserts. After few hours and around 2.5
> millions rows inserted the process simply hangs with no what so ever error
> indication (neither by ZK, master, regionservers nor the clients). All the
> inserting clients stop virtually at the same moment, but HBase it self is
> not down and can be queried. 
> 
> In fact, the clients not even crash on time out exception for its
> connection. I have ran into such problem always when I attempted to run
> such importing progress with the new HBase versions (even 0.90.1). Can
> anybody address this problem? Does other have similar problems?
> 
> I can provide further info about the configuration if needed.
> 
> Stan Barton
> 
> 
> 
> 
> ajay.gov wrote:
>> 
>> Sorry, my server config was not attached. Its here:
>> http://pastebin.com/U41QZGiq
>> 
>> thanks
>> -ajay
>> 
>> 
>> 
>> ajay.gov wrote:
>>> 
>>> I am doing a load test for which I need to load a table with many rows. 
>>> I have a small java program that has a for loop and calls HTable.put.  I
>>> am inserting a map of 2 items into a table that has one column family.
>>> The limit of the for loop is currently 20000. However after 15876 rows
>>> the call to Put hangs. I am using autoFlush on the HTable. Any ideas why
>>> this may happen? 
>>> 
>>> The table configuration:
>>> DESCRIPTION                                          ENABLED                    
>>>  {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true                       
>>>  1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'                            
>>>  , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2                            
>>>  147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal                            
>>>  se', BLOCKCACHE => 'true'}]}
>>> 
>>> The HBase config on the client is the one in the hbase-default.xml. Some
>>> values:
>>> hbase.client.write.buffer=2097152
>>> hbase.client.pause=1000
>>> hbase.client.retries.number=10
>>> 
>>> If i use another client I am able to put items to the table. I am also
>>> able to scan items from the table using the hbase shell.
>>> 
>>> I have attached the server configuratio
>>> I don't see anything in the region server or master logs. I have them
>>> here.
>>> 
>>> The master server log:
>>> 2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.rootScanner scanning meta region {server:
>>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
>>> 2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.rootScanner scan of 1 row(s) of meta region {server:
>>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
>>> complete
>>> 2011-04-06 19:02:40,157 INFO
>>> org.apache.hadoop.hbase.master.ServerManager: 1 region servers, 0 dead,
>>> average load 42.0
>>> 2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.metaScanner scanning meta region {server:
>>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
>>> 2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> RegionManager.metaScanner scan of 40 row(s) of meta region {server:
>>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
>>> complete
>>> 2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner:
>>> All 1 .META. region(s) scanned
>>> 
>>> 
>>> The region server logs:
>>> 2011-04-06 19:02:21,294 DEBUG
>>> org.apache.hadoop.hbase.regionserver.HRegion: Creating region
>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
>>> 2011-04-06 19:02:21,295 INFO
>>> org.apache.hadoop.hbase.regionserver.HRegion: Onlined
>>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
>>> sequenceid=1
>>> 
>>> 
>> 
>> 
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31480444.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by Stan Barton <ba...@gmail.com>.
I am running into similar problem with HBase 0.90.2. My setting is 6 RSs one
master server, 3 ZK servers and about 20 clients (on different servers)
feeding the database with inserts. After few hours and around 2.5 millions
rows inserted the process simply hangs with no what so ever error indication
(neither by ZK, master, regionservers nor the clients). All the inserting
clients stop virtually at the same moment, but HBase it self is not down and
can be queried. 

In fact, the clients not even crash on time out exception for its
connection. I have ran into such problem always when I attempted to run such
importing progress with the new HBase versions (even 0.90.1). Can anybody
address this problem? Does other have similar problems?

I can provide further info about the configuration if needed.

Stan Barton




ajay.gov wrote:
> 
> Sorry, my server config was not attached. Its here:
> http://pastebin.com/U41QZGiq
> 
> thanks
> -ajay
> 
> 
> 
> ajay.gov wrote:
>> 
>> I am doing a load test for which I need to load a table with many rows. 
>> I have a small java program that has a for loop and calls HTable.put.  I
>> am inserting a map of 2 items into a table that has one column family.
>> The limit of the for loop is currently 20000. However after 15876 rows
>> the call to Put hangs. I am using autoFlush on the HTable. Any ideas why
>> this may happen? 
>> 
>> The table configuration:
>> DESCRIPTION                                          ENABLED                    
>>  {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true                       
>>  1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'                            
>>  , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2                            
>>  147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal                            
>>  se', BLOCKCACHE => 'true'}]}
>> 
>> The HBase config on the client is the one in the hbase-default.xml. Some
>> values:
>> hbase.client.write.buffer=2097152
>> hbase.client.pause=1000
>> hbase.client.retries.number=10
>> 
>> If i use another client I am able to put items to the table. I am also
>> able to scan items from the table using the hbase shell.
>> 
>> I have attached the server configuratio
>> I don't see anything in the region server or master logs. I have them
>> here.
>> 
>> The master server log:
>> 2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
>> RegionManager.rootScanner scanning meta region {server:
>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
>> 2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
>> RegionManager.rootScanner scan of 1 row(s) of meta region {server:
>> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
>> complete
>> 2011-04-06 19:02:40,157 INFO
>> org.apache.hadoop.hbase.master.ServerManager: 1 region servers, 0 dead,
>> average load 42.0
>> 2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
>> RegionManager.metaScanner scanning meta region {server:
>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
>> 2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
>> RegionManager.metaScanner scan of 40 row(s) of meta region {server:
>> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
>> complete
>> 2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner:
>> All 1 .META. region(s) scanned
>> 
>> 
>> The region server logs:
>> 2011-04-06 19:02:21,294 DEBUG
>> org.apache.hadoop.hbase.regionserver.HRegion: Creating region
>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
>> 2011-04-06 19:02:21,295 INFO
>> org.apache.hadoop.hbase.regionserver.HRegion: Onlined
>> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
>> sequenceid=1
>> 
>> 
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31477194.html
Sent from the HBase User mailing list archive at Nabble.com.


Re: HTable.put hangs on bulk loading

Posted by "ajay.gov" <ag...@yahoo.com>.
Sorry, my server config was not attached. Its here:
http://pastebin.com/U41QZGiq

thanks
-ajay



ajay.gov wrote:
> 
> I am doing a load test for which I need to load a table with many rows.  I
> have a small java program that has a for loop and calls HTable.put.  I am
> inserting a map of 2 items into a table that has one column family. The
> limit of the for loop is currently 20000. However after 15876 rows the
> call to Put hangs. I am using autoFlush on the HTable. Any ideas why this
> may happen? 
> 
> The table configuration:
> DESCRIPTION                                          ENABLED                    
>  {NAME => 'TABLE2', FAMILIES => [{NAME => 'TABLE2_CF true                       
>  1', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0'                            
>  , COMPRESSION => 'NONE', VERSIONS => '3', TTL => '2                            
>  147483647', BLOCKSIZE => '65536', IN_MEMORY => 'fal                            
>  se', BLOCKCACHE => 'true'}]}
> 
> The HBase config on the client is the one in the hbase-default.xml. Some
> values:
> hbase.client.write.buffer=2097152
> hbase.client.pause=1000
> hbase.client.retries.number=10
> 
> If i use another client I am able to put items to the table. I am also
> able to scan items from the table using the hbase shell.
> 
> I have attached the server configuratio
> I don't see anything in the region server or master logs. I have them
> here.
> 
> The master server log:
> 2011-04-06 19:02:40,149 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.rootScanner scanning meta region {server:
> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
> 2011-04-06 19:02:40,152 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.rootScanner scan of 1 row(s) of meta region {server:
> 184.106.69.238:60020, regionname: -ROOT-,,0.70236052, startKey: <>}
> complete
> 2011-04-06 19:02:40,157 INFO org.apache.hadoop.hbase.master.ServerManager:
> 1 region servers, 0 dead, average load 42.0
> 2011-04-06 19:03:15,252 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.metaScanner scanning meta region {server:
> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
> 2011-04-06 19:03:15,265 INFO org.apache.hadoop.hbase.master.BaseScanner:
> RegionManager.metaScanner scan of 40 row(s) of meta region {server:
> 184.106.69.238:60020, regionname: .META.,,1.1028785192, startKey: <>}
> complete
> 2011-04-06 19:03:15,266 INFO org.apache.hadoop.hbase.master.BaseScanner:
> All 1 .META. region(s) scanned
> 
> 
> The region server logs:
> 2011-04-06 19:02:21,294 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegion: Creating region
> TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.
> 2011-04-06 19:02:21,295 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined TABLE2,,1302141740486.010a5ae704ed53f656cbddb8e489162a.; next
> sequenceid=1
> 
> 

-- 
View this message in context: http://old.nabble.com/HTable.put-hangs-on-bulk-loading-tp31338874p31345580.html
Sent from the HBase User mailing list archive at Nabble.com.