[CASSANDRA-2930] corrupt commitlog

• Type: Bug
• Status: Resolved
• Priority: Normal
• Resolution: Cannot Reproduce
• Labels: datastax_qa

Environment

Linux, amd64.
Java(TM) SE Runtime Environment (build 1.6.0_26-b03)

• Severity: Normal
• Assignee: Unassigned
• Reporter: ivan
• Created: 21/Jul/11 12:34
• Updated: 16/Apr/19 09:32
• Resolved: 16/May/12 21:24

Description

We get "Exception encountered during startup" error while Cassandra starts.

Error messages:
INFO 13:56:28,736 Finished reading /var/lib/cassandra/commitlog/CommitLog-1310637513214.log
ERROR 13:56:28,736 Exception encountered during startup.
java.io.IOError: java.io.EOFException
at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.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(ConcurrentSkipListMap.java:1493)
at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.java:1443)
at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:419)
at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:139)
at org.apache.cassandra.db.ColumnFamilySerializer.deserialize(ColumnFamilySerializer.java:127)
at org.apache.cassandra.db.RowMutation$RowMutationSerializer.deserialize(RowMutation.java:382)
at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:278)
at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:158)
at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:175)
at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:368)
at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:80)
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:394)
at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368)
at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:87)
at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:261)
... 13 more
Exception encountered during startup.
java.io.IOError: java.io.EOFException
at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.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(ConcurrentSkipListMap.java:1493)
at java.util.concurrent.ConcurrentSkipListMap.<init>(ConcurrentSkipListMap.java:1443)
at org.apache.cassandra.db.SuperColumnSerializer.deserialize(SuperColumn.java:419)
at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:139)
at org.apache.cassandra.db.ColumnFamilySerializer.deserialize(ColumnFamilySerializer.java:127)
at org.apache.cassandra.db.RowMutation$RowMutationSerializer.deserialize(RowMutation.java:382)
at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:278)
at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:158)
at org.apache.cassandra.service.AbstractCassandraDaemon.setup(AbstractCassandraDaemon.java:175)
at org.apache.cassandra.service.AbstractCassandraDaemon.activate(AbstractCassandraDaemon.java:368)
at org.apache.cassandra.thrift.CassandraDaemon.main(CassandraDaemon.java:80)
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:394)
at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368)
at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:87)
at org.apache.cassandra.io.util.ColumnIterator.deserializeNext(ColumnSortedMap.java:261)
... 13 more

After some debugging I found that in some serialized supercolumns column counter is less than the number of serialized columns. Difference was always 1 in corrupt commitlogs. This error always appears with supercolumns with more than one column, but there are properly serialized supercolumns also in commitlog.

I have no clue yet why this error happens. I suspect it maybe a race condition.