Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 3DDDB200BE5 for ; Sat, 24 Dec 2016 13:16:31 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 3C5EC160B2F; Sat, 24 Dec 2016 12:16:31 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 12697160B2B for ; Sat, 24 Dec 2016 13:16:29 +0100 (CET) Received: (qmail 82323 invoked by uid 500); 24 Dec 2016 12:16:28 -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 82313 invoked by uid 99); 24 Dec 2016 12:16:28 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 24 Dec 2016 12:16:28 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id F1A94180233 for ; Sat, 24 Dec 2016 12:16:27 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 1.679 X-Spam-Level: * X-Spam-Status: No, score=1.679 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, HTML_MESSAGE=2, RCVD_IN_DNSWL_LOW=-0.7, RCVD_IN_MSPIKE_H3=-0.01, RCVD_IN_MSPIKE_WL=-0.01, RCVD_IN_SORBS_SPAM=0.5, SPF_PASS=-0.001] autolearn=disabled Authentication-Results: spamd3-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id sV2kz4gEwQuL for ; Sat, 24 Dec 2016 12:16:25 +0000 (UTC) Received: from mail-it0-f53.google.com (mail-it0-f53.google.com [209.85.214.53]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTPS id 517A75F1BA for ; Sat, 24 Dec 2016 12:16:25 +0000 (UTC) Received: by mail-it0-f53.google.com with SMTP id 75so132739568ite.1 for ; Sat, 24 Dec 2016 04:16:25 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:in-reply-to:references:from:date:message-id:subject:to; bh=TRQEL2x/e0A5+7w6JPyB1kJKtq8KtDhEaZ/2mxHaL/o=; b=XfeNZlSe6r7I6onSYsGyG2rJ/gyfOIOfniIkEKhWDGT7dv+ZSGQyhdBXTqXBWEM+zb rAQKdjEOAOHttVh0L8nT+zpRz+30Ukfvvvr6ldVXFmSsTeF+egxIhJgmSxSwtpQdEiLc LJhJsGkodDwC8D4noO5l2MRvc3lNtY9mkGUaCdYbr8oxUoEiVeLyD1kHbxfM9G808SW5 xQQWtrsxbzm4ZERKATxozvqXAGP0+Tyq10XAiCDYldkHX40G6BnCxoyzKyBx6CDTkshP 1+ORpivC9Vog9b6qk836B/OuASwGzaNnTmNe4myy3rWfIE5z2l7EjIey42/zjMi3rK80 XrSg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:to; bh=TRQEL2x/e0A5+7w6JPyB1kJKtq8KtDhEaZ/2mxHaL/o=; b=RtgsUjPqWRgcMSgMuEftYOr1eAgurm/Hck3qqGRxDxnnnHzOiQn8fMykKVymxPC0jU kaJlGpDKLJmqO2bK5U9vft7A+H3P7bSt3uyt+nlQPdxpkZRjm4ezAj2gPv0cFeuRdT7c C/87xlTJ6IIwoUKyZ/X6TvHhZ6yoZ0B7v50kYvIYkpQIRO5BlTen1+ryySobqT/txQaV oJFc3lsaIB9cpg+OPoN4HhE4PwWDpUEr4FXeQSFU2di/f2sC1noHOCEnNtREl/b0Xqn3 3eskBblbd8O4GPWPtlN969E6l3ftSunLBEOwFpqwwYJSsun8XO1hP458Jlqt+asloV/J A8uA== X-Gm-Message-State: AIkVDXLhrCkj7zFNpHOAOO62Dx6pRF3x82gOjM84N1g4iCJOxq9W3ZtlTI5XeQed3SxozbcmAid/9VABIIBaUg== X-Received: by 10.36.26.148 with SMTP id 142mr19769604iti.74.1482581777229; Sat, 24 Dec 2016 04:16:17 -0800 (PST) MIME-Version: 1.0 Received: by 10.36.102.194 with HTTP; Sat, 24 Dec 2016 04:16:16 -0800 (PST) In-Reply-To: References: <049FAE46-2AD8-4A9A-AA86-CE3BD09FC779@aol.com> From: horschi Date: Sat, 24 Dec 2016 13:16:16 +0100 Message-ID: Subject: Re: All subsequent CAS requests time out after heavy use of new CAS feature To: user@cassandra.apache.org Content-Type: multipart/alternative; boundary=001a11440fea2eb612054466789a archived-at: Sat, 24 Dec 2016 12:16:31 -0000 --001a11440fea2eb612054466789a Content-Type: text/plain; charset=UTF-8 Oh yes it is, like Couters :-) On Sat, Dec 24, 2016 at 4:02 AM, Edward Capriolo wrote: > Anecdotal CAS works differently than the typical cassandra workload. If > you run a stress instance 3 nodes one host, you find that you typically run > into CPU issues, but if you are doing a CAS workload you see things timing > out and before you hit 100% CPU. It is a strange beast. > > On Fri, Dec 23, 2016 at 7:28 AM, horschi wrote: > >> Update: I replace all quorum reads on that table with serial reads, and >> now these errors got less. Somehow quorum reads on CAS values cause most of >> these WTEs. >> >> Also I found two tickets on that topic: >> https://issues.apache.org/jira/browse/CASSANDRA-9328 >> https://issues.apache.org/jira/browse/CASSANDRA-8672 >> >> On Thu, Dec 15, 2016 at 3:14 PM, horschi wrote: >> >>> Hi, >>> >>> I would like to warm up this old thread. I did some debugging and found >>> out that the timeouts are coming from StorageProxy.proposePaxos() >>> - callback.isFullyRefused() returns false and therefore triggers a >>> WriteTimeout. >>> >>> Looking at my ccm cluster logs, I can see that two replica nodes return >>> different results in their ProposeVerbHandler. In my opinion the >>> coordinator should not throw a Exception in such a case, but instead retry >>> the operation. >>> >>> What do the CAS/Paxos experts on this list say to this? Feel free to >>> instruct me to do further tests/code changes. I'd be glad to help. >>> >>> Log: >>> >>> node1/logs/system.log:WARN [SharedPool-Worker-5] 2016-12-15 >>> 14:48:36,896 PaxosState.java:124 - Rejecting proposal for >>> Commit(2d803540-c2cd-11e6-2e48-53a129c60cfc, [MDS.Lock] key=locktest_ 1 >>> columns=[[] | [value]] >>> node1/logs/system.log- Row: id=@ | value=) because >>> inProgress is now Commit(2d8146b0-c2cd-11e6-f996-e5c8d88a1da4, >>> [MDS.Lock] key=locktest_ 1 columns=[[] | [value]] >>> -- >>> node1/logs/system.log:ERROR [SharedPool-Worker-12] 2016-12-15 >>> 14:48:36,980 StorageProxy.java:506 - proposePaxos: >>> Commit(2d803540-c2cd-11e6-2e48-53a129c60cfc, [MDS.Lock] key=locktest_ 1 >>> columns=[[] | [value]] >>> node1/logs/system.log- Row: id=@ | value=)//1//0 >>> -- >>> node2/logs/system.log:WARN [SharedPool-Worker-7] 2016-12-15 >>> 14:48:36,969 PaxosState.java:117 - Accepting proposal: >>> Commit(2d803540-c2cd-11e6-2e48-53a129c60cfc, [MDS.Lock] key=locktest_ 1 >>> columns=[[] | [value]] >>> node2/logs/system.log- Row: id=@ | value=) >>> -- >>> node3/logs/system.log:WARN [SharedPool-Worker-2] 2016-12-15 >>> 14:48:36,897 PaxosState.java:124 - Rejecting proposal for >>> Commit(2d803540-c2cd-11e6-2e48-53a129c60cfc, [MDS.Lock] key=locktest_ 1 >>> columns=[[] | [value]] >>> node3/logs/system.log- Row: id=@ | value=) because >>> inProgress is now Commit(2d8146b0-c2cd-11e6-f996-e5c8d88a1da4, >>> [MDS.Lock] key=locktest_ 1 columns=[[] | [value]] >>> >>> >>> kind regards, >>> Christian >>> >>> >>> On Fri, Apr 15, 2016 at 8:27 PM, Denise Rogers wrote: >>> >>>> My thinking was that due to the size of the data that there maybe I/O >>>> issues. But it sounds more like you're competing for locks and hit a >>>> deadlock issue. >>>> >>>> Regards, >>>> Denise >>>> Cell - (860)989-3431 <(860)%20989-3431> >>>> >>>> Sent from mi iPhone >>>> >>>> On Apr 15, 2016, at 9:00 AM, horschi wrote: >>>> >>>> Hi Denise, >>>> >>>> in my case its a small blob I am writing (should be around 100 bytes): >>>> >>>> CREATE TABLE "Lock" ( >>>> lockname varchar, >>>> id varchar, >>>> value blob, >>>> PRIMARY KEY (lockname, id) >>>> ) WITH COMPACT STORAGE >>>> AND COMPRESSION = { 'sstable_compression' : >>>> 'SnappyCompressor', 'chunk_length_kb' : '8' }; >>>> >>>> You ask because large values are known to cause issues? Anything >>>> special you have in mind? >>>> >>>> kind regards, >>>> Christian >>>> >>>> >>>> >>>> >>>> On Fri, Apr 15, 2016 at 2:42 PM, Denise Rogers >>>> wrote: >>>> >>>>> Also, what type of data were you reading/writing? >>>>> >>>>> Regards, >>>>> Denise >>>>> >>>>> Sent from mi iPad >>>>> >>>>> On Apr 15, 2016, at 8:29 AM, horschi wrote: >>>>> >>>>> Hi Jan, >>>>> >>>>> were you able to resolve your Problem? >>>>> >>>>> We are trying the same and also see a lot of WriteTimeouts: >>>>> WriteTimeoutException: Cassandra timeout during write query at >>>>> consistency SERIAL (2 replica were required but only 1 acknowledged the >>>>> write) >>>>> >>>>> How many clients were competing for a lock in your case? In our case >>>>> its only two :-( >>>>> >>>>> cheers, >>>>> Christian >>>>> >>>>> >>>>> On Tue, Sep 24, 2013 at 12:18 AM, Robert Coli >>>>> wrote: >>>>> >>>>>> On Mon, Sep 16, 2013 at 9:09 AM, Jan Algermissen < >>>>>> jan.algermissen@nordsc.com> wrote: >>>>>> >>>>>>> I am experimenting with C* 2.0 ( and today's java-driver 2.0 >>>>>>> snapshot) for implementing distributed locks. >>>>>>> >>>>>> >>>>>> [ and I'm experiencing the problem described in the subject ... ] >>>>>> >>>>>> >>>>>>> Any idea how to approach this problem? >>>>>>> >>>>>> >>>>>> 1) Upgrade to 2.0.1 release. >>>>>> 2) Try to reproduce symptoms. >>>>>> 3) If able to, file a JIRA at https://issues.apache.org/jira >>>>>> /secure/Dashboard.jspa including repro steps >>>>>> 4) Reply to this thread with the JIRA ticket URL >>>>>> >>>>>> =Rob >>>>>> >>>>>> >>>>>> >>>>> >>>>> >>>> >>> >> > --001a11440fea2eb612054466789a Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
Oh yes it is, like Couters :-)


On Sat, Dec 24, 2016 at = 4:02 AM, Edward Capriolo <edlinuxguru@gmail.com> wrote:<= br>
Anecdotal CAS works diff= erently than the typical cassandra workload. If you run a stress instance 3= nodes one host, you find that you typically run into CPU issues, but if yo= u are doing a CAS workload you see things timing out and before you hit 100= % CPU. It is a strange beast.=C2=A0

On Fri, D= ec 23, 2016 at 7:28 AM, horschi <horschi@gmail.com> wrote:
Update: I replace all quo= rum reads on that table with serial reads, and now these errors got less. S= omehow quorum reads on CAS values cause most of these WTEs.

<= div>Also I found two tickets on that topic:

On Thu, Dec 15, 201= 6 at 3:14 PM, horschi <horschi@gmail.com> wrote:
Hi,

I would like= to warm up this old thread. I did some debugging and found out that the ti= meouts are coming from StorageProxy.proposePaxos() -=C2=A0callback.isFullyR= efused() returns false and therefore triggers a WriteTimeout.
Looking at my ccm cluster logs, I can see that two replica node= s return different results in their=C2=A0ProposeVerbHandler. In my opinion = the coordinator should not throw a Exception in such a case, but instead re= try the operation.

What do the CAS/Paxos experts o= n this list say to this? Feel free to instruct me to do further tests/code = changes. I'd be glad to help.

Log:
<= br>
node1/logs/system.lo= g:WARN =C2=A0[SharedPool-Worker-5] 2016-12-15 14:48:36,896 PaxosState.java:= 124 - Rejecting proposal for Commit(2d803540-c2cd-11e6-2e48-53a129c60c= fc, [MDS.Lock] key=3Dlocktest_ 1 columns=3D[[] | [value]]
= node1/logs/system.log- =C2=A0 =C2=A0Row= : id=3D@ | value=3D<tombstone>) because inProgress is now Commit(2d81= 46b0-c2cd-11e6-f996-e5c8d88a1da4, [MDS.Lock] key=3Dlocktest_ 1 columns= =3D[[] | [value]]
--
node1/logs/system.log:E= RROR [SharedPool-Worker-12] 2016-12-15 14:48:36,980 StorageProxy.java:506 -= proposePaxos: Commit(2d803540-c2cd-11e6-2e48-53a129c60cfc, [MDS.Lock]= key=3Dlocktest_ 1 columns=3D[[] | [value]]
node1/logs/system.log- =C2=A0 =C2=A0Row: id=3D@ | val= ue=3D<tombstone>)//1//0
--
node2/logs/= system.log:WARN =C2=A0[SharedPool-Worker-7] 2016-12-15 14:48:36,969 PaxosSt= ate.java:117 - Accepting proposal: Commit(2d803540-c2cd-11e6-2e48-53a1= 29c60cfc, [MDS.Lock] key=3Dlocktest_ 1 columns=3D[[] | [value]]
node2/logs/system.log- =C2=A0 =C2= =A0Row: id=3D@ | value=3D<tombstone>)
--
node3/logs/system.log:WARN =C2=A0[SharedPool-Worker-2] 2016-12-15 14:48:= 36,897 PaxosState.java:124 - Rejecting proposal for Commit(2d803540-c2cd-11= e6-2e48-53a129c60cfc, [MDS.Lock] key=3Dlocktest_ 1 columns=3D[[] | [va= lue]]
node3/logs/syste= m.log- =C2=A0 =C2=A0Row: id=3D@ | value=3D<tombstone>) because inProg= ress is now Commit(2d8146b0-c2cd-11e6-f996-e5c8d88a1da4, [MDS.Lock] ke= y=3Dlocktest_ 1 columns=3D[[] | [value]]

<= div>
kind regards,
Christian


On Fri, Apr 15, 2016 at 8:27 PM, Deni= se Rogers <datagwal@aol.com> wrote:
My thinking was that due to the size of th= e data that there maybe I/O issues. But it sounds more like you're comp= eting for locks and hit a deadlock issue.=C2=A0

Regards,
<= div>Denise

Sent from = mi iPhone

On Apr 15, 2016, at 9:00 AM, horschi &= lt;horschi@gmail.com= > wrote:

Hi Denise,

in my case its a small blob I am writ= ing (should be around 100 bytes):

=C2=A0 =C2=A0 =C2= =A0CREATE TABLE "Lock" (
=C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0lockname varchar,
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0id varc= har,
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0value blob,
=C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0PRIMARY KEY (lockname, id)
=C2=A0 = =C2=A0 =C2=A0) WITH COMPACT STORAGE=C2=A0
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0AND COMPRESSION =3D { 'sstable_compression' : 'Sna= ppyCompressor', 'chunk_length_kb' : '8' };
<= div>
You ask because large values are known to cause issues? = Anything special you have in mind?

kind regards,
Christian



=

On Fri, Apr 15, 2= 016 at 2:42 PM, Denise Rogers <datagwal@aol.com> wrote:
Also, what type of data= were you reading/writing?

Regards,
Deni= se

Sent from mi iPad
On Apr 15, 2016, at 8:29 AM, horschi <horschi@gmail.com> wrote:

Hi Jan,

were yo= u able to resolve your Problem?

We are trying the = same and also see a lot of WriteTimeouts:
WriteTimeoutException: = Cassandra timeout during write query at consistency SERIAL (2 replica were = required but only 1 acknowledged the write)

Ho= w many clients were competing for a lock in your case? In our case its only= two :-(

cheers,
Christian

On T= ue, Sep 24, 2013 at 12:18 AM, Robert Coli <rcoli@eventbrite.com>= wrote:
On = Mon, Sep 16, 2013 at 9:09 AM, Jan Algermissen <jan.algermissen@no= rdsc.com> wrote:
I am experimenting with C* 2.0 ( and today's java-driv= er 2.0 snapshot) for implementing distributed locks.

[ and I'm experiencing the prob= lem described in the subject ... ]
=C2=A0
Any idea how to approach this problem?

1) Upgrade to 2.0.1 release.
2) Try to reproduce symptoms.=
3) If able to, file a JIRA at https://issues.apache.org/= jira/secure/Dashboard.jspa including repro steps
4) Reply to this thread with the JIRA ticket URL

<= div>=3DRob

=C2=A0






--001a11440fea2eb612054466789a--