You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@cassandra.apache.org by J T <jt...@googlemail.com> on 2010/10/06 04:50:25 UTC
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.IndexScanCommand@1422265 from
1268@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
Re: Null Pointer Exception / Secondary Indices
Posted by J T <jt...@googlemail.com>.
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 <gd...@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 <jt...@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.IndexScanCommand@b3a5a0 from
> > 101@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:58@1286840713
> > DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line
> 122)
> > collecting 3 of 2147483647: requestor:false:58@1286840713
> > DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line
> 122)
> > collecting 4 of 2147483647: requestor_network:false:57@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 <jt...@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 <jt...@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 <st...@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" <jt...@googlemail.com>
> >>>> Sent: Tuesday, October 5, 2010 9:50pm
> >>>> To: cassandra-user@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.IndexScanCommand@1422265 from
> >>>> 1268@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
> >>>>
> >>>>
> >>>
> >>
> >
> >
>
Re: Null Pointer Exception / Secondary Indices
Posted by Gary Dusbabek <gd...@gmail.com>.
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 <jt...@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.IndexScanCommand@b3a5a0 from
> 101@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:58@1286840713
> DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line 122)
> collecting 3 of 2147483647: requestor:false:58@1286840713
> DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line 122)
> collecting 4 of 2147483647: requestor_network:false:57@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 <jt...@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 <jt...@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 <st...@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" <jt...@googlemail.com>
>>>> Sent: Tuesday, October 5, 2010 9:50pm
>>>> To: cassandra-user@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.IndexScanCommand@1422265 from
>>>> 1268@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
>>>>
>>>>
>>>
>>
>
>
Re: Null Pointer Exception / Secondary Indices
Posted by J T <jt...@googlemail.com>.
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.IndexScanCommand@b3a5a0 from
101@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:58@1286840713
DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line 122)
collecting 3 of 2147483647: requestor:false:58@1286840713
DEBUG [ReadStage:6] 2010-10-12 08:30:31,200 SliceQueryFilter.java (line 122)
collecting 4 of 2147483647: requestor_network:false:57@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 <jt...@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 <jt...@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 <st...@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" <jt...@googlemail.com>
>>> Sent: Tuesday, October 5, 2010 9:50pm
>>> To: cassandra-user@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.IndexScanCommand@1422265 from
>>> 1268@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
>>>
>>>
>>>
>>
>
Re: Null Pointer Exception / Secondary Indices
Posted by J T <jt...@googlemail.com>.
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 <jt...@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 <st...@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" <jt...@googlemail.com>
>> Sent: Tuesday, October 5, 2010 9:50pm
>> To: cassandra-user@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.IndexScanCommand@1422265 from
>> 1268@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
>>
>>
>>
>
Re: Null Pointer Exception / Secondary Indices
Posted by J T <jt...@googlemail.com>.
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 <st...@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" <jt...@googlemail.com>
> Sent: Tuesday, October 5, 2010 9:50pm
> To: cassandra-user@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.IndexScanCommand@1422265 from
> 1268@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
>
>
>
RE: Null Pointer Exception / Secondary Indices
Posted by Stu Hood <st...@rackspace.com>.
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" <jt...@googlemail.com>
Sent: Tuesday, October 5, 2010 9:50pm
To: cassandra-user@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.IndexScanCommand@1422265 from
1268@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
Null Pointer Exception / Secondary Indices
Posted by J T <jt...@googlemail.com>.
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 never 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.IndexScanCommand@1422265 from
1268@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