Return-Path: Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: (qmail 79525 invoked from network); 19 Aug 2010 14:24:41 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 19 Aug 2010 14:24:41 -0000 Received: (qmail 32930 invoked by uid 500); 19 Aug 2010 14:24:40 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 32696 invoked by uid 500); 19 Aug 2010 14:24:37 -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 32687 invoked by uid 99); 19 Aug 2010 14:24:36 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 19 Aug 2010 14:24:36 +0000 X-ASF-Spam-Status: No, hits=-0.0 required=10.0 tests=SPF_HELO_PASS,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of gcdcu-cassandra-user-1@m.gmane.org designates 80.91.229.12 as permitted sender) Received: from [80.91.229.12] (HELO lo.gmane.org) (80.91.229.12) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 19 Aug 2010 14:24:30 +0000 Received: from list by lo.gmane.org with local (Exim 4.69) (envelope-from ) id 1Om62I-0006nB-Uu for user@cassandra.apache.org; Thu, 19 Aug 2010 16:24:07 +0200 Received: from sbs.nextcentury.com ([71.179.165.114]) by main.gmane.org with esmtp (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Thu, 19 Aug 2010 16:24:06 +0200 Received: from julie.sugar by sbs.nextcentury.com with local (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Thu, 19 Aug 2010 16:24:06 +0200 X-Injected-Via-Gmane: http://gmane.org/ To: user@cassandra.apache.org From: Julie Subject: Re: Cassandra disk space utilization WAY higher than I would expect Date: Thu, 19 Aug 2010 14:23:58 +0000 (UTC) Lines: 146 Message-ID: References:

<4C5C8370.7070107@digg.com>

Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7bit X-Complaints-To: usenet@dough.gmane.org X-Gmane-NNTP-Posting-Host: sea.gmane.org User-Agent: Loom/3.14 (http://gmane.org/) X-Loom-IP: 71.179.165.114 (Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.6) Gecko/20091216 Fedora/3.5.6-1.fc11 Firefox/3.5.6) Peter Schuller infidyne.com> writes: > Without necessarily dumping all the information - approximately what > do they contain? Do they contain anything about compactions, > anti-compactions, streaming, etc? > > With an idle node after taking writes, I *think* the only expected > disk I/O (once it has settled) would be a memtable flush triggered by > memtable_flush_after_mins, and possibly compactions resulting from > that (depending on how close one were to triggering compaction prior > to the memtable flush). Whatever is causing additional sstables to be > written, even if somehow triggered incorrectly, I'd hope that they > were logged still. ****************************************************** Hi Peter, Thanks for your ideas. Here is what I see in the bloated node's system.log file (condensed) starting 4 minutes after the last write. At this time, data usage on this node was only around 28GB (as expected). ****************************************************** INFO [COMPACTION-POOL:1] 2010-08-16 13:51:38,432 CompactionManager.java (line 246) Compacting ... INFO [COMPACTION-POOL:1] 2010-08-16 14:20:02,840 CompactionManager.java (line 246) Compacting ... INFO [COMPACTION-POOL:1] 2010-08-16 14:28:37,085 CompactionManager.java (line 246) Compacting ... INFO [Thread-25] 2010-08-16 14:34:06,827 StreamCompletionHandler.java (line 64) Streaming added /var/lib/cassandra/data/Keyspace1/Standard1-467-Data.db INFO [Timer-1] 2010-08-16 14:34:31,655 Gossiper.java (line 179) InetAddress /10.254.107.178 is now dead. INFO [GMFD:1] 2010-08-16 14:35:03,012 Gossiper.java (line 568) InetAddress /10.254.107.178 is now UP INFO [COMPACTION-POOL:1] 2010-08-16 14:36:04,808 CompactionManager.java (line 246) Compacting ... INFO [COMPACTION-POOL:1] 2010-08-16 14:40:31,283 CompactionManager.java (line 246) Compacting ... INFO [FLUSH-TIMER] 2010-08-16 14:50:46,570 ColumnFamilyStore.java (line 357) Standard1 has reached its threshold; switching in a fresh Memtable at CommitLogContext(file= '/var/lib/cassandra/commitlog/CommitLog-1281980828674.log', position=87493038) INFO [FLUSH-TIMER] 2010-08-16 14:50:46,602 ColumnFamilyStore.java (line 609) Enqueuing flush of Memtable(Standard1)@31873581 INFO [FLUSH-WRITER-POOL:1] 2010-08-16 14:50:46,647 Memtable.java (line 148) Writing Memtable(Standard1)@31873581 INFO [GC inspection] 2010-08-16 14:50:47,350 GCInspector.java (line 110) GC for ConcurrentMarkSweep: 362 ms, 506927464 reclaimed leaving 129128920 used; max is 1172766720 INFO [FLUSH-WRITER-POOL:1] 2010-08-16 14:50:51,137 Memtable.java (line 162) Completed flushing /var/lib/cassandra/data/Keyspace1/Standard1-472-Data.db INFO [SSTABLE-CLEANUP-TIMER] 2010-08-16 14:50:58,411 SSTableDeletingReference.java (line 104) Deleted /var/lib/cassandra/data/Keyspace1/Standard1-223-Data.db ... ... INFO [SSTABLE-CLEANUP-TIMER] 2010-08-16 14:51:40,662 SSTableDeletingReference.java (line 104) Deleted /var/lib/cassandra/data/Keyspace1/Standard1-407-Data.db INFO [Timer-1] 2010-08-16 14:51:40,772 Gossiper.java (line 179) InetAddress /10.254.242.159 is now dead. INFO [SSTABLE-CLEANUP-TIMER] 2010-08-16 14:51:41,011 SSTableDeletingReference.java (line 104) Deleted /var/lib/cassandra/data/Keyspace1/Standard1-279-Data.db ... ... INFO [SSTABLE-CLEANUP-TIMER] 2010-08-16 14:52:22,206 SSTableDeletingReference.java (line 104) Deleted /var/lib/cassandra/data/Keyspace1/Standard1-389-Data.db INFO [GMFD:1] 2010-08-16 14:52:34,906 Gossiper.java (line 568) InetAddress /10.254.242.159 is now UP INFO [COMPACTION-POOL:1] 2010-08-16 14:58:48,958 CompactionManager.java (line 246) Compacting ... INFO [COMPACTION-POOL:1] 2010-08-16 15:02:43,444 CompactionManager.java (line 246) Compacting ... INFO [COMPACTION-POOL:1] 2010-08-16 15:05:08,837 CompactionManager.java (line 246) Compacting [] INFO [Timer-1] 2010-08-16 15:17:38,697 Gossiper.java (line 179) InetAddress /10.254.234.226 is now dead. INFO [GMFD:1] 2010-08-16 15:18:37,471 Gossiper.java (line 568) InetAddress /10.254.234.226 is now UP INFO [Thread-28] 2010-08-16 15:38:34,685 StreamCompletionHandler.java (line 64) Streaming added /var/lib/cassandra/data/Keyspace1/Standard1-475-Data.db INFO [COMPACTION-POOL:1] 2010-08-16 16:05:08,811 CompactionManager.java (line 246) Compacting [] INFO [COMPACTION-POOL:1] 2010-08-16 17:05:08,792 CompactionManager.java (line 246) Compacting [] INFO [Timer-1] 2010-08-16 17:05:55,583 Gossiper.java (line 179) InetAddress /10.254.242.159 is now dead. INFO [GMFD:1] 2010-08-16 17:06:19,614 Gossiper.java (line 568) InetAddress /10.254.242.159 is now UP INFO [Thread-34] 2010-08-16 17:24:57,584 StreamCompletionHandler.java (line 64) Streaming added /var/lib/cassandra/data/Keyspace1/Standard1-477-Data.db INFO [Timer-1] 2010-08-16 17:25:19,206 Gossiper.java (line 179) InetAddress /10.210.157.187 is now dead. INFO [GMFD:1] 2010-08-16 17:25:53,096 Gossiper.java (line 568) InetAddress /10.210.157.187 is now UP INFO [Thread-31] 2010-08-16 17:26:37,281 StreamCompletionHandler.java (line 64) Streaming added /var/lib/cassandra/data/Keyspace1/Standard1-476-Data.db INFO [Timer-1] 2010-08-16 17:27:01,939 Gossiper.java (line 179) InetAddress /10.254.234.226 is now dead. INFO [GMFD:1] 2010-08-16 17:27:24,115 Gossiper.java (line 568) InetAddress /10.254.234.226 is now UP INFO [COMPACTION-POOL:1] 2010-08-16 18:05:08,764 CompactionManager.java (line 246) Compacting [] INFO [COMPACTION-POOL:1] 2010-08-16 19:05:08,741 CompactionManager.java (line 246) Compacting [] INFO [COMPACTION-POOL:1] 2010-08-16 20:05:08,718 CompactionManager.java (line 246) Compacting [] INFO [COMPACTION-POOL:1] 2010-08-16 21:05:08,694 CompactionManager.java (line 246) Compacting [] INFO [COMPACTION-POOL:1] 2010-08-16 22:05:08,674 CompactionManager.java (line 246) Compacting [] ****************************************************** At this point, I logged in. The data distribution on this node was 122GB. I started performing a manual nodetool cleanup. ******************************************************