Return-Path: Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: (qmail 93651 invoked from network); 6 May 2010 17:06:34 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 6 May 2010 17:06:34 -0000 Received: (qmail 15194 invoked by uid 500); 6 May 2010 17:06:33 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 15177 invoked by uid 500); 6 May 2010 17:06:33 -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 15169 invoked by uid 99); 6 May 2010 17:06:33 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 06 May 2010 17:06:33 +0000 X-ASF-Spam-Status: No, hits=2.5 required=10.0 tests=FREEMAIL_FROM,HTML_FONT_FACE_BAD,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 weijunli@gmail.com designates 209.85.160.44 as permitted sender) Received: from [209.85.160.44] (HELO mail-pw0-f44.google.com) (209.85.160.44) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 06 May 2010 17:06:26 +0000 Received: by pwj2 with SMTP id 2so85013pwj.31 for ; Thu, 06 May 2010 10:06:04 -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=3T1V7eNZTrHbB7ojrfe3h2ijdivJM7lUn7nBfLLlTN8=; b=Kop47JSnBe4S3booStdGjxBcF9a4V6T7dZtIm8Lf3B2tk5LfJNrCfgZ4qeC52ZIvBq YNCh+kcD8uik+uaAKNSA4Y/0cZaenDChW7JmMD6zsr+Lqopgf4acldRgJuN9O5UPGNJo 0y4J7NHBl7dvSVUDy+UDzMyT1JRAMMN/HqIUg= 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=a2EzweNRvL15iYAdIysxp0sGa9NbQh8YQ7mAaG3LlnecPJrFY98MlSJtsaM9lJWCbe SP4MG9NwrXzvC4CHin5gTJSY5cBdllAsdNWahv11jszICAqZm3LMwRQQVMsaJIDwrzmS ZmQZcnX4kmt3ciO/aVwMnXeMbZXghwkZTkpq8= MIME-Version: 1.0 Received: by 10.140.56.14 with SMTP id e14mr7013405rva.158.1273165563296; Thu, 06 May 2010 10:06:03 -0700 (PDT) Received: by 10.140.247.13 with HTTP; Thu, 6 May 2010 10:06:02 -0700 (PDT) In-Reply-To: References: <8A606DEA-CB57-4D0B-90C0-FE79B2DE22E9@discovereads.com> Date: Thu, 6 May 2010 10:06:02 -0700 Message-ID: Subject: Re: performance tuning - where does the slowness come from? From: Weijun Li To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=001636b2ac8623fdf70485eff508 X-Virus-Checked: Checked by ClamAV on apache.org --001636b2ac8623fdf70485eff508 Content-Type: text/plain; charset=ISO-8859-1 Our use case is a little different: our server is a typical high volume transaction server that processes more than half billion requests per day. The write/read ratio is close to 1, and the cluster needs to serve >10k write+read with strict latency (<20ms) otherwise the client will treat it as failure. Plus we have hundreds of millions of keys so the generated sstable files are much bigger that the ram size. In this case using mmap will cause Cassandra to use sometimes > 100G virtual memory which is much more than the physical ram, since we are using random partitioner the OS will be busy doing swap. I have finally customized cassandra to meet the above requirement by using cheap hardware (32G ram + SATA drives): one thing I learned is that you have to carefully avoid swapping, especially when you need to cache most of the keys in memory, swap can easily damage the performance of your in memory cache. I also made some optimizations to reduce memory/disk consumption and to make it easier for us to diagnose issues. In one word: cassandra is very well written but there's still huge potential for you to improve it to meet your special requirements. -Weijun On Wed, May 5, 2010 at 9:43 AM, Jordan Pittier wrote: > I disagree. Swapping could be avoided. I don't know Cassandra internals > mechanisms but what I am expecting is that whenever I want to read rows that > are not in RAM, Cassandra load them from hard drive to RAM if space is > available, and, if RAM is full to reply my query without saving rows in RAM. > No need for swapping. > > I have no try yet to change DiskAccessMode to standard, I hope it will help > me. > > Another thing : please dont post your benchmark figures without any > explanation on the work load generator or your cluster settings. It really > doesn't make any sense... > > > On Wed, May 5, 2010 at 6:16 PM, Weijun Li wrote: > >> When you have much more data than you can hold in memory, it will be >> difficult for you to get around of swap which will most likely ruin your >> performance. Also in this case mmap doesn't seem to make much sense if you >> use random partitioner which will end up with crazy swap too. However we >> found a way to get around read/write performance issue by integrating >> memcached into Cassandra: in this case you need to ask memcached to disable >> disk swap so you can achieve move than 10k read+write with milli-second >> level of latency. Actually this is the only way that we figured out that can >> gracefully solve the performance and memory issue. >> >> -Weijun >> >> >> On Wed, May 5, 2010 at 8:19 AM, Ran Tavory wrote: >> >>> I'm still trying to figure out where my slowness is coming from... >>> By now I'm pretty sure it's the reads are slow, but not sure how to >>> improve them. >>> >>> I'm looking at cfstats. Can you say if there are better configuration >>> options? So far I've used all default settings, except for: >>> >>> >>> >> KeysCached="50%"/> >>> >>> org.apache.cassandra.locator.RackAwareStrategy >>> 2 >>> >>> org.apache.cassandra.locator.EndPointSnitch >>> >>> >>> >>> What does a good read latency look like? I was expecting 10ms, however so >>> far it seems that my KvImpressions read latency is 30ms and in the system >>> keyspace I have 800ms :( >>> I thought adding KeysCached="50%" would improve my situation but >>> unfortunately looks like the hitrate is about 0. I realize that's >>> application specific, but maybe there are other magic bullets... >>> >>> Is there something like adding cache to the system keyspace? 800 ms is >>> pretty bad, isn't it? >>> >>> See stats below and thanks. >>> >>> >>> Keyspace: outbrain_kvdb >>> Read Count: 651668 >>> Read Latency: 34.18622328547666 ms. >>> Write Count: 655542 >>> Write Latency: 0.041145092152752985 ms. >>> Pending Tasks: 0 >>> Column Family: KvImpressions >>> SSTable count: 13 >>> Space used (live): 23304548897 >>> Space used (total): 23304548897 >>> Memtable Columns Count: 895 >>> Memtable Data Size: 2108990 >>> Memtable Switch Count: 8 >>> Read Count: 468083 >>> Read Latency: 151.603 ms. >>> Write Count: 552566 >>> Write Latency: 0.023 ms. >>> Pending Tasks: 0 >>> Key cache capacity: 17398656 >>> Key cache size: 567967 >>> Key cache hit rate: 0.0 >>> Row cache: disabled >>> Compacted row minimum size: 269 >>> Compacted row maximum size: 54501 >>> Compacted row mean size: 933 >>> ... >>> ---------------- >>> Keyspace: system >>> Read Count: 1151 >>> Read Latency: 872.5014448305822 ms. >>> Write Count: 51215 >>> Write Latency: 0.07156788050375866 ms. >>> Pending Tasks: 0 >>> Column Family: HintsColumnFamily >>> SSTable count: 5 >>> Space used (live): 437366878 >>> Space used (total): 437366878 >>> Memtable Columns Count: 14987 >>> Memtable Data Size: 87975 >>> Memtable Switch Count: 2 >>> Read Count: 1150 >>> Read Latency: NaN ms. >>> Write Count: 51211 >>> Write Latency: 0.027 ms. >>> Pending Tasks: 0 >>> Key cache capacity: 6 >>> Key cache size: 4 >>> Key cache hit rate: NaN >>> Row cache: disabled >>> Compacted row minimum size: 0 >>> Compacted row maximum size: 0 >>> Compacted row mean size: 0 >>> >>> Column Family: LocationInfo >>> SSTable count: 2 >>> Space used (live): 3504 >>> Space used (total): 3504 >>> Memtable Columns Count: 0 >>> Memtable Data Size: 0 >>> Memtable Switch Count: 1 >>> Read Count: 1 >>> Read Latency: NaN ms. >>> Write Count: 7 >>> Write Latency: NaN ms. >>> Pending Tasks: 0 >>> Key cache capacity: 2 >>> Key cache size: 1 >>> Key cache hit rate: NaN >>> Row cache: disabled >>> Compacted row minimum size: 0 >>> Compacted row maximum size: 0 >>> Compacted row mean size: 0 >>> >>> >>> On Tue, May 4, 2010 at 10:57 PM, Kyusik Chung wrote: >>> >>>> Im using Ubuntu 8.04 on 64 bit hosts on rackspace cloud. >>>> >>>> Im in the middle of repeating some perf tests, but so far, I get as-good >>>> or slightly better read perf by using standard disk access mode vs mmap. So >>>> far consecutive tests are returning consistent numbers. >>>> >>>> Im not sure how to explain it...maybe its an ubuntu 8.04 issue with >>>> mmap. Back when I was using mmap, I was definitely seeing the kswapd0 >>>> process start using cpu as the box ran out of memory, and read performance >>>> significantly degraded. >>>> >>>> Next, Ill run some tests with mmap_index_only, and Ill test with heavy >>>> concurrent writes as well as reads. Ill let everyone know what I find. >>>> >>>> Kyusik Chung >>>> CEO, Discovereads.com >>>> kyusik@discovereads.com >>>> >>>> On May 4, 2010, at 12:27 PM, Jonathan Ellis wrote: >>>> >>>> > Are you using 32 bit hosts? If not don't be scared of mmap using a >>>> > lot of address space, you have plenty. It won't make you swap more >>>> > than using buffered i/o. >>>> > >>>> > On Tue, May 4, 2010 at 1:57 PM, Ran Tavory wrote: >>>> >> I canceled mmap and indeed memory usage is sane again. So far >>>> performance >>>> >> hasn't been great, but I'll wait and see. >>>> >> I'm also interested in a way to cap mmap so I can take advantage of >>>> it but >>>> >> not swap the host to death... >>>> >> >>>> >> On Tue, May 4, 2010 at 9:38 PM, Kyusik Chung < >>>> kyusik@discovereads.com> >>>> >> wrote: >>>> >>> >>>> >>> This sounds just like the slowness I was asking about in another >>>> thread - >>>> >>> after a lot of reads, the machine uses up all available memory on >>>> the box >>>> >>> and then starts swapping. >>>> >>> My understanding was that mmap helps greatly with read and write >>>> perf >>>> >>> (until the box starts swapping I guess)...is there any way to use >>>> mmap and >>>> >>> cap how much memory it takes up? >>>> >>> What do people use in production? mmap or no mmap? >>>> >>> Thanks! >>>> >>> Kyusik Chung >>>> >>> On May 4, 2010, at 10:11 AM, Schubert Zhang wrote: >>>> >>> >>>> >>> 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 < >>>> 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 >>>> 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; >>>> >>>>>> ... >>>> >>>>> >>>> >>> >>>> >>> >>>> >> >>>> >> >>>> > >>>> > >>>> > >>>> > -- >>>> > Jonathan Ellis >>>> > Project Chair, Apache Cassandra >>>> > co-founder of Riptano, the source for professional Cassandra support >>>> > http://riptano.com >>>> >>>> >>> >> > --001636b2ac8623fdf70485eff508 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Our use case is a little different: our server is a typical high volume tra= nsaction server that processes more than half billion requests per day. The= write/read ratio is close to 1, and the cluster needs to serve >10k wri= te+read with strict latency (<20ms) otherwise the client will treat it a= s failure. Plus we have hundreds of millions of keys so the generated sstab= le files are much bigger that the ram size. In this case using mmap will ca= use Cassandra to use sometimes > 100G virtual memory which is much more = than the physical ram, since we are using random partitioner the OS will be= busy doing swap.

I have finally customized cassandra to meet the above requirement by us= ing cheap hardware (32G ram + SATA drives): one thing I learned is that you= have to carefully avoid swapping, especially when you need to cache most o= f the keys in memory, swap can easily damage the performance of your in mem= ory cache. I also made some optimizations to reduce memory/disk consumption= and to make it easier for us to diagnose issues. In one word: cassandra is= very well written but there's still huge potential for you to improve = it to meet your special requirements.

-Weijun

On Wed, May 5, 2010 at 9:43 A= M, Jordan Pittier <jordan.pittier@gmail.com> wrote:
I disagree. Swapping could be avoided. I don't know Cassandra internals= mechanisms but what I am expecting is that whenever I want to read rows th= at are not in RAM, Cassandra load them from hard drive to RAM if space is a= vailable, and, if RAM is full to reply my query without saving rows in RAM.= No need for swapping.

I have no try yet to change DiskAccessMode to standard, I hope it will = help me.

Another thing : please dont post your benchmark figures wit= hout any explanation on the work load generator or your cluster settings. I= t really doesn't make any sense...


On Wed, May 5, 2010 at 6:16 PM, Weijun Li <weijunli@gmail.com> wrote:
When you have much more data than you can hold in memory, it will be diffic= ult for you to get around of swap which will most likely ruin your performa= nce. Also in this case mmap doesn't seem to make much sense if you use = random partitioner which will end up with crazy swap too. However we found = a way to get around read/write performance issue by integrating memcached i= nto Cassandra: in this case you need to ask memcached to disable disk swap = so you can achieve move than 10k read+write with milli-second level of late= ncy. Actually this is the only way that we figured out that can gracefully = solve the performance and memory issue.

-Weijun


O= n Wed, May 5, 2010 at 8:19 AM, Ran Tavory <rantav@gmail.com> = wrote:
I'm still trying to figure out where my slowness = is coming from...
By now I'm pretty sure it's the reads a= re slow, but not sure how to improve them.

I'm look= ing at cfstats. Can you say if there are better configuration options? So f= ar I've used all default settings, except for:

=A0=A0 = =A0<Keyspace Name=3D"outbrain_kvdb">
=A0=A0 =A0 =A0<ColumnFamily C= ompareWith=3D"BytesType" Name=3D"KvImpressions" = KeysCached=3D"50%"/>
=A0=A0 =A0 =A0<Repl= icaPlacementStrategy>org.apache.cassandra.locator.RackAwareStrategy</= ReplicaPlacementStrategy>
=A0=A0 =A0 =A0<ReplicationFactor>2</Replication= Factor>
=A0=A0 =A0 =A0<EndP= ointSnitch>org.apache.cassandra.locator.EndPointSnitch</EndPointSnitc= h>
=A0= =A0 =A0</Keyspace>


What does a good read latency look= like? I was expecting 10ms, however so far it seems that my KvImpressions = read latency is 30ms and in the system keyspace I have 800ms :(
I thought adding=A0KeysCached=3D"50%" would improve my situation = but unfortunately looks like the hitrate is about 0. I realize that's a= pplication specific, but maybe there are other magic bullets...

Is there something like adding cache to the system keyspace? 800= ms is pretty bad, isn't it?

See stats below a= nd thanks.


Keyspace: outbrain_kvdb
<= div>=A0=A0 =A0 =A0 =A0Read Count: 651668
=A0=A0 =A0 =A0 =A0Read L= atency: 34.18622328547666 ms.
=A0=A0 =A0 =A0 =A0Write Count: 6555= 42
=A0=A0 =A0 =A0 =A0Write Latency: 0.041145092152752985 ms.
=A0=A0 =A0 =A0 =A0Pending Tasks: 0
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Column Family: KvImpressions
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0SSTable count: 13
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Sp= ace used (live): 23304548897
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Sp= ace used (total): 23304548897
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Columns Count: 895
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Data Size: 2108990
= =A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Switch Count: 8
=A0=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0Read Count: 468083
=A0=A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0Read Latency: 151.603 ms.
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Write Count: 552566
=A0=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0Write Latency: 0.023 ms.
=A0=A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0Pending Tasks: 0
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Key cache capacity: 17398656
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Key cache size: 567967
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Key cache hit rate: 0.0
= =A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Row cache: disabled
=A0=A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0Compacted row minimum size: 269
=A0=A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0Compacted row maximum size: 54501
=A0=A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0Compacted row mean size: 933
...
----------------
Keyspace: system
<= div>=A0=A0 =A0 =A0 =A0Read Count: 1151
=A0=A0 =A0 =A0 =A0Read Lat= ency: 872.5014448305822 ms.
=A0=A0 =A0 =A0 =A0Write Count: 51215<= /div>
=A0=A0 =A0 =A0 =A0Write Latency: 0.07156788050375866 ms.
=A0=A0 =A0 =A0 =A0Pending Tasks: 0
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Column Family: HintsColumnFamily
=A0=A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0SSTable count: 5
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0Space used (live): 437366878
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0Space used (total): 437366878
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Columns Count: 14987
<= div>=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Data Size: 87975
= =A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Switch Count: 2
=A0=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0Read Count: 1150
=A0=A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0Read Latency: NaN ms.
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Write Count: 51211
=A0=A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0Write Latency: 0.027 ms.
=A0=A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0Pending Tasks: 0
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Key cache capacity: 6
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0Key cache size: 4
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Key cache hit rate: NaN
= =A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Row cache: disabled
=A0=A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0Compacted row minimum size: 0
=A0=A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0Compacted row maximum size: 0
=A0=A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0Compacted row mean size: 0

=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Column Family: Locati= onInfo
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0SSTable count: 2
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Space used (live): 3504
=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Space used (total): 3504
=A0=A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Columns Count: 0
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Data Size: 0
=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Memtable Switch Count: 1
=A0=A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0Read Count: 1
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Read Latency: NaN ms.
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0Write Count: 7
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Write Latency: NaN ms.
=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Pending Tasks: 0
=A0=A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0Key cache capacity: 2
=A0=A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0Key cache size: 1
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Ke= y cache hit rate: NaN
=A0=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0Row cache: disabled
=A0=A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0Compacted row minimum size: 0
=A0=A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0Compacted row maximum size: 0
=A0=A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0Compacted row mean size: 0


On Tue, May 4, 2010 at 10:57 PM, K= yusik Chung <kyusik@discovereads.com> wrote:
Im using Ubuntu 8.04 on 64 bit hosts on rackspace cloud.

Im in the middle of repeating some perf tests, but so far, I get as-good or= slightly better read perf by using standard disk access mode vs mmap. =A0S= o far consecutive tests are returning consistent numbers.

Im not sure how to explain it...maybe its an ubuntu 8.04 issue with mmap. = =A0Back when I was using mmap, I was definitely seeing the kswapd0 process = start using cpu as the box ran out of memory, and read performance signific= antly degraded.

Next, Ill run some tests with mmap_index_only, and Ill test with heavy conc= urrent writes as well as reads. =A0Ill let everyone know what I find.

Kyusik Chung
CEO, Discovereads.com
kyusik@discove= reads.com

On May 4, 2010, at 12:27 PM, Jonathan Ellis wrote:

> Are you using 32 bit hosts? =A0If not don't be scared of mmap usin= g a
> lot of address space, you have plenty. =A0It won't make you swap m= ore
> than using buffered i/o.
>
> On Tue, May 4, 2010 at 1:57 PM, Ran Tavory <rantav@gmail.com> wrote:
>> I canceled mmap and indeed memory usage is sane again. So far perf= ormance
>> hasn't been great, but I'll wait and see.
>> I'm also interested in a way to cap mmap so I can take advanta= ge of it but
>> not swap the host to death...
>>
>> On Tue, May 4, 2010 at 9:38 PM, Kyusik Chung <kyusik@discovereads.com>=
>> wrote:
>>>
>>> This sounds just like the slowness I was asking about in anoth= er thread -
>>> after a lot of reads, the machine uses up all available memory= on the box
>>> and then starts swapping.
>>> My understanding was that mmap helps greatly with read and wri= te perf
>>> (until the box starts swapping I guess)...is there any way to = use mmap and
>>> cap how much memory it takes up?
>>> What do people use in production? =A0mmap or no mmap?
>>> Thanks!
>>> Kyusik Chung
>>> On May 4, 2010, at 10:11 AM, Schubert Zhang wrote:
>>>
>>> 1. When initially startup your nodes, please plan your Initial= Token of
>>> each node evenly.
>>> 2. <DiskAccessMode>standard</DiskAccessMode>
>>>
>>> On Tue, May 4, 2010 at 9:09 PM, Boris Shulman <shulmanb@gmail.com> wrot= e:
>>>>
>>>> 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 occur= s when I perform read
>>>>> operations (write are very fast :)). So I can't he= lp you with the
>>>>> memory
>>>>> probleme.
>>>>>
>>>>> But to balance the load evenly between nodes in cluste= r 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> wro= te:
>>>>>>
>>>>>> 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 cl= uster used to make
>>>>>> around 3-5k read and writes per second (6-10k oper= ations per second),
>>>>>> but
>>>>>> how it's in the order of 200-400 ops per secon= d, sometimes even less.
>>>>>> 2 looks like this:
>>>>>> $ tail -f /outbrain/cassandra/log/system.log
>>>>>> =A0INFO [GC inspection] 2010-05-04 00:42:18,636 GC= Inspector.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 GC= Inspector.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 GC= Inspector.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 ev= enly b/w the hosts,
>>>>>> 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 =A0= v =A0 |
>>>>>> 192.168.252.61Up =A0 =A0 =A0 =A0 11.36 GB
>>>>>> =A0144413773383729447702215082383444206680 =A0 =A0= |-->|
>>>>>> The slow host is 192.168.252.61 and it isn't t= he most loaded one.
>>>>>> The host is waiting a lot on IO and the load avera= ge 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-- -----i= o---- --system--
>>>>>> -----cpu------
>>>>>> =A0r =A0b =A0 swpd =A0 free =A0 buff =A0cache =A0 = si =A0 so =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 =A00 =A02345 =A0 =A058 3372 9957 =A02
>>>>>> =A02
>>>>>> 78 18 =A00
>>>>>> =A00 =A03 2146432 =A045704 =A0 1812 4453956 =A0342= =A0 =A00 =A02274 =A0 108 3937 10732
>>>>>> =A02 =A02
>>>>>> 78 19 =A00
>>>>>> =A00 =A01 2146252 =A044696 =A0 1804 4453436 =A0345= =A0164 =A01939 =A0 294 3647 7833 =A02
>>>>>> =A02
>>>>>> 78 18 =A00
>>>>>> =A00 =A01 2145960 =A046924 =A0 1744 4451260 =A0158= =A0 =A00 =A02423 =A0 122 4354 14597
>>>>>> =A02 =A02
>>>>>> 77 18 =A00
>>>>>> =A07 =A01 2138344 =A044676 =A0 =A0952 4504148 1722= =A0403 =A01722 =A0 406 1388 =A0439 87
>>>>>> =A00
>>>>>> 10 =A02 =A00
>>>>>> =A07 =A02 2137248 =A045652 =A0 =A0956 4499436 1384= =A0655 =A01384 =A0 658 1356 =A0392 87
>>>>>> =A00
>>>>>> 10 =A03 =A00
>>>>>> =A07 =A01 2135976 =A046764 =A0 =A0956 4495020 1366= =A0718 =A01366 =A0 718 1395 =A0380 87
>>>>>> =A00
>>>>>> =A09 =A04 =A00
>>>>>> =A00 =A08 2134484 =A046964 =A0 =A0956 4489420 1673= =A0555 =A01814 =A0 586 1601 215590
>>>>>> 14
>>>>>> =A02 68 16 =A00
>>>>>> =A00 =A01 2135388 =A047444 =A0 =A0972 4488516 =A07= 85 =A0833 =A02390 =A0 995 3812 8305 =A02
>>>>>> =A02
>>>>>> 77 20 =A00
>>>>>> =A00 10 2135164 =A045928 =A0 =A0980 4488796 =A0788= =A0543 =A02275 =A0 626 36
>>>>>> So, the host is swapping like crazy...
>>>>>> top shows that it's using a lot of memory. As = noted before -Xmx=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 h= ost, 92% is used by
>>>>>> cassandra. How's that?
>>>>>> Top shows there's 3.9g Shared and 7.2g Residen= t and 15.9g Virtual. Why
>>>>>> does it have 15g virtual? And why 7.2 RES? This ca= n explain the
>>>>>> slowness in
>>>>>> swapping.
>>>>>> $ top
>>>>>> =A0 PID USER =A0 =A0 =A0PR =A0NI =A0VIRT =A0RES = =A0SHR S %CPU %MEM =A0 =A0TIME+ =A0COMMAND
>>>>>>
>>>>>>
>>>>>> 20281 cassandr =A025 =A0 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 an= d nothing seemed
>>>>>> suspicious
>>>>>> so far. By suspicious i mean a large number of pen= ding tasks - there
>>>>>> were
>>>>>> always very small numbers in each pool.
>>>>>> About read and write latencies, I'm not sure w= hat the normal state is,
>>>>>> but
>>>>>> here's an example of what I see on the problem= atic host:
>>>>>> #mbean =3D org.apache.cassandra.service:type=3DSto= rageProxy:
>>>>>> 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=3D= ROW-READ-STAGE:
>>>>>> ActiveCount =3D 8;
>>>>>> PendingTasks =3D 8;
>>>>>> CompletedTasks =3D 5427955;
>>>>>> Any help finding the solution is appreciated, than= ks...
>>>>>> Below are a few more JMXes I collected from the sy= stem that may be
>>>>>> interesting.
>>>>>> #mbean =3D java.lang:type=3DMemory:
>>>>>> Verbose =3D false;
>>>>>> HeapMemoryUsage =3D {
>>>>>> =A0 committed =3D 3767279616;
>>>>>> =A0 init =3D 134217728;
>>>>>> =A0 max =3D 4293656576;
>>>>>> =A0 used =3D 1237105080;
>>>>>> =A0};
>>>>>> NonHeapMemoryUsage =3D {
>>>>>> =A0 committed =3D 35061760;
>>>>>> =A0 init =3D 24313856;
>>>>>> =A0 max =3D 138412032;
>>>>>> =A0 used =3D 23151320;
>>>>>> =A0};
>>>>>> ObjectPendingFinalizationCount =3D 0;
>>>>>> #mbean =3D java.lang:name=3DParNew,type=3DGarbageC= ollector:
>>>>>> LastGcInfo =3D {
>>>>>> =A0 GcThreadCount =3D 11;
>>>>>> =A0 duration =3D 136;
>>>>>> =A0 endTime =3D 42219272;
>>>>>> =A0 id =3D 11719;
>>>>>> =A0 memoryUsageAfterGc =3D {
>>>>>> =A0 =A0 ( CMS Perm Gen ) =3D {
>>>>>> =A0 =A0 =A0 key =3D CMS Perm Gen;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 29229056;
>>>>>> =A0 =A0 =A0 =A0 init =3D 21757952;
>>>>>> =A0 =A0 =A0 =A0 max =3D 88080384;
>>>>>> =A0 =A0 =A0 =A0 used =3D 17648848;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( Code Cache ) =3D {
>>>>>> =A0 =A0 =A0 key =3D Code Cache;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 5832704;
>>>>>> =A0 =A0 =A0 =A0 init =3D 2555904;
>>>>>> =A0 =A0 =A0 =A0 max =3D 50331648;
>>>>>> =A0 =A0 =A0 =A0 used =3D 5563520;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( CMS Old Gen ) =3D {
>>>>>> =A0 =A0 =A0 key =3D CMS Old Gen;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 3594133504;
>>>>>> =A0 =A0 =A0 =A0 init =3D 112459776;
>>>>>> =A0 =A0 =A0 =A0 max =3D 4120510464;
>>>>>> =A0 =A0 =A0 =A0 used =3D 964565720;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( Par Eden Space ) =3D {
>>>>>> =A0 =A0 =A0 key =3D Par Eden Space;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 171835392;
>>>>>> =A0 =A0 =A0 =A0 init =3D 21495808;
>>>>>> =A0 =A0 =A0 =A0 max =3D 171835392;
>>>>>> =A0 =A0 =A0 =A0 used =3D 0;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( Par Survivor Space ) =3D {
>>>>>> =A0 =A0 =A0 key =3D Par Survivor Space;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 1310720;
>>>>>> =A0 =A0 =A0 =A0 init =3D 131072;
>>>>>> =A0 =A0 =A0 =A0 max =3D 1310720;
>>>>>> =A0 =A0 =A0 =A0 used =3D 0;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0};
>>>>>> =A0 memoryUsageBeforeGc =3D {
>>>>>> =A0 =A0 ( CMS Perm Gen ) =3D {
>>>>>> =A0 =A0 =A0 key =3D CMS Perm Gen;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 29229056;
>>>>>> =A0 =A0 =A0 =A0 init =3D 21757952;
>>>>>> =A0 =A0 =A0 =A0 max =3D 88080384;
>>>>>> =A0 =A0 =A0 =A0 used =3D 17648848;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( Code Cache ) =3D {
>>>>>> =A0 =A0 =A0 key =3D Code Cache;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 5832704;
>>>>>> =A0 =A0 =A0 =A0 init =3D 2555904;
>>>>>> =A0 =A0 =A0 =A0 max =3D 50331648;
>>>>>> =A0 =A0 =A0 =A0 used =3D 5563520;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( CMS Old Gen ) =3D {
>>>>>> =A0 =A0 =A0 key =3D CMS Old Gen;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 3594133504;
>>>>>> =A0 =A0 =A0 =A0 init =3D 112459776;
>>>>>> =A0 =A0 =A0 =A0 max =3D 4120510464;
>>>>>> =A0 =A0 =A0 =A0 used =3D 959221872;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( Par Eden Space ) =3D {
>>>>>> =A0 =A0 =A0 key =3D Par Eden Space;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 171835392;
>>>>>> =A0 =A0 =A0 =A0 init =3D 21495808;
>>>>>> =A0 =A0 =A0 =A0 max =3D 171835392;
>>>>>> =A0 =A0 =A0 =A0 used =3D 171835392;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0 ( Par Survivor Space ) =3D {
>>>>>> =A0 =A0 =A0 key =3D Par Survivor Space;
>>>>>> =A0 =A0 =A0 value =3D {
>>>>>> =A0 =A0 =A0 =A0 committed =3D 1310720;
>>>>>> =A0 =A0 =A0 =A0 init =3D 131072;
>>>>>> =A0 =A0 =A0 =A0 max =3D 1310720;
>>>>>> =A0 =A0 =A0 =A0 used =3D 0;
>>>>>> =A0 =A0 =A0 =A0};
>>>>>> =A0 =A0 =A0};
>>>>>> =A0 =A0};
>>>>>> =A0 startTime =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/cassandra/apache-cassandra-0.6.1/bin/../build/classes:/outbr= ain/cassandra/apache-cassandra-0.6.1/bin/..
>>>>>>
>>>>>>
>>>>>> /lib/antlr-3.1.3.jar:/outbrain/cassandra/apache-ca= ssandra-0.6.1/bin/../lib/apache-cassandra-0.6.1.jar:/outbrain/cassandra/apa= che-cassandra-0.6.1/bin/../lib/avro-1.2.0-dev.jar:/outb
>>>>>>
>>>>>>
>>>>>> rain/cassandra/apache-cassandra-0.6.1/bin/../lib/c= lhm-production.jar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/co= mmons-cli-1.1.jar:/outbrain/cassandra/apache-cassandra-
>>>>>>
>>>>>>
>>>>>> 0.6.1/bin/../lib/commons-codec-1.2.jar:/outbrain/c= assandra/apache-cassandra-0.6.1/bin/../lib/commons-collections-3.2.1.jar:/o= utbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/com
>>>>>>
>>>>>>
>>>>>> mons-lang-2.4.jar:/outbrain/cassandra/apache-cassa= ndra-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/iv= y-2.1.0.jar:/outbrain/cassandra/apache-cassandra-0.6.1/
>>>>>>
>>>>>>
>>>>>> bin/../lib/jackson-core-asl-1.4.0.jar:/outbrain/ca= ssandra/apache-cassandra-0.6.1/bin/../lib/jackson-mapper-asl-1.4.0.jar:/out= brain/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.j= ar:/outbrain/cassandra/apache-cassandra-0.6.1/bin/../lib/slf4j-api-1.5.8.ja= r:/outbrain/cassandra/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:/us= r/java/jdk1.6.0_17/jre/lib/sunrsasign.j
>>>>>>
>>>>>>
>>>>>> ar:/usr/java/jdk1.6.0_17/jre/lib/jsse.jar:/usr/jav= a/jdk1.6.0_17/jre/lib/jce.jar:/usr/java/jdk1.6.0_17/jre/lib/charsets.jar:/u= sr/java/jdk1.6.0_17/jre/classes;
>>>>>>
>>>>>> LibraryPath =3D
>>>>>>
>>>>>> /usr/java/jdk1.6.0_17/jre/lib/amd64/server:/usr/ja= va/jdk1.6.0_17/jre/lib/amd64:/usr/java/jdk1.6.0_17/jre/../lib/amd64:/usr/ja= va/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:Ta= rgetSurvivorRatio=3D90,
>>>>>> -XX:+AggressiveOpts, -XX:+UseParNewGC, -XX:+UseCon= cMarkSweepGC,
>>>>>> -XX:+CMSParallelRemarkEnabled, -XX:+HeapDumpOnOutO= fMemoryError,
>>>>>> -XX:SurvivorRatio=3D128, -XX:MaxTenuringThreshold= =3D0,
>>>>>> -Dcom.sun.management.jmxremote.port=3D9004,
>>>>>> -Dcom.sun.management.jmxremote.ssl=3Dfalse,
>>>>>> -Dcom.sun.management.jmxremote.authenticate=3Dfals= e,
>>>>>>
>>>>>> -Dstorage-config=3D/outbrain/cassandra/apache-cass= andra-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;
>>>>>> ...
>>>>>
>>>
>>>
>>
>>
>
>
>
> --
> Jonathan Ellis
> Project Chair, Apache Cassandra
> co-founder of Riptano, the source for professional Cassandra support > http://riptano.com





--001636b2ac8623fdf70485eff508--