cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From J T <jt4websi...@googlemail.com>
Subject Re: Null Pointer Exception / Secondary Indices
Date Wed, 13 Oct 2010 16:15:01 GMT
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 <gdusbabek@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 <jt4websites@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 <jt4websites@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 <jt4websites@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.hood@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" <jt4websites@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
> >>>>
> >>>>
> >>>
> >>
> >
> >
>

Mime
View raw message