incubator-cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Peter Schuller <peter.schul...@infidyne.com>
Subject Re: Memory leak with Sun Java 1.6 ?
Date Tue, 14 Dec 2010 18:38:04 GMT
> I can rule out the first 3. I was running cassandra with default settings, i.e. 1GB heap
and 256M memtable. So, with 3 memtables+1GB the JVM should run with >1.75G (although http://wiki.apache.org/cassandra/MemtableThresholds
considers to increase heap size only gently). Did so. 4GB machine with 2GB 64bit-JVM seemed
to run stable for quite some time but then also crashed with OOM. Looking at the heap dump
it's always the same: all memory nearly always bound in CompactionExecutor (ColumnFamilyStore/ConcurrentSkipListMap,
respectively).

Note that the memtables are just data structures in memory and are in
the heap. They are not in addition to the heap. mmap():ed files will
be though.

For debugging purposes you may want to switch Cassandra to "standard"
IO mode instead of mmap. This will have a performance-penalty, but the
virtual/resident sizes won't be polluted with mmap():ed data.

In general, unless you're hitting something particularly strange or
just a bug in Cassandra, you shouldn't be randomly getting OOM:s
unless you are truly using that heap space. What do you mean by
"always bound in compactionexecutor" - by what method did you
determine this to be the case?

Note that memtables are ConcurrentSkipListMap:s, so they are expected
to contain a lot of data (and maybe be significant themselves if lots
of small items are stored).

> This looks like somebody else recently have had a similar problem (->Bottom line:
more heap - which is okay, but I'd like to understand why):
> http://www.mail-archive.com/user@cassandra.apache.org/msg07516.html

There should be no magic need for CPU. Unless you are severely taxing
it in terms of very high write load or similar, an out-of-the-box
configured cassandra should be needing limited amounts of memory. Did
you run with default memtable thresholds (memtable_throughput_in_mb in
particular)? How many column families do you have? You need memory for
*each* column family, taking into account it's memtable thresholds.

> This is my only CF currently in use (via JMX):
>
> - column_families:
>  - column_type: Standard
>    comment: tracking column family
>    compare_with: org.apache.cassandra.db.marshal.UTF8Type
>    default_validation_class: org.apache.cassandra.db.marshal.UTF8Type
>    gc_grace_seconds: 864000
>    key_cache_save_period_in_seconds: 3600
>    keys_cached: 200000.0
>    max_compaction_threshold: 32
>    memtable_flush_after_mins: 60
>    min_compaction_threshold: 4
>    name: tracking
>    read_repair_chance: 1.0
>    row_cache_save_period_in_seconds: 0
>    rows_cached: 0.0
>  name: test
>  replica_placement_strategy: org.apache.cassandra.locator.SimpleStrategy
>  replication_factor: 3

This is the only column family being used?

> In addition...actually there is plenty of free memory on the heap (?):
>
> 3605.478: [GC 3605.478: [ParNew
> Desired survivor size 2162688 bytes, new threshold 1 (max 1)
> - age   1:     416112 bytes,     416112 total
> : 16887K->553K(38336K), 0.0209550 secs]3605.499: [CMS: 1145267K->447565K(2054592K),
1.9143630 secs] 1161938K->447565K(2092928K), [CMS Perm : 18186K->18158K(30472K)], 1.9355340
secs] [Times: user=1.95 sys=0.00, real=1.94 secs]
> 3607.414: [Full GC 3607.414: [CMS: 447565K->447453K(2054592K), 1.9694960 secs] 447565K->447453K(2092928K),
[CMS Perm : 18158K->18025K(30472K)], 1.9696450 secs] [Times: user=1.92 sys=0.00, real=1.97
secs]

1.9 seconds to do [CMS: 1145267K->447565K(2054592K) is completely
abnormal if that represents a pause (but not if it's just concurrent
mark/sweep time). I don't quite recognize the format of this log...
I'm suddenly unsure what this log output is coming from. A normal
-XX:+PrintGC and -XX:+PrintGCDetails should yield stuff like:

22.634: [GC 22.634: [ParNew: 19136K->2112K(19136K), 0.0058490 secs]
123155K->108012K(202688K), 0.0059050 secs] [Times: user=0.02 sys=0.00,
real=0.00 secs]
22.660: [GC 22.660: [ParNew: 19136K->2112K(19136K), 0.0063220 secs]
125036K->109893K(202688K), 0.0063910 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
22.686: [GC 22.686: [ParNew: 19136K->2112K(19136K), 0.0067150 secs]
126917K->111864K(202688K), 0.0067730 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
22.724: [CMS-concurrent-abortable-preclean: 0.041/0.257 secs] [Times:
user=0.24 sys=0.01, real=0.26 secs]
22.724: [GC[YG occupancy: 19037 K (19136 K)]22.724: [Rescan (parallel)
, 0.0085230 secs]22.732: [weak refs processing, 0.0142440 secs] [1
CMS-remark: 109752K(183552K)] 128790K(202688K), 0.0228750 secs]
[Times: user=0.03 sys=0.00, real=0.02 secs]
22.747: [CMS-concurrent-sweep-start]
22.749: [GC 22.749: [ParNew: 19136K->2112K(19136K), 0.0082060 secs]
128813K->113837K(202688K), 0.0082620 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
22.772: [GC 22.772: [ParNew: 19136K->1500K(19136K), 0.0064660 secs]
116825K->101174K(202688K), 0.0065400 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
22.804: [CMS-concurrent-sweep: 0.041/0.057 secs] [Times: user=0.12
sys=0.00, real=0.05 secs]
22.804: [CMS-concurrent-reset-start]
22.816: [CMS-concurrent-reset: 0.012/0.012 secs] [Times: user=0.02
sys=0.00, real=0.02 secs]
22.910: [GC 22.910: [ParNew: 18524K->2112K(19136K), 0.0024290 secs]
98398K->81987K(202688K), 0.0024860 secs] [Times: user=0.01 sys=0.00,
real=0.00 secs]
22.938: [GC 22.938: [ParNew: 19136K->2112K(19136K), 0.0077940 secs]
99011K->83980K(202688K), 0.0078510 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]
22.965: [GC 22.965: [ParNew: 19136K->2112K(19136K), 0.0063160 secs]
101004K->85959K(202688K), 0.0063760 secs] [Times: user=0.02 sys=0.00,
real=0.01 secs]

Where you can clearly see what constitute stop times and what are just
timing the CMS activity in the background. Yours seems to be somewhere
in between. I vaguely recognize it but I don't remember what produces
that...

Anyways it certainly looks like you have reasonable heap usage going
on as expected.

I'm concerned since you reported that independent JVM:s like nodetool
suffered OOM:s as well; that really indicates there is a real problem
of some kind.

-- 
/ Peter Schuller

Mime
View raw message