Mailing-List: contact dev-help@cassandra.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@cassandra.apache.org
Received-SPF: pass (athena.apache.org: domain of rantav@gmail.com designates
 209.85.216.182 as permitted sender)
DomainKey-Signature: a=rsa-sha1; c=nofws;
        d=gmail.com; s=gamma;
        h=mime-version:from:date:message-id:subject:to:content-type;
        b=wYfS8BuBWLzxzxfQHIieNuA3eW+SwWDrLFN3uufzGDA8nhYFS1REnniIbEjcVD11Ip
         JyxOjeZ6ZgTWE2u1Cft5Tp/ebiZb3VoYJAU1fUYqnWWPeqdmOV6BPsy9Dj2H9SxvMGIZ
         RWvABMXdUesctuSaeZVgBkdk8fBuCeuiRZ4G8=
MIME-Version: 1.0
From: Ran Tavory <rantav@gmail.com>
Date: Sat, 18 Sep 2010 18:18:15 +0200
Message-ID: <AANLkTi=uSTY7FW=_ZO0Q42O=gCyCZ_5C6Y7GLWrhUArR@mail.gmail.com>
Subject: OOM when running hector's unit tests at 0.7.0
To: cassandra-dev@incubator.apache.org,
	Hector Dev <hector-dev@googlegroups.com>
Content-Type: multipart/alternative; boundary=0015175ccf609bd87a04908b08b0

--0015175ccf609bd87a04908b08b0
Content-Type: text/plain; charset=UTF-8

I started seeing OOM when running hector's unit-tests on 0.7.0. The OOM is
in cassandra's code so either there had been recent changes within cassandra
or it's just that we added new coverage which causes this OOM.

On my mac it's 100% repro but other hector devs have reported they don't get
this OOM. Moreover, it I place a Thread.sleep(5000) in one of the tests the
OOM goes away (but other errors are still present see more below)

To reproduce the error you may checkout hector from
http://github.com/rantav/hector, switch to the 0.7.0 branch and run:

$ MAVEN_OPTS="-Xmx1G -Xms256M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC
-XX:+CMSParallelRemarkEnabled -XX:SurvivorRatio=8
-XX:MaxTenuringThreshold=1" *mvn test -Dtest=CassandraClusterTest*

(I'm using the default memory settings from 0.7.0)

The test class source code is here
http://github.com/rantav/hector/blob/0.7.0/src/test/java/me/prettyprint/cassandra/service/CassandraClusterTest.java

This test basically adds, removes, renames keyspaces etc.

Here's the OOM log:

18:07:04,197  INFO ColumnFamilyStore:734 - Enqueuing flush of
Memtable-Schema@72177013(3455 bytes, 3 operations)
18:07:04,487 ERROR AbstractCassandraDaemon:88 - Fatal exception in thread
Thread[FLUSH-WRITER-POOL:1,5,main]
java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: Java
heap space
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
 at java.util.concurrent.FutureTask.get(FutureTask.java:83)
at
org.apache.cassandra.concurrent.DebuggableThreadPoolExecutor.afterExecute(DebuggableThreadPoolExecutor.java:87)
 at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:888)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
 at java.lang.Thread.run(Thread.java:637)
Caused by: java.lang.OutOfMemoryError: Java heap space
at
org.apache.cassandra.io.util.BufferedRandomAccessFile.init(BufferedRandomAccessFile.java:151)
 at
org.apache.cassandra.io.util.BufferedRandomAccessFile.<init>(BufferedRandomAccessFile.java:144)
at
org.apache.cassandra.io.sstable.SSTableWriter.<init>(SSTableWriter.java:61)
 at org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:151)
at org.apache.cassandra.db.Memtable.access$000(Memtable.java:44)
 at org.apache.cassandra.db.Memtable$1.runMayThrow(Memtable.java:168)
at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
 at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
 ... 2 more
18:07:04,491  INFO Memtable:150 - Writing Memtable-Schema@72177013(3455
bytes, 3 operations)
18:07:04,812  INFO CompactionManager:323 - Compacted to
/Users/ran/dev/cassandra/hector/tmp/var/lib/cassandra/data/system/Schema-tmp-e-6-Data.db.
 15,707 to 15,173 (~96% of original) bytes for 5 keys.  Time: 860ms.
18:07:04,812 ERROR AbstractCassandraDaemon:88 - Fatal exception in thread
Thread[FLUSH-WRITER-POOL:1,5,main]
java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: Java
heap space
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
 at java.util.concurrent.FutureTask.get(FutureTask.java:83)
at
org.apache.cassandra.concurrent.DebuggableThreadPoolExecutor.afterExecute(DebuggableThreadPoolExecutor.java:87)
 at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:888)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
 at java.lang.Thread.run(Thread.java:637)
Caused by: java.lang.OutOfMemoryError: Java heap space
at
org.apache.cassandra.io.util.BufferedRandomAccessFile.init(BufferedRandomAccessFile.java:151)
 at
org.apache.cassandra.io.util.BufferedRandomAccessFile.<init>(BufferedRandomAccessFile.java:144)
at
org.apache.cassandra.io.sstable.SSTableWriter.<init>(SSTableWriter.java:61)
 at org.apache.cassandra.db.Memtable.writeSortedContents(Memtable.java:151)
at org.apache.cassandra.db.Memtable.access$000(Memtable.java:44)
 at org.apache.cassandra.db.Memtable$1.runMayThrow(Memtable.java:168)
at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
 at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
 at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
 ... 2 more


Here the log after I place a sleep(5000) at this line
http://github.com/rantav/hector/blob/0.7.0/src/test/java/me/prettyprint/cassandra/service/CassandraClusterTest.java#L88
The file-not-found error is even more suspicious...

18:04:28,293 ERROR AbstractCassandraDaemon:88 - Fatal exception in thread
Thread[CompactionExecutor:1,1,main]
java.util.concurrent.ExecutionException: java.io.FileNotFoundException:
/Users/ran/dev/cassandra/hector/tmp/var/lib/cassandra/data/system/Schema-tmp-e-7-Filter.db
(No such file or directory)
 at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
at java.util.concurrent.FutureTask.get(FutureTask.java:83)
 at
org.apache.cassandra.concurrent.DebuggableThreadPoolExecutor.afterExecute(DebuggableThreadPoolExecutor.java:87)
at
org.apache.cassandra.db.CompactionManager$CompactionExecutor.afterExecute(CompactionManager.java:604)
 at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:888)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
 at java.lang.Thread.run(Thread.java:637)
Caused by: java.io.FileNotFoundException:
/Users/ran/dev/cassandra/hector/tmp/var/lib/cassandra/data/system/Schema-tmp-e-7-Filter.db
(No such file or directory)
 at java.io.FileOutputStream.open(Native Method)
at java.io.FileOutputStream.<init>(FileOutputStream.java:179)
 at java.io.FileOutputStream.<init>(FileOutputStream.java:70)
at
org.apache.cassandra.io.sstable.SSTableWriter$IndexWriter.close(SSTableWriter.java:382)
 at
org.apache.cassandra.io.sstable.SSTableWriter.closeAndOpenReader(SSTableWriter.java:144)
at
org.apache.cassandra.db.CompactionManager.doCompaction(CompactionManager.java:314)
 at
org.apache.cassandra.db.CompactionManager$1.call(CompactionManager.java:107)
at
org.apache.cassandra.db.CompactionManager$1.call(CompactionManager.java:88)
 at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
 at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
... 2 more


$ java -version
java version "1.6.0_20"
Java(TM) SE Runtime Environment (build 1.6.0_20-b02-279-9M3165)
Java HotSpot(TM) 64-Bit Server VM (build 16.3-b01-279, mixed mode)

--0015175ccf609bd87a04908b08b0--