Return-Path: Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: (qmail 46447 invoked from network); 16 Oct 2010 11:51:08 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 16 Oct 2010 11:51:08 -0000 Received: (qmail 30305 invoked by uid 500); 16 Oct 2010 11:51:06 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 30191 invoked by uid 500); 16 Oct 2010 11:51: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 30182 invoked by uid 99); 16 Oct 2010 11:51:01 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 16 Oct 2010 11:51:01 +0000 X-ASF-Spam-Status: No, hits=4.4 required=10.0 tests=FREEMAIL_ENVFROM_END_DIGIT,FREEMAIL_FROM,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS,T_TO_NO_BRKTS_FREEMAIL X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of wav100@gmail.com designates 209.85.213.172 as permitted sender) Received: from [209.85.213.172] (HELO mail-yx0-f172.google.com) (209.85.213.172) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 16 Oct 2010 11:50:55 +0000 Received: by yxk30 with SMTP id 30so850017yxk.31 for ; Sat, 16 Oct 2010 04:50:35 -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=OvscSuj9XwrUThjCFoj8Dpa05PyDDS4b+u6eSXfIjrk=; b=OEB74xK9u3zk0491BQvMbA9Y3wfOwcbcxC6WrmFYIkvFosolmeW0jza9w8yeAh7SQH pVNRIb0P/uIvt5hI1XccAA2F8x2izV4VOrpKSZ9aLqLDrKoVC5GOkNiLg/mq1k7X+16f DIEABeadaYJtjVFC2HgJQgIygjbZ/0IvhMg4k= 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=pH/TG5ClP5LTIQApiPEo+8KF47/rH7seXYFdzNQHAbxu2xwAsbATRJGmkfUz90Bp2z SN1RKIyet/2H4bsNRe22FD5BOquIau1n7s4aSiPSiFIeIup+CrZpXCXmbi3MA6kaM5Fq ZqPoAD9sFSiSxE2GXJF8UJJtxYvI7vVXvmLxY= MIME-Version: 1.0 Received: by 10.101.142.15 with SMTP id u15mr838656ann.156.1287229834523; Sat, 16 Oct 2010 04:50:34 -0700 (PDT) Received: by 10.100.108.6 with HTTP; Sat, 16 Oct 2010 04:50:34 -0700 (PDT) In-Reply-To: References: Date: Sat, 16 Oct 2010 07:50:34 -0400 Message-ID: Subject: Re: Read Latency From: Wayne To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=0016e68fd07307f51b0492ba8d42 --0016e68fd07307f51b0492ba8d42 Content-Type: text/plain; charset=ISO-8859-1 While doing a read I get a TApplicationException: Internal Error processing get_slice. On Fri, Oct 15, 2010 at 5:49 PM, Jonathan Ellis wrote: > On Fri, Oct 15, 2010 at 2:21 PM, Wayne wrote: > > The optimization definitely shaved off some time. Now it is running about > 3x > > CFSTATS reported time. Below are the logs. > > > > There is a ~300ms time frame after the last ResponseVerbHandler prior to > the > > resolver starting. Based on a quorum read the response resolver should > kick > > after 2 reads come in correct? That would mean it waited 500ms before > > starting. Where is this time going? > > It's going to deserialize the replies to see if it has both the data > and enough digests to call resolve(). Then resolve deserializes them > a 2nd time, so there's an easy win there caching the first > deserialize, in the patch attached. (Applies on top of the previous > one, which has been committed to the 0.6 svn branch at > https://svn.apache.org/repos/asf/cassandra/branches/cassandra-0.6.) > > > There is still the 3+ second delay between the last 2 entries. Is this > the > > thrift server? > > It's converting the reply from Cassandra's internal representation to > thrift, and sending it to the client. I suspect most of the time is > the actual sending/waiting for the client to read part. Patch 2 also > includes a debug statement after the convert-to-thrift stage to > verify. > > -- > Jonathan Ellis > Project Chair, Apache Cassandra > co-founder of Riptano, the source for professional Cassandra support > http://riptano.com > --0016e68fd07307f51b0492ba8d42 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable While doing a read I get a TApplicationException: Internal Error processing= get_slice.

On Fri, Oct 15, 2010 at 5:49 = PM, Jonathan Ellis <jbellis@gmail.com> wrote:
On Fri, Oct 15, 2010 at 2:21 PM, Wayne <wav100@gmail.com> wrote:
> The optimization definitely shaved off some time. Now it is running ab= out 3x
> CFSTATS reported time. Below are the logs.
>
> There is a ~300ms time frame after the last ResponseVerbHandler prior = to the
> resolver starting. Based on a quorum read the response resolver should= kick
> after 2 reads come in correct? That would mean it waited 500ms before<= br> > starting. Where is this time going?

It's going to deserialize the replies to see if it has both the d= ata
and enough digests to call resolve(). =A0Then resolve deserializes them
a 2nd time, so there's an easy win there caching the first
deserialize, in the patch attached. =A0(Applies on top of the previous
one, which has been committed to the 0.6 svn branch at
https://svn.apache.org/repos/asf/cassandra/branches/ca= ssandra-0.6.)

> There is still the 3+ second delay between the last 2 entries. Is this= the
> thrift server?

It's converting the reply from Cassandra's internal represent= ation to
thrift, and sending it to the client. =A0I suspect most of the time is
the actual sending/waiting for the client to read part. =A0Patch 2 also
includes a debug statement after the convert-to-thrift stage to
verify.

--
Jonathan Ellis
Project Chair, Apache Cassandra
co-founder of Riptano, the source for professional Cassandra support
http://riptano.com

--0016e68fd07307f51b0492ba8d42--