Return-Path: X-Original-To: apmail-cassandra-user-archive@www.apache.org Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id EDBC0F97F for ; Fri, 22 Mar 2013 16:43:04 +0000 (UTC) Received: (qmail 17568 invoked by uid 500); 22 Mar 2013 16:43:02 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 17543 invoked by uid 500); 22 Mar 2013 16:43:02 -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 17535 invoked by uid 99); 22 Mar 2013 16:43:02 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 22 Mar 2013 16:43:02 +0000 X-ASF-Spam-Status: No, hits=2.2 required=5.0 tests=HTML_MESSAGE,RCVD_IN_DNSWL_LOW,SPF_NEUTRAL X-Spam-Check-By: apache.org Received-SPF: neutral (nike.apache.org: local policy) Received: from [209.85.220.173] (HELO mail-vc0-f173.google.com) (209.85.220.173) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 22 Mar 2013 16:42:56 +0000 Received: by mail-vc0-f173.google.com with SMTP id gd11so3307231vcb.32 for ; Fri, 22 Mar 2013 09:42:34 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=mime-version:x-received:sender:x-originating-ip:in-reply-to :references:date:x-google-sender-auth:message-id:subject:from:to :content-type:x-gm-message-state; bh=JRycySCfQyhP2JViLE3Hwbn3DCu+6g54EV18fHQtgdA=; b=Mvc2lETxhIqg2xoo6v2n4XZH5hGbQvlQoudp457zmA9cxRkyvsHfmgOnmtExYwHUIl XXsv1HPZuRzZA6bMoCiFO6KKBwdMv9lbVrOef76wplaA/UkIIzIMJ+P6ni1zSty3mxTL Tk0S+CV79ifocrmnQRkgZrdgH6kgLE5izdvT4Pn/gBBprX9dYC6RRdUKm37VTfeGSpYR PNMHfq9iGVWxTAVAc8duU5SP86bpQCeBmCrtpZ5id/0PMCS4wkYAp+IM9VUEYqUKT4C7 sodE8Tgjgyme3XXdBnBHJM6sVSKiNJOx3LphzKPz8RUkN3etIZswHfFheoNpaB31D3lI IcDw== MIME-Version: 1.0 X-Received: by 10.52.26.209 with SMTP id n17mr2771496vdg.26.1363970554466; Fri, 22 Mar 2013 09:42:34 -0700 (PDT) Sender: zodiak@fifth-aeon.net Received: by 10.52.180.42 with HTTP; Fri, 22 Mar 2013 09:42:34 -0700 (PDT) X-Originating-IP: [67.188.154.177] In-Reply-To: References: <57C7C3CBDCB04F45A57AEC4CB21C0CCD1DB64478@mbx024-e1-nj-6.exch024.domain.local> Date: Fri, 22 Mar 2013 09:42:34 -0700 X-Google-Sender-Auth: cqv_eK0jdizexufon2o5yz0kmYs Message-ID: Subject: Re: High disk I/O during reads From: Jon Scarborough To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=20cf3079c100622bd704d8862466 X-Gm-Message-State: ALoCoQlJ/Q2dWazPu58CDSY+rK3nA/ekS35KFQ+h7H8Y3i5EyOVa5BxySkSigpCR9eWKvkA0StDa X-Virus-Checked: Checked by ClamAV on apache.org --20cf3079c100622bd704d8862466 Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: quoted-printable Key distribution across probably varies a lot from row to row in our case. Most reads would probably only need to look at a few SSTables, a few might need to look at more. I don't yet have a deep understanding of C* internals, but I would imagine even the more expensive use cases would involve something like this: 1) Check the index for each SSTable to determine if part of the row is there. 2) Look at the endpoints of the slice to determine if the data in a particular SSTable is relevant to the query. 3) Read the chunks of those SSTables, working backwards from the end of the slice until enough columns have been read to satisfy the limit clause in the query. So I would have guessed that even the more expensive queries on wide rows typically wouldn't need to read more than a few hundred KB from disk to do all that. Seems like I'm missing something major. Here's the complete CF definition, including compression settings: CREATE COLUMNFAMILY conversation_text_message ( conversation_key bigint PRIMARY KEY ) WITH comment=3D'' AND comparator=3D'CompositeType(org.apache.cassandra.db.marshal.DateType,org.ap= ache.cassandra.db.marshal.LongType,org.apache.cassandra.db.marshal.AsciiTyp= e,org.apache.cassandra.db.marshal.AsciiType)' AND read_repair_chance=3D0.100000 AND gc_grace_seconds=3D864000 AND default_validation=3Dtext AND min_compaction_threshold=3D4 AND max_compaction_threshold=3D32 AND replicate_on_write=3DTrue AND compaction_strategy_class=3D'SizeTieredCompactionStrategy' AND compression_parameters:sstable_compression=3D'org.apache.cassandra.io.compr= ess.SnappyCompressor'; Much thanks for any additional ideas. -Jon On Fri, Mar 22, 2013 at 8:15 AM, Hiller, Dean wrote: > Did you mean to ask "are 'all' your keys spread across all SSTables"? I > am guessing at your intention. > > I mean I would very well hope my keys are spread across all sstables or > otherwise that sstable should not be there as he has no keys in it ;). > > And I know we had HUGE disk size from the duplication in our sstables on > size-tiered compaction=85.we never ran a major compaction but after we > switched to LCS, we went from 300G to some 120G or something like that > which was nice. We only have 300 data point posts / second so not an > extreme write load on 6 nodes as well though these posts causes read to > check authorization and such of our system. > > Dean > > From: Kanwar Sangha > > Reply-To: "user@cassandra.apache.org" < > user@cassandra.apache.org> > Date: Friday, March 22, 2013 8:38 AM > To: "user@cassandra.apache.org" < > user@cassandra.apache.org> > Subject: RE: High disk I/O during reads > > Are your Keys spread across all SSTables ? That will cause every sstable > read which will increase the I/O. > > What compaction are you using ? > > From: zodiak@fifth-aeon.net [mailto: > zodiak@fifth-aeon.net] On Behalf Of Jon Scarborough > Sent: 21 March 2013 23:00 > To: user@cassandra.apache.org > Subject: High disk I/O during reads > > Hello, > > We've had a 5-node C* cluster (version 1.1.0) running for several months. > Up until now we've mostly been writing data, but now we're starting to > service more read traffic. We're seeing far more disk I/O to service the= se > reads than I would have anticipated. > > The CF being queried consists of chat messages. Each row represents a > conversation between two people. Each column represents a message. The > column key is composite, consisting of the message date and a few other > bits of information. The CF is using compression. > > The query is looking for a maximum of 50 messages between two dates, in > reverse order. Usually the two dates used as endpoints are 30 days ago a= nd > the current time. The query in Astyanax looks like this: > > ColumnList result =3D > keyspace.prepareQuery(CF_CONVERSATION_TEXT_MESSAGE) > .setConsistencyLevel(ConsistencyLevel.CL_QUORUM) > .getKey(conversationKey) > .withColumnRange( > textMessageSerializer.makeEndpoint(endDate, > Equality.LESS_THAN).toBytes(), > textMessageSerializer.makeEndpoint(startDate, > Equality.GREATER_THAN_EQUALS).toBytes(), > true, > maxMessages) > .execute() > .getResult(); > > We're currently servicing around 30 of these queries per second. > > Here's what the cfstats for the CF look like: > > Column Family: conversation_text_message > SSTable count: 15 > Space used (live): 211762982685 > Space used (total): 211762982685 > Number of Keys (estimate): 330118528 > Memtable Columns Count: 68063 > Memtable Data Size: 53093938 > Memtable Switch Count: 9743 > Read Count: 4313344 > Read Latency: 118.831 ms. > Write Count: 817876950 > Write Latency: 0.023 ms. > Pending Tasks: 0 > Bloom Filter False Postives: 6055 > Bloom Filter False Ratio: 0.00260 > Bloom Filter Space Used: 686266048 > Compacted row minimum size: 87 > Compacted row maximum size: 14530764 > Compacted row mean size: 1186 > > On the C* nodes, iostat output like this is typical, and can spike to be > much worse: > > avg-cpu: %user %nice %system %iowait %steal %idle > 1.91 0.00 2.08 30.66 0.50 64.84 > > Device: tps kB_read/s kB_wrtn/s kB_read kB_wrtn > xvdap1 0.13 0.00 1.07 0 16 > xvdb 474.20 13524.53 25.33 202868 380 > xvdc 469.87 13455.73 30.40 201836 456 > md0 972.13 26980.27 55.73 404704 836 > > Any thoughts on what could be causing read I/O to the disk from these > queries? > > Much thanks! > > -Jon > --20cf3079c100622bd704d8862466 Content-Type: text/html; charset=windows-1252 Content-Transfer-Encoding: quoted-printable Key distribution across probably varies a lot from row to row in our case.= =A0 Most reads would probably only need to look at a few SSTables, a few mi= ght need to look at more.

I don't yet have a deep understanding = of C* internals, but I would imagine even the more expensive use cases woul= d involve something like this:

1) Check the index for each SSTable to determine if part of the row is = there.
2) Look at the endpoints of the slice to determine if the data in= a particular SSTable is relevant to the query.
3) Read the chunks of th= ose SSTables, working backwards from the end of the slice until enough colu= mns have been read to satisfy the limit clause in the query.

So I would have guessed that even the more expensive queries on wide ro= ws typically wouldn't need to read more than a few hundred KB from disk= to do all that.=A0 Seems like I'm missing something major.

Here= 's the complete CF definition, including compression settings:

CREATE COLUMNFAMILY conversation_text_message (
=A0 conversation_key= bigint PRIMARY KEY
) WITH
=A0 comment=3D'' AND
=A0 compar= ator=3D'CompositeType(org.apache.cassandra.db.marshal.DateType,org.apac= he.cassandra.db.marshal.LongType,org.apache.cassandra.db.marshal.AsciiType,= org.apache.cassandra.db.marshal.AsciiType)' AND
=A0 read_repair_chance=3D0.100000 AND
=A0 gc_grace_seconds=3D864000 AND<= br>=A0 default_validation=3Dtext AND
=A0 min_compaction_threshold=3D4 AN= D
=A0 max_compaction_threshold=3D32 AND
=A0 replicate_on_write=3DTrue= AND
=A0 compaction_strategy_class=3D'SizeTieredCompactionStrategy&#= 39; AND
=A0 compression_parameters:sstable_compression=3D'org.apache.cassandra.= io.compress.SnappyCompressor';

Much thanks for any additional id= eas.

-Jon


On Fri, Mar 22, 2013= at 8:15 AM, Hiller, Dean <Dean.Hiller@nrel.gov> wrote:
Did you mean to ask "are 'all' = your keys spread across all SSTables"? =A0I am guessing at your intent= ion.

I mean I would very well hope my keys are spread across all sstables or oth= erwise that sstable should not be there as he has no keys in it ;).

And I know we had HUGE disk size from the duplication in our sstables on si= ze-tiered compaction=85.we never ran a major compaction but after we switch= ed to LCS, we went from 300G to some 120G or something like that which was = nice. =A0We only have 300 data point posts / second so not an extreme write= load on 6 nodes as well though these posts causes read to check authorizat= ion and such of our system.

Dean

From: Kanwar Sangha <kanwar@maveni= r.com<mailto:kanwar@mavenir.co= m>>
Reply-To: "user@cassandra= .apache.org<mailto:user= @cassandra.apache.org>" <user@cassandra.apache.org<mailto:user@cassandra.apache.org>>
Date: Friday, March 22, 2013 8:38 AM
To: "user@cassandra.apach= e.org<mailto:user@cassa= ndra.apache.org>" <user@cassandra.apache.org<mailto:user@cassandra.apache.org>>
Subject: RE: High disk I/O during reads

Are your Keys spread across all SSTables ? That will cause every sstable re= ad which will increase the I/O.

What compaction are you using ?

From: zodiak@fifth-aeon.net<= /a><mailto:zodiak@fifth-aeon.ne= t> [mailto:zodiak@fifth-aeo= n.net] On Behalf Of Jon Scarborough
Sent: 21 March 2013 23:00
To: user@cassandra.apach= e.org<mailto:user@cassa= ndra.apache.org>
Subject: High disk I/O during reads=

Hello,

We've had a 5-node C* cluster (version 1.1.0) running for several month= s. =A0Up until now we've mostly been writing data, but now we're st= arting to service more read traffic. =A0We're seeing far more disk I/O = to service these reads than I would have anticipated.

The CF being queried consists of chat messages. =A0Each row represents a co= nversation between two people. =A0Each column represents a message. =A0The = column key is composite, consisting of the message date and a few other bit= s of information. =A0The CF is using compression.

The query is looking for a maximum of 50 messages between two dates, in rev= erse order. =A0Usually the two dates used as endpoints are 30 days ago and = the current time. =A0The query in Astyanax looks like this:

=A0 =A0 =A0 =A0 =A0 =A0 ColumnList<ConversationTextMessageKey> result= =3D keyspace.prepareQuery(CF_CONVERSATION_TEXT_MESSAGE)
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 .setConsistencyLevel(ConsistencyLev= el.CL_QUORUM)
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 .getKey(conversationKey)
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 .withColumnRange(
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 textMessageSerializ= er.makeEndpoint(endDate, Equality.LESS_THAN).toBytes(),
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 textMessageSerializ= er.makeEndpoint(startDate, Equality.GREATER_THAN_EQUALS).toBytes(),
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 true,
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 maxMessages)
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 .execute()
=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 .getResult();

We're currently servicing around 30 of these queries per second.

Here's what the cfstats for the CF look like:

=A0 =A0 =A0 =A0 Column Family: conversation_text_message
=A0 =A0 =A0 =A0 SSTable count: 15
=A0 =A0 =A0 =A0 Space used (live): 211762982685
=A0 =A0 =A0 =A0 Space used (total): 211762982685
=A0 =A0 =A0 =A0 Number of Keys (estimate): 330118528
=A0 =A0 =A0 =A0 Memtable Columns Count: 68063
=A0 =A0 =A0 =A0 Memtable Data Size: 53093938
=A0 =A0 =A0 =A0 Memtable Switch Count: 9743
=A0 =A0 =A0 =A0 Read Count: 4313344
=A0 =A0 =A0 =A0 Read Latency: 118.831 ms.
=A0 =A0 =A0 =A0 Write Count: 817876950
=A0 =A0 =A0 =A0 Write Latency: 0.023 ms.
=A0 =A0 =A0 =A0 Pending Tasks: 0
=A0 =A0 =A0 =A0 Bloom Filter False Postives: 6055
=A0 =A0 =A0 =A0 Bloom Filter False Ratio: 0.00260
=A0 =A0 =A0 =A0 Bloom Filter Space Used: 686266048
=A0 =A0 =A0 =A0 Compacted row minimum size: 87
=A0 =A0 =A0 =A0 Compacted row maximum size: 14530764
=A0 =A0 =A0 =A0 Compacted row mean size: 1186

On the C* nodes, iostat output like this is typical, and can spike to be mu= ch worse:

avg-cpu: =A0%user =A0 %nice %system %iowait =A0%steal =A0 %idle
=A0 =A0 =A0 =A0 =A0 =A01.91 =A0 =A00.00 =A0 =A02.08 =A0 30.66 =A0 =A00.50 = =A0 64.84

Device: =A0 =A0 =A0 =A0 =A0 =A0tps =A0 =A0kB_read/s =A0 =A0kB_wrtn/s =A0 = =A0kB_read =A0 =A0kB_wrtn
xvdap1 =A0 =A0 =A0 =A0 =A0 =A00.13 =A0 =A0 =A0 =A0 0.00 =A0 =A0 =A0 =A0 1.0= 7 =A0 =A0 =A0 =A0 =A00 =A0 =A0 =A0 =A0 16
xvdb =A0 =A0 =A0 =A0 =A0 =A0474.20 =A0 =A0 13524.53 =A0 =A0 =A0 =A025.33 = =A0 =A0 202868 =A0 =A0 =A0 =A0380
xvdc =A0 =A0 =A0 =A0 =A0 =A0469.87 =A0 =A0 13455.73 =A0 =A0 =A0 =A030.40 = =A0 =A0 201836 =A0 =A0 =A0 =A0456
md0 =A0 =A0 =A0 =A0 =A0 =A0 972.13 =A0 =A0 26980.27 =A0 =A0 =A0 =A055.73 = =A0 =A0 404704 =A0 =A0 =A0 =A0836

Any thoughts on what could be causing read I/O to the disk from these queri= es?

Much thanks!

-Jon

--20cf3079c100622bd704d8862466--