From cassandra-user-return-468-apmail-incubator-cassandra-user-archive=incubator.apache.org@incubator.apache.org Wed Aug 19 21:43:17 2009 Return-Path: Delivered-To: apmail-incubator-cassandra-user-archive@minotaur.apache.org Received: (qmail 17006 invoked from network); 19 Aug 2009 21:43:17 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 19 Aug 2009 21:43:17 -0000 Received: (qmail 87396 invoked by uid 500); 19 Aug 2009 21:43:36 -0000 Delivered-To: apmail-incubator-cassandra-user-archive@incubator.apache.org Received: (qmail 87372 invoked by uid 500); 19 Aug 2009 21:43:36 -0000 Mailing-List: contact cassandra-user-help@incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: cassandra-user@incubator.apache.org Delivered-To: mailing list cassandra-user@incubator.apache.org Received: (qmail 87360 invoked by uid 99); 19 Aug 2009 21:43:36 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 19 Aug 2009 21:43:36 +0000 X-ASF-Spam-Status: No, hits=1.5 required=10.0 tests=SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: domain of jbellis@gmail.com designates 209.85.219.208 as permitted sender) Received: from [209.85.219.208] (HELO mail-ew0-f208.google.com) (209.85.219.208) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 19 Aug 2009 21:43:27 +0000 Received: by ewy4 with SMTP id 4so1202231ewy.27 for ; Wed, 19 Aug 2009 14:43:07 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:in-reply-to:references :date:message-id:subject:from:to:content-type :content-transfer-encoding; bh=bbPpn+ozTdJmDwyx4FOEalfiNmQ5HCjzFI4A8pGpLTU=; b=fG9rfYDIxrEBZ5tPTrT1C3B0+VxMtIhQj77BCLMrdUjqQ2sPHpkc1Pxq6UCRYOBh08 FoDtLlWEZjkAmf3vHBemLWo/qMOBDoRZEeeiHrVEy7pFAuw0wOqRLNJYQn/EjQl1tD8i dZLSixJ1LreoeMkbdfF4f3gSORKiM5jmG+HbI= 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:content-transfer-encoding; b=ZyOTrDXYmveAsZkLZGUfueB6R2jfNRhmF/sn6In97tFvYQsiyj2NrdW6AST6o0DRJP svT4IsH7TEeSnYajfABxwlix90px/Ft5Aho+f86/3Xl8NyHve7AqwSeJd4EFdQGz3VDK w8GMmcxJfyPNdunws9EBCBafi5pfRb1eQYSWY= MIME-Version: 1.0 Received: by 10.216.25.209 with SMTP id z59mr1670614wez.204.1250718187102; Wed, 19 Aug 2009 14:43:07 -0700 (PDT) In-Reply-To: <18D28A58-4E5F-40F2-8F84-4A6D5E1AF1CD@digitalreasoning.com> References: <18D28A58-4E5F-40F2-8F84-4A6D5E1AF1CD@digitalreasoning.com> Date: Wed, 19 Aug 2009 14:43:07 -0700 Message-ID: Subject: Re: quorum read timeout From: Jonathan Ellis To: cassandra-user@incubator.apache.org Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable X-Virus-Checked: Checked by ClamAV on apache.org Is this 0.3 or 0.4/trunk? On Wed, Aug 19, 2009 at 2:36 PM, Phillip Michalak wrote: > I'm running three Cassandra nodes in virtual machines. > During a 'get' operation from Cassandra-remote directed at one of these > nodes, I'm receiving the following output > > vadmin@vadmin:~/cassandra$ interface/gen-py/cassandra/Cassandra-remote -h > 192.168.133.130:9160 get 'MockElementLibrary' '0401318uuuuruepwdcznr' > "ColumnPath('strings', None, 'id')" 2 > /usr/local/lib/python2.6/dist-packages/thrift/Thrift.py:58: > DeprecationWarning: BaseException.message has been deprecated as of Pytho= n > 2.6 > =A0=A0self.message =3D message > /usr/local/lib/python2.6/dist-packages/thrift/Thrift.py:99: > DeprecationWarning: BaseException.message has been deprecated as of Pytho= n > 2.6 > =A0=A0self.message =3D iprot.readString(); > Traceback (most recent call last): > =A0=A0File "interface/gen-py/cassandra/Cassandra-remote", line 93, in > =A0=A0 =A0pp.pprint(client.get(args[0],args[1],eval(args[2]),eval(args[3]= ),)) > =A0=A0File > "/home/vadmin/cassandra-0.4.0-beta1/interface/gen-py/cassandra/Cassandra.= py", > line 182, in get > =A0=A0 =A0return self.recv_get() > =A0=A0File > "/home/vadmin/cassandra-0.4.0-beta1/interface/gen-py/cassandra/Cassandra.= py", > line 201, in recv_get > =A0=A0 =A0raise x > thrift.Thrift.TApplicationException/usr/local/lib/python2.6/dist-packages= /thrift/Thrift.py:76: > DeprecationWarning: BaseException.message has been deprecated as of Pytho= n > 2.6 > =A0=A0if self.message: > /usr/local/lib/python2.6/dist-packages/thrift/Thrift.py:77: > DeprecationWarning: BaseException.message has been deprecated as of Pytho= n > 2.6 > =A0=A0return self.message > : Internal error processing get > > The same 'get' operation from Cassandra-remote directed at another of the= se > nodes, yields 'normal' output > vadmin@vadmin:~/cassandra$ interface/gen-py/cassandra/Cassandra-remote -h > 192.168.133.129:9160 get 'MockElementLibrary' '0401318uuuuruepwdcznr' > "ColumnPath('strings', None, 'id')" 2 > Traceback (most recent call last): > =A0=A0File "interface/gen-py/cassandra/Cassandra-remote", line 93, in > =A0=A0 =A0pp.pprint(client.get(args[0],args[1],eval(args[2]),eval(args[3]= ),)) > =A0=A0File > "/home/vadmin/cassandra-0.4.0-beta1/interface/gen-py/cassandra/Cassandra.= py", > line 182, in get > =A0=A0 =A0return self.recv_get() > =A0=A0File > "/home/vadmin/cassandra-0.4.0-beta1/interface/gen-py/cassandra/Cassandra.= py", > line 210, in recv_get > =A0=A0 =A0raise result.nfe > ttypes.NotFoundException: NotFoundException() > Furthermore, querying the same column for (some) other keys is successful > when no matter which node it is directed at. > Looking at the log for the node that produced the error from the query > above: > > DEBUG [pool-1-thread-22] 2009-08-19 16:54:57,618 CassandraServer.java (li= ne > 221) get > DEBUG [pool-1-thread-22] 2009-08-19 16:54:57,618 StorageProxy.java (line > 420) strongread reading data for > SliceByNamesReadCommand(table=3D'MockElementLibrary', > key=3D'0401318uuuuruepwdcznr', > columnParent=3D'QueryPath(columnFamilyName=3D'strings', superColumnName= =3D'null', > columnName=3D'null')', columns=3D[id,]) from 38184@null > DEBUG [pool-1-thread-22] 2009-08-19 16:54:57,619 StorageProxy.java (line > 427) strongread reading digest for > SliceByNamesReadCommand(table=3D'MockElementLibrary', > key=3D'0401318uuuuruepwdcznr', > columnParent=3D'QueryPath(columnFamilyName=3D'strings', superColumnName= =3D'null', > columnName=3D'null')', columns=3D[id,]) from=A038185@192.168.133.129:7000 > =A0WARN [MESSAGE-SERIALIZER-POOL:4] 2009-08-19 16:54:57,619 > MessageSerializationTask.java (line 81) Exception was generated at : > 08/19/2009 16:54:57 on thread MESSAGE-SERIALIZER-POOL:4 > java.lang.NullPointerException > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.net.TcpConnection.(TcpConnection.java:83) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.net.TcpConnectionManager.getConnection(TcpConnection= Manager.java:64) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.net.MessagingService.getConnection(MessagingService.= java:306) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.net.MessageSerializationTask.run(MessageSerializatio= nTask.java:66) > =A0=A0 =A0 =A0 =A0at > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor= .java:886) > =A0=A0 =A0 =A0 =A0at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.jav= a:908) > =A0=A0 =A0 =A0 =A0at java.lang.Thread.run(Thread.java:619) > DEBUG [RESPONSE-STAGE:4] 2009-08-19 16:54:57,622 ResponseVerbHandler.java > (line 38) Processing response on a callback > from=A065B1E352-A0A3-1A7F-138B-9BEA3E1D787F@192.168.133.129:7000 > ERROR [pool-1-thread-22] 2009-08-19 16:55:02,619 Cassandra.java (line 608= ) > Internal error processing get > java.lang.RuntimeException: java.util.concurrent.TimeoutException: Operat= ion > timed out - received only 1 responses from 192.168.133.129:7000 . > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.CassandraServer.readColumnFamily(CassandraSe= rver.java:100) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.CassandraServer.get(CassandraServer.java:226= ) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.Cassandra$Processor$get.process(Cassandra.ja= va:602) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.Cassandra$Processor.process(Cassandra.java:5= 60) > =A0=A0 =A0 =A0 =A0at > org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolS= erver.java:252) > =A0=A0 =A0 =A0 =A0at > java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor= .java:886) > =A0=A0 =A0 =A0 =A0at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.jav= a:908) > =A0=A0 =A0 =A0 =A0at java.lang.Thread.run(Thread.java:619) > Caused by: java.util.concurrent.TimeoutException: Operation timed out - > received only 1 responses from 192.168.133.129:7000 . > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.QuorumResponseHandler.get(QuorumResponseHand= ler.java:86) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.StorageProxy.strongRead(StorageProxy.java:43= 5) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.StorageProxy.readProtocol(StorageProxy.java:= 330) > =A0=A0 =A0 =A0 =A0at > org.apache.cassandra.service.CassandraServer.readColumnFamily(CassandraSe= rver.java:92) > =A0=A0 =A0 =A0 =A0... 7 more > > It appears to me that there is a timeout during the QuorumResponseHandler > processing, stemming from a NullPointerException that occurs as part of t= he > read process. I suspect that this NullPointerException has something to d= o > with the second DEBUG [pool-1-thread-22] comment regarding strongread ... > from 38184@null. > Does anyone know why this might be happening? > Thanks for any insight, > Phil >