Mailing-List: contact user-help@cassandra.apache.org; run by ezmlm
Precedence: bulk
Reply-To: user@cassandra.apache.org
Received-SPF: pass (athena.apache.org: local policy)
From: "Poziombka, Wade L" <wade.l.poziombka@intel.com>
To: "user@cassandra.apache.org" <user@cassandra.apache.org>
Subject: RE: memory issue on 1.1.0
Thread-Topic: memory issue on 1.1.0
Thread-Index: Ac1B3lnh5s9+1+fvRku4HYw5xZMA4gBL1riAAA/MncAAD6HeAAANPsdQ
Date: Tue, 5 Jun 2012 20:08:56 +0000
Message-ID: 
 <BEF40F3557A6B24CB87D1F17775EA4FD0FF45215@FMSMSX101.amr.corp.intel.com>
References: 
 <BEF40F3557A6B24CB87D1F17775EA4FD0FF43412@FMSMSX101.amr.corp.intel.com>
 <CAAafH9QkWLDxAchRoa_uns=XnO8roPf8636VCH0iwsqsekdRHw@mail.gmail.com>
 <BEF40F3557A6B24CB87D1F17775EA4FD0FF45068@FMSMSX101.amr.corp.intel.com>
 <6FEB097F-287B-471D-BEA2-48862B30F382@bloomdigital.com>
In-Reply-To: <6FEB097F-287B-471D-BEA2-48862B30F382@bloomdigital.com>
Accept-Language: en-US
Content-Language: en-US
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0

Thank you.  I do have some of the same observations.  Do you do deletes?

My observation is that without deletes (or column updates I guess) I can ru=
n forever happy.  but when I run (what for me is a batch process) operation=
s that delete and modify column values I run into this.

Reading bug https://issues.apache.org/jira/browse/CASSANDRA-3741 the advice=
 is to NOT do deletes individually and to truncate.  I am scrambling to try=
 to do this but curious if it will be worth the effort.

Wade

-----Original Message-----
From: Mina Naguib [mailto:mina.naguib@bloomdigital.com]=20
Sent: Tuesday, June 05, 2012 2:24 PM
To: user@cassandra.apache.org
Subject: Re: memory issue on 1.1.0


Hi Wade

I don't know if your scenario matches mine, but I've been struggling with m=
emory pressure in 1.x as well.  I made the jump from 0.7.9 to 1.1.0, along =
with enabling compression and levelled compactions, so I don't know which s=
pecifically is the main culprit.

Specifically, all my nodes seem to "lose" heap memory.  As parnew and CMS d=
o their job, over any reasonable period of time, the "floor" of memory afte=
r a GC keeps rising.  This is quite visible if you leave jconsole connected=
 for a day or so, and manifests itself as a funny-looking cone like so: htt=
p://mina.naguib.ca/images/cassandra_jconsole.png

Once memory pressure reaches a point where the heap can't be maintained rel=
iably below 75%, cassandra goes into survival mode - via a bunch of tunable=
s in cassandra.conf it'll do things like flush memtables, drop caches, etc =
- all of which, in my experience, especially with the recent off-heap data =
structures, exasperate the problem.

I've been meaning, of course, to collect enough technical data to file a bu=
g report, but haven't had the time.  I have not yet tested 1.1.1 to see if =
it improves the situation.

What I have found however, is a band-aid which you see at the rightmost sec=
tion of the graph in the screenshot I posted.  That is simply to hit "Perfo=
rm GC" button in jconsole.  It seems that a full System.gc() *DOES* reclaim=
 heap memory that parnew and CMS fail to reclaim.

On my production cluster I have a full-GC via JMX scheduled in a rolling fa=
shion every 4 hours.  It's extremely expensive (20-40 seconds of unresponsi=
veness) but is a necessary evil in my situation.  Without it, my nodes ente=
r a nasty spiral of constant flushing, constant compactions, high heap usag=
e, instability and high latency.


On 2012-06-05, at 2:56 PM, Poziombka, Wade L wrote:

> Alas, upgrading to 1.1.1 did not solve my issue.
>=20
> -----Original Message-----
> From: Brandon Williams [mailto:driftx@gmail.com]
> Sent: Monday, June 04, 2012 11:24 PM
> To: user@cassandra.apache.org
> Subject: Re: memory issue on 1.1.0
>=20
> Perhaps the deletes:=20
> https://issues.apache.org/jira/browse/CASSANDRA-3741
>=20
> -Brandon
>=20
> On Sun, Jun 3, 2012 at 6:12 PM, Poziombka, Wade L <wade.l.poziombka@intel=
.com> wrote:
>> Running a very write intensive (new column, delete old column etc.) proc=
ess and failing on memory.  Log file attached.
>>=20
>> Curiously when I add new data I have never seen this have in past=20
>> sent hundreds of millions "new" transactions.  It seems to be when I=20
>> modify.  my process is as follows
>>=20
>> key slice to get columns to modify in batches of 100, in separate thread=
s modify those columns.  I advance the slice with the start key each with l=
ast key in previous batch.  Mutations done are update a column value in one=
 column family(token), delete column and add new column in another (pan).
>>=20
>> Runs well until after about 5 million rows then it seems to run out of m=
emory.  Note that these column families are quite small.
>>=20
>> WARN [ScheduledTasks:1] 2012-06-03 17:49:01,558 GCInspector.java=20
>> (line
>> 145) Heap is 0.7967470834946492 full.  You may need to reduce=20
>> memtable and/or cache sizes.  Cassandra will now flush up to the two=20
>> largest memtables to free up memory.  Adjust=20
>> flush_largest_memtables_at threshold in cassandra.yaml if you don't=20
>> want Cassandra to do this automatically  INFO [ScheduledTasks:1]=20
>> 2012-06-03 17:49:01,559 StorageService.java (line 2772) Unable to=20
>> reduce heap usage since there are no dirty column families  INFO=20
>> [GossipStage:1] 2012-06-03 17:49:01,999 Gossiper.java (line 797)=20
>> InetAddress /10.230.34.170 is now UP  INFO [ScheduledTasks:1]=20
>> 2012-06-03 17:49:10,048 GCInspector.java (line 122) GC for ParNew:=20
>> 206 ms for 1 collections, 7345969520 used; max is 8506048512  INFO=20
>> [ScheduledTasks:1] 2012-06-03 17:49:53,187 GCInspector.java (line=20
>> 122) GC for ConcurrentMarkSweep: 12770 ms for 1 collections,
>> 5714800208 used; max is 8506048512
>>=20
>> ----------------
>> Keyspace: keyspace
>>        Read Count: 50042632
>>        Read Latency: 0.23157864418482224 ms.
>>        Write Count: 44948323
>>        Write Latency: 0.019460829472992797 ms.
>>        Pending Tasks: 0
>>                Column Family: pan
>>                SSTable count: 5
>>                Space used (live): 1977467326
>>                Space used (total): 1977467326
>>                Number of Keys (estimate): 16334848
>>                Memtable Columns Count: 0
>>                Memtable Data Size: 0
>>                Memtable Switch Count: 74
>>                Read Count: 14985122
>>                Read Latency: 0.408 ms.
>>                Write Count: 19972441
>>                Write Latency: 0.022 ms.
>>                Pending Tasks: 0
>>                Bloom Filter False Postives: 829
>>                Bloom Filter False Ratio: 0.00073
>>                Bloom Filter Space Used: 37048400
>>                Compacted row minimum size: 125
>>                Compacted row maximum size: 149
>>                Compacted row mean size: 149
>>=20
>>                Column Family: token
>>                SSTable count: 4
>>                Space used (live): 1250973873
>>                Space used (total): 1250973873
>>                Number of Keys (estimate): 14217216
>>                Memtable Columns Count: 0
>>                Memtable Data Size: 0
>>                Memtable Switch Count: 49
>>                Read Count: 30059563
>>                Read Latency: 0.167 ms.
>>                Write Count: 14985488
>>                Write Latency: 0.014 ms.
>>                Pending Tasks: 0
>>                Bloom Filter False Postives: 13642
>>                Bloom Filter False Ratio: 0.00322
>>                Bloom Filter Space Used: 28002984
>>                Compacted row minimum size: 150
>>                Compacted row maximum size: 258
>>                Compacted row mean size: 224
>>=20
>>                Column Family: counters
>>                SSTable count: 2
>>                Space used (live): 561549994
>>                Space used (total): 561549994
>>                Number of Keys (estimate): 9985024
>>                Memtable Columns Count: 0
>>                Memtable Data Size: 0
>>                Memtable Switch Count: 38
>>                Read Count: 4997947
>>                Read Latency: 0.092 ms.
>>                Write Count: 9990394
>>                Write Latency: 0.023 ms.
>>                Pending Tasks: 0
>>                Bloom Filter False Postives: 191
>>                Bloom Filter False Ratio: 0.37525
>>                Bloom Filter Space Used: 18741152
>>                Compacted row minimum size: 125
>>                Compacted row maximum size: 179
>>                Compacted row mean size: 150
>>=20
>> ----------------