Hmm, I wish that were the case, since once those messages start appearing .. they never stop .. resulting in timeouts on all client requests until I stop the server.
When I restart the server and try querying for anything via the index the messages then resumed. Right now the problem has gone away, but only because I have stopped deleting any rows that have indexes defined on them (for now) but thats not a long term solution of course. On Wed, Oct 13, 2010 at 2:52 PM, Gary Dusbabek <gdusba...@gmail.com> wrote: > If you're not seeing the NullPointerException at this point, things > are probably good. These messages are expected when logging at DEBUG. > > Gary. > > On Tue, Oct 12, 2010 at 02:35, J T <jt4websi...@googlemail.com> wrote: > > 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 > >>>> > >>>> > >>> > >> > > > > >
