You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@cassandra.apache.org by Ramesh Natarajan <ra...@gmail.com> on 2011/12/09 13:37:33 UTC

IOException running cassandra 1.0.5

Hi,

 I have a 30 node cassandra cluster running on RHEL6 64 bit. RF=3,
reads and  writes performed with QUORUM. After few hours of test run,
I am seeing this error in the system.log file.

[root@MSA-VM-18 cassandra]# cat
/var/lib/cassandra/data/MSA/modseq-hb-419-Digest.sha1
71e43a932a29553720149bb4f93727e4d269735d
modseq-hb-419-Data.db[root@MSA-VM-18 cassandra]#
[root@MSA-VM-18 cassandra]# sha1sum
/var/lib/cassandra/data/MSA/modseq-hb-419-Data.db
033f5aea5590851377d3bb79df27f0e6eedb6b95
/var/lib/cassandra/data/MSA/modseq-hb-419-Data.db
[root@MSA-VM-18 cassandra]#

Any pointers to troubleshoot this issue?

I am attaching the system.log file for your reference.

thanks
Ramesh


 INFO [CompactionExecutor:296] 2011-12-09 04:36:40,430
CompactionTask.java (line 112) Compacting
[SSTableReader(path='/var/lib/cassandra/data/MSA/transactions-hb-55-Data.db'),
SSTableReader(path='/var/lib/cassandra/data/MSA/transactions-hb-53-Data.db')]
 INFO [CompactionExecutor:296] 2011-12-09 04:36:40,501
CompactionTask.java (line 213) Compacted to
[/var/lib/cassandra/data/MSA/transactions-hb-56-Data.db,].  280,210 to
144,785 (~51% of original) bytes for 3 keys at 2.191710MB/s.  Time:
63ms.
ERROR [CompactionExecutor:295] 2011-12-09 04:36:41,320
AbstractCassandraDaemon.java (line 133) Fatal exception in thread
Thread[CompactionExecutor:295,1,main]
java.io.IOError: java.io.IOException: dataSize of 14293651161088
starting at 5541742 would be larger than file
/var/lib/cassandra/data/MSA/modseq-hb-419-Data.db length 10486511
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:154)
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:86)
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:70)
        at org.apache.cassandra.io.sstable.SSTableScanner$KeyScanningIterator.next(SSTableScanner.java:177)
        at org.apache.cassandra.io.sstable.SSTableScanner$KeyScanningIterator.next(SSTableScanner.java:142)
        at org.apache.cassandra.io.sstable.SSTableScanner.next(SSTableScanner.java:134)
        at org.apache.cassandra.io.sstable.SSTableScanner.next(SSTableScanner.java:37)
        at org.apache.cassandra.utils.MergeIterator$Candidate.advance(MergeIterator.java:147)
        at org.apache.cassandra.utils.MergeIterator$ManyToOne.advance(MergeIterator.java:124)
        at org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:98)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
        at com.google.common.collect.Iterators$7.computeNext(Iterators.java:614)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
        at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:172)
        at org.apache.cassandra.db.compaction.LeveledCompactionTask.execute(LeveledCompactionTask.java:57)
        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:134)
        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:114)
        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
Caused by: java.io.IOException: dataSize of 14293651161088 starting at
5541742 would be larger than file
/var/lib/cassandra/data/MSA/modseq-hb-419-Data.db length 10486511
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:115)
        ... 23 more
 INFO [COMMIT-LOG-WRITER] 2011-12-09 04:36:52,668
CommitLogSegment.java (line 60) Creating new commitlog segment
/var/lib/cassandra/commitlog/CommitLog-1323405412668.log

Re: IOException running cassandra 1.0.5

Posted by Ramesh Natarajan <ra...@gmail.com>.
Do you have any pointers on how to resolve this?   We can see no
issues reported in the syslog or on the RAID or ESXi. We changed the
filesystem from xfs to  ext4, still we get the same error. I am
attaching some more signatures here in case anyone has any comments..


ERROR [CompactionExecutor:207] 2011-12-10 03:23:09,354
PrecompactedRow.java (line 108) Skipping row DecoratedKey(-1, ) in
/data/MSA/modseq-hb-177-Data.db
org.apache.cassandra.db.ColumnSerializer$CorruptColumnException:
invalid column name length 0
        at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:98)
        at org.apache.cassandra.db.ColumnSerializer.deserialize(ColumnSerializer.java:37)
        at org.apache.cassandra.db.ColumnFamilySerializer.deserializeColumns(ColumnFamilySerializer.java:147)
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.getColumnFamilyWithColumns(SSTableIdentityIterator.java:232)
        at org.apache.cassandra.db.compaction.PrecompactedRow.merge(PrecompactedRow.java:104)
        at org.apache.cassandra.db.compaction.PrecompactedRow.<init>(PrecompactedRow.java:92)
        at org.apache.cassandra.db.compaction.CompactionController.getCompactedRow(CompactionController.java:137)
        at org.apache.cassandra.db.compaction.CompactionIterable$Reducer.getReduced(CompactionIterable.java:102)
        at org.apache.cassandra.db.compaction.CompactionIterable$Reducer.getReduced(CompactionIterable.java:87)
        at org.apache.cassandra.utils.MergeIterator$ManyToOne.consume(MergeIterator.java:116)
        at org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:99)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
        at com.google.common.collect.Iterators$7.computeNext(Iterators.java:614)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
        at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:172)
        at org.apache.cassandra.db.compaction.LeveledCompactionTask.execute(LeveledCompactionTask.java:57)
        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:134)
        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:114)
        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)




ERROR [CompactionExecutor:207] 2011-12-10 03:23:09,525
AbstractCassandraDaemon.java (line 133) Fatal exception in thread
Thread[CompactionExecutor:207,1,main]
java.lang.NullPointerException
        at org.apache.cassandra.db.compaction.PrecompactedRow.removeDeletedAndOldShards(PrecompactedRow.java:65)
        at org.apache.cassandra.db.compaction.PrecompactedRow.<init>(PrecompactedRow.java:92)
        at org.apache.cassandra.db.compaction.CompactionController.getCompactedRow(CompactionController.java:137)
        at org.apache.cassandra.db.compaction.CompactionIterable$Reducer.getReduced(CompactionIterable.java:102)
        at org.apache.cassandra.db.compaction.CompactionIterable$Reducer.getReduced(CompactionIterable.java:87)
        at org.apache.cassandra.utils.MergeIterator$ManyToOne.consume(MergeIterator.java:116)
        at org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:99)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
        at com.google.common.collect.Iterators$7.computeNext(Iterators.java:614)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
        at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:172)
        at org.apache.cassandra.db.compaction.LeveledCompactionTask.execute(LeveledCompactionTask.java:57)
        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:134)
        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:114)
        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)



ERROR [ReadStage:50] 2011-12-10 03:27:20,577
AbstractCassandraDaemon.java (line 133) Fatal exception in thread
Thread[ReadStage:50,5,main]
java.lang.AssertionError: DecoratedKey(-1, ) !=
DecoratedKey(53731996390544741435985962281191741460,
37303730323632333931) in /data/MSA/modseq-hb-177-Data.db
        at org.apache.cassandra.db.columniterator.SSTableNamesIterator.<init>(SSTableNamesIterator.java:70)
        at org.apache.cassandra.db.filter.NamesQueryFilter.getSSTableColumnIterator(NamesQueryFilter.java:60)
        at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:78)
        at org.apache.cassandra.db.CollationController.collectTimeOrderedData(CollationController.java:114)
        at org.apache.cassandra.db.CollationController.getTopLevelColumns(CollationController.java:62)
        at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1275)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1161)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1128)
        at org.apache.cassandra.db.Table.getRow(Table.java:375)
        at org.apache.cassandra.db.SliceByNamesReadCommand.getRow(SliceByNamesReadCommand.java:58)
        at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:53)
        at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:59)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)




On Fri, Dec 9, 2011 at 6:52 AM, Sylvain Lebresne <sy...@datastax.com> wrote:
> The sha1 don't match, which would indicate that the sstable
> has been modified after being written. But Cassandra never
> modify a sstable once it has been written, so this would
> suggest an external modification, typically some bit rot.
>
> In that case you don't have much other choice than removing
> the mentioned data file and run a repair.
>
> --
> Sylvain
>
> On Fri, Dec 9, 2011 at 1:37 PM, Ramesh Natarajan <ra...@gmail.com> wrote:
>> Hi,
>>
>>  I have a 30 node cassandra cluster running on RHEL6 64 bit. RF=3,
>> reads and  writes performed with QUORUM. After few hours of test run,
>> I am seeing this error in the system.log file.
>>
>> [root@MSA-VM-18 cassandra]# cat
>> /var/lib/cassandra/data/MSA/modseq-hb-419-Digest.sha1
>> 71e43a932a29553720149bb4f93727e4d269735d
>> modseq-hb-419-Data.db[root@MSA-VM-18 cassandra]#
>> [root@MSA-VM-18 cassandra]# sha1sum
>> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db
>> 033f5aea5590851377d3bb79df27f0e6eedb6b95
>> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db
>> [root@MSA-VM-18 cassandra]#
>>
>> Any pointers to troubleshoot this issue?
>>
>> I am attaching the system.log file for your reference.
>>
>> thanks
>> Ramesh
>>
>>
>>  INFO [CompactionExecutor:296] 2011-12-09 04:36:40,430
>> CompactionTask.java (line 112) Compacting
>> [SSTableReader(path='/var/lib/cassandra/data/MSA/transactions-hb-55-Data.db'),
>> SSTableReader(path='/var/lib/cassandra/data/MSA/transactions-hb-53-Data.db')]
>>  INFO [CompactionExecutor:296] 2011-12-09 04:36:40,501
>> CompactionTask.java (line 213) Compacted to
>> [/var/lib/cassandra/data/MSA/transactions-hb-56-Data.db,].  280,210 to
>> 144,785 (~51% of original) bytes for 3 keys at 2.191710MB/s.  Time:
>> 63ms.
>> ERROR [CompactionExecutor:295] 2011-12-09 04:36:41,320
>> AbstractCassandraDaemon.java (line 133) Fatal exception in thread
>> Thread[CompactionExecutor:295,1,main]
>> java.io.IOError: java.io.IOException: dataSize of 14293651161088
>> starting at 5541742 would be larger than file
>> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db length 10486511
>>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:154)
>>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:86)
>>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:70)
>>        at org.apache.cassandra.io.sstable.SSTableScanner$KeyScanningIterator.next(SSTableScanner.java:177)
>>        at org.apache.cassandra.io.sstable.SSTableScanner$KeyScanningIterator.next(SSTableScanner.java:142)
>>        at org.apache.cassandra.io.sstable.SSTableScanner.next(SSTableScanner.java:134)
>>        at org.apache.cassandra.io.sstable.SSTableScanner.next(SSTableScanner.java:37)
>>        at org.apache.cassandra.utils.MergeIterator$Candidate.advance(MergeIterator.java:147)
>>        at org.apache.cassandra.utils.MergeIterator$ManyToOne.advance(MergeIterator.java:124)
>>        at org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:98)
>>        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
>>        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
>>        at com.google.common.collect.Iterators$7.computeNext(Iterators.java:614)
>>        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
>>        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
>>        at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:172)
>>        at org.apache.cassandra.db.compaction.LeveledCompactionTask.execute(LeveledCompactionTask.java:57)
>>        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:134)
>>        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:114)
>>        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
>>        at java.util.concurrent.FutureTask.run(Unknown Source)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
>> Source)
>>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
>>        at java.lang.Thread.run(Unknown Source)
>> Caused by: java.io.IOException: dataSize of 14293651161088 starting at
>> 5541742 would be larger than file
>> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db length 10486511
>>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:115)
>>        ... 23 more
>>  INFO [COMMIT-LOG-WRITER] 2011-12-09 04:36:52,668
>> CommitLogSegment.java (line 60) Creating new commitlog segment
>> /var/lib/cassandra/commitlog/CommitLog-1323405412668.log

Re: IOException running cassandra 1.0.5

Posted by Sylvain Lebresne <sy...@datastax.com>.
The sha1 don't match, which would indicate that the sstable
has been modified after being written. But Cassandra never
modify a sstable once it has been written, so this would
suggest an external modification, typically some bit rot.

In that case you don't have much other choice than removing
the mentioned data file and run a repair.

--
Sylvain

On Fri, Dec 9, 2011 at 1:37 PM, Ramesh Natarajan <ra...@gmail.com> wrote:
> Hi,
>
>  I have a 30 node cassandra cluster running on RHEL6 64 bit. RF=3,
> reads and  writes performed with QUORUM. After few hours of test run,
> I am seeing this error in the system.log file.
>
> [root@MSA-VM-18 cassandra]# cat
> /var/lib/cassandra/data/MSA/modseq-hb-419-Digest.sha1
> 71e43a932a29553720149bb4f93727e4d269735d
> modseq-hb-419-Data.db[root@MSA-VM-18 cassandra]#
> [root@MSA-VM-18 cassandra]# sha1sum
> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db
> 033f5aea5590851377d3bb79df27f0e6eedb6b95
> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db
> [root@MSA-VM-18 cassandra]#
>
> Any pointers to troubleshoot this issue?
>
> I am attaching the system.log file for your reference.
>
> thanks
> Ramesh
>
>
>  INFO [CompactionExecutor:296] 2011-12-09 04:36:40,430
> CompactionTask.java (line 112) Compacting
> [SSTableReader(path='/var/lib/cassandra/data/MSA/transactions-hb-55-Data.db'),
> SSTableReader(path='/var/lib/cassandra/data/MSA/transactions-hb-53-Data.db')]
>  INFO [CompactionExecutor:296] 2011-12-09 04:36:40,501
> CompactionTask.java (line 213) Compacted to
> [/var/lib/cassandra/data/MSA/transactions-hb-56-Data.db,].  280,210 to
> 144,785 (~51% of original) bytes for 3 keys at 2.191710MB/s.  Time:
> 63ms.
> ERROR [CompactionExecutor:295] 2011-12-09 04:36:41,320
> AbstractCassandraDaemon.java (line 133) Fatal exception in thread
> Thread[CompactionExecutor:295,1,main]
> java.io.IOError: java.io.IOException: dataSize of 14293651161088
> starting at 5541742 would be larger than file
> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db length 10486511
>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:154)
>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:86)
>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:70)
>        at org.apache.cassandra.io.sstable.SSTableScanner$KeyScanningIterator.next(SSTableScanner.java:177)
>        at org.apache.cassandra.io.sstable.SSTableScanner$KeyScanningIterator.next(SSTableScanner.java:142)
>        at org.apache.cassandra.io.sstable.SSTableScanner.next(SSTableScanner.java:134)
>        at org.apache.cassandra.io.sstable.SSTableScanner.next(SSTableScanner.java:37)
>        at org.apache.cassandra.utils.MergeIterator$Candidate.advance(MergeIterator.java:147)
>        at org.apache.cassandra.utils.MergeIterator$ManyToOne.advance(MergeIterator.java:124)
>        at org.apache.cassandra.utils.MergeIterator$ManyToOne.computeNext(MergeIterator.java:98)
>        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
>        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
>        at com.google.common.collect.Iterators$7.computeNext(Iterators.java:614)
>        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:140)
>        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:135)
>        at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:172)
>        at org.apache.cassandra.db.compaction.LeveledCompactionTask.execute(LeveledCompactionTask.java:57)
>        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:134)
>        at org.apache.cassandra.db.compaction.CompactionManager$1.call(CompactionManager.java:114)
>        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
>        at java.util.concurrent.FutureTask.run(Unknown Source)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown
> Source)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
>        at java.lang.Thread.run(Unknown Source)
> Caused by: java.io.IOException: dataSize of 14293651161088 starting at
> 5541742 would be larger than file
> /var/lib/cassandra/data/MSA/modseq-hb-419-Data.db length 10486511
>        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:115)
>        ... 23 more
>  INFO [COMMIT-LOG-WRITER] 2011-12-09 04:36:52,668
> CommitLogSegment.java (line 60) Creating new commitlog segment
> /var/lib/cassandra/commitlog/CommitLog-1323405412668.log