[CASSANDRA-15970] 3.x fails to start if commit log has range tombstones from a column which is also deleted - ASF JIRA

Details

Type: Bug
Status: Resolved
Priority: Normal
Resolution: Fixed
Fix Version/s: 3.0.22, 3.11.8
Component/s: Legacy/Local Write-Read Paths, Local/Commit Log
Labels:
None

Bug Category:
Correctness - Unrecoverable Corruption / Loss
Severity:
Critical
Complexity:
Normal
Discovered By:
Workload Replay
Platform:

All
Impacts:

None
Since Version:

3.0.0
Source Control Link:

https://github.com/apache/cassandra/commit/4b0c0817fa7b8e12a8e6cf96a9a2b67f36b449e8
Test and Documentation Plan:

Hide

upgrade dtest

Show
upgrade dtest

Description

Cassandra crashes with the following exception

ERROR [node1_isolatedExecutor:1] node1 2020-07-21 18:59:39,048 JVMStabilityInspector.java:102 - Exiting due to error while processing commit log during initialization.
org.apache.cassandra.db.commitlog.CommitLogReplayer$CommitLogReplayException: Unexpected error deserializing mutation; saved to /var/folders/cm/08cddl2s25j7fq3jdb76gh4r0000gn/T/mutation6239873170066752296dat.  This may be caused by replaying a mutation against a table with the same name but incompatible schema.
	at org.apache.cassandra.db.commitlog.CommitLogReplayer.handleReplayError(CommitLogReplayer.java:731) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLogReplayer.replayMutation(CommitLogReplayer.java:656) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLogReplayer.replaySyncSection(CommitLogReplayer.java:609) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLogReplayer.recover(CommitLogReplayer.java:493) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLogReplayer.recover(CommitLogReplayer.java:189) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:170) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLog.recover(CommitLog.java:151) [dtest-3.0.21.jar:na]
	at org.apache.cassandra.distributed.impl.Instance.lambda$startup$7(Instance.java:535) [dtest-3.0.21.jar:na]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_242]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_242]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_242]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_242]
	at org.apache.cassandra.concurrent.NamedThreadFactory.lambda$threadLocalDeallocator$0(NamedThreadFactory.java:83) ~[dtest-3.0.21.jar:na]
	at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_242]
Caused by: java.lang.NullPointerException: null
	at org.apache.cassandra.db.ClusteringComparator.validate(ClusteringComparator.java:206) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.partitions.PartitionUpdate.validate(PartitionUpdate.java:494) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.commitlog.CommitLogReplayer.replayMutation(CommitLogReplayer.java:629) [dtest-3.0.21.jar:na]
	... 12 common frames omitted

If you drain in 2.2 before upgrade, you get the following

ERROR [SharedPool-Worker-1] node1 2020-07-21 22:17:25,661 AbstractLocalAwareExecutorService.java:169 - Uncaught exception on thread Thread[SharedPool-Worker-1,5,node1]
java.lang.RuntimeException: java.lang.NullPointerException
	at org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2537) ~[dtest-3.0.21.jar:na]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_242]
	at org.apache.cassandra.concurrent.AbstractLocalAwareExecutorService$FutureTask.run(AbstractLocalAwareExecutorService.java:165) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.concurrent.SEPWorker.run(SEPWorker.java:109) [dtest-3.0.21.jar:na]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_242]
Caused by: java.lang.NullPointerException: null
	at org.apache.cassandra.db.ClusteringComparator.compare(ClusteringComparator.java:131) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.UnfilteredDeserializer$OldFormatDeserializer.compareNextTo(UnfilteredDeserializer.java:391) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.columniterator.SSTableIterator$ForwardReader.handlePreSliceData(SSTableIterator.java:105) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.columniterator.SSTableIterator$ForwardReader.hasNextInternal(SSTableIterator.java:164) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.columniterator.AbstractSSTableIterator$Reader.hasNext(AbstractSSTableIterator.java:336) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.filter.ClusteringIndexNamesFilter$1.hasNext(ClusteringIndexNamesFilter.java:157) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.rows.UnfilteredRowIterator.isEmpty(UnfilteredRowIterator.java:70) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.SinglePartitionReadCommand.queryMemtableAndSSTablesInTimestampOrder(SinglePartitionReadCommand.java:952) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.SinglePartitionReadCommand.queryMemtableAndDiskInternal(SinglePartitionReadCommand.java:679) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.SinglePartitionReadCommand.queryMemtableAndDisk(SinglePartitionReadCommand.java:656) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.SinglePartitionReadCommand.queryStorage(SinglePartitionReadCommand.java:491) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.db.ReadCommand.executeLocally(ReadCommand.java:418) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.service.StorageProxy$LocalReadRunnable.runMayThrow(StorageProxy.java:1793) ~[dtest-3.0.21.jar:na]
	at org.apache.cassandra.service.StorageProxy$DroppableRunnable.run(StorageProxy.java:2533) ~[dtest-3.0.21.jar:na]
	... 4 common frames omitted

The issue found was as follows