[
https://issues.apache.org/jira/browse/CASSANDRA-7465?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14046733#comment-14046733
]
Jason Brown commented on CASSANDRA-7465:
----------------------------------------
Yup, the SSNTI.key's BB is definitely getting corrupted. I added a quick
capture of the key's raw string in the ctor:
{code}
...
public final DecoratedKey key;
private final String originalKey; // <- new member field
public SSTableNamesIterator(SSTableReader sstable, DecoratedKey key,
SortedSet<CellName> columns)
{
assert columns != null;
this.sstable = sstable;
this.columns = columns;
this.key = key;
originalKey = key.toString();
....
}
{code}
Then print out the originalKey on assert fail:
{code}
assert keyInDisk.equals(key) : String.format("%s != %s in %s,
originalKey = %s", keyInDisk, key, file.getPath(), originalKey);
{code}
Here's a sample assert error output:
{code}
java.lang.AssertionError: DecoratedKey(-6380411336414528869,
30303033313546384530) != DecoratedKey(-6380411336414528869,
30303036433842334234) in
/u/sdd/cassandra-jasobrown/data/Keyspace1/Standard1-6ab9bd90fe3b11e385edff96c2ef2fd6/Keyspace1-Standard1-ka-109-Data.db,
originalKey = DecoratedKey(-6380411336414528869, 30303033313546384530)
{code}
The first key printed, 30303033313546384530, is the one from disk (that was
pointed to by the buffer from the key cache); note that it matches the original
key (last key printed). The key in the middle, 30303036433842334234, is the
corrupted value that occurred after the lookup to the key cache, yet before the
assert. Thus, I believe my hypothesis is correct.
As to how to fix the problem, I'm not sure if there's a quick solution to
having a systematic way to detect refs to the key's buffer, but we can quite
readily fix the known problems: key cache and, as [~benedict] correctly pointed
out, row cache.
> DecoratedKey assertion error on reads
> -------------------------------------
>
> Key: CASSANDRA-7465
> URL: https://issues.apache.org/jira/browse/CASSANDRA-7465
> Project: Cassandra
> Issue Type: Bug
> Components: Core
> Environment: 3 nodes
> Oracle Linux Server 6.3
> kernel ver 2.6.39
> Reporter: Jason Brown
> Priority: Blocker
> Fix For: 2.1.0
>
>
> Getting the following exception when running read stress:
> {code}WARN [SharedPool-Worker-31] 2014-06-27 21:25:51,391
> AbstractTracingAwareExecutorService.java:166 - Uncaught exception on thread
> Thread[SharedPool-Worker-31,10,main]: {}
> java.lang.AssertionError: DecoratedKey(-5397116645141815707,
> 30303031393143364639) != DecoratedKey(-5397116645141815707,
> 30303031343439443233) in
> /u/sdd/cassandra-jasobrown/data/Keyspace1/Standard1-6ab9bd90fe3b11e385edff96c2ef2fd6/Keyspace1-Standard1-ka-73-Data.db
> at
> org.apache.cassandra.db.columniterator.SSTableNamesIterator.read(SSTableNamesIterator.java:111)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.columniterator.SSTableNamesIterator.<init>(SSTableNamesIterator.java:59)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.filter.NamesQueryFilter.getSSTableColumnIterator(NamesQueryFilter.java:89)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.filter.QueryFilter.getSSTableColumnIterator(QueryFilter.java:62)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.CollationController.collectTimeOrderedData(CollationController.java:125)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.CollationController.getTopLevelColumns(CollationController.java:59)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.ColumnFamilyStore.getTopLevelColumns(ColumnFamilyStore.java:1873)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.ColumnFamilyStore.getColumnFamily(ColumnFamilyStore.java:1681)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at org.apache.cassandra.db.Keyspace.getRow(Keyspace.java:341)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.db.SliceByNamesReadCommand.getRow(SliceByNamesReadCommand.java:55)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.service.StorageProxy$LocalReadRunnable.runMayThrow(StorageProxy.java:1393)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2060)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> ~[na:1.7.0_13]
> at
> org.apache.cassandra.concurrent.AbstractTracingAwareExecutorService$FutureTask.run(AbstractTracingAwareExecutorService.java:162)
> ~[apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:103)
> [apache-cassandra-2.1.0-rc2-SNAPSHOT.jar:2.1.0-rc2-SNAPSHOT]
> at java.lang.Thread.run(Thread.java:722) [na:1.7.0_13]
> {code}
> I have a three node cluster, which I populate with the following stress
> command:
> {code}
> cassandra-stress write n=60000000 -schema replication\(factor\=2\) -key
> populate=1..60000000 -rate threads=42 -mode native prepared cql3 -port
> native=9043 thrift=9161 -node athena06-a,athena06-b,athena06-c -col
> n=fixed\(21\) size=exp\(11..42\)
> {code}
> Then I run the read stress:
> {code}
> cassandra-stress read n=100000000 -key dist=extr\(1..600000000,2\) -mode
> native prepared cql3 -port native=9043 thrift=9161 -node
> athena06-b,athena06-c,athena06-a -col n=fixed\(21\) -rate threads=64
> {code}
> The above exception occurs semi-frequently (several to ~50 times a minute,
> but seems to depend on amount of data in cluster - anecdotal evidence only).
--
This message was sent by Atlassian JIRA
(v6.2#6252)
