[
https://issues.apache.org/jira/browse/CASSANDRA-17609?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17545060#comment-17545060
]
Andres de la Peña commented on CASSANDRA-17609:
-----------------------------------------------
The test can also fail without CDC, also with a pretty low flakiness, as it is
shown by [this repeated
run|https://app.circleci.com/pipelines/github/adelapena/cassandra/1641/workflows/7dd9bb59-3e8f-4889-ab84-bcfe4aca6297].
As a clue, the test passes when running isolated from the rest of the tests on
{{{}CompactionsCQLTest{}}}. This is shown by [this other
run|https://app.circleci.com/pipelines/github/adelapena/cassandra/1637/workflows/287964de-8ab3-4c84-8c03-bdc87fd8858e].
So it seems that the problem is due to the interaction with the other tests.
If we dig into the logs we can find the messages informing about the 50 flushes
requested by the test. Thanks to the changes recently introduced by
CASSANDRA-17034, those flushes have a "reason" property that is included in the
the log message. The reason for the 50 flushes explicitly requested by the test
is {{{}UNIT_TESTS{}}}. However, the logs for the failed runs contain an
additional flush with {{COMMITLOG_DIRTY}} as the reason. Also, those flushes
seem to appear among messages generated by the asynchronous {{CQLTester}} task
that cleans up the data of the previous tests:
{code:java}
...
[junit-timeout] INFO [OptionalTasks:1] 2022-05-30 16:05:45,164
ColumnFamilyStore.java:1010 - Enqueuing flush of cql_test_keyspace.table_07,
Reason: COMMITLOG_DIRTY, Usage: 0.745KiB (0%) on-heap, 400.133KiB (0%) off-heap
[junit-timeout] INFO [OptionalTasks:1] 2022-05-30 16:05:45,165
ColumnFamilyStore.java:1010 - Enqueuing flush of system.local, Reason:
COMMITLOG_DIRTY, Usage: 0.370KiB (0%) on-heap, 0.289KiB (0%) off-heap
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,166
LogTransaction.java:242 - Unfinished transaction log, deleting
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-Data.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,166
SSTable.java:127 - Deleting sstable:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,166
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-Index.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,166
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-CompressionInfo.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,166
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-Statistics.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,167
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-Digest.crc32
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,167
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-Filter.db
[junit-timeout] INFO [PerDiskMemtableFlushWriter_0:1] 2022-05-30 16:05:45,167
Flushing.java:145 - Writing Memtable-sstable_activity@215544135(0.422KiB
serialized bytes, 54 ops, 13.236KiB (0%) on-heap, 2.008KiB (0%) off-heap),
flushed range = [null, null)
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,167
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-TOC.txt
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,167
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-29-big-Summary.db
[junit-timeout] INFO [PerDiskMemtableFlushWriter_0:2] 2022-05-30 16:05:45,174
Flushing.java:145 - Writing Memtable-sstable_activity_v2@1687505407(0.422KiB
serialized bytes, 54 ops, 13.236KiB (0%) on-heap, 1.875KiB (0%) off-heap),
flushed range = [null, null)
[junit-timeout] INFO [PerDiskMemtableFlushWriter_0:2] 2022-05-30 16:05:45,175
Flushing.java:171 - Completed flushing
/tmp/cassandra/build/test/cassandra/data/system/sstable_activity_v2-62efe31f3be8310c8d298963439c1288/nb-8-big-Data.db
(2.455KiB) for commitlog position CommitLogPosition(segmentId=1653926717793,
position=102496)
[junit-timeout] INFO [PerDiskMemtableFlushWriter_0:1] 2022-05-30 16:05:45,175
Flushing.java:171 - Completed flushing
/tmp/cassandra/build/test/cassandra/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/nb-8-big-Data.db
(2.588KiB) for commitlog position CommitLogPosition(segmentId=1653926717793,
position=102496)
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
LogTransaction.java:242 - Unfinished transaction log, deleting
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-Data.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
SSTable.java:127 - Deleting sstable:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-Index.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-CompressionInfo.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-Statistics.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-Digest.crc32
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-Filter.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-TOC.txt
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,176
PathUtils.java:74 - Deleting file during startup:
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb-32-big-Summary.db
[junit-timeout] INFO [NonPeriodicTasks:1] 2022-05-30 16:05:45,177
LogTransaction.java:242 - Unfinished transaction log, deleting
/tmp/cassandra/build/test/cassandra/data/system_schema/tables-afddfb9dbc1e30688056eed6c302ba09/nb_txn_compaction_5ccb3290-e032-11ec-8dd1-458238a818cd.log
[junit-timeout] INFO [main] 2022-05-30 16:05:45,177
ColumnFamilyStore.java:1010 - Enqueuing flush of cql_test_keyspace.table_07,
Reason: UNIT_TESTS, Usage: 0.870KiB (0%) on-heap, 500.164KiB (0%) off-heap
...
{code}
So it seems that the problem is that the failing test is finding more flushes
than expected due to the dirty commitlog that is left by the previous tests,
particularly those playing with intentionally corrupted data.
The proposed [PR|https://github.com/apache/cassandra/pull/1657] just manually
resets the commitlog at the beginning of the tests to get rid of any remains
left by previous tests. This approach passes the repeated runs for
[j8|https://app.circleci.com/pipelines/github/adelapena/cassandra/1656/workflows/f911bcd3-2ce9-4778-81ae-650f964253c4]
and
[j11|https://app.circleci.com/pipelines/github/adelapena/cassandra/1656/workflows/c7d673c3-aed6-4a21-8cb6-ba867d319d0d].
> Fix
> org.apache.cassandra.db.compaction.CompactionsCQLTest.testLCSThresholdParams-cdc
> (from org.apache.cassandra.db.compaction.CompactionsCQLTest-cdc)
> -----------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: CASSANDRA-17609
> URL: https://issues.apache.org/jira/browse/CASSANDRA-17609
> Project: Cassandra
> Issue Type: Bug
> Components: CI
> Reporter: Ekaterina Dimitrova
> Assignee: Andres de la Peña
> Priority: Normal
> Fix For: 4.1-beta
>
>
> {color:#172b4d}[https://ci-cassandra.apache.org/job/Cassandra-4.1/5/testReport/org.apache.cassandra.db.compaction/CompactionsCQLTest/testLCSThresholdParams_cdc_2/]{color}
> h3.
> {code:java}
> Error Message
> expected:<50> but was:<51>
> Stacktrace
> junit.framework.AssertionFailedError: expected:<50> but was:<51> at
> org.apache.cassandra.db.compaction.CompactionsCQLTest.testLCSThresholdParams(CompactionsCQLTest.java:419)
> at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method) at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> {code}
>
--
This message was sent by Atlassian Jira
(v8.20.7#820007)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
