[CASSANDRA-18963] Test Failure: sstableutil_test.TestSSTableUtil

• Type: Bug
• Status: Resolved
• Priority: Normal
• Resolution: Fixed
• Fix Version/s: 4.0.12, 4.1.4, 5.0-beta1, 5.0, 5.1
• Component/s: Legacy/Local Write-Read Paths
• Bug Category: Correctness
• Severity: Normal
• Complexity: Normal
• Discovered By: Unit Test
• Platform: All
• Since Version: 4.0.0

Source Control Link

https://github.com/apache/cassandra/commit/dece96f21dbdbbb3176d6544d72bef3d44571dc6

Test and Documentation Plan

run regressions and new test

• Assignee: Jacek Lewandowski
• Reporter: Berenguer Blasi

Authors

Jacek Lewandowski

Reviewers

Benjamin Lerer

• Created: 26/Oct/23 09:42
• Updated: 05/Dec/23 12:51
• Resolved: 28/Nov/23 17:55

Description

Seems flaky https://app.circleci.com/pipelines/github/driftx/cassandra/1342/workflows/9554c7b5-dd60-4f08-8db5-c954febc8ad6/jobs/58957/tests

• test_abortedcompaction

sstableutil_test.TestSSTableUtil 
 

self = <sstableutil_test.TestSSTableUtil object at 0x7fc099ecea58> def test_abortedcompaction(self): """ @jira_ticket CASSANDRA-7066 @jira_ticket CASSANDRA-11497 Check that we can cleanup temporary files after a compaction is aborted. """ log_file_name = 'debug.log' cluster = self.cluster cluster.populate(1).start() node = cluster.nodelist()[0] numrecords = 250000 self._create_data(node, KeyspaceName, TableName, numrecords) finalfiles, tmpfiles = self._check_files(node, KeyspaceName, TableName) assert len(finalfiles) > 0, "Expected to find some final files" assert 0 == len(tmpfiles), "Expected no tmp files" t = InterruptCompaction(node, TableName, filename=log_file_name, delay=2) t.start() try: logger.debug("Compacting...") node.compact() except ToolError: pass # expected to fail t.join() finalfiles = _normcase_all(self._invoke_sstableutil(KeyspaceName, TableName, type='final')) tmpfiles = _normcase_all(self._invoke_sstableutil(KeyspaceName, TableName, type='tmp')) # In most cases we should end up with some temporary files to clean up, but it may happen # that no temporary files are created if compaction finishes too early or starts too late # see CASSANDRA-11497 logger.debug("Got {} final files and {} tmp files after compaction was interrupted" .format(len(finalfiles), len(tmpfiles))) self._invoke_sstableutil(KeyspaceName, TableName, cleanup=True) self._check_files(node, KeyspaceName, TableName, finalfiles, []) # restart to make sure not data is lost logger.debug("Restarting node...") > node.start(wait_for_binary_proto=True) sstableutil_test.py:97: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ ../env3.6/lib/python3.6/site-packages/ccmlib/node.py:914: in start self.wait_for_binary_interface(from_mark=self.mark) ../env3.6/lib/python3.6/site-packages/ccmlib/node.py:702: in wait_for_binary_interface self.watch_log_for("Starting listening for CQL clients", **kwargs) ../env3.6/lib/python3.6/site-packages/ccmlib/node.py:599: in watch_log_for self.raise_node_error_if_cassandra_process_is_terminated() _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = <ccmlib.node.Node object at 0x7fc08a583be0> def raise_node_error_if_cassandra_process_is_terminated(self): if not self._is_pid_running(): msg = "C* process with {pid} is terminated".format(pid=self.pid) common.debug(msg) > raise NodeError(msg) E ccmlib.node.NodeError: C* process with 19530 is terminated ../env3.6/lib/python3.6/site-packages/ccmlib/node.py:683: NodeError

failed on teardown with "Unexpected error found in node logs (see stdout for full details). Errors: [[node1] 'ERROR [SSTableBatchOpen:1] 2023-10-19 22:25:07,449 DefaultFSErrorHandler.java:129 - Exiting forcefully due to file system exception on startup, disk failure policy "stop"\norg.apache.cassandra.io.sstable.CorruptSSTableException: Corrupted: /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-4-big\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:111)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:397)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:353)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.lambda$openAll$4(SSTableReader.java:414)\n\tat org.apache.cassandra.concurrent.FutureTask$1.call(FutureTask.java:96)\n\tat org.apache.cassandra.concurrent.FutureTask.call(FutureTask.java:61)\n\tat org.apache.cassandra.concurrent.FutureTask.run(FutureTask.java:71)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: java.lang.IllegalArgumentException: null\n\tat com.google.common.base.Preconditions.checkArgument(Preconditions.java:129)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:79)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:58)\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:92)\n\t... 10 common frames omitted', [node1] 'ERROR [SSTableBatchOpen:4] 2023-10-19 22:25:07,449 DefaultFSErrorHandler.java:129 - Exiting forcefully due to file system exception on startup, disk failure policy "stop"\norg.apache.cassandra.io.sstable.CorruptSSTableException: Corrupted: /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-5-big\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:111)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:397)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:353)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.lambda$openAll$4(SSTableReader.java:414)\n\tat org.apache.cassandra.concurrent.FutureTask$1.call(FutureTask.java:96)\n\tat org.apache.cassandra.concurrent.FutureTask.call(FutureTask.java:61)\n\tat org.apache.cassandra.concurrent.FutureTask.run(FutureTask.java:71)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: java.lang.IllegalArgumentException: null\n\tat com.google.common.base.Preconditions.checkArgument(Preconditions.java:129)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:79)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:58)\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:92)\n\t... 10 common frames omitted', [node1] 'ERROR [SSTableBatchOpen:4] 2023-10-19 22:25:07,450 SSTableReader.java:419 - Corrupt sstable /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-5-big=[Index.db, Data.db]; skipping table\norg.apache.cassandra.io.sstable.CorruptSSTableException: Corrupted: /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-5-big\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:111)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:397)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:353)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.lambda$openAll$4(SSTableReader.java:414)\n\tat org.apache.cassandra.concurrent.FutureTask$1.call(FutureTask.java:96)\n\tat org.apache.cassandra.concurrent.FutureTask.call(FutureTask.java:61)\n\tat org.apache.cassandra.concurrent.FutureTask.run(FutureTask.java:71)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: java.lang.IllegalArgumentException: null\n\tat com.google.common.base.Preconditions.checkArgument(Preconditions.java:129)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:79)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:58)\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:92)\n\t... 10 common frames omitted']" Unexpected error found in node logs (see stdout for full details). Errors: [[node1] 'ERROR [SSTableBatchOpen:1] 2023-10-19 22:25:07,449 DefaultFSErrorHandler.java:129 - Exiting forcefully due to file system exception on startup, disk failure policy "stop"\norg.apache.cassandra.io.sstable.CorruptSSTableException: Corrupted: /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-4-big\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:111)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:397)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:353)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.lambda$openAll$4(SSTableReader.java:414)\n\tat org.apache.cassandra.concurrent.FutureTask$1.call(FutureTask.java:96)\n\tat org.apache.cassandra.concurrent.FutureTask.call(FutureTask.java:61)\n\tat org.apache.cassandra.concurrent.FutureTask.run(FutureTask.java:71)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: java.lang.IllegalArgumentException: null\n\tat com.google.common.base.Preconditions.checkArgument(Preconditions.java:129)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:79)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:58)\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:92)\n\t... 10 common frames omitted', [node1] 'ERROR [SSTableBatchOpen:4] 2023-10-19 22:25:07,449 DefaultFSErrorHandler.java:129 - Exiting forcefully due to file system exception on startup, disk failure policy "stop"\norg.apache.cassandra.io.sstable.CorruptSSTableException: Corrupted: /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-5-big\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:111)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:397)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:353)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.lambda$openAll$4(SSTableReader.java:414)\n\tat org.apache.cassandra.concurrent.FutureTask$1.call(FutureTask.java:96)\n\tat org.apache.cassandra.concurrent.FutureTask.call(FutureTask.java:61)\n\tat org.apache.cassandra.concurrent.FutureTask.run(FutureTask.java:71)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: java.lang.IllegalArgumentException: null\n\tat com.google.common.base.Preconditions.checkArgument(Preconditions.java:129)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:79)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:58)\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:92)\n\t... 10 common frames omitted', [node1] 'ERROR [SSTableBatchOpen:4] 2023-10-19 22:25:07,450 SSTableReader.java:419 - Corrupt sstable /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-5-big=[Index.db, Data.db]; skipping table\norg.apache.cassandra.io.sstable.CorruptSSTableException: Corrupted: /tmp/dtest-ahz16wrh/test/node1/data0/system/prepared_statements-18a9c2576a0c3841ba718cd529849fef/nc-5-big\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:111)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:397)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.open(SSTableReader.java:353)\n\tat org.apache.cassandra.io.sstable.format.SSTableReader.lambda$openAll$4(SSTableReader.java:414)\n\tat org.apache.cassandra.concurrent.FutureTask$1.call(FutureTask.java:96)\n\tat org.apache.cassandra.concurrent.FutureTask.call(FutureTask.java:61)\n\tat org.apache.cassandra.concurrent.FutureTask.run(FutureTask.java:71)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:829)\nCaused by: java.lang.IllegalArgumentException: null\n\tat com.google.common.base.Preconditions.checkArgument(Preconditions.java:129)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:79)\n\tat org.apache.cassandra.io.sstable.format.big.BigSSTableReaderLoadingBuilder.openComponents(BigSSTableReaderLoadingBuilder.java:58)\n\tat org.apache.cassandra.io.sstable.format.SSTableReaderLoadingBuilder.build(SSTableReaderLoadingBuilder.java:92)\n\t... 10 common frames omitted']

Issue Links

• is caused by: CASSANDRA-18747 Test failure: Fix assertion error AssertionError: Unknown keyspace system_auth\n\tat org.apache.cassandra.db.Keyspace.<init>(Keyspace.java:324)\n\tat org.apache.cassandra.db.Keyspace.lambda$open$0(Keyspace.java:162)
• is duplicated by: CASSANDRA-18991 Test failure: sstableutil_test.TestSSTableUtil.test_abortedcompaction
• Testing discovered: CASSANDRA-18991 Test failure: sstableutil_test.TestSSTableUtil.test_abortedcompaction
• links to: 4.0 PR
• links to: 4.1 PR
• links to: 5.0 PR
• links to: trunk PR