You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@cassandra.apache.org by Paul Lorenz <pl...@gmail.com> on 2011/04/13 02:22:38 UTC

Exception on cassandra startup 0.7.4

Hello,
  I've been running a single node cluster (0.7.4 built from the SVN
tag, running on JDK 1.6.0_21 on Ubuntu 10.10) for testing purposes.
After running fine for a couple of weeks, I got the error below on
startup. It sounded like the error which is supposed to be fixed by
the nodetool scrub command, but since I can't run the scrub command
without starting up the instance, and the instance won't start, this
wasn't any use. Also, I'm fairly certain that the keyspaces in this
node have only been written by 0.7.4 code.

Since it was just a test node, I just blew away the data directory.
Had I been thinking, I would have saved it off so I could duplicate
the issue. If I can provide any other information, please let me know.

Thank you,
Paul

paul@host:~/apps/cassandra-svn/bin$ ./cassandra -f
 INFO 20:57:44,344 Logging initialized
 INFO 20:57:44,357 Heap size: 3051814912/3052863488
 INFO 20:57:44,358 JNA not found. Native methods will be disabled.
 INFO 20:57:44,365 Loading settings from
file:/home/paul/apps/cassandra-svn/conf/cassandra.yaml
 INFO 20:57:44,474 DiskAccessMode 'auto' determined to be mmap,
indexAccessMode is mmap
 INFO 20:57:44,593 Opening
/home/paul/apps/cassandra/node1/data/system/Schema-f-378
 INFO 20:57:44,606 Opening
/home/paul/apps/cassandra/node1/data/system/Schema-f-379
 INFO 20:57:44,608 Opening
/home/paul/apps/cassandra/node1/data/system/Schema-f-377
 INFO 20:57:44,618 Opening
/home/paul/apps/cassandra/node1/data/system/Migrations-f-377
 INFO 20:57:44,620 Opening
/home/paul/apps/cassandra/node1/data/system/Migrations-f-378
 INFO 20:57:44,622 Opening
/home/paul/apps/cassandra/node1/data/system/Migrations-f-379
 INFO 20:57:44,627 Opening
/home/paul/apps/cassandra/node1/data/system/LocationInfo-f-29
 INFO 20:57:44,629 Opening
/home/paul/apps/cassandra/node1/data/system/LocationInfo-f-30
 INFO 20:57:44,631 Opening
/home/paul/apps/cassandra/node1/data/system/LocationInfo-f-31
 INFO 20:57:44,674 Loading schema version debf273e-631f-11e0-ac72-e700f669bcfc
 INFO 20:57:44,883 Opening
/home/paul/apps/cassandra/node1/data/DaisyWorksKS/User-f-1
 INFO 20:57:44,886 Opening
/home/paul/apps/cassandra/node1/data/DaisyWorksKS/User-f-2
 INFO 20:57:44,892 Opening
/home/paul/apps/cassandra/node1/data/DaisyWorksTest/User-f-11
 INFO 20:57:44,895 Opening
/home/paul/apps/cassandra/node1/data/DaisyWorksTest/Product-f-10
 INFO 20:57:44,908 Creating new commitlog segment
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302569864908.log
 INFO 20:57:44,916 Replaying
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302379611027.log,
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567818267.log,
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567841352.log,
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567871659.log,
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302568152030.log,
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302569289258.log
 INFO 20:57:44,937 Finished reading
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302379611027.log
ERROR 20:57:44,937 Exception encountered during startup.
java.io.IOError: java.io.EOFException
        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:246)
        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:262)
        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:223)
        at java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(ConcurrentSkipListMap.java:1493)
        at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.java:1443)
        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:363)
        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:311)
        at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:129)
        at org.apache.cassandra.db.ColumnFamilySerializer.deserialize(ColumnFamilySerializer.java:120)
        at org.apache.cassandra.db.RowMutation$RowMutationSerializer.deserialize(RowMutation.java:380)
        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:253)
        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:156)
        at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:173)
        at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:314)
        at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:79)
Caused by: java.io.EOFException
        at java.io.DataInputStream.readFully(DataInputStream.java:180)
        at java.io.DataInputStream.readFully(DataInputStream.java:152)
        at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:320)
        at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:289)
        at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:66)
        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:242)
        ... 14 more
Exception encountered during startup.
java.io.IOError: java.io.EOFException
        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:246)
        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:262)
        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:223)
        at java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(ConcurrentSkipListMap.java:1493)
        at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.java:1443)
        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:363)
        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:311)
        at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:129)
        at org.apache.cassandra.db.ColumnFamilySerializer.deserialize(ColumnFamilySerializer.java:120)
        at org.apache.cassandra.db.RowMutation$RowMutationSerializer.deserialize(RowMutation.java:380)
        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:253)
        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:156)
        at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:173)
        at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:314)
        at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:79)
Caused by: java.io.EOFException
        at java.io.DataInputStream.readFully(DataInputStream.java:180)
        at java.io.DataInputStream.readFully(DataInputStream.java:152)
        at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:320)
        at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:289)
        at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:66)
        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:242)
        ... 14 more
paul@host:~/apps/cassandra-svn/bin$ l

Re: Exception on cassandra startup 0.7.4

Posted by Jonathan Ellis <jb...@gmail.com>.
This is a problem reading the commitlog, which is not something scrub
can help with.

Looks like there is bad data in
/home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567818267.log.
Somehow it's corrupt in a way that the checksum is ok. (Which sounds
like https://issues.apache.org/jira/browse/CASSANDRA-2128 but that was
fixed for 0.7.2.)

Quick fix to get up and running again would be to just remove that
file. (Any data in it will be missing, of course.) Longer term you
should gzip it (and your system keyspace, so we get the schema too)
and attach it to a ticket so we can take a closer look.

On Tue, Apr 12, 2011 at 7:22 PM, Paul Lorenz <pl...@gmail.com> wrote:
> Hello,
>  I've been running a single node cluster (0.7.4 built from the SVN
> tag, running on JDK 1.6.0_21 on Ubuntu 10.10) for testing purposes.
> After running fine for a couple of weeks, I got the error below on
> startup. It sounded like the error which is supposed to be fixed by
> the nodetool scrub command, but since I can't run the scrub command
> without starting up the instance, and the instance won't start, this
> wasn't any use. Also, I'm fairly certain that the keyspaces in this
> node have only been written by 0.7.4 code.
>
> Since it was just a test node, I just blew away the data directory.
> Had I been thinking, I would have saved it off so I could duplicate
> the issue. If I can provide any other information, please let me know.
>
> Thank you,
> Paul
>
> paul@host:~/apps/cassandra-svn/bin$ ./cassandra -f
>  INFO 20:57:44,344 Logging initialized
>  INFO 20:57:44,357 Heap size: 3051814912/3052863488
>  INFO 20:57:44,358 JNA not found. Native methods will be disabled.
>  INFO 20:57:44,365 Loading settings from
> file:/home/paul/apps/cassandra-svn/conf/cassandra.yaml
>  INFO 20:57:44,474 DiskAccessMode 'auto' determined to be mmap,
> indexAccessMode is mmap
>  INFO 20:57:44,593 Opening
> /home/paul/apps/cassandra/node1/data/system/Schema-f-378
>  INFO 20:57:44,606 Opening
> /home/paul/apps/cassandra/node1/data/system/Schema-f-379
>  INFO 20:57:44,608 Opening
> /home/paul/apps/cassandra/node1/data/system/Schema-f-377
>  INFO 20:57:44,618 Opening
> /home/paul/apps/cassandra/node1/data/system/Migrations-f-377
>  INFO 20:57:44,620 Opening
> /home/paul/apps/cassandra/node1/data/system/Migrations-f-378
>  INFO 20:57:44,622 Opening
> /home/paul/apps/cassandra/node1/data/system/Migrations-f-379
>  INFO 20:57:44,627 Opening
> /home/paul/apps/cassandra/node1/data/system/LocationInfo-f-29
>  INFO 20:57:44,629 Opening
> /home/paul/apps/cassandra/node1/data/system/LocationInfo-f-30
>  INFO 20:57:44,631 Opening
> /home/paul/apps/cassandra/node1/data/system/LocationInfo-f-31
>  INFO 20:57:44,674 Loading schema version debf273e-631f-11e0-ac72-e700f669bcfc
>  INFO 20:57:44,883 Opening
> /home/paul/apps/cassandra/node1/data/DaisyWorksKS/User-f-1
>  INFO 20:57:44,886 Opening
> /home/paul/apps/cassandra/node1/data/DaisyWorksKS/User-f-2
>  INFO 20:57:44,892 Opening
> /home/paul/apps/cassandra/node1/data/DaisyWorksTest/User-f-11
>  INFO 20:57:44,895 Opening
> /home/paul/apps/cassandra/node1/data/DaisyWorksTest/Product-f-10
>  INFO 20:57:44,908 Creating new commitlog segment
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302569864908.log
>  INFO 20:57:44,916 Replaying
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302379611027.log,
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567818267.log,
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567841352.log,
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302567871659.log,
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302568152030.log,
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302569289258.log
>  INFO 20:57:44,937 Finished reading
> /home/paul/apps/cassandra/node1/commitlog/CommitLog-1302379611027.log
> ERROR 20:57:44,937 Exception encountered during startup.
> java.io.IOError: java.io.EOFException
>        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:246)
>        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:262)
>        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:223)
>        at java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(ConcurrentSkipListMap.java:1493)
>        at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.java:1443)
>        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:363)
>        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:311)
>        at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:129)
>        at org.apache.cassandra.db.ColumnFamilySerializer.deserialize(ColumnFamilySerializer.java:120)
>        at org.apache.cassandra.db.RowMutation$RowMutationSerializer.deserialize(RowMutation.java:380)
>        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:253)
>        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:156)
>        at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:173)
>        at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:314)
>        at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:79)
> Caused by: java.io.EOFException
>        at java.io.DataInputStream.readFully(DataInputStream.java:180)
>        at java.io.DataInputStream.readFully(DataInputStream.java:152)
>        at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:320)
>        at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:289)
>        at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:66)
>        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:242)
>        ... 14 more
> Exception encountered during startup.
> java.io.IOError: java.io.EOFException
>        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:246)
>        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:262)
>        at org.apache.cassandra.io.util.ColumnIterator.next(ColumnSortedMap.java:223)
>        at java.util.concurrent.ConcurrentSkipListMap.buildFromSorted(ConcurrentSkipListMap.java:1493)
>        at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.java:1443)
>        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:363)
>        at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:311)
>        at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:129)
>        at org.apache.cassandra.db.ColumnFamilySerializer.deserialize(ColumnFamilySerializer.java:120)
>        at org.apache.cassandra.db.RowMutation$RowMutationSerializer.deserialize(RowMutation.java:380)
>        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:253)
>        at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:156)
>        at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:173)
>        at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:314)
>        at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:79)
> Caused by: java.io.EOFException
>        at java.io.DataInputStream.readFully(DataInputStream.java:180)
>        at java.io.DataInputStream.readFully(DataInputStream.java:152)
>        at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:320)
>        at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:289)
>        at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:66)
>        at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:242)
>        ... 14 more
> paul@host:~/apps/cassandra-svn/bin$ l
>



-- 
Jonathan Ellis
Project Chair, Apache Cassandra
co-founder of DataStax, the source for professional Cassandra support
http://www.datastax.com