You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Tyler Hobbs (JIRA)" <ji...@apache.org> on 2012/08/31 04:04:07 UTC

[jira] [Commented] (CASSANDRA-4206) AssertionError: originally calculated column size of 629444349 but now it is 588008950

    [ https://issues.apache.org/jira/browse/CASSANDRA-4206?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13445572#comment-13445572 ] 

Tyler Hobbs commented on CASSANDRA-4206:
----------------------------------------

I'm not sure how useful it is at this point, but just for the record I'm seeing what appears to be the same issue with 1.0.7 (which means it shouldn't be CASSANDRA-3579):

{noformat}
 INFO [GossipTasks:1] 2012-08-27 14:22:50,242 Gossiper.java (line 818) InetAddress /xx.xx.178.59 is now dead.
 INFO [GossipStage:1] 2012-08-27 14:22:59,090 Gossiper.java (line 804) InetAddress /xx.xx.178.59 is now UP
 INFO [HintedHandoff:1] 2012-08-27 14:23:41,548 HintedHandOffManager.java (line 296) Started hinted handoff for token: 132332031580364958013534569556798748899 with IP: /xx.xx.178.59
 INFO [HintedHandoff:1] 2012-08-27 14:23:41,870 ColumnFamilyStore.java (line 704) Enqueuing flush of Memtable-HintsColumnFamily@2081164539(597050/47764000 serialized/live bytes, 857 ops)
 INFO [FlushWriter:181] 2012-08-27 14:23:41,870 Memtable.java (line 246) Writing Memtable-HintsColumnFamily@2081164539(597050/47764000 serialized/live bytes, 857 ops)
 INFO [FlushWriter:181] 2012-08-27 14:23:41,959 Memtable.java (line 283) Completed flushing /xx/xx/xx/cassandra/datafile/system/HintsColumnFamily-hc-6730-Data.db (624946 bytes)
 INFO [CompactionExecutor:884] 2012-08-27 14:23:41,961 CompactionTask.java (line 113) Compacting [SSTableReader(path='/xx/xx/xx/cassandra/datafile/system/HintsColumnFamily-hc-6729-Data.db'), SSTableReader(path='/ngs/app/xcardp/cassandra/datafile/system/HintsColumnFamily-hc-6730-Data.db')]
 INFO [CompactionExecutor:884] 2012-08-27 14:23:41,987 CompactionController.java (line 133) Compacting large row system/HintsColumnFamily:31372e33342e3137382e3534 (274816343 bytes) incrementally
ERROR [CompactionExecutor:884] 2012-08-27 14:23:56,322 AbstractCassandraDaemon.java (line 139) Fatal exception in thread Thread[CompactionExecutor:884,1,main]
java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at org.apache.cassandra.db.compaction.LazilyCompactedRow.write(LazilyCompactedRow.java:124)
    at org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:160)
    at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:159)
    at org.apache.cassandra.db.compaction.CompactionManager$6.call(CompactionManager.java:275)
    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)
ERROR [HintedHandoff:1] 2012-08-27 14:23:56,323 AbstractCassandraDaemon.java (line 139) Fatal exception in thread Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpointInternal(HintedHandOffManager.java:369)
    at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:248)
    at org.apache.cassandra.db.HintedHandOffManager.access$200(HintedHandOffManager.java:84)
    at org.apache.cassandra.db.HintedHandOffManager$3.runMayThrow(HintedHandOffManager.java:416)
    at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
    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.util.concurrent.ExecutionException: java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
    at java.util.concurrent.FutureTask.get(FutureTask.java:83)
    at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpointInternal(HintedHandOffManager.java:365)
    ... 7 more
Caused by: java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at org.apache.cassandra.db.compaction.LazilyCompactedRow.write(LazilyCompactedRow.java:124)
    at org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:160)
    at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:159)
    at org.apache.cassandra.db.compaction.CompactionManager$6.call(CompactionManager.java:275)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    ... 3 more
ERROR [HintedHandoff:1] 2012-08-27 14:23:56,345 AbstractCassandraDaemon.java (line 139) Fatal exception in thread Thread[HintedHandoff:1,1,main]
java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpointInternal(HintedHandOffManager.java:369)
    at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:248)
    at org.apache.cassandra.db.HintedHandOffManager.access$200(HintedHandOffManager.java:84)
    at org.apache.cassandra.db.HintedHandOffManager$3.runMayThrow(HintedHandOffManager.java:416)
    at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
    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.util.concurrent.ExecutionException: java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
    at java.util.concurrent.FutureTask.get(FutureTask.java:83)
    at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpointInternal(HintedHandOffManager.java:365)
    ... 7 more
Caused by: java.lang.AssertionError: originally calculated column size of 197713629 but now it is 197711561
    at org.apache.cassandra.db.compaction.LazilyCompactedRow.write(LazilyCompactedRow.java:124)
    at org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:160)
    at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:159)
    at org.apache.cassandra.db.compaction.CompactionManager$6.call(CompactionManager.java:275)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
    at java.util.concurrent.FutureTask.run(FutureTask.java:138)
    ... 3 more
 INFO [COMMIT-LOG-WRITER] 2012-08-27 14:48:20,812 CommitLogSegment.java (line 60) Creating new commitlog segment /xxx/xxx/xxx/commitlog/CommitLog-1346078900812.log
{noformat}

I should note that this node was upgraded from 0.7.4 about three days prior.
                
> AssertionError: originally calculated column size of 629444349 but now it is 588008950
> --------------------------------------------------------------------------------------
>
>                 Key: CASSANDRA-4206
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-4206
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 1.0.9
>         Environment: Debian Squeeze Linux, kernel 2.6.32, sun-java6-bin 6.26-0squeeze1
>            Reporter: Patrik Modesto
>
> I've 4 node cluster of Cassandra 1.0.9. There is a rfTest3 keyspace with RF=3 and one CF with two secondary indexes. I'm importing data into this CF using Hadoop Mapreduce job, each row has less than 10 colkumns. From JMX:
> MaxRowSize:  1597
> MeanRowSize: 369
> And there are some tens of millions of rows.
> It's write-heavy usage and there is a big pressure on each node, there are quite some dropped mutations on each node. After ~12 hours of inserting I see these assertion exceptiona on 3 out of four nodes:
> {noformat}
> ERROR 06:25:40,124 Fatal exception in thread Thread[HintedHandoff:1,1,main]
> java.lang.RuntimeException: java.util.concurrent.ExecutionException:
> java.lang.AssertionError: originally calculated column size of 629444349 but now it is 588008950
>        at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpointInternal(HintedHandOffManager.java:388)
>        at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpoint(HintedHandOffManager.java:256)
>        at org.apache.cassandra.db.HintedHandOffManager.access$300(HintedHandOffManager.java:84)
>        at org.apache.cassandra.db.HintedHandOffManager$3.runMayThrow(HintedHandOffManager.java:437)
>        at org.apache.cassandra.utils.WrappedRunnable.run(WrappedRunnable.java:30)
>        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.util.concurrent.ExecutionException:
> java.lang.AssertionError: originally calculated column size of
> 629444349 but now it is 588008950
>        at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222)
>        at java.util.concurrent.FutureTask.get(FutureTask.java:83)
>        at org.apache.cassandra.db.HintedHandOffManager.deliverHintsToEndpointInternal(HintedHandOffManager.java:384)
>        ... 7 more
> Caused by: java.lang.AssertionError: originally calculated column size
> of 629444349 but now it is 588008950
>        at org.apache.cassandra.db.compaction.LazilyCompactedRow.write(LazilyCompactedRow.java:124)
>        at org.apache.cassandra.io.sstable.SSTableWriter.append(SSTableWriter.java:160)
>        at org.apache.cassandra.db.compaction.CompactionTask.execute(CompactionTask.java:161)
>        at org.apache.cassandra.db.compaction.CompactionManager$7.call(CompactionManager.java:380)
>        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>        ... 3 more
> {noformat}
> Few lines regarding Hints from the output.log:
> {noformat}
>  INFO 06:21:26,202 Compacting large row system/HintsColumnFamily:70000000000000000000000000000000 (1712834057 bytes) incrementally
>  INFO 06:22:52,610 Compacting large row system/HintsColumnFamily:10000000000000000000000000000000 (2616073981 bytes) incrementally
>  INFO 06:22:59,111 flushing high-traffic column family CFS(Keyspace='system', ColumnFamily='HintsColumnFamily') (estimated 305147360 bytes)
>  INFO 06:22:59,813 Enqueuing flush of Memtable-HintsColumnFamily@833933926(3814342/305147360 serialized/live bytes, 7452 ops)
>  INFO 06:22:59,814 Writing Memtable-HintsColumnFamily@833933926(3814342/305147360 serialized/live bytes, 7452 ops)
> {noformat}
> I think the problem may be somehow connected to an IntegerType secondary index. I had a different problem with CF with two secondary indexes, the first UTF8Type, the second IntegerType. After a few hours of inserting data in the afternoon and midnight repair+compact, the next day I couldn't find any row using the IntegerType secondary index. The output was like this:
> {noformat}
> [default@rfTest3] get IndexTest where col1 = '3230727:http://zaskolak.cz/download.php';
> -------------------
> RowKey: 3230727:8383582:http://zaskolak.cz/download.php
> => (column=col1, value=3230727:http://zaskolak.cz/download.php, timestamp=1335348630332000)
> => (column=col2, value=8383582, timestamp=1335348630332000)
> -------------------
> RowKey: 3230727:8383583:http://zaskolak.cz/download.php
> => (column=col1, value=3230727:http://zaskolak.cz/download.php, timestamp=1335348449078000)
> => (column=col2, value=8383583, timestamp=1335348449078000)
> -------------------
> RowKey: 3230727:8383579:http://zaskolak.cz/download.php
> => (column=col1, value=3230727:http://zaskolak.cz/download.php, timestamp=1335348778577000)
> => (column=col2, value=8383579, timestamp=1335348778577000)
> 3 Rows Returned.
> Elapsed time: 292 msec(s).
> [default@rfTest3] get IndexTest where col2 = 8383583;
> 0 Row Returned.
> Elapsed time: 7 msec(s
> {noformat}
> You can see there really is an 8383583 in col2 in on of the listed rows, but the search by secondary index returns nothing.
> The Assert Exception also happend only on CF with the secondary index of IntegerType. There were also secondary indexes of UTF8Type and
> LongType types. It's the first time I've tried secondary indexes of other type than UTF8Type.
> Regards,
> Patrik

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira