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 12:42:40 GMT
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(ColumnSortedMap.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(ConcurrentSkipListMap.java:1493)
~[na:1.6.0_24]
	at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.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$IndexedBlockFetcher.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(AbstractIterator.java:140)
~[guava-r08.jar:na]
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135) ~[guava-r08.jar:na]
	at org.apache.cassandra.db.columniterator.SSTableSliceIterator.hasNext(SSTableSliceIterator.java:108)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.commons.collections.iterators.CollatingIterator.set(CollatingIterator.java:283)
~[commons-collections-3.2.1.jar:3.2.1]
	at org.apache.commons.collections.iterators.CollatingIterator.least(CollatingIterator.java:326)
~[commons-collections-3.2.1.jar:3.2.1]
	at org.apache.commons.collections.iterators.CollatingIterator.next(CollatingIterator.java:230)
~[commons-collections-3.2.1.jar:3.2.1]
	at org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingIterator.java:69) ~[apache-cassandra-0.8.6.jar:0.8.6]
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
~[guava-r08.jar:na]
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java: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(QueryFilter.java:142)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1427)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1304)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1261)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.HintedHandOffManager.sendRow(HintedHandOffManager.java:155) ~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:350)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOffManager.java:89)
~[apache-cassandra-0.8.6.jar:0.8.6]
	at org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHandOffManager.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(ThreadPoolExecutor.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(ColumnSortedMap.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(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.Table.getRow(Table.java:385)
> ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at
> org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadComma
> nd.java:61) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at
> org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69
> ) ~[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(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: java.io.IOException: Corrupt (negative) value length encountered
>        at
> org.apache.cassandra.utils.ByteBufferUtil.readWithLength(ByteBufferUti
> 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(ColumnSort
> 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(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.anyHasNext(
> CollatingIterator.java:364) ~[commons-collections-3.2.1.jar:3.2.1]
>        at
> org.apache.commons.collections.iterators.CollatingIterator.hasNext(Col
> latingIterator.java:217) ~[commons-collections-3.2.1.jar:3.2.1]
>        at
> org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingIterat
> or.java:55) ~[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.Table.getRow(Table.java:385)
> ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at
> org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadComma
> nd.java:61) ~[apache-cassandra-0.8.6.jar:0.8.6]
>        at
> org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69
> ) ~[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(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]
>        ... 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/HintsColumnFa
>> 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(ColumnSor
>> 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(Concurrent
>> S
>> kipListMap.java:1493)
>>
>>                 at
>> java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListM
>> 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$IndexedBloc
>> k
>> Fetcher.getNextBlock(IndexedSliceReader.java:179)
>>
>>                 at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext
>> (
>> IndexedSliceReader.java:121)
>>
>>                 at
>> org.apache.cassandra.db.columniterator.IndexedSliceReader.computeNext
>> (
>> IndexedSliceReader.java:49)
>>
>>                 at
>> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractI
>> 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(Collat
>> i
>> ngIterator.java:283)
>>
>>                 at
>> org.apache.commons.collections.iterators.CollatingIterator.least(Coll
>> a
>> tingIterator.java:326)
>>
>>                 at
>> org.apache.commons.collections.iterators.CollatingIterator.next(Colla
>> t
>> ingIterator.java:230)
>>
>>                 at
>> org.apache.cassandra.utils.ReducingIterator.computeNext(ReducingItera
>> t
>> or.java:69)
>>
>>                 at
>> com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractI
>> t
>> erator.java:140)
>>
>>                 at
>> com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.j
>> a
>> va:135)
>>
>>                 at
>> org.apache.cassandra.db.filter.SliceQueryFilter.collectReducedColumns
>> (
>> SliceQueryFilter.java:116)
>>
>>                 at
>> org.apache.cassandra.db.filter.QueryFilter.collectCollatedColumns(Que
>> r
>> yFilter.java:142)
>>
>>                 at
>> org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFa
>> m
>> ilyStore.java:1427)
>>
>>                 at
>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamil
>> y
>> Store.java:1304)
>>
>>                 at
>> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamil
>> y
>> Store.java:1261)
>>
>>                 at
>> org.apache.cassandra.db.HintedHandOffManager.sendRow(HintedHandOffMan
>> a
>> ger.java:155)
>>
>>                 at
>> org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(H
>> i
>> ntedHandOffManager.java:350)
>>
>>                 at
>> org.apache.cassandra.db.HintedHandOffManager.access$100(HintedHandOff
>> M
>> anager.java:89)
>>
>>                 at
>> org.apache.cassandra.db.HintedHandOffManager$2.runMayThrow(HintedHand
>> O
>> ffManager.java:397)
>>
>>                 at
>> org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:3
>> 0
>> )
>>
>>                 at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec
>> 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(ColumnSor
>> 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