Home | About | Sematext search-lucene.com search-hadoop.com
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB
 Search Hadoop and all its subprojects:

Switch to Threaded View
HBase >> mail # user >> GC and High CPU


Copy link to this message
-
Re: GC and High CPU
I think this will resolve my issue, here is the output:

     14 2011-05-16T15:58
     13 2011-05-16T15:59
     12 2011-05-16T16:00
     14 2011-05-16T16:01
     14 2011-05-16T16:02
     13 2011-05-16T16:03
     11 2011-05-16T16:04
     12 2011-05-16T16:05
     11 2011-05-16T16:06
16:06:55 10.103.7.27 root@mtag27:/usr/lib/hbase/logs $ tail -f gc-hbase.log
2011-05-16T16:06:05.528-0700: 1725.183: [GC 1725.183: [ParNew:
76665K->7644K(76672K), 0.0301560 secs] 3255607K->3194064K(12279488K)
icms_dc=0 , 0.0302940 secs] [Times: user=0.09 sys=0.01, real=0.03
secs]
2011-05-16T16:06:11.457-0700: 1731.112: [GC 1731.112: [ParNew:
75800K->7168K(76672K), 0.0311670 secs] 3262220K->3198429K(12279488K)
icms_dc=0 , 0.0312880 secs] [Times: user=0.09 sys=0.00, real=0.03
secs]
2011-05-16T16:06:16.546-0700: 1736.202: [GC 1736.202: [ParNew:
75328K->7674K(76672K), 0.0270760 secs] 3266589K->3203675K(12279488K)
icms_dc=0 , 0.0271940 secs] [Times: user=0.09 sys=0.01, real=0.03
secs]
2011-05-16T16:06:21.407-0700: 1741.063: [GC 1741.063: [ParNew:
75832K->8512K(76672K), 0.0285340 secs] 3271833K->3209994K(12279488K)
icms_dc=0 , 0.0286380 secs] [Times: user=0.07 sys=0.01, real=0.03
secs]
2011-05-16T16:06:26.571-0700: 1746.226: [GC 1746.226: [ParNew:
76627K->6049K(76672K), 0.0254590 secs] 3278109K->3213405K(12279488K)
icms_dc=0 , 0.0255890 secs] [Times: user=0.08 sys=0.00, real=0.03
secs]
Now running GC less often with larger cleans. And here is another
server that runs under same load:

     40 2011-05-16T15:53
     50 2011-05-16T15:54
     45 2011-05-16T15:55
     43 2011-05-16T15:56
     39 2011-05-16T15:57
     37 2011-05-16T15:58
     37 2011-05-16T15:59
     35 2011-05-16T16:00
     36 2011-05-16T16:01
     25 2011-05-16T16:02
16:08:39 10.103.7.25 root@mtag25:/usr/lib/hbase/logs $ tail -f gc-hbase.log
2011-05-16T16:08:29.154-0700: 171956.381: [GC 171956.382: [ParNew:
19130K->2112K(19136K), 0.0403890 secs] 6649843K->6634911K(11885508K),
0.0407000 secs] [Times: user=0.15 sys=0.01, real=0.04 secs]
2011-05-16T16:08:30.237-0700: 171957.464: [GC 171957.465: [ParNew:
19077K->2112K(19136K), 0.0367750 secs] 6651877K->6636722K(11885508K),
0.0369370 secs] [Times: user=0.14 sys=0.00, real=0.04 secs]
2011-05-16T16:08:31.864-0700: 171959.092: [GC 171959.092: [ParNew:
19120K->1656K(19136K), 0.0396040 secs] 6653731K->6637891K(11885508K),
0.0397500 secs] [Times: user=0.14 sys=0.01, real=0.04 secs]
2011-05-16T16:08:33.551-0700: 171960.778: [GC 171960.779: [ParNew:
18620K->2112K(19136K), 0.0398640 secs] 6654855K->6638900K(11885508K),
0.0400910 secs] [Times: user=0.15 sys=0.00, real=0.04 secs]
2011-05-16T16:08:35.116-0700: 171962.344: [GC 171962.344: [ParNew:
19136K->2112K(19136K), 0.0375530 secs] 6655924K->6641070K(11885508K),
0.0377090 secs] [Times: user=0.14 sys=0.01, real=0.04 secs]
2011-05-16T16:08:36.562-0700: 171963.790: [GC 171963.790: [ParNew:
19131K->1763K(19136K), 0.0453660 secs] 6658090K->6642325K(11885508K),
0.0455130 secs] [Times: user=0.17 sys=0.00, real=0.04 secs]
2011-05-16T16:08:37.675-0700: 171964.903: [GC 171964.903: [ParNew:
18733K->1400K(19136K), 0.0457320 secs] 6659295K->6643257K(11885508K),
0.0459240 secs] [Times: user=0.17 sys=0.00, real=0.05 secs]
Way more often, less to clean, and CPU usage is visibly higher.  And
GC config changes are:
export HBASE_OPTS="$HBASE_OPTS -XX:+UseConcMarkSweepGC
-XX:MaxDirectMemorySize=2G"

# Uncomment below to enable java garbage collection logging.
export HBASE_OPTS="$HBASE_OPTS -verbose:gc -Xms12000m
-XX:CMSInitiatingOccupancyFraction=70 -XX:+PrintGCDetails
-XX:+PrintGCDateStamps -XX:+HeapDumpOnOutOfMemoryError
-Xloggc:$HBASE_HOME/logs/gc-hbase.log \
-XX:+CMSIncrementalMode \  <--------
-XX:+CMSIncrementalPacing \ <-------
-XX:-TraceClassUnloading <---------------

This way GC statistically adapts, and lesses the load on CPU.

-Jack
On Mon, May 16, 2011 at 3:17 PM, Jack Levin <[EMAIL PROTECTED]> wrote:
> hlog rolled, and qps was at 1000, not much at all.  I tend to believe
> that concurrent GC collection is taking way too many threads from the
NEW: Monitor These Apps!
elasticsearch, apache solr, apache hbase, hadoop, redis, casssandra, amazon cloudwatch, mysql, memcached, apache kafka, apache zookeeper, apache storm, ubuntu, centOS, red hat, debian, puppet labs, java, senseiDB