I rinsed & repeated after updating to the latest trunk version and checking if the 1571 patch was included (which it appeared to be) and the start of the repeating error sequence was:
DEBUG [pool-1-thread-21] 2010-10-12 08:30:31,143 ClientState.java (line 81) logged in: #<User allow_all groups=[]> DEBUG [pool-1-thread-21] 2010-10-12 08:30:31,166 CassandraServer.java (line 543) scan DEBUG [pool-1-thread-21] 2010-10-12 08:30:31,169 StorageProxy.java (line 563) restricted single token match for query [0,0] DEBUG [pool-1-thread-21] 2010-10-12 08:30:31,169 StorageProxy.java (line 649) scan ranges are [0,0] DEBUG [pool-1-thread-21] 2010-10-12 08:30:31,179 StorageProxy.java (line 669) reading org.apache.cassandra.db.indexscancomm...@b3a5a0 from 1...@localhost/127.0.0.1 DEBUG [ReadStage:6] 2010-10-12 08:30:31,194 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,198 SliceQueryFilter.java (line 122) collecting 0 of 2147483647: is_confirmed:false:5...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,198 SliceQueryFilter.java (line 122) collecting 1 of 2147483647: request_type:false:6...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,199 SliceQueryFilter.java (line 122) collecting 2 of 2147483647: requested:false:5...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line 122) collecting 3 of 2147483647: requestor:false:5...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line 122) collecting 4 of 2147483647: requestor_network:false:5...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,206 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,209 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,211 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,214 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,217 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,220 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,223 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 DEBUG [ReadStage:6] 2010-10-12 08:30:31,225 SliceQueryFilter.java (line 122) collecting 0 of 1: null:false:0...@1286840713 On Tue, Oct 12, 2010 at 7:50 AM, J T <jt4websi...@googlemail.com> wrote: > Hi, > > Looks like I was premature in my response. > > I had cause today to wipe my datastore and restart cassandra and reload the > .yaml containing the schema definition. > > After doing a restart of my app which essentially inserted into a CF with a > 2ndary idx and then queried that CF I was left with log files full of the > following. > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,849 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,850 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,851 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,852 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,798 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,853 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,854 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,854 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,855 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,855 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,856 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:1] 2010-10-12 07:29:26,856 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,857 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,858 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > DEBUG [ReadStage:3] 2010-10-12 07:29:26,859 SliceQueryFilter.java (line > 122) collecting 0 of 1: null:false:0...@1286840713 > > > This resulted in timeouts in my app. > > > Jason > > On Wed, Oct 6, 2010 at 7:11 PM, J T <jt4websi...@googlemail.com> wrote: > >> Hi, >> >> On a first pass, that patch seems to have solved the problem. >> I'll be testing that functionality repeatedly in the next day or so I'll >> let you know how it fairs. >> >> Thanks >> >> Jason >> >> >> On Wed, Oct 6, 2010 at 4:06 PM, Stu Hood <stu.h...@rackspace.com> wrote: >> >>> Hey JT, >>> >>> I believe this issue should be fixed by CASSANDRA-1571... if you're able >>> to test that patch, it would be very helpful. >>> >>> Thanks, >>> Stu >>> >>> -----Original Message----- >>> From: "J T" <jt4websi...@googlemail.com> >>> Sent: Tuesday, October 5, 2010 9:50pm >>> To: cassandra-u...@incubator.apache.org >>> Subject: Null Pointer Exception / Secondary Indices >>> >>> Hi, >>> >>> I've been battling against some errors that only seem to crop up when I'm >>> messing around with secondary indices in 0.7-beta2. >>> >>> Namely I seem to get errors like this start to happen, after I 'delete' a >>> row in a CF that has a couple of secondary indices on it and then at some >>> point later try to query for any rows from that CF. >>> Usually I don;t get the Null pointer exception below, instead what often >>> happens is that the SliceQueryFilter.java line before it, repeats itself >>> forever bever stopping until I kill the server >>> >>> On this occasion I got a null pointer exception as well. This is on trunk >>> as >>> of tonight (but I was getting it over the weekend as well). >>> >>> DEBUG [pool-1-thread-149] 2010-10-06 03:43:15,436 ClientState.java (line >>> 102) logged in: #<User allow_all groups=[]> >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,444 CassandraServer.java >>> (line >>> 536) scan >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,444 StorageProxy.java (line >>> 571) computing restricted ranges for query [0,0] >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,445 StorageProxy.java (line >>> 583) Adding to restricted ranges >>> (91870423363853801063842423182856312085,0] >>> for >>> >>> (91870423363853801063842423182856312085,91870423363853801063842423182856312085] >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,446 StorageProxy.java (line >>> 583) Adding to restricted ranges >>> (0,91870423363853801063842423182856312085] >>> for >>> >>> (91870423363853801063842423182856312085,91870423363853801063842423182856312085] >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,447 StorageProxy.java (line >>> 617) Sorted ranges are [(0,91870423363853801063842423182856312085], >>> (91870423363853801063842423182856312085,0]] >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,447 StorageProxy.java (line >>> 680) scan ranges are >>> >>> (0,91870423363853801063842423182856312085],(91870423363853801063842423182856312085,0] >>> DEBUG [pool-1-thread-99] 2010-10-06 03:43:15,448 StorageProxy.java (line >>> 700) reading org.apache.cassandra.db.indexscancomm...@1422265 from >>> 1...@localhost/127.0.0.1 >>> *DEBUG [ReadStage:24] 2010-10-06 03:43:15,450 SliceQueryFilter.java (line >>> 122) collecting 0 of 1: null:false:0...@1286332576* >>> ERROR [ReadStage:24] 2010-10-06 03:43:15,451 >>> DebuggableThreadPoolExecutor.java (line 103) Error in ThreadPoolExecutor >>> java.lang.RuntimeException: java.lang.NullPointerException >>> at >>> >>> org.apache.cassandra.service.IndexScanVerbHandler.doVerb(IndexScanVerbHandler.java:50) >>> at >>> >>> org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:50) >>> at >>> >>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) >>> at >>> >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) >>> at java.lang.Thread.run(Thread.java:636) >>> Caused by: java.lang.NullPointerException >>> at >>> >>> org.apache.cassandra.db.ColumnFamilyStore.satisfies(ColumnFamilyStore.java:1297) >>> at >>> >>> org.apache.cassandra.db.ColumnFamilyStore.scan(ColumnFamilyStore.java:1245) >>> at >>> >>> org.apache.cassandra.service.IndexScanVerbHandler.doVerb(IndexScanVerbHandler.java:41) >>> ... 4 more >>> ERROR [ReadStage:24] 2010-10-06 03:43:15,453 AbstractCassandraDaemon.java >>> (line 88) Fatal exception in thread Thread[ReadStage:24,5,main] >>> java.lang.RuntimeException: java.lang.NullPointerException >>> at >>> >>> org.apache.cassandra.service.IndexScanVerbHandler.doVerb(IndexScanVerbHandler.java:50) >>> at >>> >>> org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:50) >>> at >>> >>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) >>> at >>> >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) >>> at java.lang.Thread.run(Thread.java:636) >>> Caused by: java.lang.NullPointerException >>> at >>> >>> org.apache.cassandra.db.ColumnFamilyStore.satisfies(ColumnFamilyStore.java:1297) >>> at >>> >>> org.apache.cassandra.db.ColumnFamilyStore.scan(ColumnFamilyStore.java:1245) >>> at >>> >>> org.apache.cassandra.service.IndexScanVerbHandler.doVerb(IndexScanVerbHandler.java:41) >>> ... 4 more >>> >>> >>> >> >
