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 BDB7210D03 for ; Mon, 30 Sep 2013 09:45:23 +0000 (UTC) Received: (qmail 43805 invoked by uid 500); 30 Sep 2013 09:43:51 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 43725 invoked by uid 500); 30 Sep 2013 09:43:50 -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 43633 invoked by uid 99); 30 Sep 2013 09:43:43 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 30 Sep 2013 09:43:43 +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 (nike.apache.org: domain of chris.wirt@struq.com designates 209.85.215.177 as permitted sender) Received: from [209.85.215.177] (HELO mail-ea0-f177.google.com) (209.85.215.177) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 30 Sep 2013 09:43:35 +0000 Received: by mail-ea0-f177.google.com with SMTP id f15so2511941eak.22 for ; Mon, 30 Sep 2013 02:43:15 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:from:to:references:in-reply-to:subject:date :message-id:mime-version:content-type:thread-index:content-language; bh=yG4ol+g8ssVZ7fKe/uqMQIgCVFHGJW/Wd7caQ7Cg9cY=; b=ewLZT6zjFhSHrE3/5Ql6RCFXQJUiREEa3TfxLNE6iaokqD2jiaIRcvVULfTWOjPETe 9ng+uGGoa1w109L9/xeYUSdEpoVZxQk9TtPDA6cZm01kcJm54CcuOc56v4lsDOkpbYXp wO0+9TkqQqblaahjnMs5XnKXIHAnmVdXX16nRrfxgsdYliUuoPumeTcz+BzV8Rm2BCV1 bLfghTBV0Sylp5rga4GZK7ehf5vTtDzRlQgZPXkrUNMv8BXYFvQ2mJbEsQf9INOUptKu Niex0SHrBUN2tfTJGX0Um+Sjh5VGOO2DGnOedSziZrtwMoHTU7a2WPEC81BakPJsBlH/ /MJQ== X-Gm-Message-State: ALoCoQn8JZlR5oOm60EYxUsMCB4qd+gPbjDWlPdJp9ics4JzhmjLo0vdSVyLVs3Xn9MtK60yIcVU X-Received: by 10.14.5.133 with SMTP id 5mr2201868eel.56.1380534195726; Mon, 30 Sep 2013 02:43:15 -0700 (PDT) Received: from StevePereiraPC (host81-133-200-21.in-addr.btopenworld.com. [81.133.200.21]) by mx.google.com with ESMTPSA id a43sm49104974eep.9.1969.12.31.16.00.00 (version=TLSv1 cipher=RC4-SHA bits=128/128); Mon, 30 Sep 2013 02:43:15 -0700 (PDT) From: "Christopher Wirt" To: References: <01f201cebb6f$5a5050a0$0ef0f1e0$@struq.com> <74827C78-CEC1-4FD9-91B9-55322D15A6E0@thelastpickle.com> In-Reply-To: <74827C78-CEC1-4FD9-91B9-55322D15A6E0@thelastpickle.com> Subject: RE: 2.0.1 counter replicate on write error Date: Mon, 30 Sep 2013 10:43:12 +0100 Message-ID: <011c01cebdc1$7bf848d0$73e8da70$@struq.com> MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_NextPart_000_011D_01CEBDC9.DDBFE520" X-Mailer: Microsoft Outlook 14.0 Thread-Index: AQGk5foIlpoNg6MdUge3giAjscYjmQHTWDGfmiMamJA= Content-Language: en-gb X-Virus-Checked: Checked by ClamAV on apache.org This is a multipart message in MIME format. ------=_NextPart_000_011D_01CEBDC9.DDBFE520 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Thanks Aaron, I've added to the ticket. We were not running on TRACE logging. From: Aaron Morton [mailto:aaron@thelastpickle.com] Sent: 30 September 2013 08:37 To: user@cassandra.apache.org Subject: Re: 2.0.1 counter replicate on write error ERROR [ReplicateOnWriteStage:19] 2013-09-27 10:17:14,778 CassandraDaemon.java (line 185) Exception in thread Thread[ReplicateOnWriteStage:19,5,main] java.lang.AssertionError: DecoratedKey(-1754949563326053382, a414b0c07f0547f8a75410555716ced6) != DecoratedKey(-1754949563326053382, aeadcec8184445d4ab631ef4250927d0) in /disk3/cassandra/data/struqrealtime/counters/struqrealtime-counters-jb-83195 3-Data.db at org.apache.cassandra.db.columniterator.SSTableNamesIterator.read(SSTableName sIterator.java:114) at org.apache.cassandra.db.columniterator.SSTableNamesIterator.(SSTableNa mesIterator.java:62) When reading from an SSTable the position returned from the -Index.db / KEYS cache pointed to a row in the -Data.db component that was for a different row. DecoratedKey(-1754949563326053382, aeadcec8184445d4ab631ef4250927d0) Was what we were searching for DecoratedKey(-1754949563326053382, a414b0c07f0547f8a75410555716ced6) Is what was found in the data component. The first part is the Token (M3 hash) the second is the key. It looks like a collision, but it could also be a bug somewhere else. Code in SSTableReader.getPosition() points to https://issues.apache.org/jira/browse/CASSANDRA-4687 and adds an assertion that is only trigger if TRACE logging is running. Can you add to the 4687 ticket and update the thread ? Cheers ----------------- Aaron Morton New Zealand @aaronmorton Co-Founder & Principal Consultant Apache Cassandra Consulting http://www.thelastpickle.com On 27/09/2013, at 10:50 PM, Christopher Wirt wrote: Hello, I've started to see a slightly worrying error appear in our logs occasionally. We're writing at 400qps per machine and I only see this appear every 5-10minutes. Seems to have started when I switched us to using the hsha thrift server this morning. We've been running 2.0.1 ran off the sync thrift server since yesterday without seeing this error. But might not be related. There are some machines in another DC still running 1.2.10. Anyone seen this before? Have any insight? ERROR [ReplicateOnWriteStage:19] 2013-09-27 10:17:14,778 CassandraDaemon.java (line 185) Exception in thread Thread[ReplicateOnWriteStage:19,5,main] java.lang.AssertionError: DecoratedKey(-1754949563326053382, a414b0c07f0547f8a75410555716ced6) != DecoratedKey(-1754949563326053382, aeadcec8184445d4ab631ef4250927d0) in /disk3/cassandra/data/struqrealtime/counters/struqrealtime-counters-jb-83195 3-Data.db at org.apache.cassandra.db.columniterator.SSTableNamesIterator.read(SSTableName sIterator.java:114) at org.apache.cassandra.db.columniterator.SSTableNamesIterator.(SSTableNa mesIterator.java:62) at org.apache.cassandra.db.filter.NamesQueryFilter.getSSTableColumnIterator(Nam esQueryFilter.java:87) at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFil ter.java:62) at org.apache.cassandra.db.CollationController.collectAllData(CollationControll er.java:249) at org.apache.cassandra.db.CollationController.getTopLevelColumns(CollationCont roller.java:53) at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilySto re.java:1468) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore. java:1294) at org.apache.cassandra.db.Keyspace.getRow(Keyspace.java:332) at org.apache.cassandra.db.SliceByNamesReadCommand.getRow(SliceByNamesReadComma nd.java:55) at org.apache.cassandra.db.CounterMutation.makeReplicationMutation(CounterMutat ion.java:100) at org.apache.cassandra.service.StorageProxy$8$1.runMayThrow(StorageProxy.java: 1107) at org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy .java:1897) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11 45) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6 15) at java.lang.Thread.run(Thread.java:724) ------=_NextPart_000_011D_01CEBDC9.DDBFE520 Content-Type: text/html; charset="us-ascii" Content-Transfer-Encoding: quoted-printable

Thanks Aaron, I’ve added to the ticket. We were not running on = TRACE logging.

 

From:= Aaron = Morton [mailto:aaron@thelastpickle.com]
Sent: 30 September = 2013 08:37
To: user@cassandra.apache.org
Subject: = Re: 2.0.1 counter replicate on write = error

 

ERROR = [ReplicateOnWriteStage:19] 2013-09-27 10:17:14,778 CassandraDaemon.java = (line 185) Exception in thread = Thread[ReplicateOnWriteStage:19,5,main]

<= p class=3DMsoNormal>java.lang.A= ssertionError: DecoratedKey(-1754949563326053382, = a414b0c07f0547f8a75410555716ced6) !=3D = DecoratedKey(-1754949563326053382, aeadcec8184445d4ab631ef4250927d0) in = /disk3/cassandra/data/struqrealtime/counters/struqrealtime-counters-jb-83= 1953-Data.db

  = ;      at = org.apache.cassandra.db.columniterator.SSTableNamesIterator.read(SSTableN= amesIterator.java:114)

  = ;      at = org.apache.cassandra.db.columniterator.SSTableNamesIterator.<init>(= SSTableNamesIterator.java:62)

 

When reading from an SSTable the position returned = from the -Index.db / KEYS cache pointed to a row in the -Data.db = component that was for a different row. 

 

DecoratedKe= y(-1754949563326053382, = aeadcec8184445d4ab631ef4250927d0)

Was what we were searching = for

 

DecoratedKe= y(-1754949563326053382, = a414b0c07f0547f8a75410555716ced6)

Is what was found in the data = component. 

 

The first part is the Token (M3 hash) the second is = the key. It looks like a collision, but it could also be a bug somewhere = else. 

 

Code in SSTableReader.getPosition() points to https://iss= ues.apache.org/jira/browse/CASSANDRA-4687 and adds an assertion = that is only trigger if TRACE logging is running. Can you add to the = 4687 ticket and update the thread ? 

 

Cheers

 

-----------------

Aaron Morton

New Zealand

@aaronmorton

 

Co-Founder & Principal = Consultant

Apache Cassandra Consulting

 

On = 27/09/2013, at 10:50 PM, Christopher Wirt <chris.wirt@struq.com> = wrote:



Hello,=

 =

I’ve = started to see a slightly worrying error appear in our logs = occasionally. We’re writing at 400qps per machine and I only see = this appear every 5-10minutes.

 =

Seems to = have started when I switched us to using the hsha thrift server this = morning. We’ve been running 2.0.1 ran off the sync thrift server = since yesterday without seeing this error.  But might not be = related.

 =

There are = some machines in another DC still running = 1.2.10.

 =

Anyone = seen this before? Have any insight?

 =

ERROR = [ReplicateOnWriteStage:19] 2013-09-27 10:17:14,778 CassandraDaemon.java = (line 185) Exception in thread = Thread[ReplicateOnWriteStage:19,5,main]

<= p class=3DMsoNormal>java.lang.A= ssertionError: DecoratedKey(-1754949563326053382, = a414b0c07f0547f8a75410555716ced6) !=3D = DecoratedKey(-1754949563326053382, aeadcec8184445d4ab631ef4250927d0) in = /disk3/cassandra/data/struqrealtime/counters/struqrealtime-counters-jb-83= 1953-Data.db

  = ;      at = org.apache.cassandra.db.columniterator.SSTableNamesIterator.read(SSTableN= amesIterator.java:114)

  = ;      at = org.apache.cassandra.db.columniterator.SSTableNamesIterator.<init>(= SSTableNamesIterator.java:62)

  = ;      at = org.apache.cassandra.db.filter.NamesQueryFilter.getSSTableColumnIterator(= NamesQueryFilter.java:87)

  = ;      at = org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(Query= Filter.java:62)

  = ;      at = org.apache.cassandra.db.CollationController.collectAllData(CollationContr= oller.java:249)

  = ;      at = org.apache.cassandra.db.CollationController.getTopLevelColumns(CollationC= ontroller.java:53)

  = ;      at = org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamily= Store.java:1468)

  = ;      at = org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilySto= re.java:1294)

  = ;      at = org.apache.cassandra.db.Keyspace.getRow(Keyspace.java:332)

  = ;      at = org.apache.cassandra.db.SliceByNamesReadCommand.getRow(SliceByNamesReadCo= mmand.java:55)

  = ;      at = org.apache.cassandra.db.CounterMutation.makeReplicationMutation(CounterMu= tation.java:100)

  = ;      at = org.apache.cassandra.service.StorageProxy$8$1.runMayThrow(StorageProxy.ja= va:1107)

  = ;      at = org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StoragePr= oxy.java:1897)

  = ;      at = java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java= :1145)

  = ;      at = java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.jav= a:615)

  = ;      at = java.lang.Thread.run(Thread.java:724)

 

------=_NextPart_000_011D_01CEBDC9.DDBFE520--