From cassandra-user-return-177-apmail-incubator-cassandra-user-archive=incubator.apache.org@incubator.apache.org Mon Jul 13 13:33:59 2009 Return-Path: Delivered-To: apmail-incubator-cassandra-user-archive@minotaur.apache.org Received: (qmail 82699 invoked from network); 13 Jul 2009 13:33:59 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 13 Jul 2009 13:33:59 -0000 Received: (qmail 18125 invoked by uid 500); 13 Jul 2009 13:34:08 -0000 Delivered-To: apmail-incubator-cassandra-user-archive@incubator.apache.org Received: (qmail 18108 invoked by uid 500); 13 Jul 2009 13:34:08 -0000 Mailing-List: contact cassandra-user-help@incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: cassandra-user@incubator.apache.org Delivered-To: mailing list cassandra-user@incubator.apache.org Received: (qmail 18099 invoked by uid 99); 13 Jul 2009 13:34:08 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 13 Jul 2009 13:34:08 +0000 X-ASF-Spam-Status: No, hits=3.7 required=10.0 tests=HTML_MESSAGE,NORMAL_HTTP_TO_IP,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of rkmr.em@gmail.com designates 209.85.212.177 as permitted sender) Received: from [209.85.212.177] (HELO mail-vw0-f177.google.com) (209.85.212.177) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 13 Jul 2009 13:34:00 +0000 Received: by vwj7 with SMTP id 7so1695692vwj.32 for ; Mon, 13 Jul 2009 06:33:39 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:in-reply-to:references :date:message-id:subject:from:to:content-type; bh=USn3LQA02iT77AWAtPFBO/abrQ97cn/3UrnaZ2kADgM=; b=SKA8Cb/3HB4PitIosJotTTO1expdyXRhGy7QPvUYtf/RrmaZPhoKUdYSgPBzO1lcha +LdL44EDBj+2+2tRym2sXmPa5Ishg6WuJ/Ke3X7NfY94gQmDzaoKoV5s+D9zrivYDUg7 7TLHrSeZPQOMuNcdMAD/QB7n5s71yk1Nt0wkE= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; b=QnZK3ZevH4LEhxQvsBnyrTIMjCfhLCPdfq1piLRDxWjCEjN7M00h5VVki6Az+Ou79+ X5SBGXOyY6cSMiKWrcd9ToTtXn2w/Mrgfm60fff+O7sn3WVpz3R9z8br+yE+uim8pHQ7 XpGx70XR3qtld1nnaIuWNG6PXT8351yT080GM= MIME-Version: 1.0 Received: by 10.220.85.81 with SMTP id n17mr7127414vcl.54.1247492019153; Mon, 13 Jul 2009 06:33:39 -0700 (PDT) In-Reply-To: References: Date: Mon, 13 Jul 2009 06:33:39 -0700 Message-ID: Subject: Re: cassandra slows down after inserts From: "rkmr.em@gmail.com" To: cassandra-user@incubator.apache.org Content-Type: multipart/alternative; boundary=0016e6461218a9777c046e965e59 X-Virus-Checked: Checked by ClamAV on apache.org --0016e6461218a9777c046e965e59 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Jonathan, good to know this is normal. but the reason i sent this is , once i stop and start cassandra it gets ready in few seconds and insertion and get_slices are super fast like few milliseconds. but after it starts to slow down even after 10 hours it is still slow. why is this the case? On Mon, Jul 13, 2009 at 6:14 AM, Jonathan Ellis wrote: > Cassandra is replaying the transaction log and preloading SSTable > indexes. This is normal. > > On Mon, Jul 13, 2009 at 8:10 AM, rkmr.em@gmail.com > wrote: > > when i stop cassandra and start it again, this is what is printed. it > takes > > just a couple of seconds for this to run. > > and after that it becomes really fast. > > > > > > Listening for transport dt_socket at address: 8888 > > DEBUG - Loading settings from ./../conf/storage-conf.xml > > DEBUG - adding Super1 as 0 > > DEBUG - adding Standard2 as 1 > > DEBUG - adding Standard1 as 2 > > DEBUG - adding StandardByTime1 as 3 > > DEBUG - adding LocationInfo as 4 > > DEBUG - adding HintsColumnFamily as 5 > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-9-Data.db: 400 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-52-Data.db: 300 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-92-Data.db: 300 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-138-Data.db: 751 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-150-Data.db: 100 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-152-Data.db: 50 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Super1-154-Data.db: 100 ms. > > INFO - Compacting > > > [/home/mark/local/var/cassandra/data/Table1-Super1-138-Data.db,/home/mark/local/var/cassandra/data/Table1-Super1-150-Data.db,/home/mark/local/var/cassandra/data/Table1-Super1-152-Data.db,/home/mark/local/var/cassandra/data/Table1-Super1-154-Data.db] > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Standard1-2-Data.db: 0 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Standard1-4-Data.db: 50 ms. > > DEBUG - INDEX LOAD TIME for > > /home/mark/local/var/cassandra/data/Table1-Standard1-6-Data.db: 0 ms. > > INFO - Replaying > > /home/mark/local/var/cassandra/commitlog/CommitLog-1247454203796.log > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Super1-138-Data.db : 73600 > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Super1-150-Data.db : 84224 > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Super1-152-Data.db : 94848 > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Super1-154-Data.db : 105472 > > DEBUG - Expected bloom filter size : 105472 > > INFO - Compacted to > > /home/mark/local/var/cassandra/data/Table1-Super1-139-Data.db. > 0/28831084 > > bytes for 104856/104860 keys read/written. Time: 8119ms. > > INFO - Flushing Memtable(Super1)@552364977 > > DEBUG - Submitting Super1 for compaction > > INFO - Completed flushing Memtable(Super1)@552364977 > > INFO - Flushing Memtable(Standard1)@1290243769 > > DEBUG - Submitting Standard1 for compaction > > INFO - Completed flushing Memtable(Standard1)@1290243769 > > INFO - Compacting > > > [/home/mark/local/var/cassandra/data/Table1-Standard1-2-Data.db,/home/mark/local/var/cassandra/data/Table1-Standard1-4-Data.db,/home/mark/local/var/cassandra/data/Table1-Standard1-6-Data.db,/home/mark/local/var/cassandra/data/Table1-Standard1-8-Data.db] > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Standard1-2-Data.db : 256 > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Standard1-4-Data.db : 512 > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Standard1-6-Data.db : 768 > > DEBUG - index size for bloom filter calc for file : > > /home/mark/local/var/cassandra/data/Table1-Standard1-8-Data.db : 1024 > > DEBUG - Expected bloom filter size : 1024 > > INFO - Compacted to > > /home/mark/local/var/cassandra/data/Table1-Standard1-3-Data.db. 0/210 > bytes > > for 0/1 keys read/written. Time: 301ms. > > DEBUG - Starting to listen on 127.0.0.1:7001 > > INFO - Cassandra starting up... > > > > > > > > On Mon, Jul 13, 2009 at 6:06 AM, rkmr.em@gmail.com > > wrote: > >> > >> how do i find out if JVM is GCing? > >> > >> On Sun, Jul 12, 2009 at 10:37 PM, Sandeep Tata > >> wrote: > >>> > >>> What hardware are you running one? > >> > >> dual quadcore intel xeon 2.0 ghz, 32GB ram, and hardware raid config > >> operating system is fedora core 9 > >> > >> > >>> How long does the slowdown last ? > >> > >> i stopped inserting data after slowdown starts, and it is still slow now > >> after over 10 hours. > >> however if i stop cassandra and start it, it becomes super fast > >> immediately. till i insert another 100k or so rows when it becomes > really > >> slow again. > >> > >> > >>> > >>> There are a few reasons for temporary slowdowns ... perhaps the JVM > >>> started GCing? > >> > >> how do i find out if this is the cause? > >> > >> > >>> > >>> Cassandra spends time cleaning up the on-disk SSTables > >>> in a process called compaction. This could cause the client to observe > >>> a slowdown. > >>> > >>> Things you could try -- > >>> Reduce the Memtable size in the config files. (If GCing was the > problem) > >>> Increasing the number of SSTables written before compaction kicks in. > >> > >> can you tell me what numbers i should use? > >> > >> thanks! > >> > > > > > --0016e6461218a9777c046e965e59 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Jonathan,
good to know this is normal. but the reason i sent this is , once i stop and start cassandra it gets ready in few seconds and insertion and get_slices are super fast like few milliseconds.

but a= fter it starts to slow down even after 10 hours it is still slow. why is th= is the case?

On Mon, Jul 13, 2009 at 6:14= AM, Jonathan Ellis <jbellis@gmail.com> wrote:
Cassandra is repl= aying the transaction log and preloading SSTable
indexes. =A0This is normal.

On Mon, Jul 13, 2009 at 8:10 AM, rkmr.= em@gmail.com<rkmr.em@gmail.com<= /a>> wrote:
> when i stop cassandra and start it again, this is what is printed. it = takes
> just a couple of seconds for this to run.
> and after that it becomes really fast.
>
>
> Listening for transport dt_socket at address: 8888
> DEBUG - Loading settings from ./../conf/storage-conf.xml
> DEBUG - adding Super1 as 0
> DEBUG - adding Standard2 as 1
> DEBUG - adding Standard1 as 2
> DEBUG - adding StandardByTime1 as 3
> DEBUG - adding LocationInfo as 4
> DEBUG - adding HintsColumnFamily as 5
> DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-9-Data.db: 400 ms. > DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-52-Data.db: 300 ms.<= br> > DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-92-Data.db: 300 ms.<= br> > DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-138-Data.db: 751 ms.=
> DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-150-Data.db: 100 ms.=
> DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-152-Data.db: 50 ms.<= br> > DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Super1-154-Data.db: 100 ms.=
> INFO - Compacting
> [/home/mark/local/var/cassandra/data/Table1-Super1-138-Data.db,/home/m= ark/local/var/cassandra/data/Table1-Super1-150-Data.db,/home/mark/local/var= /cassandra/data/Table1-Super1-152-Data.db,/home/mark/local/var/cassandra/da= ta/Table1-Super1-154-Data.db]
> DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Standard1-2-Data.db: 0 ms.<= br> > DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Standard1-4-Data.db: 50 ms.=
> DEBUG - INDEX LOAD TIME for
> /home/mark/local/var/cassandra/data/Table1-Standard1-6-Data.db: 0 ms.<= br> > INFO - Replaying
> /home/mark/local/var/cassandra/commitlog/CommitLog-1247454203796.log > DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Super1-138-Data.db=A0=A0 : = 73600
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Super1-150-Data.db=A0=A0 : = 84224
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Super1-152-Data.db=A0=A0 : = 94848
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Super1-154-Data.db=A0=A0 : = 105472
> DEBUG - Expected bloom filter size : 105472
> INFO - Compacted to
> /home/mark/local/var/cassandra/data/Table1-Super1-139-Data.db.=A0 0/28= 831084
> bytes for 104856/104860 keys read/written.=A0 Time: 8119ms.
> INFO - Flushing Memtable(Super1)@552364977
> DEBUG - Submitting Super1 for compaction
> INFO - Completed flushing Memtable(Super1)@552364977
> INFO - Flushing Memtable(Standard1)@1290243769
> DEBUG - Submitting Standard1 for compaction
> INFO - Completed flushing Memtable(Standard1)@1290243769
> INFO - Compacting
> [/home/mark/local/var/cassandra/data/Table1-Standard1-2-Data.db,/home/= mark/local/var/cassandra/data/Table1-Standard1-4-Data.db,/home/mark/local/v= ar/cassandra/data/Table1-Standard1-6-Data.db,/home/mark/local/var/cassandra= /data/Table1-Standard1-8-Data.db]
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Standard1-2-Data.db=A0=A0 := 256
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Standard1-4-Data.db=A0=A0 := 512
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Standard1-6-Data.db=A0=A0 := 768
> DEBUG - index size for bloom filter calc for file=A0 :
> /home/mark/local/var/cassandra/data/Table1-Standard1-8-Data.db=A0=A0 := 1024
> DEBUG - Expected bloom filter size : 1024
> INFO - Compacted to
> /home/mark/local/var/cassandra/data/Table1-Standard1-3-Data.db.=A0 0/2= 10 bytes
> for 0/1 keys read/written.=A0 Time: 301ms.
> DEBUG - Starting to listen on 127.0.0.1:7001
> INFO - Cassandra starting up...
>
>
>
> On Mon, Jul 13, 2009 at 6:06 AM, = rkmr.em@gmail.com <rkmr.em@gmai= l.com>
> wrote:
>>
>> how do i find out if JVM is GCing?
>>
>> On Sun, Jul 12, 2009 at 10:37 PM, Sandeep Tata <sandeep.tata@gmail.com>
>> wrote:
>>>
>>> What hardware are you running one?
>>
>> =A0dual quadcore intel xeon 2.0 ghz, 32GB ram, and hardware raid c= onfig
>> operating system is fedora core 9
>>
>>
>>> How long does the slowdown last ?
>>
>> i stopped inserting data after slowdown starts, and it is still sl= ow now
>> after over 10 hours.
>> however if i stop cassandra and start it, it becomes super fast >> immediately. till i insert another 100k or so rows when it becomes= really
>> slow again.
>>
>>
>>>
>>> =A0There are a few reasons for temporary slowdowns ... perhaps= the JVM
>>> started GCing?
>>
>> how do i find out if this is the cause?
>>
>>
>>>
>>> Cassandra spends time cleaning up the on-disk SSTables
>>> in a process called compaction. This could cause the client to= observe
>>> a slowdown.
>>>
>>> Things you could try --
>>> Reduce the Memtable size in the config files. (If GCing was th= e problem)
>>> Increasing the number of SSTables written before compaction ki= cks in.
>>
>> can you tell me what numbers i should use?
>>
>> thanks!
>>
>
>

--0016e6461218a9777c046e965e59--