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 A9B08D4DB for ; Thu, 8 Nov 2012 18:05:05 +0000 (UTC) Received: (qmail 46821 invoked by uid 500); 8 Nov 2012 18:05:03 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 46780 invoked by uid 500); 8 Nov 2012 18:05:03 -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 46769 invoked by uid 99); 8 Nov 2012 18:05:03 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 08 Nov 2012 18:05:03 +0000 X-ASF-Spam-Status: No, hits=1.5 required=5.0 tests=HTML_MESSAGE,RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of ailinykh@gmail.com designates 74.125.83.44 as permitted sender) Received: from [74.125.83.44] (HELO mail-ee0-f44.google.com) (74.125.83.44) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 08 Nov 2012 18:04:57 +0000 Received: by mail-ee0-f44.google.com with SMTP id d4so1961805eek.31 for ; Thu, 08 Nov 2012 10:04:36 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=5ffuEELACChS5CNZ7MVXYIqb9J4R3lgJOj0aXqQtFj4=; b=FQySaIxecT3INK3FnYR7c1l9+4zY1E62xq9+6rb9MizKOTKkN6rQ/sL+7HkciDLNaZ aJjtmMbvRaRiT8vZl2p9hqYWoOjRyc6UOCHl1QZvQrAakyhdwLH3Kv98qxw2M+/EGkNq w3ZcPfEACW1sZX6XcKkhlOrNWStuorG42o0kHy+FwypK9XaNVNLA/Dohl4AgLScS26sJ ZzuuRSMVROAx1NtEIfC/RmdD4f4+f1YEJ7umH+ADDfgfZmcD9TnEeaB5Do5/rK9K4H1J VwUcaTjgUOozOUpM12X4pED+9Cx008kauadqVsrj8dY4yWMAU194NHifyx16kayD255U cqOA== MIME-Version: 1.0 Received: by 10.14.0.68 with SMTP id 44mr30112992eea.1.1352397876378; Thu, 08 Nov 2012 10:04:36 -0800 (PST) Received: by 10.14.176.68 with HTTP; Thu, 8 Nov 2012 10:04:36 -0800 (PST) In-Reply-To: References: <274B0A13-59D2-4220-8711-36F370721DE4@co.sapo.pt> <4C258FB6-F8BF-43E2-B678-7BF8CECB2A49@co.sapo.pt> Date: Thu, 8 Nov 2012 10:04:36 -0800 Message-ID: Subject: Re: Strange delay in query From: Andrey Ilinykh To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=047d7b622822043bc104cdffab47 X-Virus-Checked: Checked by ClamAV on apache.org --047d7b622822043bc104cdffab47 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable What is the size of columns? Probably those two are huge. On Thu, Nov 8, 2012 at 4:01 AM, Andr=E9 Cruz wrote: > On Nov 7, 2012, at 12:15 PM, Andr=E9 Cruz wrote: > > > This error also happens on my application that uses pycassa, so I don't > think this is the same bug. > > I have narrowed it down to a slice between two consecutive columns. > Observe this behaviour using pycassa: > > >>> > DISCO_CASS.col_fam_nsrev.get(uuid.UUID('3cd88d97-ffde-44ca-8ae9-5336caaeb= c4e'), > column_count=3D2, > column_start=3Duuid.UUID('13957152-234b-11e2-92bc-e0db550199f4')).keys() > DEBUG 2012-11-08 11:55:51,170 pycassa_library.pool:30 6849 13992879126297= 6 > Connection 52905488 (xxx:9160) was checked out from pool 51715344 > DEBUG 2012-11-08 11:55:53,415 pycassa_library.pool:37 6849 13992879126297= 6 > Connection 52905488 (xxx:9160) was checked in to pool 51715344 > [UUID('13957152-234b-11e2-92bc-e0db550199f4'), > UUID('40b7ae4e-2449-11e2-8610-e0db550199f4')] > > A two column slice took more than 2s to return. If I request the next 2 > column slice: > > >>> > DISCO_CASS.col_fam_nsrev.get(uuid.UUID('3cd88d97-ffde-44ca-8ae9-5336caaeb= c4e'), > column_count=3D2, > column_start=3Duuid.UUID('40b7ae4e-2449-11e2-8610-e0db550199f4')).keys() > DEBUG 2012-11-08 11:57:32,750 pycassa_library.pool:30 6849 13992879126297= 6 > Connection 52904912 (xxx:9160) was checked out from pool 51715344 > DEBUG 2012-11-08 11:57:32,774 pycassa_library.pool:37 6849 13992879126297= 6 > Connection 52904912 (xxx:9160) was checked in to pool 51715344 > [UUID('40b7ae4e-2449-11e2-8610-e0db550199f4'), > UUID('a364b028-2449-11e2-8882-e0db550199f4')] > > This takes 20msec... Is there a rational explanation for this different > behaviour? Is there some threshold that I'm running into? Is there any wa= y > to obtain more debugging information about this problem? > > Thanks, > Andr=E9 --047d7b622822043bc104cdffab47 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable What is the size of columns? Probably those two are huge.


On Thu, Nov 8, 2012 at 4:01 AM,= Andr=E9 Cruz <andre.cruz@co.sapo.pt> wrote:
On Nov 7, 2012, at 12:15 PM, Andr=E9 Cruz &l= t;andre.cruz@co.sapo.pt> wr= ote:

> This error also happens on my application that uses pycassa, so I don&= #39;t think this is the same bug.

I have narrowed it down to a slice between two consecutive columns. Observe= this behaviour using pycassa:

>>> DISCO_CASS.col_fam_nsrev.get(uuid.UUID('3cd88d97-ffde-44ca= -8ae9-5336caaebc4e'), column_count=3D2, column_start=3Duuid.UUID('1= 3957152-234b-11e2-92bc-e0db550199f4')).keys()
DEBUG 2012-11-08 11:55:51,170 pycassa_library.pool:30 6849 139928791262976 = Connection 52905488 (xxx:9160) was checked out from pool 51715344
DEBUG 2012-11-08 11:55:53,415 pycassa_library.pool:37 6849 139928791262976 = Connection 52905488 (xxx:9160) was checked in to pool 51715344
[UUID('13957152-234b-11e2-92bc-e0db550199f4'), UUID('40b7ae4e-2= 449-11e2-8610-e0db550199f4')]

A two column slice took more than 2s to return. If I request the next 2 col= umn slice:

>>> DISCO_CASS.col_fam_nsrev.get(uuid.UUID('3cd88d97-ffde-44ca= -8ae9-5336caaebc4e'), column_count=3D2, column_start=3Duuid.UUID('4= 0b7ae4e-2449-11e2-8610-e0db550199f4')).keys()
DEBUG 2012-11-08 11:57:32,750 pycassa_library.pool:30 6849 139928791262976 = Connection 52904912 (xxx:9160) was checked out from pool 51715344
DEBUG 2012-11-08 11:57:32,774 pycassa_library.pool:37 6849 139928791262976 = Connection 52904912 (xxx:9160) was checked in to pool 51715344
[UUID('40b7ae4e-2449-11e2-8610-e0db550199f4'), UUID('a364b028-2= 449-11e2-8882-e0db550199f4')]

This takes 20msec... Is there a rational explanation for this different beh= aviour? Is there some threshold that I'm running into? Is there any way= to obtain more debugging information about this problem?

Thanks,
Andr=E9

--047d7b622822043bc104cdffab47--