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 7076710ED8 for ; Thu, 6 Feb 2014 19:19:58 +0000 (UTC) Received: (qmail 14576 invoked by uid 500); 6 Feb 2014 19:19:54 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 14525 invoked by uid 500); 6 Feb 2014 19:19:54 -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 14517 invoked by uid 99); 6 Feb 2014 19:19:54 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 06 Feb 2014 19:19:54 +0000 X-ASF-Spam-Status: No, hits=2.2 required=5.0 tests=HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: local policy) Received: from [98.139.213.148] (HELO nm27-vm1.bullet.mail.bf1.yahoo.com) (98.139.213.148) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 06 Feb 2014 19:19:46 +0000 Received: from [66.196.81.171] by nm27.bullet.mail.bf1.yahoo.com with NNFMP; 06 Feb 2014 19:19:24 -0000 Received: from [98.139.212.225] by tm17.bullet.mail.bf1.yahoo.com with NNFMP; 06 Feb 2014 19:19:24 -0000 Received: from [127.0.0.1] by omp1034.mail.bf1.yahoo.com with NNFMP; 06 Feb 2014 19:19:24 -0000 X-Yahoo-Newman-Property: ymail-3 X-Yahoo-Newman-Id: 99060.3426.bm@omp1034.mail.bf1.yahoo.com Received: (qmail 62385 invoked by uid 60001); 6 Feb 2014 19:19:23 -0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s1024; t=1391714363; bh=zE6f8Svi5coJBM6gNdv+EsutZRaaKXlPLyvkTQE56gw=; h=X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type; b=fWva8Ab/2ddxqScKKyoTnLz3VgeuaNcCDtMn8PxwXfhKeSqUvI0jCe3Kp8J4r6vEY2I8hLgYRN/jcE9QjEE0aA2DVjF6h+MMmv/ubWw+9J0aOIdaHrYvgIFszPoYf2NyMZaBpSk89lL4H3afTA3GDJBUciW8O//LzXyMX2Wm+ik= DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com; h=X-YMail-OSG:Received:X-Rocket-MIMEInfo:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:In-Reply-To:MIME-Version:Content-Type; b=uyrPqG5bMGkaeb5yQxntytKJnUa3C7iuBHWvRP+Ra9EAjpkzgOBbHb9cCy6U4ADdmGQeM7ItulKRJ3uBqyj66PXEjlwikXnk4UvkZw70dF6NT6othcqZRiZaWVIMYbUqe2C+7KJYB8+/QNAzHy7ronZba0qP3j6PBZKK0JuKWWY=; X-YMail-OSG: H1bkRY4VM1mk_ZC.9Qtgq8UxyApXWPC1vGs9tBVWXndVphr 26aqb.SxdB0Tys2qaf33u5bJuOMb0p8Uvt6v3wnmixsdIji4cTG1sLTb8M_7 JektlCpYh3iH.FA4AikleCkq0oksYCZ_QomsZWAQxBZrEUS7oeN5rjBYMJGz 7T6Nth2O2r_1QGIvS9lYjZ5TB212OxU6RvqX2D4P2Lh0Kpc4_RXrrq3x6eCo WeedIDCYFgk6k8bfpkZzLzciD45bgsE7U9rE5wylW6TJVR_LJ6rlTJlKmYMF rCRVDzKz4dJVlKsBeoKwIffa9vbTO5nMJ5FWF5TYaqGGFuPOOBr0OZ0ZWzZ9 FFcy9Ygq0rOkvYY00.KwUhl62W78aFwV6ISoJUIpNIL1s10dA6JhZ8qwBsAj exNkaw_yfjekTckLd2sv7JQH_kiK2ePYXRIOwU7VL703fLHlu2ts8bf4Zyl4 _tMCeHXgQRGiYKuuH7Jy1a9kYZ8L2RpBqsKQMdIyjnDdL9UCRCBx1nkalmGw 5cyUCvNuB4Rz2NtFwohZnVRFyVTUohWyn._x3bq4pbvaasea2fbzeSwXafs5 3X9k_smacPPy0hBMptMo4Ngfqx_hK9vq8znyiWw-- Received: from [66.228.162.40] by web142801.mail.bf1.yahoo.com via HTTP; Thu, 06 Feb 2014 11:19:23 PST X-Rocket-MIMEInfo: 002.001,SSdtIHNlZWluZyB0aGUgc2FtZSB3aXRoIGNhc3NhbmRyYS0yLjAuNCBkdXJpbmcgY29tcGFjdGlvbiwgYWZ0ZXIgbG90IG9mIHNzdGFibGUgZmlsZXMgYXJlIHN0cmVhbWVkIGFmdGVyIGJvb3RzdHJhcC9yZXBhaXIuIFN0cmFuZ2UgdGhpbmcgaXMsIHRoZSAnTGFzdCB3cml0dGVuIGtleSA.PSBjdXJyZW50IGtleScgZXhjZXB0aW9uIGR1cmluZyBjb21wYWN0aW9uIG9mIEwwLCBMMSBzc3RhYmxlcywgZ29lcyBhd2F5IGFmdGVyIHJlc3RhcnRpbmcgY2Fzc2FuZHJhLiBCdXQsIHRoZW4gc2VlIHRob3NlIHdhcm4BMAEBAQE- X-Mailer: YahooMailWebService/0.8.175.632 References: Message-ID: <1391714363.45299.YahooMailNeo@web142801.mail.bf1.yahoo.com> Date: Thu, 6 Feb 2014 11:19:23 -0800 (PST) From: ravi prasad Reply-To: ravi prasad Subject: Re: exception during add node due to test beforeAppend on SSTableWriter To: "user@cassandra.apache.org" In-Reply-To: MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="469468616-2132171084-1391714363=:45299" X-Virus-Checked: Checked by ClamAV on apache.org --469468616-2132171084-1391714363=:45299 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable I'm seeing the same with cassandra-2.0.4 during compaction, after lot of ss= table files are streamed after bootstrap/repair. Strange thing is, the 'Las= t written key >=3D current key' exception during compaction of L0, L1 sstab= les, goes away after restarting cassandra. But, then see those warnings abo= ut overlapping sstables. =0A=0AI think this change in https://issues.apache= .org/jira/browse/CASSANDRA-5921 is causing overlapping of sstables in L1. D= idn't used to see this with cassandra-1.2.9 which had https://issues.apache= .org/jira/browse/CASSANDRA-5907 fixed.=C2=A0 Can you open a jira reporting = this issue?=0A=0A=0A=0A=0A=0AOn Thursday, February 6, 2014 4:31 AM, "Desimp= el, Ignace" wrote:=0A =0A =0AAlso, these nodes= and data are entirely created by a 2.0.4 code, so should not really be a 1= .1.x related bug.=0AAlso, I restarted the whole test, thus completely new d= atabase, and I get similar problems.=0A=C2=A0=0AFrom:Desimpel, Ignace =0ASe= nt: vrijdag 31 januari 2014 18:02=0ATo: user@cassandra.apache.org=0ASubject= : exception during add node due to test beforeAppend on SSTableWriter=0A=C2= =A0=0AThe join with auto bootstrap itself was finished. So I restarted the = added node. During restart I saw a message indicating that something is wro= ng about this row and sstable.=0AOf course, in my case I did not drop sstab= le from another node. But I did decommission and add the node, so that is s= till a kind of =E2=80=98data-from-another-node=E2=80=99.=0A=C2=A0=0AAt leve= l 2, SSTableReader(path=3D'../../../../data/cdi.cassandra.cdi/dbdatafile/Ks= 100K/ForwardStringFunction/Ks100K-ForwardStringFunction-jb-67-Data.db') [De= coratedKey(065864ce01024e4e505300, 065864ce01024e4e505300), DecoratedKey(14= c9d35e0102646973706f736974696f6e7300, 14c9d35e0102646973706f736974696f6e730= 0)] overlaps SSTableReader(path=3D'../../../../data/cdi.cassandra.cdi/dbdat= afile/Ks100K/ForwardStringFunction/Ks100K-ForwardStringFunction-jb-64-Data.= db') [DecoratedKey(068c2e4101024d6f64616c207665726200, 068c2e4101024d6f6461= 6c207665726200), DecoratedKey(06c566b4010244657465726d696e657200, 06c566b40= 10244657465726d696e657200)].=C2=A0 This could be caused by a bug in Cassand= ra 1.1.0 .. 1.1.3 or due to the fact that you have dropped sstables from an= other node into the data directory. Sending back to L0.=C2=A0 If you didn't= drop in sstables, and have not yet run scrub, you should do so since you m= ay also have rows out-of-order within an sstable=0A=C2=A0=0A=C2=A0=0A=C2=A0= =0AFrom:Desimpel, Ignace =0ASent: vrijdag 31 januari 2014 17:43=0ATo: user@= cassandra.apache.org=0ASubject: exception during add node due to test befor= eAppend on SSTableWriter=0A=C2=A0=0A4 node, byte ordered, LCS, 3 Compaction= Executors, replication factor 1=0ACode is 2.0.4 version but with patch for= CASSANDRA-6638 However, no cleanup is run so patch should not play a roll= =0A=C2=A0=0A4 node cluster is started and insert/queries are done up to abo= ut only 10 GB of data on each node.=0AThen decommission one node, and delet= e local files.=0AThen add node again.=0AException : see below.=0A=C2=A0=0AA= ny idea?=0A=C2=A0=0ARegards,=0AIgnace Desimpel=0A=C2=A0=0A=09* 2014-01-31 1= 7:12:02.600 =3D=3D>> Bootstrap is streaming data from other nodes... Please= wait ... =0A=09* 2014-01-31 17:12:02.600 =3D=3D>> Bootstrap stream state := rx=3D 29.00 tx=3D 100.00 Please wait ... =0A=09* 2014-01-31 17:12:18.908 E= nqueuing flush of Memtable-compactions_in_progress@350895652(0/0 serialized= /live bytes, 1 ops) =0A=09* 2014-01-31 17:12:18.908 Writing Memtable-compac= tions_in_progress@350895652(0/0 serialized/live bytes, 1 ops) =0A=09* 2014-= 01-31 17:12:19.009 Completed flushing ../../../../data/cdi.cassandra.cdi/db= datafile/system/compactions_in_progress/system-compactions_in_progress-jb-7= 4-Data.db (42 bytes) for commitlog position ReplayPosition(segmentId=3D1391= 184546183, position=3D561494) =0A=09* 2014-01-31 17:12:19.018 Exception in = thread Thread[CompactionExecutor:1,1,main] =0A=09* java.lang.RuntimeExcepti= on: Last written key DecoratedKey(8afc923701038000000000178575, 8afc9237010= 38000000000178575) >=3D current key DecoratedKey(6e0bb95501038000000003dfdd= 1d, 6e0bb95501038000000003dfdd1d) writing into /media/datadrive1/cdi.cassan= dra.cdi/dbdatafile/Ks100K/ForwardLongFunction/Ks100K-ForwardLongFunction-tm= p-jb-159-Data.db =0A=09* at org.apache.cassandra.io.sstable.SSTableWriter.b= eforeAppend(SSTableWriter.java:142) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2= .0.4-SNAPSHOT] =0A=09* at org.apache.cassandra.io.sstable.SSTableWriter.app= end(SSTableWriter.java:165) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNA= PSHOT] =0A=09* at org.apache.cassandra.db.compaction.CompactionTask.runWith= (CompactionTask.java:160) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPS= HOT] =0A=09* at org.apache.cassandra.io.util.DiskAwareRunnable.runMayThrow(= DiskAwareRunnable.java:48) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAP= SHOT] =0A=09* at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunn= able.java:28) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT] =0A=09*= at org.apache.cassandra.db.compaction.CompactionTask.executeInternal(Compa= ctionTask.java:60) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT] = =0A=09* at org.apache.cassandra.db.compaction.AbstractCompactionTask.execut= e(AbstractCompactionTask.java:59) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0= .4-SNAPSHOT] =0A=09* at org.apache.cassandra.db.compaction.CompactionManage= r$BackgroundCompactionTask.run(CompactionManager.java:197) ~[apache-cassand= ra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT] =0A=09* at java.util.concurrent.Execu= tors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_40] =0A=09* at jav= a.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_40] =0A=09= * at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.j= ava:1145) ~[na:1.7.0_40] =0A=09* at java.util.concurrent.ThreadPoolExecutor= $Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_40] =0A=09* at java.lang= .Thread.run(Thread.java:724) [na:1.7.0_40] --469468616-2132171084-1391714363=:45299 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: quoted-printable
I'm seeing the same with cassandra-2.0.4 during compaction, a= fter lot of sstable files are streamed after bootstrap/repair. Strange thin= g is, the 'Last written key >=3D current key' exception during compactio= n of L0, L1 sstables, goes away after restarting cassandra. But, then see t= hose warnings about overlapping sstables.

I think this change in https://issu= es.apache.org/jira/browse/CASSANDRA-5921 is causing overlapping of ssta= bles in L1. Didn't used to see this with cassandra-1.2.9 which had https://issues.ap= ache.org/jira/browse/CASSANDRA-5907 fixed.  Can you open a jira re= porting this issue?



On Thursday, February 6, 2014 4:31 AM= , "Desimpel, Ignace" <Ignace.Desimpel@nuance.com> wrote:
 =
=0A=0A =0A= =0A=0A=0A
=0A
=0A
Also, these nodes and data are entirely created by a 2.0.4 code, so= should not really be a 1.1.x related bug.
=0A
Also, I restarted the = whole test, thus completely new database, and I get similar problems.
=0A
 
=0A
=0A
=0A
From: Desimpel, Ignace=0A
=0ASent: vrijdag 31= januari 2014 18:02
=0ATo: user@cassandra.apache.org
=0ASub= ject: exception during add node due to test beforeAppend on SSTableWrit= er
=0A
=0A
=0A
=  
=0A
The join with auto bootstrap itself was finished. So = I restarted the added node. During restart I saw a message indicating that = something is wrong about this row and sstable.
=0A
Of course, in my case I did not drop s= stable from another node. But I did decommission and add the node, so that = is still a kind of =E2=80=98data-from-another-node=E2=80=99.
= =0A
 
=0A
At level 2, SSTableReader(path= =3D'../../../../data/cdi.cassandra.cdi/dbdatafile/Ks100K/ForwardStringFunct= ion/Ks100K-ForwardStringFunction-jb-67-Data.db')=0A [DecoratedKey(065864ce0= 1024e4e505300, 065864ce01024e4e505300), DecoratedKey(14c9d35e0102646973706f= 736974696f6e7300, 14c9d35e0102646973706f736974696f6e7300)] overlaps SSTable= Reader(path=3D'../../../../data/cdi.cassandra.cdi/dbdatafile/Ks100K/Forward= StringFunction/Ks100K-ForwardStringFunction-jb-64-Data.db')=0A [DecoratedKe= y(068c2e4101024d6f64616c207665726200, 068c2e4101024d6f64616c207665726200), = DecoratedKey(06c566b4010244657465726d696e657200, 06c566b4010244657465726d69= 6e657200)].  This could be caused by a bug in Cassandra 1.1.0 .. 1.1.3= or due to the fact that=0A you have dropped sstables from another node int= o the data directory. Sending back to L0.  If you didn't drop in sstab= les, and have not yet run scrub, you should do so since you may also have r= ows out-of-order within an sstable
=0A
 
=0A
 
=0A
 
=0A
=0A
=0A
From: Desimpel, Ignace=0A
=0ASent: vrijdag 3= 1 januari 2014 17:43
=0ATo: user@cassandra.apache.org
=0ASubject: exception = during add node due to test beforeAppend on SSTableWriter
=0A<= /div>=0A
=0A
 
=0A4 node, byte ordered, LCS, 3 Compaction = Executors, replication factor 1
=0A
Code is 2.0.4 version but with patch for =0ACA= SSANDRA-6638 However, no cleanup is run so patch should not play a roll=
=0A
 
=0A
4 node cluster is started and insert/queries ar= e done up to about only 10 GB of data on each node.
=0A
Then decommission one node, and delete local files.=
=0A
Then add node again.
= =0A
Exception : see below.
=0A  
=0A
Any idea?
=0A
&= nbsp;
=0A
Regards,
=0AIgnace Desimpel
=0A
 
=0A
    =0A
  • =0A2014-= 01-31 17:12:02.600 =3D=3D>> Bootstrap is streaming data from other no= des... Please wait ...=0A
  • =0A2014-01-31 17:12:02.600 =3D= =3D>> Bootstrap stream state : rx=3D 29.00 tx=3D 100.00 Please wait .= ..=0A
  • =0A2014-01-31 17:12:18.908 Enqueuing flush of Memta= ble-compactions_in_progress@350895652(0/0 serialized/live bytes, 1 ops)=0A<= /span>
  • =0A2014-01-31 17:12:18.908 Writing Memtable-compactions= _in_progress@350895652(0/0 serialized/live bytes, 1 ops)=0A
  • =0A2014-01-31 17:12:19.009 Completed flushing ../../../../data/cdi.cassa= ndra.cdi/dbdatafile/system/compactions_in_progress/system-compactions_in_pr= ogress-jb-74-Data.db (42 bytes) for commitlog=0A position ReplayPosition(se= gmentId=3D1391184546183, position=3D561494)
  • =0A2014-01-3= 1 17:12:19.018 Exception in thread Thread[CompactionExecutor:1,1,main]=0A
  • =0Ajava.lang.RuntimeException: Last written key DecoratedK= ey(8afc923701038000000000178575, 8afc923701038000000000178575) >=3D curr= ent key DecoratedKey(6e0bb95501038000000003dfdd1d, 6e0bb95501038000000003df= dd1d)=0A writing into /media/datadrive1/cdi.cassandra.cdi/dbdatafile/Ks100K= /ForwardLongFunction/Ks100K-ForwardLongFunction-tmp-jb-159-Data.db=0A
  • =0Aat org.apache.cassandra.io.sstable.SSTableWriter.beforeAppe= nd(SSTableWriter.java:142) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAP= SHOT]=0A
  • =0Aat org.apache.cassandra.io.sstable.SSTableWri= ter.append(SSTableWriter.java:165) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.= 0.4-SNAPSHOT]=0A
  • =0Aat org.apache.cassandra.db.compaction= .CompactionTask.runWith(CompactionTask.java:160) ~[apache-cassandra-2.0.4-S= NAPSHOT.jar:2.0.4-SNAPSHOT]=0A
  • =0Aat org.apache.cassandra= .io.util.DiskAwareRunnable.runMayThrow(DiskAwareRunnable.java:48) ~[apache-= cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT]=0A
  • =0Aat org= .apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:28) ~[apac= he-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT]=0A
  • =0Aat = org.apache.cassandra.db.compaction.CompactionTask.executeInternal(Compactio= nTask.java:60) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT]=0A
  • =0Aat org.apache.cassandra.db.compaction.AbstractCompactionT= ask.execute(AbstractCompactionTask.java:59) ~[apache-cassandra-2.0.4-SNAPSH= OT.jar:2.0.4-SNAPSHOT]=0A
  • =0Aat org.apache.cassandra.db.c= ompaction.CompactionManager$BackgroundCompactionTask.run(CompactionManager.= java:197) ~[apache-cassandra-2.0.4-SNAPSHOT.jar:2.0.4-SNAPSHOT]=0A
  • =0Aat java.util.concurrent.Executors$RunnableAdapter.call(Executo= rs.java:471) ~[na:1.7.0_40]=0A
  • =0Aat java.util.concurrent= .FutureTask.run(FutureTask.java:262) ~[na:1.7.0_40]=0A
  • =0Aat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.ja= va:1145) ~[na:1.7.0_40]=0A
  • =0Aat java.util.concurrent.Thr= eadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_40]=0A
  • =0Aat java.lang.Thread.run(Thread.java:724) [na:1.7.0_40]= =0A
=0A
 
= =0A
=0A
=0A


--469468616-2132171084-1391714363=:45299--