Return-Path: Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: (qmail 70450 invoked from network); 4 May 2010 17:13:50 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 4 May 2010 17:13:50 -0000 Received: (qmail 40839 invoked by uid 500); 4 May 2010 17:13:49 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 40812 invoked by uid 500); 4 May 2010 17:13:49 -0000 Mailing-List: contact user-help@cassandra.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@cassandra.apache.org Delivered-To: mailing list user@cassandra.apache.org Received: (qmail 40804 invoked by uid 99); 4 May 2010 17:13:49 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 04 May 2010 17:13:49 +0000 X-ASF-Spam-Status: No, hits=2.2 required=10.0 tests=FREEMAIL_FROM,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS,T_TO_NO_BRKTS_FREEMAIL X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of zsongbo@gmail.com designates 209.85.221.196 as permitted sender) Received: from [209.85.221.196] (HELO mail-qy0-f196.google.com) (209.85.221.196) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 04 May 2010 17:13:41 +0000 Received: by qyk34 with SMTP id 34so4571134qyk.10 for ; Tue, 04 May 2010 10:13:20 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:received:in-reply-to :references:date:message-id:subject:from:to:content-type; bh=jSda2ak/wAp6G3J3j5rgGRIiBY/oXlsX0MK4GToUxe0=; b=ppInyPC9tms2lczEfSV4VWauPPbks5znQkD2QKUK7MwfQwOD0PfxLnNfCYGXP1C5bA cVE0qwHyBudXlT5W2tvUCckORLdJrZmd424Hpg0+b4JAMR6Fg9ghP0VDLygiBidWd149 vk1kV1MYgwxxuqK/GfEPn5w6UY+RGZtKV9WEo= 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=R3eE1WizREEc+IDe3O5OJ23CtjeDk3SOYZTldZFDXERCC2DUQGP+dXK0zDK+gP4sgi 92e4uXhqZ/A9DYZCxeneBtCZXCZXg/W+fWs1tJcyZqnY0nvXpvKlWwzQoJYjuA+d6C0V D8arjT+uBNhaMx6PSOcPEDahc5o5m6UMJPJ98= MIME-Version: 1.0 Received: by 10.229.227.68 with SMTP id iz4mr1903911qcb.44.1272993117912; Tue, 04 May 2010 10:11:57 -0700 (PDT) Received: by 10.229.91.137 with HTTP; Tue, 4 May 2010 10:11:57 -0700 (PDT) In-Reply-To: References: Date: Wed, 5 May 2010 01:11:57 +0800 Message-ID: Subject: Re: performance tuning - where does the slowness come from? From: Schubert Zhang To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=0016362849829841560485c7ce8d X-Virus-Checked: Checked by ClamAV on apache.org --0016362849829841560485c7ce8d Content-Type: text/plain; charset=ISO-8859-1 1. When initially startup your nodes, please plan your InitialToken of each node evenly. 2. standard On Tue, May 4, 2010 at 9:09 PM, Boris Shulman wrote: > I think that the extra (more than 4GB) memory usage comes from the > mmaped io, that is why it happens only for reads. > > On Tue, May 4, 2010 at 2:02 PM, Jordan Pittier > wrote: > > I'm facing the same issue with swap. It only occurs when I perform read > > operations (write are very fast :)). So I can't help you with the memory > > probleme. > > > > But to balance the load evenly between nodes in cluster just manually fix > > their token.(the "formula" is i * 2^127 / nb_nodes). > > > > Jordzn > > > > On Tue, May 4, 2010 at 8:20 AM, Ran Tavory wrote: > >> > >> I'm looking into performance issues on a 0.6.1 cluster. I see two > >> symptoms: > >> 1. Reads and writes are slow > >> 2. One of the hosts is doing a lot of GC. > >> 1 is slow in the sense that in normal state the cluster used to make > >> around 3-5k read and writes per second (6-10k operations per second), > but > >> how it's in the order of 200-400 ops per second, sometimes even less. > >> 2 looks like this: > >> $ tail -f /outbrain/cassandra/log/system.log > >> INFO [GC inspection] 2010-05-04 00:42:18,636 GCInspector.java (line > 110) > >> GC for ParNew: 672 ms, 166482384 reclaimed leaving 2872087208 used; max > is > >> 4432068608 > >> INFO [GC inspection] 2010-05-04 00:42:28,638 GCInspector.java (line > 110) > >> GC for ParNew: 498 ms, 166493352 reclaimed leaving 2836049448 used; max > is > >> 4432068608 > >> INFO [GC inspection] 2010-05-04 00:42:38,640 GCInspector.java (line > 110) > >> GC for ParNew: 327 ms, 166091528 reclaimed leaving 2796888424 used; max > is > >> 4432068608 > >> ... and it goes on and on for hours, no stopping... > >> The cluster is made of 6 hosts, 3 in one DC and 3 in another. > >> Each host has 8G RAM. > >> -Xmx=4G > >> For some reason, the load isn't distributed evenly b/w the hosts, > although > >> I'm not sure this is the cause for slowness > >> $ nodetool -h localhost -p 9004 ring > >> Address Status Load Range > >> Ring > >> > >> 144413773383729447702215082383444206680 > >> 192.168.252.99Up 15.94 GB > >> 66002764663998929243644931915471302076 |<--| > >> 192.168.254.57Up 19.84 GB > >> 81288739225600737067856268063987022738 | ^ > >> 192.168.254.58Up 973.78 MB > >> 86999744104066390588161689990810839743 v | > >> 192.168.252.62Up 5.18 GB > >> 88308919879653155454332084719458267849 | ^ > >> 192.168.254.59Up 10.57 GB > >> 142482163220375328195837946953175033937 v | > >> 192.168.252.61Up 11.36 GB > >> 144413773383729447702215082383444206680 |-->| > >> The slow host is 192.168.252.61 and it isn't the most loaded one. > >> The host is waiting a lot on IO and the load average is usually 6-7 > >> $ w > >> 00:42:56 up 11 days, 13:22, 1 user, load average: 6.21, 5.52, 3.93 > >> $ vmstat 5 > >> procs -----------memory---------- ---swap-- -----io---- --system-- > >> -----cpu------ > >> r b swpd free buff cache si so bi bo in cs us sy > id > >> wa st > >> 0 8 2147844 45744 1816 4457384 6 5 66 32 5 2 1 > 1 > >> 96 2 0 > >> 0 8 2147164 49020 1808 4451596 385 0 2345 58 3372 9957 2 > 2 > >> 78 18 0 > >> 0 3 2146432 45704 1812 4453956 342 0 2274 108 3937 10732 2 > 2 > >> 78 19 0 > >> 0 1 2146252 44696 1804 4453436 345 164 1939 294 3647 7833 2 > 2 > >> 78 18 0 > >> 0 1 2145960 46924 1744 4451260 158 0 2423 122 4354 14597 2 > 2 > >> 77 18 0 > >> 7 1 2138344 44676 952 4504148 1722 403 1722 406 1388 439 87 > 0 > >> 10 2 0 > >> 7 2 2137248 45652 956 4499436 1384 655 1384 658 1356 392 87 > 0 > >> 10 3 0 > >> 7 1 2135976 46764 956 4495020 1366 718 1366 718 1395 380 87 > 0 > >> 9 4 0 > >> 0 8 2134484 46964 956 4489420 1673 555 1814 586 1601 215590 14 > >> 2 68 16 0 > >> 0 1 2135388 47444 972 4488516 785 833 2390 995 3812 8305 2 > 2 > >> 77 20 0 > >> 0 10 2135164 45928 980 4488796 788 543 2275 626 36 > >> So, the host is swapping like crazy... > >> top shows that it's using a lot of memory. As noted before -Xmx=4G and > >> nothing else seems to be using a lot of memory on the host except for > the > >> cassandra process, however, of the 8G ram on the host, 92% is used by > >> cassandra. How's that? > >> Top shows there's 3.9g Shared and 7.2g Resident and 15.9g Virtual. Why > >> does it have 15g virtual? And why 7.2 RES? This can explain the slowness > in > >> swapping. > >> $ top > >> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND > >> > >> > >> 20281 cassandr 25 0 15.9g 7.2g 3.9g S 33.3 92.6 175:30.27 java > >> So, can the total memory be controlled? > >> Or perhaps I'm looking in the wrong direction... > >> I've looked at all the cassandra JMX counts and nothing seemed > suspicious > >> so far. By suspicious i mean a large number of pending tasks - there > were > >> always very small numbers in each pool. > >> About read and write latencies, I'm not sure what the normal state is, > but > >> here's an example of what I see on the problematic host: > >> #mbean = org.apache.cassandra.service:type=StorageProxy: > >> RecentReadLatencyMicros = 30105.888180684495; > >> TotalReadLatencyMicros = 78543052801; > >> TotalWriteLatencyMicros = 4213118609; > >> RecentWriteLatencyMicros = 1444.4809201925639; > >> ReadOperations = 4779553; > >> RangeOperations = 0; > >> TotalRangeLatencyMicros = 0; > >> RecentRangeLatencyMicros = NaN; > >> WriteOperations = 4740093; > >> And the only pool that I do see some pending tasks is the > ROW-READ-STAGE, > >> but it doesn't look like much, usually around 6-8: > >> #mbean = org.apache.cassandra.concurrent:type=ROW-READ-STAGE: > >> ActiveCount = 8; > >> PendingTasks = 8; > >> CompletedTasks = 5427955; > >> Any help finding the solution is appreciated, thanks... > >> Below are a few more JMXes I collected from the system that may be > >> interesting. > >> #mbean = java.lang:type=Memory: > >> Verbose = false; > >> HeapMemoryUsage = { > >> committed = 3767279616; > >> init = 134217728; > >> max = 4293656576; > >> used = 1237105080; > >> }; > >> NonHeapMemoryUsage = { > >> committed = 35061760; > >> init = 24313856; > >> max = 138412032; > >> used = 23151320; > >> }; > >> ObjectPendingFinalizationCount = 0; > >> #mbean = java.lang:name=ParNew,type=GarbageCollector: > >> LastGcInfo = { > >> GcThreadCount = 11; > >> duration = 136; > >> endTime = 42219272; > >> id = 11719; > >> memoryUsageAfterGc = { > >> ( CMS Perm Gen ) = { > >> key = CMS Perm Gen; > >> value = { > >> committed = 29229056; > >> init = 21757952; > >> max = 88080384; > >> used = 17648848; > >> }; > >> }; > >> ( Code Cache ) = { > >> key = Code Cache; > >> value = { > >> committed = 5832704; > >> init = 2555904; > >> max = 50331648; > >> used = 5563520; > >> }; > >> }; > >> ( CMS Old Gen ) = { > >> key = CMS Old Gen; > >> value = { > >> committed = 3594133504; > >> init = 112459776; > >> max = 4120510464; > >> used = 964565720; > >> }; > >> }; > >> ( Par Eden Space ) = { > >> key = Par Eden Space; > >> value = { > >> committed = 171835392; > >> init = 21495808; > >> max = 171835392; > >> used = 0; > >> }; > >> }; > >> ( Par Survivor Space ) = { > >> key = Par Survivor Space; > >> value = { > >> committed = 1310720; > >> init = 131072; > >> max = 1310720; > >> used = 0; > >> }; > >> }; > >> }; > >> memoryUsageBeforeGc = { > >> ( CMS Perm Gen ) = { > >> key = CMS Perm Gen; > >> value = { > >> committed = 29229056; > >> init = 21757952; > >> max = 88080384; > >> used = 17648848; > >> }; > >> }; > >> ( Code Cache ) = { > >> key = Code Cache; > >> value = { > >> committed = 5832704; > >> init = 2555904; > >> max = 50331648; > >> used = 5563520; > >> }; > >> }; > >> ( CMS Old Gen ) = { > >> key = CMS Old Gen; > >> value = { > >> committed = 3594133504; > >> init = 112459776; > >> max = 4120510464; > >> used = 959221872; > >> }; > >> }; > >> ( Par Eden Space ) = { > >> key = Par Eden Space; > >> value = { > >> committed = 171835392; > >> init = 21495808; > >> max = 171835392; > >> used = 171835392; > >> }; > >> }; > >> ( Par Survivor Space ) = { > >> key = Par Survivor Space; > >> value = { > >> committed = 1310720; > >> init = 131072; > >> max = 1310720; > >> used = 0; > >> }; > >> }; > >> }; > >> startTime = 42219136; > >> }; > >> CollectionCount = 11720; > >> CollectionTime = 4561730; > >> Name = ParNew; > >> Valid = true; > >> MemoryPoolNames = [ Par Eden Space, Par Survivor Space ]; > >> #mbean = java.lang:type=OperatingSystem: > >> MaxFileDescriptorCount = 63536; > >> OpenFileDescriptorCount = 75; > >> CommittedVirtualMemorySize = 17787711488; > >> FreePhysicalMemorySize = 45522944; > >> FreeSwapSpaceSize = 2123968512; > >> ProcessCpuTime = 12251460000000; > >> TotalPhysicalMemorySize = 8364417024; > >> TotalSwapSpaceSize = 4294959104; > >> Name = Linux; > >> AvailableProcessors = 8; > >> Arch = amd64; > >> SystemLoadAverage = 4.36; > >> Version = 2.6.18-164.15.1.el5; > >> #mbean = java.lang:type=Runtime: > >> Name = 20281@ob1061.nydc1.outbrain.com; > >> > >> ClassPath = > >> > /outbrain/cassandra/apache-cassandra-0.6.1/bin/../conf:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../build/classes:/outbrain/cassandra/apache-cassandra-0.6.1/bin/.. > >> > >> > /lib/antlr-3.1.3.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/apache-cassandra-0.6.1.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/avro-1.2.0-dev.jar:/outb > >> > >> > rain/cassandra/apache-cassandra-0.6.1/bin/../lib/clhm-production.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/commons-cli-1.1.jar:/outbrain/cassandra/apache-cassandra- > >> > >> > 0.6.1/bin/../lib/commons-codec-1.2.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/commons-collections-3.2.1.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/com > >> > >> > mons-lang-2.4.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/google-collections-1.0.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/hadoop-core-0.20.1.jar:/out > >> > >> > brain/cassandra/apache-cassandra-0.6.1/bin/../lib/high-scale-lib.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/ivy-2.1.0.jar:/outbrain/cassandra/apache-cassandra-0.6.1/ > >> > >> > bin/../lib/jackson-core-asl-1.4.0.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/jackson-mapper-asl-1.4.0.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/jline > >> > >> > -0.9.94.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/json-simple-1.1.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/libthrift-r917130.jar:/outbrain/cassandr > >> > >> > a/apache-cassandra-0.6.1/bin/../lib/log4j-1.2.14.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/slf4j-api-1.5.8.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib > >> /slf4j-log4j12-1.5.8.jar; > >> > >> BootClassPath = > >> > /usr/java/jdk1.6.0_17/jre/lib/alt-rt.jar:/usr/java/jdk1.6.0_17/jre/lib/resources.jar:/usr/java/jdk1.6.0_17/jre/lib/rt.jar:/usr/java/jdk1.6.0_17/jre/lib/sunrsasign.j > >> > >> > ar:/usr/java/jdk1.6.0_17/jre/lib/jsse.jar:/usr/java/jdk1.6.0_17/jre/lib/jce.jar:/usr/java/jdk1.6.0_17/jre/lib/charsets.jar:/usr/java/jdk1.6.0_17/jre/classes; > >> > >> LibraryPath = > >> > /usr/java/jdk1.6.0_17/jre/lib/amd64/server:/usr/java/jdk1.6.0_17/jre/lib/amd64:/usr/java/jdk1.6.0_17/jre/../lib/amd64:/usr/java/packages/lib/amd64:/lib:/usr/lib; > >> > >> VmName = Java HotSpot(TM) 64-Bit Server VM; > >> > >> VmVendor = Sun Microsystems Inc.; > >> > >> VmVersion = 14.3-b01; > >> > >> BootClassPathSupported = true; > >> > >> InputArguments = [ -ea, -Xms128M, -Xmx4G, -XX:TargetSurvivorRatio=90, > >> -XX:+AggressiveOpts, -XX:+UseParNewGC, -XX:+UseConcMarkSweepGC, > >> -XX:+CMSParallelRemarkEnabled, -XX:+HeapDumpOnOutOfMemoryError, > >> -XX:SurvivorRatio=128, -XX:MaxTenuringThreshold=0, > >> -Dcom.sun.management.jmxremote.port=9004, > >> -Dcom.sun.management.jmxremote.ssl=false, > >> -Dcom.sun.management.jmxremote.authenticate=false, > >> -Dstorage-config=/outbrain/cassandra/apache-cassandra-0.6.1/bin/../conf, > >> -Dcassandra-pidfile=/var/run/cassandra.pid ]; > >> > >> ManagementSpecVersion = 1.2; > >> > >> SpecName = Java Virtual Machine Specification; > >> > >> SpecVendor = Sun Microsystems Inc.; > >> > >> SpecVersion = 1.0; > >> > >> StartTime = 1272911001415; > >> ... > > > --0016362849829841560485c7ce8d Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable 1. When initially startup your nodes, please plan your InitialToken of each= node evenly.
2. <DiskAccessMode>standard</DiskAccessMode>
On Tue, May 4, 2010 at 9:09 PM, Boris Shul= man <shulmanb@gm= ail.com> wrote:
I think that the = extra (more than 4GB) memory usage comes from the
mmaped io, that is why it happens only for reads.

On Tue, May 4, 2010 at 2:02 PM, Jordan Pittier <jordan.pittier@gmail.com> wrote:
> I'm facing the same issue with swap. It only occurs when I perform= read
> operations (write are very fast :)). So I can't help you with the = memory
> probleme.
>
> But to balance the load evenly between nodes in cluster just manually = fix
> their token.(the "formula" is i * 2^127 / nb_nodes).
>
> Jordzn
>
> On Tue, May 4, 2010 at 8:20 AM, Ran Tavory <rantav@gmail.com> wrote:
>>
>> I'm looking into performance issues on a 0.6.1 cluster. I see = two
>> symptoms:
>> 1. Reads and writes are slow
>> 2. One of the hosts is doing a lot of GC.
>> 1 is slow in the sense that in normal state the cluster used to ma= ke
>> around 3-5k read and writes per second (6-10k operations per secon= d), but
>> how it's in the order of 200-400 ops per second, sometimes eve= n less.
>> 2 looks like this:
>> $ tail -f /outbrain/cassandra/log/system.log
>> =A0INFO [GC inspection] 2010-05-04 00:42:18,636 GCInspector.java (= line 110)
>> GC for ParNew: 672 ms, 166482384 reclaimed leaving 2872087208 used= ; max is
>> 4432068608
>> =A0INFO [GC inspection] 2010-05-04 00:42:28,638 GCInspector.java (= line 110)
>> GC for ParNew: 498 ms, 166493352 reclaimed leaving 2836049448 used= ; max is
>> 4432068608
>> =A0INFO [GC inspection] 2010-05-04 00:42:38,640 GCInspector.java (= line 110)
>> GC for ParNew: 327 ms, 166091528 reclaimed leaving 2796888424 used= ; max is
>> 4432068608
>> ... and it goes on and on for hours, no stopping...
>> The cluster is made of 6 hosts, 3 in one DC and 3 in another.
>> Each host has 8G RAM.
>> -Xmx=3D4G
>> For some reason, the load isn't distributed evenly b/w the hos= ts, although
>> I'm not sure this is the cause for slowness
>> $ nodetool -h localhost -p 9004 ring
>> Address =A0 =A0 =A0 Status =A0 =A0 Load =A0 =A0 =A0 =A0 =A0Range >> =A0 =A0 =A0 =A0Ring
>>
>> 144413773383729447702215082383444206680
>> 192.168.252.99Up =A0 =A0 =A0 =A0 15.94 GB
>> =A066002764663998929243644931915471302076 =A0 =A0 |<--|
>> 192.168.254.57Up =A0 =A0 =A0 =A0 19.84 GB
>> =A081288739225600737067856268063987022738 =A0 =A0 | =A0 ^
>> 192.168.254.58Up =A0 =A0 =A0 =A0 973.78 MB
>> 86999744104066390588161689990810839743 =A0 =A0 v =A0 |
>> 192.168.252.62Up =A0 =A0 =A0 =A0 5.18 GB
>> 88308919879653155454332084719458267849 =A0 =A0 | =A0 ^
>> 192.168.254.59Up =A0 =A0 =A0 =A0 10.57 GB
>> =A0142482163220375328195837946953175033937 =A0 =A0v =A0 |
>> 192.168.252.61Up =A0 =A0 =A0 =A0 11.36 GB
>> =A0144413773383729447702215082383444206680 =A0 =A0|-->|
>> The slow host is=A0192.168.252.61 and it isn't the most loaded= one.
>> The host is waiting a lot on IO and the load average is usually 6-= 7
>> $ w
>> =A000:42:56 up 11 days, 13:22, =A01 user, =A0load average: 6.21, 5= .52, 3.93
>> $ vmstat 5
>> procs -----------memory---------- ---swap-- -----io---- --system--=
>> -----cpu------
>> =A0r =A0b =A0 swpd =A0 free =A0 buff =A0cache =A0=A0si=A0=A0=A0so= =A0=A0 =A0bi =A0 =A0bo =A0 in =A0 cs us sy id
>> wa st
>> =A00 =A08 2147844 =A045744 =A0 1816 4457384 =A0 =A06 =A0 =A05 =A0 = =A066 =A0 =A032 =A0 =A05 =A0 =A02 =A01 =A01
>> 96 =A02 =A00
>> =A00 =A08 2147164 =A049020 =A0 1808 4451596 =A0385=A0=A0 =A00 =A02= 345 =A0 =A058 3372 9957 =A02 =A02
>> 78 18 =A00
>> =A00 =A03 2146432 =A045704 =A0 1812 4453956 =A0342=A0=A0 =A00 =A02= 274 =A0 108 3937 10732 =A02 =A02
>> 78 19 =A00
>> =A00 =A01 2146252 =A044696 =A0 1804 4453436 =A0345=A0=A0164=A0=A01= 939 =A0 294 3647 7833 =A02 =A02
>> 78 18 =A00
>> =A00 =A01 2145960 =A046924 =A0 1744 4451260 =A0158=A0=A0 =A00 =A02= 423 =A0 122 4354 14597 =A02 =A02
>> 77 18 =A00
>> =A07 =A01 2138344 =A044676 =A0 =A0952 4504148=A01722=A0=A0403=A0= =A01722 =A0 406 1388 =A0439 87 =A00
>> 10 =A02 =A00
>> =A07 =A02 2137248 =A045652 =A0 =A0956 4499436=A01384=A0=A0655=A0= =A01384 =A0 658 1356 =A0392 87 =A00
>> 10 =A03 =A00
>> =A07 =A01 2135976 =A046764 =A0 =A0956 4495020=A01366=A0=A0718=A0= =A01366 =A0 718 1395 =A0380 87 =A00
>> =A09 =A04 =A00
>> =A00 =A08 2134484 =A046964 =A0 =A0956 4489420=A01673=A0=A0555=A0= =A01814 =A0 586 1601 215590 14
>> =A02 68 16 =A00
>> =A00 =A01 2135388 =A047444 =A0 =A0972 4488516 =A0785=A0=A0833=A0= =A02390 =A0 995 3812 8305 =A02 =A02
>> 77 20 =A00
>> =A00 10 2135164 =A045928 =A0 =A0980 4488796 =A0788=A0=A0543=A0=A02= 275 =A0 626 36
>> So, the host is swapping like crazy...
>> top shows that it's using a lot of memory. As noted before -Xm= x=3D4G and
>> nothing else seems to be using a lot of memory on the host except = for the
>> cassandra process, however, of the 8G ram on the host, 92% is used= by
>> cassandra. How's that?
>> Top shows there's 3.9g Shared and 7.2g Resident and 15.9g Virt= ual. Why
>> does it have 15g virtual? And why 7.2 RES? This can explain the sl= owness in
>> swapping.
>> $ top
>> =A0=A0PID USER =A0 =A0 =A0PR =A0NI =A0VIRT =A0RES =A0SHR S %CPU %M= EM =A0 =A0TIME+ =A0COMMAND
>>
>>
>> 20281 cassandr =A025 =A0 0=A015.9g=A07.2g 3.9g S 33.3 92.6 175:30.= 27 java
>> So, can the total memory be controlled?
>> Or perhaps I'm looking in the wrong direction...
>> I've looked at all the cassandra JMX counts and nothing seemed= suspicious
>> so far. By suspicious i mean a large number of pending tasks - the= re were
>> always very small=A0numbers=A0in each pool.
>> About read and write latencies, I'm not sure what the normal s= tate is, but
>> here's an example of what I see on the problematic host:
>> #mbean =3D org.apache.cassandra.service:type=3DStorageProxy:
>> RecentReadLatencyMicros =3D 30105.888180684495;
>> TotalReadLatencyMicros =3D 78543052801;
>> TotalWriteLatencyMicros =3D 4213118609;
>> RecentWriteLatencyMicros =3D 1444.4809201925639;
>> ReadOperations =3D 4779553;
>> RangeOperations =3D 0;
>> TotalRangeLatencyMicros =3D 0;
>> RecentRangeLatencyMicros =3D NaN;
>> WriteOperations =3D 4740093;
>> And the only pool that I do see some pending tasks is the ROW-READ= -STAGE,
>> but it doesn't look like much, usually around 6-8:
>> #mbean =3D org.apache.cassandra.concurrent:type=3DROW-READ-STAGE:<= br> >> ActiveCount =3D 8;
>> PendingTasks =3D 8;
>> CompletedTasks =3D 5427955;
>> Any help finding the solution is appreciated, thanks...
>> Below are a few more JMXes I collected from the system that may be=
>> interesting.
>> #mbean =3D java.lang:type=3DMemory:
>> Verbose =3D false;
>> HeapMemoryUsage =3D {
>> =A0=A0committed =3D 3767279616;
>> =A0=A0init =3D 134217728;
>> =A0=A0max =3D 4293656576;
>> =A0=A0used =3D 1237105080;
>> =A0};
>> NonHeapMemoryUsage =3D {
>> =A0=A0committed =3D 35061760;
>> =A0=A0init =3D 24313856;
>> =A0=A0max =3D 138412032;
>> =A0=A0used =3D 23151320;
>> =A0};
>> ObjectPendingFinalizationCount =3D 0;
>> #mbean =3D java.lang:name=3DParNew,type=3DGarbageCollector:
>> LastGcInfo =3D {
>> =A0=A0GcThreadCount =3D 11;
>> =A0=A0duration =3D 136;
>> =A0=A0endTime =3D 42219272;
>> =A0=A0id =3D 11719;
>> =A0=A0memoryUsageAfterGc =3D {
>> =A0=A0 =A0( CMS Perm Gen ) =3D {
>> =A0=A0 =A0 =A0key =3D CMS Perm Gen;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 29229056;
>> =A0=A0 =A0 =A0 =A0init =3D 21757952;
>> =A0=A0 =A0 =A0 =A0max =3D 88080384;
>> =A0=A0 =A0 =A0 =A0used =3D 17648848;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( Code Cache ) =3D {
>> =A0=A0 =A0 =A0key =3D Code Cache;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 5832704;
>> =A0=A0 =A0 =A0 =A0init =3D 2555904;
>> =A0=A0 =A0 =A0 =A0max =3D 50331648;
>> =A0=A0 =A0 =A0 =A0used =3D 5563520;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( CMS Old Gen ) =3D {
>> =A0=A0 =A0 =A0key =3D CMS Old Gen;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 3594133504;
>> =A0=A0 =A0 =A0 =A0init =3D 112459776;
>> =A0=A0 =A0 =A0 =A0max =3D 4120510464;
>> =A0=A0 =A0 =A0 =A0used =3D 964565720;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( Par Eden Space ) =3D {
>> =A0=A0 =A0 =A0key =3D Par Eden Space;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 171835392;
>> =A0=A0 =A0 =A0 =A0init =3D 21495808;
>> =A0=A0 =A0 =A0 =A0max =3D 171835392;
>> =A0=A0 =A0 =A0 =A0used =3D 0;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( Par Survivor Space ) =3D {
>> =A0=A0 =A0 =A0key =3D Par Survivor Space;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 1310720;
>> =A0=A0 =A0 =A0 =A0init =3D 131072;
>> =A0=A0 =A0 =A0 =A0max =3D 1310720;
>> =A0=A0 =A0 =A0 =A0used =3D 0;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 };
>> =A0=A0memoryUsageBeforeGc =3D {
>> =A0=A0 =A0( CMS Perm Gen ) =3D {
>> =A0=A0 =A0 =A0key =3D CMS Perm Gen;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 29229056;
>> =A0=A0 =A0 =A0 =A0init =3D 21757952;
>> =A0=A0 =A0 =A0 =A0max =3D 88080384;
>> =A0=A0 =A0 =A0 =A0used =3D 17648848;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( Code Cache ) =3D {
>> =A0=A0 =A0 =A0key =3D Code Cache;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 5832704;
>> =A0=A0 =A0 =A0 =A0init =3D 2555904;
>> =A0=A0 =A0 =A0 =A0max =3D 50331648;
>> =A0=A0 =A0 =A0 =A0used =3D 5563520;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( CMS Old Gen ) =3D {
>> =A0=A0 =A0 =A0key =3D CMS Old Gen;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 3594133504;
>> =A0=A0 =A0 =A0 =A0init =3D 112459776;
>> =A0=A0 =A0 =A0 =A0max =3D 4120510464;
>> =A0=A0 =A0 =A0 =A0used =3D 959221872;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( Par Eden Space ) =3D {
>> =A0=A0 =A0 =A0key =3D Par Eden Space;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 171835392;
>> =A0=A0 =A0 =A0 =A0init =3D 21495808;
>> =A0=A0 =A0 =A0 =A0max =3D 171835392;
>> =A0=A0 =A0 =A0 =A0used =3D 171835392;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 =A0( Par Survivor Space ) =3D {
>> =A0=A0 =A0 =A0key =3D Par Survivor Space;
>> =A0=A0 =A0 =A0value =3D {
>> =A0=A0 =A0 =A0 =A0committed =3D 1310720;
>> =A0=A0 =A0 =A0 =A0init =3D 131072;
>> =A0=A0 =A0 =A0 =A0max =3D 1310720;
>> =A0=A0 =A0 =A0 =A0used =3D 0;
>> =A0=A0 =A0 =A0 };
>> =A0=A0 =A0 };
>> =A0=A0 };
>> =A0=A0startTime =3D 42219136;
>> =A0};
>> CollectionCount =3D 11720;
>> CollectionTime =3D 4561730;
>> Name =3D ParNew;
>> Valid =3D true;
>> MemoryPoolNames =3D [ Par Eden Space, Par Survivor Space ];
>> #mbean =3D java.lang:type=3DOperatingSystem:
>> MaxFileDescriptorCount =3D 63536;
>> OpenFileDescriptorCount =3D 75;
>> CommittedVirtualMemorySize =3D 17787711488;
>> FreePhysicalMemorySize =3D 45522944;
>> FreeSwapSpaceSize =3D 2123968512;
>> ProcessCpuTime =3D 12251460000000;
>> TotalPhysicalMemorySize =3D 8364417024;
>> TotalSwapSpaceSize =3D 4294959104;
>> Name =3D Linux;
>> AvailableProcessors =3D 8;
>> Arch =3D amd64;
>> SystemLoadAverage =3D 4.36;
>> Version =3D 2.6.18-164.15.1.el5;
>> #mbean =3D java.lang:type=3DRuntime:
>> Name =3D 20281@= ob1061.nydc1.outbrain.com;
>>
>> ClassPath =3D
>> /outbrain/cassandra/apache-cassandra-0.6.1/bin/../conf:/outbrain/c= assandra/apache-cassandra-0.6.1/bin/../build/classes:/outbrain/cassandra/ap= ache-cassandra-0.6.1/bin/..
>>
>> /lib/antlr-3.1.3.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bi= n/../lib/apache-cassandra-0.6.1.jar:/outbrain/cassandra/apache-cassandra-0.= 6.1/bin/../lib/avro-1.2.0-dev.jar:/outb
>>
>> rain/cassandra/apache-cassandra-0.6.1/bin/../lib/clhm-production.j= ar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/commons-cli-1.1.ja= r:/outbrain/cassandra/apache-cassandra-
>>
>> 0.6.1/bin/../lib/commons-codec-1.2.jar:/outbrain/cassandra/apache-= cassandra-0.6.1/bin/../lib/commons-collections-3.2.1.jar:/outbrain/cassandr= a/apache-cassandra-0.6.1/bin/../lib/com
>>
>> mons-lang-2.4.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/.= ./lib/google-collections-1.0.jar:/outbrain/cassandra/apache-cassandra-0.6.1= /bin/../lib/hadoop-core-0.20.1.jar:/out
>>
>> brain/cassandra/apache-cassandra-0.6.1/bin/../lib/high-scale-lib.j= ar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/ivy-2.1.0.jar:/out= brain/cassandra/apache-cassandra-0.6.1/
>>
>> bin/../lib/jackson-core-asl-1.4.0.jar:/outbrain/cassandra/apache-c= assandra-0.6.1/bin/../lib/jackson-mapper-asl-1.4.0.jar:/outbrain/cassandra/= apache-cassandra-0.6.1/bin/../lib/jline
>>
>> -0.9.94.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/= json-simple-1.1.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/l= ibthrift-r917130.jar:/outbrain/cassandr
>>
>> a/apache-cassandra-0.6.1/bin/../lib/log4j-1.2.14.jar:/outbrain/cas= sandra/apache-cassandra-0.6.1/bin/../lib/slf4j-api-1.5.8.jar:/outbrain/cass= andra/apache-cassandra-0.6.1/bin/../lib
>> /slf4j-log4j12-1.5.8.jar;
>>
>> BootClassPath =3D
>> /usr/java/jdk1.6.0_17/jre/lib/alt-rt.jar:/usr/java/jdk1.6.0_17/jre= /lib/resources.jar:/usr/java/jdk1.6.0_17/jre/lib/rt.jar:/usr/java/jdk1.6.0_= 17/jre/lib/sunrsasign.j
>>
>> ar:/usr/java/jdk1.6.0_17/jre/lib/jsse.jar:/usr/java/jdk1.6.0_17/jr= e/lib/jce.jar:/usr/java/jdk1.6.0_17/jre/lib/charsets.jar:/usr/java/jdk1.6.0= _17/jre/classes;
>>
>> LibraryPath =3D
>> /usr/java/jdk1.6.0_17/jre/lib/amd64/server:/usr/java/jdk1.6.0_17/j= re/lib/amd64:/usr/java/jdk1.6.0_17/jre/../lib/amd64:/usr/java/packages/lib/= amd64:/lib:/usr/lib;
>>
>> VmName =3D Java HotSpot(TM) 64-Bit Server VM;
>>
>> VmVendor =3D Sun Microsystems Inc.;
>>
>> VmVersion =3D 14.3-b01;
>>
>> BootClassPathSupported =3D true;
>>
>> InputArguments =3D [ -ea, -Xms128M, -Xmx4G, -XX:TargetSurvivorRati= o=3D90,
>> -XX:+AggressiveOpts, -XX:+UseParNewGC, -XX:+UseConcMarkSweepGC, >> -XX:+CMSParallelRemarkEnabled, -XX:+HeapDumpOnOutOfMemoryError, >> -XX:SurvivorRatio=3D128, -XX:MaxTenuringThreshold=3D0,
>> -Dcom.sun.management.jmxremote.port=3D9004,
>> -Dcom.sun.management.jmxremote.ssl=3Dfalse,
>> -Dcom.sun.management.jmxremote.authenticate=3Dfalse,
>> -Dstorage-config=3D/outbrain/cassandra/apache-cassandra-0.6.1/bin/= ../conf,
>> -Dcassandra-pidfile=3D/var/run/cassandra.pid ];
>>
>> ManagementSpecVersion =3D 1.2;
>>
>> SpecName =3D Java Virtual Machine Specification;
>>
>> SpecVendor =3D Sun Microsystems Inc.;
>>
>> SpecVersion =3D 1.0;
>>
>> StartTime =3D 1272911001415;
>> ...
>

--0016362849829841560485c7ce8d--