Return-Path: Delivered-To: apmail-cassandra-user-archive@www.apache.org Received: (qmail 50503 invoked from network); 25 Aug 2010 07:53:32 -0000 Received: from unknown (HELO mail.apache.org) (140.211.11.3) by 140.211.11.9 with SMTP; 25 Aug 2010 07:53:32 -0000 Received: (qmail 24388 invoked by uid 500); 25 Aug 2010 07:53:31 -0000 Delivered-To: apmail-cassandra-user-archive@cassandra.apache.org Received: (qmail 24190 invoked by uid 500); 25 Aug 2010 07:53:27 -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 24182 invoked by uid 99); 25 Aug 2010 07:53:26 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 25 Aug 2010 07:53:26 +0000 X-ASF-Spam-Status: No, hits=2.2 required=10.0 tests=HTML_MESSAGE,MIME_QP_LONG_LINE,RCVD_IN_DNSWL_NONE,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: local policy) Received: from [208.113.200.5] (HELO homiemail-a59.g.dreamhost.com) (208.113.200.5) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 25 Aug 2010 07:53:20 +0000 Received: from homiemail-a59.g.dreamhost.com (localhost [127.0.0.1]) by homiemail-a59.g.dreamhost.com (Postfix) with ESMTP id 71529564069 for ; Wed, 25 Aug 2010 00:52:58 -0700 (PDT) DomainKey-Signature: a=rsa-sha1; c=nofws; d=thelastpickle.com; h=to:from :subject:message-id:content-type:mime-version:date; q=dns; s= thelastpickle.com; b=04mIz/BqWwo/M3YTmWsqDYZn6F4Xdrz1OUxkjvlTMbZ 3U5w/j1tWtYfOjp3Y18HtK8eJ3YygUNE2vfKBnY2NIxKF3mh7GGSt0+I+g6PQXpC WAQL/c3BvzdoOJ49UzaJMAGCvOQd6Hso8ewpm9TyYRrmUjti3e49GnFbsIPSA37I = DKIM-Signature: v=1; a=rsa-sha1; c=relaxed; d=thelastpickle.com; h=to :from:subject:message-id:content-type:mime-version:date; s= thelastpickle.com; bh=16s6OkuTMq51cc4jhtiUw3Qljjc=; b=h6QOIZgZvU ok6tE+JJ1USJgdad/kVOurFwSOj//byA+ac5is0l+g5pbR1qiIaG3eID9HWQAlNy HIAKCOs5kHM+8eaUukB5UHJ697caeiH4JNr5Osfw6dcHIqFK4JMOdpbB7C4PSkbE Zwbzhq8Nv3P8GG7PnoMK5vIIhwmVueloc= Received: from localhost (webms.mac.com [17.148.16.116]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) (Authenticated sender: aaron@thelastpickle.com) by homiemail-a59.g.dreamhost.com (Postfix) with ESMTPSA id 56A3E564061 for ; Wed, 25 Aug 2010 00:52:58 -0700 (PDT) To: Cassandra User From: Aaron Morton Subject: java.util.NoSuchElementException X-Mailer: MobileMe Mail (1C2649) Message-id: <3e36dd94-c652-4e6c-90a7-d65adea918d3@me.com> Content-Type: multipart/alternative; boundary=Apple-Webmail-42--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574 MIME-Version: 1.0 Date: Wed, 25 Aug 2010 00:52:58 -0700 (PDT) --Apple-Webmail-42--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=ISO-8859-1; format=flowed I'm running the v0.7-beta1 in a 4 nodes cluster and just doing some simple= testing. One of the nodes had been down (machine off, unclean shutdown) f= or an hour or so not sure how many writes were going on, when I bought it = back up this message appears in the other 3 nodes...=0A=0A=0AINFO [GOSSIP_= STAGE:1] 2010-08-25 19:29:51,199 Gossiper.java (line 584) Node /192.168.34= 27 has restarted, now UP again=0A=A0INFO [HINTED-HANDOFF-POOL:1] 2010-08-= 25 19:29:51,200 HintedHandOffManager.java (line 191) Started hinted handof= f for endpoint /192.168.34.27=0A=A0INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:= 51,201 StorageService.java (line 636) Node /192.168.34.27 state jump to no= rmal=0A=A0INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,201 StorageService.jav= a (line 643) Will not change my token ownership to /192.168.34.27=0AERROR = [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,640 CassandraDaemon.java (line= 82) Uncaught exception in thread Thread[HINTED-HANDOFF-POOL:1,5,main]=0Aj= ava.util.concurrent.ExecutionException: java.lang.RuntimeException: java.u= til.NoSuchElementException=0A=A0=A0 =A0 =A0 =A0at java.util.concurrent.Fut= ureTask$Sync.innerGet(FutureTask.java:222)=0A=A0=A0 =A0 =A0 =A0at java.uti= l.concurrent.FutureTask.get(FutureTask.java:83)=0A=A0=A0 =A0 =A0 =A0at org= apache.cassandra.concurrent.DebuggableThreadPoolExecutor.afterExecute(Deb= uggableThreadPoolExecutor.java:87)=0A=A0=A0 =A0 =A0 =A0at java.util.concur= rent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:888)=0A=A0=A0= =A0 =A0 =A0at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPo= olExecutor.java:908)=0A=A0=A0 =A0 =A0 =A0at java.lang.Thread.run(Thread.ja= va:619)=0ACaused by: java.lang.RuntimeException: java.util.NoSuchElementEx= ception=0A=A0=A0 =A0 =A0 =A0at org.apache.cassandra.utils.WrappedRunnable.= run(WrappedRunnable.java:34)=0A=A0=A0 =A0 =A0 =A0at java.util.concurrent.E= xecutors$RunnableAdapter.call(Executors.java:441)=0A=A0=A0 =A0 =A0 =A0at j= ava.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)=0A=A0=A0= =A0 =A0 =A0at java.util.concurrent.FutureTask.run(FutureTask.java:138)=0A= =A0=A0 =A0 =A0 =A0at java.util.concurrent.ThreadPoolExecutor$Worker.runTas= k(ThreadPoolExecutor.java:886)=0A=A0=A0 =A0 =A0 =A0... 2 more=0ACaused by:= java.util.NoSuchElementException=0A=A0=A0 =A0 =A0 =A0at java.util.concurr= ent.ConcurrentSkipListMap.lastKey(ConcurrentSkipListMap.java:1981)=0A=A0=A0= =A0 =A0 =A0at java.util.concurrent.ConcurrentSkipListMap$KeySet.last(Conc= urrentSkipListMap.java:2331)=0A=A0=A0 =A0 =A0 =A0at org.apache.cassandra.d= b.HintedHandOffManager.sendMessage(HintedHandOffManager.java:121)=0A=A0=A0= =A0 =A0 =A0at org.apache.cassandra.db.HintedHandOffManager.deliverHintsTo= Endpoint(HintedHandOffManager.java:218)=0A=A0=A0 =A0 =A0 =A0at org.apache.= cassandra.db.HintedHandOffManager.access$000(HintedHandOffManager.java:78)= =0A=A0=A0 =A0 =A0 =A0at org.apache.cassandra.db.HintedHandOffManager$1.run= MayThrow(HintedHandOffManager.java:296)=A0not sure how many writes were go= ing on=0A=A0=A0 =A0 =A0 =A0at org.apache.cassandra.utils.WrappedRunnable.r= un(WrappedRunnable.java:30)=0A=A0=A0 =A0 =A0 =A0... 6 more=0A=0A=0AOn the = machine that was off (34.27) there are no errors in the logs, and here are= the entries for around the same time...=0A=0A=A0INFO [main] 2010-08-25 19= :29:50,679 CommitLog.java (line 340) Recovery complete=0A=A0INFO [main] 20= 10-08-25 19:29:50,769 CommitLog.java (line 180) Log replay complete=0A=A0I= NFO [main] 2010-08-25 19:29:50,797 StorageService.java (line 342) Cassandr= a version: 0.7.0-beta1-SNAPSHOT=0A=A0INFO [main] 2010-08-25 19:29:50,797 S= torageService.java (line 343) Thrift API version: 10.0.0=0A=A0INFO [main] = 2010-08-25 19:29:50,813 SystemTable.java (line 240) Saved Token found: 850= 70591730234615865843651857942052864=0A=A0INFO [main] 2010-08-25 19:29:50,8= 13 SystemTable.java (line 257) Saved ClusterName found: FOO=0A=A0INFO [mai= n] 2010-08-25 19:29:50,813 SystemTable.java (line 272) Saved partitioner n= ot found. Using org.apache.cassandra.dht.RandomPartitioner=0A=A0INFO [main= ] 2010-08-25 19:29:50,814 ColumnFamilyStore.java (line 422) switching in a= fresh Memtable for LocationInfo at CommitLogContext(file=3D'/local1/junkb= ox/cassandra/commitlog/CommitLog-12827213897=0A70.log', position=3D41336)=0A= =A0INFO [main] 2010-08-25 19:29:50,814 ColumnFamilyStore.java (line 706) E= nqueuing flush of Memtable-LocationInfo@916236367(95 bytes, 2 operations)=0A= =A0INFO [FLUSH-WRITER-POOL:1] 2010-08-25 19:29:50,815 Memtable.java (line = 150) Writing Memtable-LocationInfo@916236367(95 bytes, 2 operations)=0A=A0= INFO [FLUSH-WRITER-POOL:1] 2010-08-25 19:29:50,873 Memtable.java (line 157= ) Completed flushing /local1/junkbox/cassandra/data/system/LocationInfo-e-= 6-Data.db=0A=A0INFO [main] 2010-08-25 19:29:50,917 StorageService.java (li= ne 374) Starting up server gossip=0A=A0INFO [main] 2010-08-25 19:29:51,093= ColumnFamilyStore.java (line 1239) Loaded 0 rows into the Super2 cache=0A= =A0INFO [main] 2010-08-25 19:29:51,170 CassandraDaemon.java (line 153) Bin= ding thrift service to /0.0.0.0:9160=0A=A0INFO [main] 2010-08-25 19:29:51,= 174 CassandraDaemon.java (line 167) Using TFramedTransport with a max fram= e size of 15728640 bytes.=0A=A0INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,1= 98 Gossiper.java (line 578) Node /192.168.34.28 is now part of the cluster= =0A=A0INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,199 Gossiper.java (line 57= 8) Node /192.168.34.29 is now part of the cluster=0A=A0INFO [GOSSIP_STAGE:= 1] 2010-08-25 19:29:51,199 Gossiper.java (line 578) Node /192.168.34.26 is= now part of the cluster=0A=A0INFO [main] 2010-08-25 19:29:51,204 Cassandr= aDaemon.java (line 208) Listening for thrift clients...=0A=A0INFO [main] 2= 010-08-25 19:29:51,210 Mx4jTool.java (line 73) Will not load MX4J, mx4j-to= ols.jar is not in the classpath=0A=A0INFO [HINTED-HANDOFF-POOL:1] 2010-08-= 25 19:29:51,417 HintedHandOffManager.java (line 191) Started hinted handof= f for endpoint /192.168.34.28=0A=A0INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:= 51,417 Gossiper.java (line 570) InetAddress /192.168.34.28 is now UP=0A=A0= INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,418 HintedHandOffManager.= java (line 247) Finished hinted handoff of 0 rows to endpoint /192.168.34.= 28=0A=A0INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,855 HintedHandOff= Manager.java (line 191) Started hinted handoff for endpoint /192.168.34.29= =0A=A0INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,855 Gossiper.java (line 57= 0) InetAddress /192.168.34.29 is now UP=0A=A0INFO [HINTED-HANDOFF-POOL:1] = 2010-08-25 19:29:51,860 HintedHandOffManager.java (line 247) Finished hint= ed handoff of 0 rows to endpoint /192.168.34.29=0A=A0INFO [HINTED-HANDOFF-= POOL:1] 2010-08-25 19:29:52,930 HintedHandOffManager.java (line 191) Start= ed hinted handoff for endpoint /192.168.34.26=0A=A0INFO [GOSSIP_STAGE:1] 2= 010-08-25 19:29:52,930 Gossiper.java (line 570) InetAddress /192.168.34.26= is now UP=0A=A0INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:52,930 Hinte= dHandOffManager.java (line 247) Finished hinted handoff of 0 rows to endpo= int /192.168.34.26=0A=0AI ran a repair on all the nodes and this was all t= hat they each logged=A0=0A=A0INFO [manual-repair-fe7c5abb-bb0a-4415-aa75-0= d72ba4e7f1b] 2010-08-25 19:49:24,194 AntiEntropyService.java (line 803) Wa= iting for repair requests to: []=0A=0A=0ACluster seems fine. Should I crea= te a Jira ?=A0=0A=0Athanks=0AAaron=0A=0A --Apple-Webmail-42--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574 Content-Type: multipart/related; type="text/html"; boundary=Apple-Webmail-86--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574 --Apple-Webmail-86--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=ISO-8859-1;
I'm running the v0.7-beta1 in a 4 nodes cluster and just doing s= ome simple testing. One of the nodes had been down (machine off, unclean s= hutdown) for an hour or so not sure how many writes were going on, when I = bought it back up this message appears in the other 3 nodes...
<= br>

INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,199= Gossiper.java (line 584) Node /192.168.34.27 has restarted, now UP again<= /div>
 INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,200 Hinte= dHandOffManager.java (line 191) Started hinted handoff for endpoint /192.1= 68.34.27
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,201 Sto= rageService.java (line 636) Node /192.168.34.27 state jump to normal
=
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,201 StorageService.ja= va (line 643) Will not change my token ownership to /192.168.34.27
ERROR [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,640 CassandraDaemon.j= ava (line 82) Uncaught exception in thread Thread[HINTED-HANDOFF-POOL:1,5,= main]
java.util.concurrent.ExecutionException: java.lang.Runtime= Exception: java.util.NoSuchElementException
     =    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.j= ava:222)
        at java.util.concurren= t.FutureTask.get(FutureTask.java:83)
       =  at org.apache.cassandra.concurrent.DebuggableThreadPoolExecutor.afte= rExecute(DebuggableThreadPoolExecutor.java:87)
   &nbs= p;    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(= ThreadPoolExecutor.java:888)
        at= java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.jav= a:908)
        at java.lang.Thread.run(= Thread.java:619)
Caused by: java.lang.RuntimeException: java.uti= l.NoSuchElementException
        at org= apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:34)
=
        at java.util.concurrent.Executors$Ru= nnableAdapter.call(Executors.java:441)
      = ;  at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:3= 03)
        at java.util.concurrent.Fut= ureTask.run(FutureTask.java:138)
       &nbs= p;at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec= utor.java:886)
        ... 2 more
=
Caused by: java.util.NoSuchElementException
   &n= bsp;    at java.util.concurrent.ConcurrentSkipListMap.lastKey(Co= ncurrentSkipListMap.java:1981)
        = at java.util.concurrent.ConcurrentSkipListMap$KeySet.last(ConcurrentSkipLi= stMap.java:2331)
        at org.apache.= cassandra.db.HintedHandOffManager.sendMessage(HintedHandOffManager.java:12= 1)
        at org.apache.cassandra.db.H= intedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:218)<= /div>
        at org.apache.cassandra.db.Hint= edHandOffManager.access$000(HintedHandOffManager.java:78)
 =        at org.apache.cassandra.db.HintedHandOffManager= $1.runMayThrow(HintedHandOffManager.java:296) not sure how many write= s were going on
        at org.apache.c= assandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
&nbs= p;       ... 6 more

On the machine that was off (34.27) there are no errors in the= logs, and here are the entries for around the same time...

=
 INFO [main] 2010-08-25 19:29:50,679 CommitLog.java (= line 340) Recovery complete
 INFO [main] 2010-08-25 19:29:5= 0,769 CommitLog.java (line 180) Log replay complete
 INFO [= main] 2010-08-25 19:29:50,797 StorageService.java (line 342) Cassandra ver= sion: 0.7.0-beta1-SNAPSHOT
 INFO [main] 2010-08-25 19:29:50= ,797 StorageService.java (line 343) Thrift API version: 10.0.0
&= nbsp;INFO [main] 2010-08-25 19:29:50,813 SystemTable.java (line 240) Saved= Token found: 85070591730234615865843651857942052864
 INFO = [main] 2010-08-25 19:29:50,813 SystemTable.java (line 257) Saved ClusterNa= me found: FOO
 INFO [main] 2010-08-25 19:29:50,813 SystemTa= ble.java (line 272) Saved partitioner not found. Using org.apache.cassandr= a.dht.RandomPartitioner
 INFO [main] 2010-08-25 19:29:50,81= 4 ColumnFamilyStore.java (line 422) switching in a fresh Memtable for Loca= tionInfo at CommitLogContext(file=3D'/local1/junkbox/cassandra/commitlog/C= ommitLog-12827213897
70.log', position=3D41336)
 = INFO [main] 2010-08-25 19:29:50,814 ColumnFamilyStore.java (line 706) Enqu= euing flush of Memtable-LocationInfo@916236367(95 bytes, 2 operations)
 INFO [FLUSH-WRITER-POOL:1] 2010-08-25 19:29:50,815 Memtable.j= ava (line 150) Writing Memtable-LocationInfo@916236367(95 bytes, 2 operati= ons)
 INFO [FLUSH-WRITER-POOL:1] 2010-08-25 19:29:50,873 Me= mtable.java (line 157) Completed flushing /local1/junkbox/cassandra/data/s= ystem/LocationInfo-e-6-Data.db
 INFO [main] 2010-08-25 19:2= 9:50,917 StorageService.java (line 374) Starting up server gossip
 INFO [main] 2010-08-25 19:29:51,093 ColumnFamilyStore.java (line 1= 239) Loaded 0 rows into the Super2 cache
 INFO [main] 2010-= 08-25 19:29:51,170 CassandraDaemon.java (line 153) Binding thrift service = to /0.0.0.0:9160
 INFO [main] 2010-08-25 19:29:51,174 Cassa= ndraDaemon.java (line 167) Using TFramedTransport with a max frame size of= 15728640 bytes.
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51= ,198 Gossiper.java (line 578) Node /192.168.34.28 is now part of the clust= er
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,199 Gossiper.= java (line 578) Node /192.168.34.29 is now part of the cluster
&= nbsp;INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,199 Gossiper.java (line 578= ) Node /192.168.34.26 is now part of the cluster
 INFO [mai= n] 2010-08-25 19:29:51,204 CassandraDaemon.java (line 208) Listening for t= hrift clients...
 INFO [main] 2010-08-25 19:29:51,210 Mx4jT= ool.java (line 73) Will not load MX4J, mx4j-tools.jar is not in the classp= ath
 INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,417 H= intedHandOffManager.java (line 191) Started hinted handoff for endpoint /1= 92.168.34.28
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51,417= Gossiper.java (line 570) InetAddress /192.168.34.28 is now UP
&= nbsp;INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,418 HintedHandOffMan= ager.java (line 247) Finished hinted handoff of 0 rows to endpoint /192.16= 8.34.28
 INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,8= 55 HintedHandOffManager.java (line 191) Started hinted handoff for endpoin= t /192.168.34.29
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:29:51= ,855 Gossiper.java (line 570) InetAddress /192.168.34.29 is now UP
 INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:51,860 HintedHandOf= fManager.java (line 247) Finished hinted handoff of 0 rows to endpoint /19= 2.168.34.29
 INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:= 52,930 HintedHandOffManager.java (line 191) Started hinted handoff for end= point /192.168.34.26
 INFO [GOSSIP_STAGE:1] 2010-08-25 19:2= 9:52,930 Gossiper.java (line 570) InetAddress /192.168.34.26 is now UP
 INFO [HINTED-HANDOFF-POOL:1] 2010-08-25 19:29:52,930 HintedHa= ndOffManager.java (line 247) Finished hinted handoff of 0 rows to endpoint= /192.168.34.26

I ran a repair on all the n= odes and this was all that they each logged 
 INFO [ma= nual-repair-fe7c5abb-bb0a-4415-aa75-0d72ba4e7f1b] 2010-08-25 19:49:24,194 = AntiEntropyService.java (line 803) Waiting for repair requests to: []


Cluster seems fine. Should I create a = Jira ? 

thanks
Aaron
--Apple-Webmail-86--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574-- --Apple-Webmail-42--c2e5bf3d-392c-e6ac-b3bd-b5b672aed574--