Mailing-List: contact cassandra-user-help@incubator.apache.org; run by ezmlm
Precedence: bulk
Reply-To: cassandra-user@incubator.apache.org
Received-SPF: pass (athena.apache.org: domain of rrabah@playdom.com designates
 74.125.149.67 as permitted sender)
MIME-Version: 1.0
In-Reply-To: <e06563880912161207n298a58bfjc47129cfeb852254@mail.gmail.com>
References: <a1625f290912161046v91e13a6n97f1848144ff5286@mail.gmail.com>
	 <e06563880912161207n298a58bfjc47129cfeb852254@mail.gmail.com>
Date: Thu, 17 Dec 2009 08:55:14 -0800
Message-ID: <a1625f290912170855q3721f6d0r9c7caeabcd6a2216@mail.gmail.com>
Subject: Re: TimedOutException
From: Ramzi Rabah <rrabah@playdom.com>
To: cassandra-user@incubator.apache.org
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

I added some debugging code to capture the time a read takes
(getColumnFamily) and the time the road trip weakRemoteRead takes.
The time it takes to read columns is negligible, so it doesn't seem a
problem with getColumnFamily. The time it takes for weakRemoteRead
however is > 5 seconds in some cases. So looking at some more
debugging output,
the log indicates that the packets are in the process of being sent by
weakRemoteRead to the correct target node, but for some reason, the
target node does not have any reference
in the log that it handled the get at all.

Couple other things to note:
1- I restarted the nodes one after another, while there was traffic
going to them. Don't know if that will throw off cassandra or that the
whole thing is a network congestion problem?
2- Read stats on the keyspace level indicate NaN value for Read
latency which seems like a bug?

Thanks
Ramzi

On Wed, Dec 16, 2009 at 12:07 PM, Jonathan Ellis <jbellis@gmail.com> wrote:
> On Wed, Dec 16, 2009 at 12:46 PM, Ramzi Rabah <rrabah@playdom.com> wrote:
>> We are observing increasing number of TimedOutExceptions in cassandra
>> 0.5 trunk although the load seems fairly low (about 400 reads/writes
>> per second).
>> cfstats reports that operations are taking less than 2 ms on average.
>>
>> 2 Things I have noticed looking at the source code.
>>
>> 1- TimedOutExceptions are silently swallowed by Cassandra and not
>> reported in the logs even at debug level
>
> It's reported to the client. =A0Hardly "swallowed" :)
>
>> 2- readstats does not account for these long time running queries that
>> time out.
>
> Right. =A0But the CF-level stats do.
>
>> I'm wondering, what could be causing the system to go haywire like
>> this?
>
> Hard to say without more information. =A0One shot in the dark is that
> get_key_range is a major offender sometimes, as well as workloads that
> do lots of deletes + re-inserts for the same keys.
>
> -Jonathan
>