cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Desimpel, Ignace" <Ignace.Desim...@nuance.com>
Subject RE: invalid column name length 0
Date Wed, 05 Oct 2011 13:49:49 GMT
TTLs : no
Deletion : yes ; but I think I can avoid this and thus running the same test without deletion,
just to eliminate possibilities.

-----Original Message-----
From: Sylvain Lebresne [mailto:sylvain@datastax.com] 
Sent: woensdag 5 oktober 2011 15:34
To: user@cassandra.apache.org
Subject: Re: invalid column name length 0

Ok. Quick other question then. Did you issue deletion and/or used TTLs for that test ?

Also, it's probably worth creating a ticket on https://issues.apache.org/jira/browse/CASSANDRA
if you don't mind.

--
Sylvain

On Wed, Oct 5, 2011 at 2:42 PM, Desimpel, Ignace <Ignace.Desimpel@nuance.com> wrote:
> Did the test again, empty database, with replication factor 3, Cassandra running in it's
own jvm.
> All data is now stored using a separate program that connects to the database using THRIFT.
> At least this results in a lot less Dead/Up messages (I guess the GC had too much work
handling the non-cassandra memory objects), but it is still there.
>
> Also the exception 'invalid column name length 0' is there again. Below is a log of machine
x.x.x.59 starting after 00:00 hour. One hour before 00:00 I stopped all storing, so that the
machines had nothing else to do besides compacting and cleaning up and ... (still compacting
and discarding obsolete commit logs).
>
> Checked the log files on all machines, and no exception nor assert related to column
names could be found.
>
> 2011-10-05 00:06:25.172 InetAddress /x.x.x.60 is now dead.
> 2011-10-05 00:06:25.179 InetAddress /x.x.x.60 is now UP
> 2011-10-05 00:46:47.091 Saved KsFullIdx-ForwardStringValues-KeyCache 
> (94 items) in 19 ms
> 2011-10-05 00:46:47.334 Saved KsFullIdx-ReverseLongValues-KeyCache 
> (98732 items) in 117 ms
> 2011-10-05 00:46:47.797 Saved KsFullIdx-ReverseLabelValues-KeyCache 
> (273425 items) in 259 ms
> 2011-10-05 00:46:48.645 Saved KsFullIdx-ReverseStringValues-KeyCache 
> (500000 items) in 472 ms
> 2011-10-05 01:00:52.691 ColumnFamilyStore(table='system', 
> columnFamily='HintsColumnFamily') liveRatio is 28.375375375375377 
> (just-counted was 28.375375375375377).  calculation took 4ms for 56 
> columns
> 2011-10-05 01:07:02.052 InetAddress /x.x.x.60 is now dead.
> 2011-10-05 01:07:02.058 InetAddress /x.x.x.60 is now UP
> 2011-10-05 01:07:02.060 InetAddress /x.x.x.61 is now dead.
> 2011-10-05 01:07:02.060 InetAddress /x.x.x.61 is now UP
> 2011-10-05 02:07:33.785 InetAddress /x.x.x.60 is now dead.
> 2011-10-05 02:07:33.791 InetAddress /x.x.x.60 is now UP
> 2011-10-05 02:41:12.528 Fatal exception in thread 
> Thread[HintedHandoff:1,5,main]
> java.io.IOError: 
> org.apache.cassandra.db.ColumnSerializer$CorruptColumnException: 
> invalid column name length 0
>        at 
> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSort
> edMap.java:265) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
> 281) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
> 236) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(ConcurrentS
> kipListMap.java:1493) ~[na:1.6.0_24]
>        at 
> java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMa
> p.java:1443) ~[na:1.6.0_24]
>        at 
> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
> java:445) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
> java:428) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
> java:418) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
> java:380) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.columniterator.IndexedSliceReader$IndexedBlock
> Fetcher.getNextBlock(IndexedSliceReader.java:179) 
> ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext(
> IndexedSliceReader.java:121) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext(
> IndexedSliceReader.java:49) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIt
> erator.java:140) ~[guava-r08.jar:na]
>        at 
> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.ja
> va:135) ~[guava-r08.jar:na]
>        at 
> org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(SS
> TableSliceIterator.java:108) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.commons.collections.iterators.CollatingIterator.set(Collati
> ngIterator.java:283) ~[commons-collections-3.2.1.jar:3.2.1]
>        at 
> org.apache.commons.collections.iterators.CollatingIterator.least(Colla
> tingIterator.java:326) ~[commons-collections-3.2.1.jar:3.2.1]
>        at 
> org.apache.commons.collections.iterators.CollatingIterator.next(Collat
> ingIterator.java:230) ~[commons-collections-3.2.1.jar:3.2.1]
>        at 
> org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingIterat
> or.java:69) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIt
> erator.java:140) ~[guava-r08.jar:na]
>        at 
> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.ja
> va:135) ~[guava-r08.jar:na]
>        at 
> org.apache.cassandra.db.filter.SliceQueryFilter.collectReducedColumns(
> SliceQueryFilter.java:116) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.filter.QueryFilter.collectCollatedColumns(Quer
> yFilter.java:142) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFam
> ilyStore.java:1427) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamily
> Store.java:1304) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamily
> Store.java:1261) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.HintedHandOffManager.sendRow(HintedHandOffMana
> ger.java:155) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(Hi
> ntedHandOffManager.java:350) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffM
> anager.java:89) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandO
> ffManager.java:397) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30
> ) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecu
> tor.java:886) ~[na:1.6.0_24]
>        at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.
> java:908) ~[na:1.6.0_24]
>        at java.lang.Thread.run(Thread.java:662) ~[na:1.6.0_24] Caused 
> by: org.apache.cassandra.db.ColumnSerializer$CorruptColumnException: 
> invalid column name length 0
>        at 
> org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.
> java:89) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at 
> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSort
> edMap.java:261) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        ... 33 common frames omitted
> 2011-10-05 02:42:04.961 Started hinted handoff for endpoint /x.x.x.60
> 2011-10-05 02:42:04.961 Finished hinted handoff of 0 rows to endpoint 
> /x.x.x.60
> 2011-10-05 02:42:18.381 Started hinted handoff for endpoint /x.x.x.61
> 2011-10-05 03:08:04.882 InetAddress /x.x.x.60 is now dead.
> 2011-10-05 03:08:04.890 InetAddress /x.x.x.61 is now dead.
>
> -----Original Message-----
> From: Desimpel, Ignace [mailto:Ignace.Desimpel@nuance.com]
> Sent: dinsdag 4 oktober 2011 10:48
> To: user@cassandra.apache.org
> Subject: RE: invalid column name length 0
>
> I run the application with the JVM -ea option, so assertions are enabled.
>
> I insert records using the StorageProxy.mutate function. The elements are created  as
specified below.
> Below : The arForwardFuncValueBytes and arReverseFuncValueBytes are tested for null or
length = 0 by my code. The oTokenColumnName bytebuffer is created each time, but is reused
in the two QueryPaths. I assume this is allowed.
>
> QueryPath oPathtoInsert = new QueryPath( sForwardColumnFamToAdd, 
> ByteBuffer.wrap(arForwardFuncValueBytes), oTokenColumnName); 
> oForwardRowMut.add(oPathtoInsert, oTokenPos, lUpdateTimeStamp);
>
> oPathtoInsert = new QueryPath(sReverseColumnFamToAdd, 
> ByteBuffer.wrap(arReverseFuncValueBytes), oTokenColumnName); 
> oReverseRowMut.add(oPathtoInsert, oTokenPos, lUpdateTimeStamp);
>
> Anyway, I will do a test inserting the same data, but via thrift and with Cassandra in
a separate jvm.
>
> Ignace
>
> -----Original Message-----
> From: Sylvain Lebresne [mailto:sylvain@datastax.com]
> Sent: maandag 3 oktober 2011 18:02
> To: user@cassandra.apache.org
> Subject: Re: invalid column name length 0
>
> On the 'invalid column name length 0' exception, since you're embedding the Cassandra
server, it could be that you modify a column ByteBuffer that you feed to Cassandra (that's
fairly easy to do with ByteBuffer by calling some relative get method of ByteBuffer). Or more
generally that you feed a zero length ByteBuffer as a column name (maybe by using a relative
put without a rewind/reset afterwards).
>
> Which leads me to a question: do you run your server without assertions enabled ? (I
suspect you do).
> If so I suggest you turn them on (to help you find the problem). It turns out that we
detect zero length column name at write time in an assertion, while we detect them at read
time using a good old 'if'. So if you do feed a zero length column name to Cassandra throught
the StorageService interface, you'd only get the exception you get at read time.
>
> Now I don't know how much those exceptions are related to the timeoutException you're
seeing, but such error would typically produce timeout on reads whatever the rpc_timeout value
is.
>
> --
> Sylvain
>
> On Mon, Oct 3, 2011 at 4:58 PM, Desimpel, Ignace <Ignace.Desimpel@nuance.com> wrote:
>> I did an extra test, again starting from scratch but with replication factor 1.
>> I still get the dead/up messages and timeout exceptions, but the system keeps running
and storing. However I ran out of disk space, logically producing a lot of other errors.
>> Then I restarted the Cassandra servers, so they were able to cleanup and restart
without errors.
>> Then I did some queries I normally do and got again exceptions like " invalid column
name length 0", but also other like " Corrupt (negative) value length encountered".
>> Exception : see below.
>>
>> With this test, I run Cassandra embedded, so a lot of processing ( and object allocations
) are done within the same JVM. I will modify the code so that 'my processing/allcations'
are done outside and the Cassandra jvm only has to store the records. But that's for tomorrow.
>>
>> Did anyone ran into this type of error? And what was the reason? Any help?
>>
>> 2011-10-03 11:49:21.035 Fatal exception in thread 
>> Thread[ReadStage:623,5,main]
>> java.io.IOError: java.io.IOException: Corrupt (negative) value length 
>> encountered
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSor
>> t
>> edMap.java:265) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
>> 281) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
>> 236) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(Concurrent
>> S
>> kipListMap.java:1493) ~[na:1.6.0_24]
>>        at
>> java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListM
>> a
>> p.java:1443) ~[na:1.6.0_24]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:445) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:428) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:418) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:380) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader$IndexedBloc
>> k
>> Fetcher.getNextBlock(IndexedSliceReader.java:179)
>> ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext
>> (
>> IndexedSliceReader.java:121) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext
>> (
>> IndexedSliceReader.java:49) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractI
>> t
>> erator.java:140) ~[guava-r08.jar:na]
>>        at
>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.j
>> a
>> va:135) ~[guava-r08.jar:na]
>>        at
>> org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(S
>> S
>> TableSliceIterator.java:108) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.commons.collections.iterators.CollatingIterator.set(Collat
>> i
>> ngIterator.java:283) ~[commons-collections-3.2.1.jar:3.2.1]
>>        at
>> org.apache.commons.collections.iterators.CollatingIterator.least(Coll
>> a
>> tingIterator.java:326) ~[commons-collections-3.2.1.jar:3.2.1]
>>        at
>> org.apache.commons.collections.iterators.CollatingIterator.next(Colla
>> t
>> ingIterator.java:230) ~[commons-collections-3.2.1.jar:3.2.1]
>>        at
>> org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingItera
>> t
>> or.java:69) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractI
>> t
>> erator.java:140) ~[guava-r08.jar:na]
>>        at
>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.j
>> a
>> va:135) ~[guava-r08.jar:na]
>>        at
>> org.apache.cassandra.db.filter.SliceQueryFilter.collectReducedColumns
>> (
>> SliceQueryFilter.java:116) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.filter.QueryFilter.collectCollatedColumns(Que
>> r
>> yFilter.java:142) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFa
>> m
>> ilyStore.java:1427) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamil
>> y
>> Store.java:1304) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamil
>> y
>> Store.java:1261) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at org.apache.cassandra.db.Table.getRow(Table.java:385)
>> ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadComm
>> a
>> nd.java:61) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:6
>> 9
>> ) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.
>> j
>> ava:59) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec
>> u
>> tor.java:886) ~[na:1.6.0_24]
>>        at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.
>> java:908) ~[na:1.6.0_24]
>>        at java.lang.Thread.run(Thread.java:662) ~[na:1.6.0_24] Caused
>> by: java.io.IOException: Corrupt (negative) value length encountered
>>        at
>> org.apache.cassandra.utils.ByteBufferUtil.readWithLength(ByteBufferUt
>> i
>> l.java:348) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.
>> java:108) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSor
>> t
>> edMap.java:261) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        ... 32 common frames omitted
>> 2011-10-03 11:55:01.745 Fatal exception in thread 
>> Thread[ReadStage:624,5,main]
>> java.io.IOError:
>> org.apache.cassandra.db.ColumnSerializer$CorruptColumnException:
>> invalid column name length 0
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSor
>> t
>> edMap.java:265) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
>> 281) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
>> 236) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(Concurrent
>> S
>> kipListMap.java:1493) ~[na:1.6.0_24]
>>        at
>> java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListM
>> a
>> p.java:1443) ~[na:1.6.0_24]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:445) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:428) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:418) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>> java:380) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader$IndexedBloc
>> k
>> Fetcher.getNextBlock(IndexedSliceReader.java:179)
>> ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext
>> (
>> IndexedSliceReader.java:121) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext
>> (
>> IndexedSliceReader.java:49) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractI
>> t
>> erator.java:140) ~[guava-r08.jar:na]
>>        at
>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.j
>> a
>> va:135) ~[guava-r08.jar:na]
>>        at
>> org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(S
>> S
>> TableSliceIterator.java:108) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.commons.collections.iterators.CollatingIterator.anyHasNext
>> (
>> CollatingIterator.java:364) ~[commons-collections-3.2.1.jar:3.2.1]
>>        at
>> org.apache.commons.collections.iterators.CollatingIterator.hasNext(Co
>> l
>> latingIterator.java:217) ~[commons-collections-3.2.1.jar:3.2.1]
>>        at
>> org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingItera
>> t
>> or.java:55) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractI
>> t
>> erator.java:140) ~[guava-r08.jar:na]
>>        at
>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.j
>> a
>> va:135) ~[guava-r08.jar:na]
>>        at
>> org.apache.cassandra.db.filter.SliceQueryFilter.collectReducedColumns
>> (
>> SliceQueryFilter.java:116) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.filter.QueryFilter.collectCollatedColumns(Que
>> r
>> yFilter.java:142) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFa
>> m
>> ilyStore.java:1427) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamil
>> y
>> Store.java:1304) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamil
>> y
>> Store.java:1261) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at org.apache.cassandra.db.Table.getRow(Table.java:385)
>> ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadComm
>> a
>> nd.java:61) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:6
>> 9
>> ) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.
>> j
>> ava:59) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec
>> u
>> tor.java:886) ~[na:1.6.0_24]
>>        at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.
>> java:908) ~[na:1.6.0_24]
>>        at java.lang.Thread.run(Thread.java:662) ~[na:1.6.0_24] Caused
>> by: org.apache.cassandra.db.ColumnSerializer$CorruptColumnException:
>> invalid column name length 0
>>        at
>> org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.
>> java:89) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        at
>> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSor
>> t
>> edMap.java:261) ~[apache-cassandra-0.8.6.jar:0.8.6]
>>        ... 31 common frames omitted
>> 2011-10-03 14:18:53.436 Saved CodeStructure-Computers-KeyCache (1
>> items) in 16 ms
>> 2011-10-03 14:19:24.804 Saved KsFullIdx-ReverseLabelValues-KeyCache
>> (123981 items) in 192 ms
>>
>> -----Original Message-----
>> From: Desimpel, Ignace [mailto:Ignace.Desimpel@nuance.com]
>> Sent: dinsdag 27 september 2011 17:51
>> To: user@cassandra.apache.org
>> Subject: RE: invalid column name length 0
>>
>> No, brand new, started from scratch, no data at all.
>> My setup get into trouble after a couple of hours since it then starts giving the
Dead/up messages.
>> I also get messages like '11 MUTATION messages dropped in server lifetime'
>> Later on I got this type of exception also.
>>
>> -----Original Message-----
>> From: Jonathan Ellis [mailto:jbellis@gmail.com]
>> Sent: dinsdag 27 september 2011 17:41
>> To: user@cassandra.apache.org
>> Subject: Re: invalid column name length 0
>>
>> Is this upgraded from an earlier version?
>>
>> On Tue, Sep 27, 2011 at 8:51 AM, Desimpel, Ignace <Ignace.Desimpel@nuance.com>
wrote:
>>> Version 0.8.6.
>>>
>>> After an extreme load to 4 (embedded) cassandra servers with 
>>> replication factor 3 ( Ubuntu 10.4, dual six core, 64 bit, no swap, 
>>> 1
>>> 15000 rpm commitlog disk, 1 15000 rpm datafile disk, ) I get a fatal 
>>> exception as listed below.
>>>
>>> No more messages were found after that.
>>>
>>>
>>>
>>> Probably other things are going wrong like the message "410 Could 
>>> not complete hinted handoff to /xxx.yyy.zzz.60", or the Dead/Up 
>>> messages (occurring long before this exception).
>>>
>>> But maybe this exception can point me in the right direction or even 
>>> point out some bug in Cassandra.
>>>
>>>
>>>
>>> Thanks,
>>>
>>> Ignace
>>>
>>>
>>>
>>>
>>>
>>> 2011-09-27 06:59:46,383 Compacting large row
>>> KsFullIdx/ForwardStringValues:3237343034 (178032211 bytes) 
>>> incrementally
>>>
>>> 2011-09-27 07:00:09,738 GC for ParNew: 311 ms for 1 collections,
>>> 8139389704 used; max is 33344716800
>>>
>>> 2011-09-27 07:00:12,818 Compacting large row
>>> KsFullIdx/ForwardStringValues:31363437 (1281862723 bytes) 
>>> incrementally
>>>
>>> 2011-09-27 07:02:16,025 Compacting large row
>>> KsFullIdx/ForwardStringValues:31363438 (1623095072 bytes) 
>>> incrementally
>>>
>>> 2011-09-27 07:04:38,332 GC for ParNew: 534 ms for 1 collections,
>>> 7811259472 used; max is 33344716800
>>>
>>> 2011-09-27 07:04:52,803 Compacting large row
>>> KsFullIdx/ForwardStringValues:3238313433 (1435774436 bytes) 
>>> incrementally
>>>
>>> 2011-09-27 07:06:57,160 Compacted to 
>>> /media/datadrive1/capd.cassandra.capd/dbdatafile/KsFullIdx/ForwardStringValues-tmp-g-542-Data.db.
>>> 43,244,902,670 to 42,780,624,408 (~98% of original) bytes for 1,260 keys.
>>> Time: 4,321,960ms.
>>>
>>> 2011-09-27 08:01:42,090 Saved KsFullIdx-ForwardStringValues-KeyCache
>>> (572
>>> items) in 16 ms
>>>
>>> 2011-09-27 08:01:42,182 Saved KsFullIdx-ReverseStringValues-KeyCache
>>> (25688
>>> items) in 63 ms
>>>
>>> 2011-09-27 08:18:13,078 InetAddress /xxx.yyy.zzz.62 is now dead.
>>>
>>> 2011-09-27 08:18:16,467 InetAddress /xxx.yyy.zzz.62 is now UP
>>>
>>> 2011-09-27 08:48:56,410 Could not complete hinted handoff to
>>> /xxx.yyy.zzz.60
>>>
>>> 2011-09-27 08:48:56,410 Enqueuing flush of
>>> Memtable-HintsColumnFamily@2083796703(12097/196566 serialized/live 
>>> bytes,
>>> 254 ops)
>>>
>>> 2011-09-27 08:48:56,411 Writing
>>> Memtable-HintsColumnFamily@2083796703(12097/196566 serialized/live 
>>> bytes,
>>> 254 ops)
>>>
>>> 2011-09-27 08:48:56,411 Nothing to compact in HintsColumnFamily; use 
>>> forceUserDefinedCompaction if you wish to force compaction of single 
>>> sstables (e.g. for tombstone collection)
>>>
>>> 2011-09-27 08:48:56,411 Finished hinted handoff of 254 rows to 
>>> endpoint
>>> /xxx.yyy.zzz.60
>>>
>>> 2011-09-27 08:48:56,490 Completed flushing 
>>> /media/datadrive1/capd.cassandra.capd/dbdatafile/system/HintsColumnF
>>> a
>>> m
>>> ily-g-10-Data.db
>>> (25079 bytes)
>>>
>>> 2011-09-27 08:49:42,858 Started hinted handoff for endpoint
>>> /xxx.yyy.zzz.62
>>>
>>> 2011-09-27 12:01:42,100 Saved KsFullIdx-ForwardStringValues-KeyCache
>>> (712
>>> items) in 27 ms
>>>
>>> 2011-09-27 12:01:42,182 Saved KsFullIdx-ReverseStringValues-KeyCache
>>> (30742
>>> items) in 55 ms
>>>
>>> 2011-09-27 12:10:01,016 InetAddress /xxx.yyy.zzz.59 is now dead.
>>>
>>> 2011-09-27 12:10:02,272 InetAddress /xxx.yyy.zzz.59 is now UP
>>>
>>> 2011-09-27 12:17:34,596 Fatal exception in thread 
>>> Thread[HintedHandoff:1,5,RMI Runtime]
>>>
>>> java.io.IOError:
>>> org.apache.cassandra.db.ColumnSerializer$CorruptColumnException:
>>> invalid column name length 0
>>>
>>>                 at
>>> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSo
>>> r
>>> t
>>> edMap.java:265)
>>>
>>>                 at
>>> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
>>> 281)
>>>
>>>                 at
>>> org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:
>>> 236)
>>>
>>>                 at
>>> java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(Concurren
>>> t
>>> S
>>> kipListMap.java:1493)
>>>
>>>                 at
>>> java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipList
>>> M
>>> a
>>> p.java:1443)
>>>
>>>                 at
>>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>>> java:445)
>>>
>>>                 at
>>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>>> java:428)
>>>
>>>                 at
>>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>>> java:418)
>>>
>>>                 at
>>> org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.
>>> java:380)
>>>
>>>                 at
>>> org.apache.cassandra.db.columniterator.IndexedSliceReader$IndexedBlo
>>> c
>>> k
>>> Fetcher.getNextBlock(IndexedSliceReader.java:179)
>>>
>>>                 at
>>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNex
>>> t
>>> (
>>> IndexedSliceReader.java:121)
>>>
>>>                 at
>>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNex
>>> t
>>> (
>>> IndexedSliceReader.java:49)
>>>
>>>                 at
>>> com.google.common.collect.AbstractIterator.tryToComputeNext(Abstract
>>> I
>>> t
>>> erator.java:140)
>>>
>>>                 at
>>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.
>>> j
>>> a
>>> va:135)
>>>
>>>                 at
>>> org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(
>>> S
>>> S
>>> TableSliceIterator.java:108)
>>>
>>>                 at
>>> org.apache.commons.collections.iterators.CollatingIterator.set(Colla
>>> t
>>> i
>>> ngIterator.java:283)
>>>
>>>                 at
>>> org.apache.commons.collections.iterators.CollatingIterator.least(Col
>>> l
>>> a
>>> tingIterator.java:326)
>>>
>>>                 at
>>> org.apache.commons.collections.iterators.CollatingIterator.next(Coll
>>> a
>>> t
>>> ingIterator.java:230)
>>>
>>>                 at
>>> org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingIter
>>> a
>>> t
>>> or.java:69)
>>>
>>>                 at
>>> com.google.common.collect.AbstractIterator.tryToComputeNext(Abstract
>>> I
>>> t
>>> erator.java:140)
>>>
>>>                 at
>>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.
>>> j
>>> a
>>> va:135)
>>>
>>>                 at
>>> org.apache.cassandra.db.filter.SliceQueryFilter.collectReducedColumn
>>> s
>>> (
>>> SliceQueryFilter.java:116)
>>>
>>>                 at
>>> org.apache.cassandra.db.filter.QueryFilter.collectCollatedColumns(Qu
>>> e
>>> r
>>> yFilter.java:142)
>>>
>>>                 at
>>> org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnF
>>> a
>>> m
>>> ilyStore.java:1427)
>>>
>>>                 at
>>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFami
>>> l
>>> y
>>> Store.java:1304)
>>>
>>>                 at
>>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFami
>>> l
>>> y
>>> Store.java:1261)
>>>
>>>                 at
>>> org.apache.cassandra.db.HintedHandOffManager.sendRow(HintedHandOffMa
>>> n
>>> a
>>> ger.java:155)
>>>
>>>                 at
>>> org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(
>>> H
>>> i
>>> ntedHandOffManager.java:350)
>>>
>>>                 at
>>> org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOf
>>> f
>>> M
>>> anager.java:89)
>>>
>>>                 at
>>> org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHan
>>> d
>>> O
>>> ffManager.java:397)
>>>
>>>                 at
>>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:
>>> 3
>>> 0
>>> )
>>>
>>>                 at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExe
>>> c
>>> u
>>> tor.java:886)
>>>
>>>                 at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.
>>> java:908)
>>>
>>>                 at java.lang.Thread.run(Thread.java:662)
>>>
>>> Caused by: org.apache.cassandra.db.ColumnSerializer$CorruptColumnException:
>>> invalid column name length 0
>>>
>>>                 at
>>> org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.
>>> java:89)
>>>
>>>                 at
>>> org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSo
>>> r
>>> t
>>> edMap.java:261)
>>>
>>>                 ... 33 more
>>>
>>> 2011-09-27 12:17:53,291 Started hinted handoff for endpoint
>>> /xxx.yyy.zzz.59
>>
>>
>>
>> --
>> Jonathan Ellis
>> Project Chair, Apache Cassandra
>> co-founder of DataStax, the source for professional Cassandra support 
>> http://www.datastax.com
>>
>

Mime
View raw message