Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Cannot Reproduce
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None

      Description

      after adding nodes to cluster & running cleanup I get scaring exceptions in log:
      2011-07-30 00:00:05:506 CEST ERROR [ReadStage:2335][org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread[ReadStage:2335,5,main]
      java.io.IOError: java.io.IOException: mmap segment underflow; remaining is 4394 but 60165 requested
      at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:80)
      at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91)
      at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67)
      at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66)
      at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80)
      at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292)
      at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189)
      at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146)
      at org.apache.cassandra.db.Table.getRow(Table.java:385)
      at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61)
      at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69)
      at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72)
      at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
      at java.lang.Thread.run(Thread.java:662)
      Caused by: java.io.IOException: mmap segment underflow; remaining is 4394 but 60165 requested
      at org.apache.cassandra.io.util.MappedFileDataInput.readBytes(MappedFileDataInput.java:117)
      at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:389)
      at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368)
      at org.apache.cassandra.io.sstable.IndexHelper$IndexInfo.deserialize(IndexHelper.java:194)
      at org.apache.cassandra.io.sstable.IndexHelper.deserializeIndex(IndexHelper.java:83)
      at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:73)
      ... 14 more

      exceptions disappeared after running scrub

        Activity

        Hide
        Jonathan Ellis added a comment -

        Is it reproducible?

        If not, it's quite possible that it's transient hardware-caused corruption.

        Show
        Jonathan Ellis added a comment - Is it reproducible? If not, it's quite possible that it's transient hardware-caused corruption.
        Hide
        Wojciech Meler added a comment -

        seen on 12 machines - on all that cleanup was run - it is hard to believe that hardware error caused that

        Show
        Wojciech Meler added a comment - seen on 12 machines - on all that cleanup was run - it is hard to believe that hardware error caused that
        Hide
        Jonathan Ellis added a comment -

        agreed

        I don't suppose you have a pre-cleanup snapshot?

        Show
        Jonathan Ellis added a comment - agreed I don't suppose you have a pre-cleanup snapshot?
        Hide
        Jonathan Ellis added a comment -

        also: do you have the log from when scrub ran?

        Show
        Jonathan Ellis added a comment - also: do you have the log from when scrub ran?
        Hide
        Wojciech Meler added a comment -

        BINGO I've run scrub in "rolling" way
        So I've done prescrub snapshots of 4 remaining nodes.
        All logs are collected. (Un)fortunately I'm going on vacation so I can give you all you need on 15'th October.
        Data set is quite big - about 140GB per node, so I'll need some instructions what to extract for you.

        Snapshot file list from 12th node:
        rw-rr- 2 cassandra cassandra 49714745792 Jul 30 02:20 fdb-g-1715-Data.db
        rw-rr- 2 cassandra cassandra 4815616 Jul 30 02:20 fdb-g-1715-Filter.db
        rw-rr- 2 cassandra cassandra 61556583 Jul 30 02:20 fdb-g-1715-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:20 fdb-g-1715-Statistics.db
        rw-rr- 2 cassandra cassandra 3450580822 Jul 30 02:22 fdb-g-1717-Data.db
        rw-rr- 2 cassandra cassandra 904096 Jul 30 02:22 fdb-g-1717-Filter.db
        rw-rr- 2 cassandra cassandra 18024560 Jul 30 02:22 fdb-g-1717-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:22 fdb-g-1717-Statistics.db
        rw-rr- 2 cassandra cassandra 3213527243 Jul 30 02:25 fdb-g-1721-Data.db
        rw-rr- 2 cassandra cassandra 904336 Jul 30 02:25 fdb-g-1721-Filter.db
        rw-rr- 2 cassandra cassandra 18026968 Jul 30 02:25 fdb-g-1721-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:25 fdb-g-1721-Statistics.db
        rw-rr- 2 cassandra cassandra 98385535 Jul 30 03:20 fdb-g-1723-Data.db
        rw-rr- 2 cassandra cassandra 247456 Jul 30 03:20 fdb-g-1723-Filter.db
        rw-rr- 2 cassandra cassandra 3130599 Jul 30 03:20 fdb-g-1723-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 03:20 fdb-g-1723-Statistics.db
        rw-rr- 2 cassandra cassandra 106856768 Jul 30 09:41 fdb-g-1734-Data.db
        rw-rr- 2 cassandra cassandra 195376 Jul 30 09:41 fdb-g-1734-Filter.db
        rw-rr- 2 cassandra cassandra 2713645 Jul 30 09:41 fdb-g-1734-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 09:41 fdb-g-1734-Statistics.db
        rw-rr- 2 cassandra cassandra 111863768 Jul 30 17:14 fdb-g-1745-Data.db
        rw-rr- 2 cassandra cassandra 194416 Jul 30 17:14 fdb-g-1745-Filter.db
        rw-rr- 2 cassandra cassandra 2761017 Jul 30 17:14 fdb-g-1745-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 17:14 fdb-g-1745-Statistics.db
        rw-rr- 2 cassandra cassandra 845886467 Jul 30 20:16 fdb-g-1750-Data.db
        rw-rr- 2 cassandra cassandra 902896 Jul 30 20:16 fdb-g-1750-Filter.db
        rw-rr- 2 cassandra cassandra 10419730 Jul 30 20:16 fdb-g-1750-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 20:16 fdb-g-1750-Statistics.db
        rw-rr- 2 cassandra cassandra 40226865 Jul 30 21:12 fdb-g-1751-Data.db
        rw-rr- 2 cassandra cassandra 66608 Jul 30 21:12 fdb-g-1751-Filter.db
        rw-rr- 2 cassandra cassandra 1319135 Jul 30 21:12 fdb-g-1751-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 21:12 fdb-g-1751-Statistics.db
        rw-rr- 2 cassandra cassandra 10904996806 Jul 30 02:41 mailcache-g-3708-Data.db
        rw-rr- 2 cassandra cassandra 254656 Jul 30 02:41 mailcache-g-3708-Filter.db
        rw-rr- 2 cassandra cassandra 5073034 Jul 30 02:41 mailcache-g-3708-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:41 mailcache-g-3708-Statistics.db
        rw-rr- 2 cassandra cassandra 18281871008 Jul 30 02:55 mailcache-g-3712-Data.db
        rw-rr- 2 cassandra cassandra 968176 Jul 30 02:55 mailcache-g-3712-Filter.db
        rw-rr- 2 cassandra cassandra 11904976 Jul 30 02:55 mailcache-g-3712-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:55 mailcache-g-3712-Statistics.db
        rw-rr- 2 cassandra cassandra 35390850 Jul 30 04:41 mailcache-g-3717-Data.db
        rw-rr- 2 cassandra cassandra 640 Jul 30 04:41 mailcache-g-3717-Filter.db
        rw-rr- 2 cassandra cassandra 12533 Jul 30 04:41 mailcache-g-3717-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 04:41 mailcache-g-3717-Statistics.db
        rw-rr- 2 cassandra cassandra 9067927959 Jul 30 11:02 mailcache-g-3727-Data.db
        rw-rr- 2 cassandra cassandra 296416 Jul 30 11:02 mailcache-g-3727-Filter.db
        rw-rr- 2 cassandra cassandra 3578551 Jul 30 11:02 mailcache-g-3727-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 11:02 mailcache-g-3727-Statistics.db
        rw-rr- 2 cassandra cassandra 67351540 Jul 30 16:08 mailcache-g-3738-Data.db
        rw-rr- 2 cassandra cassandra 1512 Jul 30 16:08 mailcache-g-3738-Filter.db
        rw-rr- 2 cassandra cassandra 29793 Jul 30 16:08 mailcache-g-3738-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 16:08 mailcache-g-3738-Statistics.db
        rw-rr- 2 cassandra cassandra 57132425 Jul 30 16:14 mailcache-g-3739-Data.db
        rw-rr- 2 cassandra cassandra 1224 Jul 30 16:14 mailcache-g-3739-Filter.db
        rw-rr- 2 cassandra cassandra 23985 Jul 30 16:14 mailcache-g-3739-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 16:14 mailcache-g-3739-Statistics.db
        rw-rr- 2 cassandra cassandra 3832970739 Jul 30 20:17 mailcache-g-3748-Data.db
        rw-rr- 2 cassandra cassandra 107056 Jul 30 20:17 mailcache-g-3748-Filter.db
        rw-rr- 2 cassandra cassandra 1660163 Jul 30 20:17 mailcache-g-3748-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 20:17 mailcache-g-3748-Statistics.db
        rw-rr- 2 cassandra cassandra 314153777 Jul 30 20:49 mailcache-g-3749-Data.db
        rw-rr- 2 cassandra cassandra 6808 Jul 30 20:49 mailcache-g-3749-Filter.db
        rw-rr- 2 cassandra cassandra 135155 Jul 30 20:49 mailcache-g-3749-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 20:49 mailcache-g-3749-Statistics.db
        rw-rr- 2 cassandra cassandra 211709838 Jul 30 21:12 mailcache-g-3750-Data.db
        rw-rr- 2 cassandra cassandra 4664 Jul 30 21:12 mailcache-g-3750-Filter.db
        rw-rr- 2 cassandra cassandra 92163 Jul 30 21:12 mailcache-g-3750-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 21:12 mailcache-g-3750-Statistics.db
        rw-rr- 2 cassandra cassandra 8404555561 Jul 30 01:34 mta_logs-g-1485-Data.db
        rw-rr- 2 cassandra cassandra 2551456 Jul 30 01:34 mta_logs-g-1485-Filter.db
        rw-rr- 2 cassandra cassandra 50978377 Jul 30 01:34 mta_logs-g-1485-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 01:34 mta_logs-g-1485-Statistics.db
        rw-rr- 2 cassandra cassandra 3759973372 Jul 30 01:37 mta_logs-g-1486-Data.db
        rw-rr- 2 cassandra cassandra 1611616 Jul 30 01:37 mta_logs-g-1486-Filter.db
        rw-rr- 2 cassandra cassandra 32166666 Jul 30 01:37 mta_logs-g-1486-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 01:37 mta_logs-g-1486-Statistics.db
        rw-rr- 2 cassandra cassandra 4179780390 Jul 30 01:41 mta_logs-g-1487-Data.db
        rw-rr- 2 cassandra cassandra 1507936 Jul 30 01:41 mta_logs-g-1487-Filter.db
        rw-rr- 2 cassandra cassandra 30052328 Jul 30 01:41 mta_logs-g-1487-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 01:41 mta_logs-g-1487-Statistics.db
        rw-rr- 2 cassandra cassandra 138623813 Jul 30 15:41 mta_logs-g-1507-Data.db
        rw-rr- 2 cassandra cassandra 429616 Jul 30 15:41 mta_logs-g-1507-Filter.db
        rw-rr- 2 cassandra cassandra 5115547 Jul 30 15:41 mta_logs-g-1507-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 15:41 mta_logs-g-1507-Statistics.db
        rw-rr- 2 cassandra cassandra 493377854 Jul 30 18:15 mta_logs-g-1513-Data.db
        rw-rr- 2 cassandra cassandra 1190896 Jul 30 18:15 mta_logs-g-1513-Filter.db
        rw-rr- 2 cassandra cassandra 13534807 Jul 30 18:15 mta_logs-g-1513-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 18:15 mta_logs-g-1513-Statistics.db
        rw-rr- 2 cassandra cassandra 36751337 Jul 30 19:14 mta_logs-g-1514-Data.db
        rw-rr- 2 cassandra cassandra 107152 Jul 30 19:14 mta_logs-g-1514-Filter.db
        rw-rr- 2 cassandra cassandra 2130178 Jul 30 19:14 mta_logs-g-1514-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 19:14 mta_logs-g-1514-Statistics.db
        rw-rr- 2 cassandra cassandra 32420585 Jul 30 20:14 mta_logs-g-1515-Data.db
        rw-rr- 2 cassandra cassandra 97784 Jul 30 20:14 mta_logs-g-1515-Filter.db
        rw-rr- 2 cassandra cassandra 1943186 Jul 30 20:14 mta_logs-g-1515-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 20:14 mta_logs-g-1515-Statistics.db
        rw-rr- 2 cassandra cassandra 30340652 Jul 30 21:12 mta_logs-g-1516-Data.db
        rw-rr- 2 cassandra cassandra 90888 Jul 30 21:12 mta_logs-g-1516-Filter.db
        rw-rr- 2 cassandra cassandra 1809686 Jul 30 21:12 mta_logs-g-1516-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 21:12 mta_logs-g-1516-Statistics.db
        rw-rr- 2 cassandra cassandra 574037723 Jul 30 02:26 quota_counters-g-476-Data.db
        rw-rr- 2 cassandra cassandra 3778336 Jul 30 02:26 quota_counters-g-476-Filter.db
        rw-rr- 2 cassandra cassandra 74766796 Jul 30 02:26 quota_counters-g-476-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:26 quota_counters-g-476-Statistics.db
        rw-rr- 2 cassandra cassandra 66750073 Jul 30 16:14 quota_counters-g-500-Data.db
        rw-rr- 2 cassandra cassandra 382512 Jul 30 16:14 quota_counters-g-500-Filter.db
        rw-rr- 2 cassandra cassandra 7587562 Jul 30 16:14 quota_counters-g-500-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 16:14 quota_counters-g-500-Statistics.db
        rw-rr- 2 cassandra cassandra 65704662 Jul 30 16:15 quota_counters-g-503-Data.db
        rw-rr- 2 cassandra cassandra 409456 Jul 30 16:15 quota_counters-g-503-Filter.db
        rw-rr- 2 cassandra cassandra 7134471 Jul 30 16:15 quota_counters-g-503-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 16:15 quota_counters-g-503-Statistics.db
        rw-rr- 2 cassandra cassandra 496890534 Jul 30 16:20 quota_counters-g-505-Data.db
        rw-rr- 2 cassandra cassandra 7479616 Jul 30 16:20 quota_counters-g-505-Filter.db
        rw-rr- 2 cassandra cassandra 53756417 Jul 30 16:20 quota_counters-g-505-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 16:20 quota_counters-g-505-Statistics.db
        rw-rr- 2 cassandra cassandra 101189405 Jul 30 19:13 quota_counters-g-508-Data.db
        rw-rr- 2 cassandra cassandra 683296 Jul 30 19:13 quota_counters-g-508-Filter.db
        rw-rr- 2 cassandra cassandra 10281151 Jul 30 19:13 quota_counters-g-508-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 19:13 quota_counters-g-508-Statistics.db
        rw-rr- 2 cassandra cassandra 36645335 Jul 30 20:49 quota_counters-g-509-Data.db
        rw-rr- 2 cassandra cassandra 182984 Jul 30 20:49 quota_counters-g-509-Filter.db
        rw-rr- 2 cassandra cassandra 3633104 Jul 30 20:49 quota_counters-g-509-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 20:49 quota_counters-g-509-Statistics.db
        rw-rr- 2 cassandra cassandra 10071816 Jul 30 21:12 quota_counters-g-510-Data.db
        rw-rr- 2 cassandra cassandra 50536 Jul 30 21:12 quota_counters-g-510-Filter.db
        rw-rr- 2 cassandra cassandra 1004098 Jul 30 21:12 quota_counters-g-510-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 21:12 quota_counters-g-510-Statistics.db
        rw-rr- 2 cassandra cassandra 118 Jul 30 02:25 quota-g-6-Data.db
        rw-rr- 2 cassandra cassandra 496 Jul 30 02:25 quota-g-6-Filter.db
        rw-rr- 2 cassandra cassandra 33 Jul 30 02:25 quota-g-6-Index.db
        rw-rr- 2 cassandra cassandra 4276 Jul 30 02:25 quota-g-6-Statistics.db

        error log sample from that node:
        java.io.IOError: java.io.IOException: mmap segment underflow; remaining is 10648 but 25701 requested
        at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:80)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67)
        at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66)
        at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80)
        at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146)
        at org.apache.cassandra.db.Table.getRow(Table.java:385)
        at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61)
        at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69)
        at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
        Caused by: java.io.IOException: mmap segment underflow; remaining is 10648 but 25701 requested
        at org.apache.cassandra.io.util.MappedFileDataInput.readBytes(MappedFileDataInput.java:117)
        at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:389)
        at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368)
        at org.apache.cassandra.io.sstable.IndexHelper$IndexInfo.deserialize(IndexHelper.java:194)
        at org.apache.cassandra.io.sstable.IndexHelper.deserializeIndex(IndexHelper.java:83)
        at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:73)
        ... 14 more
        2011-07-30 21:24:48:340 CEST ERROR [ReadStage:1993][org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread[ReadStage:1993,5,main]
        java.io.IOError: java.io.IOException: mmap segment underflow; remaining is 27299 but 28532 requested
        at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:80)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67)
        at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66)
        at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80)
        at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146)
        at org.apache.cassandra.db.Table.getRow(Table.java:385)
        at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61)
        at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69)
        at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
        Caused by: java.io.IOException: mmap segment underflow; remaining is 27299 but 28532 requested
        at org.apache.cassandra.io.util.MappedFileDataInput.readBytes(MappedFileDataInput.java:117)
        at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:389)
        at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368)
        at org.apache.cassandra.io.sstable.IndexHelper$IndexInfo.deserialize(IndexHelper.java:194)
        at org.apache.cassandra.io.sstable.IndexHelper.deserializeIndex(IndexHelper.java:83)
        at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:73)
        ... 14 more
        2011-07-30 21:26:43:823 CEST ERROR [ReadStage:1972][org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread[ReadStage:1972,5,main]
        java.lang.AssertionError
        at org.apache.cassandra.io.util.MappedFileDataInput.skipBytes(MappedFileDataInput.java:145)
        at org.apache.cassandra.io.util.FileUtils.skipBytesFully(FileUtils.java:227)
        at org.apache.cassandra.io.sstable.IndexHelper.skipBloomFilter(IndexHelper.java:50)
        at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:72)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67)
        at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66)
        at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80)
        at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146)
        at org.apache.cassandra.db.Table.getRow(Table.java:385)
        at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61)
        at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69)
        at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
        2011-07-30 21:26:53:869 CEST ERROR [ReadStage:1978][org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread[ReadStage:1978,5,main]
        java.lang.AssertionError
        at org.apache.cassandra.io.util.MappedFileDataInput.skipBytes(MappedFileDataInput.java:145)
        at org.apache.cassandra.io.util.FileUtils.skipBytesFully(FileUtils.java:227)
        at org.apache.cassandra.io.sstable.IndexHelper.skipBloomFilter(IndexHelper.java:50)
        at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:72)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91)
        at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67)
        at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66)
        at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80)
        at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189)
        at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146)
        at org.apache.cassandra.db.Table.getRow(Table.java:385)
        at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61)
        at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69)
        at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

        Show
        Wojciech Meler added a comment - BINGO I've run scrub in "rolling" way So I've done prescrub snapshots of 4 remaining nodes. All logs are collected. (Un)fortunately I'm going on vacation so I can give you all you need on 15'th October. Data set is quite big - about 140GB per node, so I'll need some instructions what to extract for you. Snapshot file list from 12th node: rw-r r - 2 cassandra cassandra 49714745792 Jul 30 02:20 fdb-g-1715-Data.db rw-r r - 2 cassandra cassandra 4815616 Jul 30 02:20 fdb-g-1715-Filter.db rw-r r - 2 cassandra cassandra 61556583 Jul 30 02:20 fdb-g-1715-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:20 fdb-g-1715-Statistics.db rw-r r - 2 cassandra cassandra 3450580822 Jul 30 02:22 fdb-g-1717-Data.db rw-r r - 2 cassandra cassandra 904096 Jul 30 02:22 fdb-g-1717-Filter.db rw-r r - 2 cassandra cassandra 18024560 Jul 30 02:22 fdb-g-1717-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:22 fdb-g-1717-Statistics.db rw-r r - 2 cassandra cassandra 3213527243 Jul 30 02:25 fdb-g-1721-Data.db rw-r r - 2 cassandra cassandra 904336 Jul 30 02:25 fdb-g-1721-Filter.db rw-r r - 2 cassandra cassandra 18026968 Jul 30 02:25 fdb-g-1721-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:25 fdb-g-1721-Statistics.db rw-r r - 2 cassandra cassandra 98385535 Jul 30 03:20 fdb-g-1723-Data.db rw-r r - 2 cassandra cassandra 247456 Jul 30 03:20 fdb-g-1723-Filter.db rw-r r - 2 cassandra cassandra 3130599 Jul 30 03:20 fdb-g-1723-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 03:20 fdb-g-1723-Statistics.db rw-r r - 2 cassandra cassandra 106856768 Jul 30 09:41 fdb-g-1734-Data.db rw-r r - 2 cassandra cassandra 195376 Jul 30 09:41 fdb-g-1734-Filter.db rw-r r - 2 cassandra cassandra 2713645 Jul 30 09:41 fdb-g-1734-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 09:41 fdb-g-1734-Statistics.db rw-r r - 2 cassandra cassandra 111863768 Jul 30 17:14 fdb-g-1745-Data.db rw-r r - 2 cassandra cassandra 194416 Jul 30 17:14 fdb-g-1745-Filter.db rw-r r - 2 cassandra cassandra 2761017 Jul 30 17:14 fdb-g-1745-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 17:14 fdb-g-1745-Statistics.db rw-r r - 2 cassandra cassandra 845886467 Jul 30 20:16 fdb-g-1750-Data.db rw-r r - 2 cassandra cassandra 902896 Jul 30 20:16 fdb-g-1750-Filter.db rw-r r - 2 cassandra cassandra 10419730 Jul 30 20:16 fdb-g-1750-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 20:16 fdb-g-1750-Statistics.db rw-r r - 2 cassandra cassandra 40226865 Jul 30 21:12 fdb-g-1751-Data.db rw-r r - 2 cassandra cassandra 66608 Jul 30 21:12 fdb-g-1751-Filter.db rw-r r - 2 cassandra cassandra 1319135 Jul 30 21:12 fdb-g-1751-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 21:12 fdb-g-1751-Statistics.db rw-r r - 2 cassandra cassandra 10904996806 Jul 30 02:41 mailcache-g-3708-Data.db rw-r r - 2 cassandra cassandra 254656 Jul 30 02:41 mailcache-g-3708-Filter.db rw-r r - 2 cassandra cassandra 5073034 Jul 30 02:41 mailcache-g-3708-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:41 mailcache-g-3708-Statistics.db rw-r r - 2 cassandra cassandra 18281871008 Jul 30 02:55 mailcache-g-3712-Data.db rw-r r - 2 cassandra cassandra 968176 Jul 30 02:55 mailcache-g-3712-Filter.db rw-r r - 2 cassandra cassandra 11904976 Jul 30 02:55 mailcache-g-3712-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:55 mailcache-g-3712-Statistics.db rw-r r - 2 cassandra cassandra 35390850 Jul 30 04:41 mailcache-g-3717-Data.db rw-r r - 2 cassandra cassandra 640 Jul 30 04:41 mailcache-g-3717-Filter.db rw-r r - 2 cassandra cassandra 12533 Jul 30 04:41 mailcache-g-3717-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 04:41 mailcache-g-3717-Statistics.db rw-r r - 2 cassandra cassandra 9067927959 Jul 30 11:02 mailcache-g-3727-Data.db rw-r r - 2 cassandra cassandra 296416 Jul 30 11:02 mailcache-g-3727-Filter.db rw-r r - 2 cassandra cassandra 3578551 Jul 30 11:02 mailcache-g-3727-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 11:02 mailcache-g-3727-Statistics.db rw-r r - 2 cassandra cassandra 67351540 Jul 30 16:08 mailcache-g-3738-Data.db rw-r r - 2 cassandra cassandra 1512 Jul 30 16:08 mailcache-g-3738-Filter.db rw-r r - 2 cassandra cassandra 29793 Jul 30 16:08 mailcache-g-3738-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 16:08 mailcache-g-3738-Statistics.db rw-r r - 2 cassandra cassandra 57132425 Jul 30 16:14 mailcache-g-3739-Data.db rw-r r - 2 cassandra cassandra 1224 Jul 30 16:14 mailcache-g-3739-Filter.db rw-r r - 2 cassandra cassandra 23985 Jul 30 16:14 mailcache-g-3739-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 16:14 mailcache-g-3739-Statistics.db rw-r r - 2 cassandra cassandra 3832970739 Jul 30 20:17 mailcache-g-3748-Data.db rw-r r - 2 cassandra cassandra 107056 Jul 30 20:17 mailcache-g-3748-Filter.db rw-r r - 2 cassandra cassandra 1660163 Jul 30 20:17 mailcache-g-3748-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 20:17 mailcache-g-3748-Statistics.db rw-r r - 2 cassandra cassandra 314153777 Jul 30 20:49 mailcache-g-3749-Data.db rw-r r - 2 cassandra cassandra 6808 Jul 30 20:49 mailcache-g-3749-Filter.db rw-r r - 2 cassandra cassandra 135155 Jul 30 20:49 mailcache-g-3749-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 20:49 mailcache-g-3749-Statistics.db rw-r r - 2 cassandra cassandra 211709838 Jul 30 21:12 mailcache-g-3750-Data.db rw-r r - 2 cassandra cassandra 4664 Jul 30 21:12 mailcache-g-3750-Filter.db rw-r r - 2 cassandra cassandra 92163 Jul 30 21:12 mailcache-g-3750-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 21:12 mailcache-g-3750-Statistics.db rw-r r - 2 cassandra cassandra 8404555561 Jul 30 01:34 mta_logs-g-1485-Data.db rw-r r - 2 cassandra cassandra 2551456 Jul 30 01:34 mta_logs-g-1485-Filter.db rw-r r - 2 cassandra cassandra 50978377 Jul 30 01:34 mta_logs-g-1485-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 01:34 mta_logs-g-1485-Statistics.db rw-r r - 2 cassandra cassandra 3759973372 Jul 30 01:37 mta_logs-g-1486-Data.db rw-r r - 2 cassandra cassandra 1611616 Jul 30 01:37 mta_logs-g-1486-Filter.db rw-r r - 2 cassandra cassandra 32166666 Jul 30 01:37 mta_logs-g-1486-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 01:37 mta_logs-g-1486-Statistics.db rw-r r - 2 cassandra cassandra 4179780390 Jul 30 01:41 mta_logs-g-1487-Data.db rw-r r - 2 cassandra cassandra 1507936 Jul 30 01:41 mta_logs-g-1487-Filter.db rw-r r - 2 cassandra cassandra 30052328 Jul 30 01:41 mta_logs-g-1487-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 01:41 mta_logs-g-1487-Statistics.db rw-r r - 2 cassandra cassandra 138623813 Jul 30 15:41 mta_logs-g-1507-Data.db rw-r r - 2 cassandra cassandra 429616 Jul 30 15:41 mta_logs-g-1507-Filter.db rw-r r - 2 cassandra cassandra 5115547 Jul 30 15:41 mta_logs-g-1507-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 15:41 mta_logs-g-1507-Statistics.db rw-r r - 2 cassandra cassandra 493377854 Jul 30 18:15 mta_logs-g-1513-Data.db rw-r r - 2 cassandra cassandra 1190896 Jul 30 18:15 mta_logs-g-1513-Filter.db rw-r r - 2 cassandra cassandra 13534807 Jul 30 18:15 mta_logs-g-1513-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 18:15 mta_logs-g-1513-Statistics.db rw-r r - 2 cassandra cassandra 36751337 Jul 30 19:14 mta_logs-g-1514-Data.db rw-r r - 2 cassandra cassandra 107152 Jul 30 19:14 mta_logs-g-1514-Filter.db rw-r r - 2 cassandra cassandra 2130178 Jul 30 19:14 mta_logs-g-1514-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 19:14 mta_logs-g-1514-Statistics.db rw-r r - 2 cassandra cassandra 32420585 Jul 30 20:14 mta_logs-g-1515-Data.db rw-r r - 2 cassandra cassandra 97784 Jul 30 20:14 mta_logs-g-1515-Filter.db rw-r r - 2 cassandra cassandra 1943186 Jul 30 20:14 mta_logs-g-1515-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 20:14 mta_logs-g-1515-Statistics.db rw-r r - 2 cassandra cassandra 30340652 Jul 30 21:12 mta_logs-g-1516-Data.db rw-r r - 2 cassandra cassandra 90888 Jul 30 21:12 mta_logs-g-1516-Filter.db rw-r r - 2 cassandra cassandra 1809686 Jul 30 21:12 mta_logs-g-1516-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 21:12 mta_logs-g-1516-Statistics.db rw-r r - 2 cassandra cassandra 574037723 Jul 30 02:26 quota_counters-g-476-Data.db rw-r r - 2 cassandra cassandra 3778336 Jul 30 02:26 quota_counters-g-476-Filter.db rw-r r - 2 cassandra cassandra 74766796 Jul 30 02:26 quota_counters-g-476-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:26 quota_counters-g-476-Statistics.db rw-r r - 2 cassandra cassandra 66750073 Jul 30 16:14 quota_counters-g-500-Data.db rw-r r - 2 cassandra cassandra 382512 Jul 30 16:14 quota_counters-g-500-Filter.db rw-r r - 2 cassandra cassandra 7587562 Jul 30 16:14 quota_counters-g-500-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 16:14 quota_counters-g-500-Statistics.db rw-r r - 2 cassandra cassandra 65704662 Jul 30 16:15 quota_counters-g-503-Data.db rw-r r - 2 cassandra cassandra 409456 Jul 30 16:15 quota_counters-g-503-Filter.db rw-r r - 2 cassandra cassandra 7134471 Jul 30 16:15 quota_counters-g-503-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 16:15 quota_counters-g-503-Statistics.db rw-r r - 2 cassandra cassandra 496890534 Jul 30 16:20 quota_counters-g-505-Data.db rw-r r - 2 cassandra cassandra 7479616 Jul 30 16:20 quota_counters-g-505-Filter.db rw-r r - 2 cassandra cassandra 53756417 Jul 30 16:20 quota_counters-g-505-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 16:20 quota_counters-g-505-Statistics.db rw-r r - 2 cassandra cassandra 101189405 Jul 30 19:13 quota_counters-g-508-Data.db rw-r r - 2 cassandra cassandra 683296 Jul 30 19:13 quota_counters-g-508-Filter.db rw-r r - 2 cassandra cassandra 10281151 Jul 30 19:13 quota_counters-g-508-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 19:13 quota_counters-g-508-Statistics.db rw-r r - 2 cassandra cassandra 36645335 Jul 30 20:49 quota_counters-g-509-Data.db rw-r r - 2 cassandra cassandra 182984 Jul 30 20:49 quota_counters-g-509-Filter.db rw-r r - 2 cassandra cassandra 3633104 Jul 30 20:49 quota_counters-g-509-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 20:49 quota_counters-g-509-Statistics.db rw-r r - 2 cassandra cassandra 10071816 Jul 30 21:12 quota_counters-g-510-Data.db rw-r r - 2 cassandra cassandra 50536 Jul 30 21:12 quota_counters-g-510-Filter.db rw-r r - 2 cassandra cassandra 1004098 Jul 30 21:12 quota_counters-g-510-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 21:12 quota_counters-g-510-Statistics.db rw-r r - 2 cassandra cassandra 118 Jul 30 02:25 quota-g-6-Data.db rw-r r - 2 cassandra cassandra 496 Jul 30 02:25 quota-g-6-Filter.db rw-r r - 2 cassandra cassandra 33 Jul 30 02:25 quota-g-6-Index.db rw-r r - 2 cassandra cassandra 4276 Jul 30 02:25 quota-g-6-Statistics.db error log sample from that node: java.io.IOError: java.io.IOException: mmap segment underflow; remaining is 10648 but 25701 requested at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:80) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67) at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66) at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80) at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146) at org.apache.cassandra.db.Table.getRow(Table.java:385) at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61) at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69) at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: java.io.IOException: mmap segment underflow; remaining is 10648 but 25701 requested at org.apache.cassandra.io.util.MappedFileDataInput.readBytes(MappedFileDataInput.java:117) at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:389) at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368) at org.apache.cassandra.io.sstable.IndexHelper$IndexInfo.deserialize(IndexHelper.java:194) at org.apache.cassandra.io.sstable.IndexHelper.deserializeIndex(IndexHelper.java:83) at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:73) ... 14 more 2011-07-30 21:24:48:340 CEST ERROR [ReadStage:1993] [org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread [ReadStage:1993,5,main] java.io.IOError: java.io.IOException: mmap segment underflow; remaining is 27299 but 28532 requested at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:80) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67) at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66) at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80) at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146) at org.apache.cassandra.db.Table.getRow(Table.java:385) at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61) at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69) at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: java.io.IOException: mmap segment underflow; remaining is 27299 but 28532 requested at org.apache.cassandra.io.util.MappedFileDataInput.readBytes(MappedFileDataInput.java:117) at org.apache.cassandra.utils.ByteBufferUtil.read(ByteBufferUtil.java:389) at org.apache.cassandra.utils.ByteBufferUtil.readWithShortLength(ByteBufferUtil.java:368) at org.apache.cassandra.io.sstable.IndexHelper$IndexInfo.deserialize(IndexHelper.java:194) at org.apache.cassandra.io.sstable.IndexHelper.deserializeIndex(IndexHelper.java:83) at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:73) ... 14 more 2011-07-30 21:26:43:823 CEST ERROR [ReadStage:1972] [org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread [ReadStage:1972,5,main] java.lang.AssertionError at org.apache.cassandra.io.util.MappedFileDataInput.skipBytes(MappedFileDataInput.java:145) at org.apache.cassandra.io.util.FileUtils.skipBytesFully(FileUtils.java:227) at org.apache.cassandra.io.sstable.IndexHelper.skipBloomFilter(IndexHelper.java:50) at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:72) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67) at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66) at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80) at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146) at org.apache.cassandra.db.Table.getRow(Table.java:385) at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61) at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69) at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) 2011-07-30 21:26:53:869 CEST ERROR [ReadStage:1978] [org.apache.cassandra.service.AbstractCassandraDaemon] Fatal exception in thread Thread [ReadStage:1978,5,main] java.lang.AssertionError at org.apache.cassandra.io.util.MappedFileDataInput.skipBytes(MappedFileDataInput.java:145) at org.apache.cassandra.io.util.FileUtils.skipBytesFully(FileUtils.java:227) at org.apache.cassandra.io.sstable.IndexHelper.skipBloomFilter(IndexHelper.java:50) at org.apache.cassandra.db.columniterator.IndexedSliceReader.<init>(IndexedSliceReader.java:72) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.createReader(SSTableSliceIterator.java:91) at org.apache.cassandra.db.columniterator.SSTableSliceIterator.<init>(SSTableSliceIterator.java:67) at org.apache.cassandra.db.filter.SliceQueryFilter.getSSTableColumnIterator(SliceQueryFilter.java:66) at org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:80) at org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1292) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1189) at org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1146) at org.apache.cassandra.db.Table.getRow(Table.java:385) at org.apache.cassandra.db.SliceFromReadCommand.getRow(SliceFromReadCommand.java:61) at org.apache.cassandra.db.ReadVerbHandler.doVerb(ReadVerbHandler.java:69) at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:72) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662)
        Hide
        Wojciech Meler added a comment -

        (( just noticed that pre-scrub snapshots are taken by default ....
        I've done snapshot on Jul 24th, cleanup on Jun 29th so don't know if it will help...

        Show
        Wojciech Meler added a comment - (( just noticed that pre-scrub snapshots are taken by default .... I've done snapshot on Jul 24th, cleanup on Jun 29th so don't know if it will help...
        Hide
        Wojciech Meler added a comment - - edited

        Scrub log from 9th node

        2011-07-30 21:39:55:386 CEST INFO [CompactionExecutor:172][org.apache.cassandra.db.compaction.CompactionManager] Scrubbing SSTableReader(path='/var/lib/cassandra/data/mail/mta_logs-g-733-Data.db')
        2011-07-30 21:39:55:469 CEST WARN [CompactionExecutor:172][org.apache.cassandra.db.compaction.CompactionManager] Non-fatal error reading row (stacktrace follows)
        java.io.IOError: java.io.IOException: Impossible row size 7933455022436196
        at org.apache.cassandra.db.compaction.CompactionManager.scrubOne(CompactionManager.java:719)
        at org.apache.cassandra.db.compaction.CompactionManager.doScrub(CompactionManager.java:633)
        at org.apache.cassandra.db.compaction.CompactionManager.access$600(CompactionManager.java:65)
        at org.apache.cassandra.db.compaction.CompactionManager$3.call(CompactionManager.java:250)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
        Caused by: java.io.IOException: Impossible row size 7933455022436196
        ... 9 more
        2011-07-30 21:39:55:470 CEST INFO [CompactionExecutor:172][org.apache.cassandra.db.compaction.CompactionManager] Retrying from row index; data is -8 bytes starting at 547199
        2011-07-30 21:39:55:470 CEST WARN [CompactionExecutor:172][org.apache.cassandra.db.compaction.CompactionManager] Retry failed too. Skipping to next row (retry's stacktrace follows)
        java.io.IOError: java.io.EOFException: bloom filter claims to be 909194543 bytes, longer than entire row size -8
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:149)
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:90)
        at org.apache.cassandra.db.compaction.CompactionManager.scrubOne(CompactionManager.java:748)
        at org.apache.cassandra.db.compaction.CompactionManager.doScrub(CompactionManager.java:633)
        at org.apache.cassandra.db.compaction.CompactionManager.access$600(CompactionManager.java:65)
        at org.apache.cassandra.db.compaction.CompactionManager$3.call(CompactionManager.java:250)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
        Caused by: java.io.EOFException: bloom filter claims to be 909194543 bytes, longer than entire row size -8
        at org.apache.cassandra.io.sstable.IndexHelper.defreezeBloomFilter(IndexHelper.java:111)
        at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:119)
        ... 10 more
        2011-07-30 21:39:55:482 CEST WARN [CompactionExecutor:172][org.apache.cassandra.db.compaction.CompactionManager] Non-fatal error reading row (stacktrace follows)

        Show
        Wojciech Meler added a comment - - edited Scrub log from 9th node 2011-07-30 21:39:55:386 CEST INFO [CompactionExecutor:172] [org.apache.cassandra.db.compaction.CompactionManager] Scrubbing SSTableReader(path='/var/lib/cassandra/data/mail/mta_logs-g-733-Data.db') 2011-07-30 21:39:55:469 CEST WARN [CompactionExecutor:172] [org.apache.cassandra.db.compaction.CompactionManager] Non-fatal error reading row (stacktrace follows) java.io.IOError: java.io.IOException: Impossible row size 7933455022436196 at org.apache.cassandra.db.compaction.CompactionManager.scrubOne(CompactionManager.java:719) at org.apache.cassandra.db.compaction.CompactionManager.doScrub(CompactionManager.java:633) at org.apache.cassandra.db.compaction.CompactionManager.access$600(CompactionManager.java:65) at org.apache.cassandra.db.compaction.CompactionManager$3.call(CompactionManager.java:250) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: java.io.IOException: Impossible row size 7933455022436196 ... 9 more 2011-07-30 21:39:55:470 CEST INFO [CompactionExecutor:172] [org.apache.cassandra.db.compaction.CompactionManager] Retrying from row index; data is -8 bytes starting at 547199 2011-07-30 21:39:55:470 CEST WARN [CompactionExecutor:172] [org.apache.cassandra.db.compaction.CompactionManager] Retry failed too. Skipping to next row (retry's stacktrace follows) java.io.IOError: java.io.EOFException: bloom filter claims to be 909194543 bytes, longer than entire row size -8 at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:149) at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:90) at org.apache.cassandra.db.compaction.CompactionManager.scrubOne(CompactionManager.java:748) at org.apache.cassandra.db.compaction.CompactionManager.doScrub(CompactionManager.java:633) at org.apache.cassandra.db.compaction.CompactionManager.access$600(CompactionManager.java:65) at org.apache.cassandra.db.compaction.CompactionManager$3.call(CompactionManager.java:250) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: java.io.EOFException: bloom filter claims to be 909194543 bytes, longer than entire row size -8 at org.apache.cassandra.io.sstable.IndexHelper.defreezeBloomFilter(IndexHelper.java:111) at org.apache.cassandra.io.sstable.SSTableIdentityIterator.<init>(SSTableIdentityIterator.java:119) ... 10 more 2011-07-30 21:39:55:482 CEST WARN [CompactionExecutor:172] [org.apache.cassandra.db.compaction.CompactionManager] Non-fatal error reading row (stacktrace follows)
        Hide
        Jonathan Ellis added a comment -

        Which CF is getting the read errors? Is it a counter CF?

        Show
        Jonathan Ellis added a comment - Which CF is getting the read errors? Is it a counter CF?
        Hide
        Sylvain Lebresne added a comment -

        Also, what is the story of that cluster. Is it a straight up 0.8 cluster, or was it upgraded from 0.7 ?

        Show
        Sylvain Lebresne added a comment - Also, what is the story of that cluster. Is it a straight up 0.8 cluster, or was it upgraded from 0.7 ?
        Hide
        Michał Kowalczuk added a comment -

        Hello, Wojciech is my colleague. This cluster was upgraded from 0.7. I'm not sure which CF was getting read errors, though.

        And as far as I know, Wojciech will be back on 15th August, not October.

        Show
        Michał Kowalczuk added a comment - Hello, Wojciech is my colleague. This cluster was upgraded from 0.7. I'm not sure which CF was getting read errors, though. And as far as I know, Wojciech will be back on 15th August, not October.
        Hide
        Wojciech Meler added a comment -

        I'm back. As Michał said cluster history was: 0.7.0 -> 0.7.2 -> 0.7.3 -> 0.7.4 -> 0.8.0 -> 0.8.1.
        It started with 6 nodes. After migrating to 0.8.0 cluster grew to 12, and after 0.8.1 to 18 nodes.

        It's hard to say which CF got read errors, but exceptions from scrub suggests that it was mta_logs which is plain CF.

        Show
        Wojciech Meler added a comment - I'm back. As Michał said cluster history was: 0.7.0 -> 0.7.2 -> 0.7.3 -> 0.7.4 -> 0.8.0 -> 0.8.1. It started with 6 nodes. After migrating to 0.8.0 cluster grew to 12, and after 0.8.1 to 18 nodes. It's hard to say which CF got read errors, but exceptions from scrub suggests that it was mta_logs which is plain CF.
        Hide
        Wojciech Meler added a comment -

        I've examined log files and found one broken sstable for which I have pre-cleanup and pre-scrub snapshots.
        It's too big for test case (8GB). I'll try to isolate the problem.

        Show
        Wojciech Meler added a comment - I've examined log files and found one broken sstable for which I have pre-cleanup and pre-scrub snapshots. It's too big for test case (8GB). I'll try to isolate the problem.

          People

          • Assignee:
            Unassigned
            Reporter:
            Wojciech Meler
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development