You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Jon Meredith (Jira)" <ji...@apache.org> on 2020/05/07 16:09:00 UTC
[jira] [Created] (CASSANDRA-15797) Fix flaky BinLogTest -
org.apache.cassandra.utils.binlog.BinLogTest
Jon Meredith created CASSANDRA-15797:
----------------------------------------
Summary: Fix flaky BinLogTest - org.apache.cassandra.utils.binlog.BinLogTest
Key: CASSANDRA-15797
URL: https://issues.apache.org/jira/browse/CASSANDRA-15797
Project: Cassandra
Issue Type: Bug
Reporter: Jon Meredith
An internal CI system is failing BinLogTest somewhat frequently under JDK11. Configuration was recently changed to reduce the number of cores the tests run with, however it is reproducible on an 8 core laptop.
{code}
[junit-timeout] OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
[junit-timeout] Testsuite: org.apache.cassandra.utils.binlog.BinLogTest
[Junit-timeout] WARNING: An illegal reflective access operation has occurred
[junit-timeout] WARNING: Illegal reflective access by net.openhft.chronicle.core.Jvm (file:/.../lib/chronicle-core-1.16.4.jar) to field java.nio.Bits.RESERVED_MEMORY
[junit-timeout] WARNING: Please consider reporting this to the maintainers of net.openhft.chronicle.core.Jvm
[junit-timeout] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
[junit-timeout] WARNING: All illegal access operations will be denied in a future release
[junit-timeout] Testsuite: org.apache.cassandra.utils.binlog.BinLogTest Tests run: 13, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 13.895 sec
[junit-timeout]
[junit-timeout] Testcase: testPutAfterStop(org.apache.cassandra.utils.binlog.BinLogTest): FAILED
[junit-timeout] expected:<null> but was:<or...@5ed190be>
[junit-timeout] junit.framework.AssertionFailedError: expected:<null> but was:<or...@5ed190be>
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.testPutAfterStop(BinLogTest.java:431)
[junit-timeout] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit-timeout] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit-timeout] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit-timeout]
[junit-timeout]
[junit-timeout] Test org.apache.cassandra.utils.binlog.BinLogTest FAILED
{code}
There's also a different failure under JDK8
{code}
junit-timeout] Testsuite: org.apache.cassandra.utils.binlog.BinLogTest
[junit-timeout] Testsuite: org.apache.cassandra.utils.binlog.BinLogTest Tests run: 13, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 15.273 sec
[junit-timeout]
[junit-timeout] Testcase: testBinLogStartStop(org.apache.cassandra.utils.binlog.BinLogTest): FAILED
[junit-timeout] expected:<2> but was:<0>
[junit-timeout] junit.framework.AssertionFailedError: expected:<2> but was:<0>
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.testBinLogStartStop(BinLogTest.java:172)
[junit-timeout]
[junit-timeout]
[junit-timeout] Test org.apache.cassandra.utils.binlog.BinLogTest FAILED
{code}
Reproducer
{code}
PASSED=0; time { while ant testclasslist -Dtest.classlistprefix=unit -Dtest.classlistfile=<(echo org/apache/cassandra/utils/binlog/BinLogTest.java); do PASSED=$((PASSED+1)); echo PASSED $PASSED; done }; echo FAILED after $PASSED runs.
{code}
In the last four attempts it has taken 31, 38, 27 and 10 rounds respectively under JDK11 and took 51 under JDK8 (about 15 minutes).
I have not tried running in a cpu-limited container or anything like that yet.
Additionally, this went past in the logs a few times (under JDK11). No idea if it's just an artifact of weird test setup, or something more serious.
{code}
[junit-timeout] WARNING: Please consider reporting this to the maintainers of net.openhft.chronicle.core.Jvm
[junit-timeout] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
[junit-timeout] WARNING: All illegal access operations will be denied in a future release
[junit-timeout] Testsuite: org.apache.cassandra.utils.binlog.BinLogTest Tests run: 13, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 12.839 sec
[junit-timeout]
[junit-timeout] java.lang.Throwable: 1e53135d-main creation ref-count=1
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.newRefCountHistory(ReferenceCounter.java:45)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.<init>(ReferenceCounter.java:35)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.onReleased(ReferenceCounter.java:40)
[junit-timeout] at net.openhft.chronicle.bytes.AbstractBytes.<init>(AbstractBytes.java:38)
[junit-timeout] at net.openhft.chronicle.bytes.MappedBytes.<init>(MappedBytes.java:59)
[junit-timeout] at net.openhft.chronicle.bytes.MappedBytes.<init>(MappedBytes.java:55)
[junit-timeout] at net.openhft.chronicle.bytes.MappedBytes.mappedBytes(MappedBytes.java:113)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueStore.bytes(SingleChronicleQueueStore.java:358)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.resetWires(SingleChronicleQueueExcerpts.java:1702)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.cycle(SingleChronicleQueueExcerpts.java:1907)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.toStart(SingleChronicleQueueExcerpts.java:1614)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue.createTailer(SingleChronicleQueue.java:401)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.readBinLogRecords(BinLogTest.java:495)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.testCleanupOnOversize(BinLogTest.java:407)
...
[junit-timeout] java.lang.Throwable: 1e53135d-main Reserve ref-count=2
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.recordResevation(ReferenceCounter.java:66)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.reserve(ReferenceCounter.java:59)
[junit-timeout] at net.openhft.chronicle.bytes.AbstractBytes.reserve(AbstractBytes.java:464)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounted.tryReserve(ReferenceCounted.java:81)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueStore.writeEOF(SingleChronicleQueueStore.java:461)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.checkMoveToNextCycle(SingleChronicleQueueExcerpts.java:1437)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.inACycleNone(SingleChronicleQueueExcerpts.java:1416)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.inACycle(SingleChronicleQueueExcerpts.java:1356)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.readingDocument(SingleChronicleQueueExcerpts.java:1168)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.readDocument(SingleChronicleQueueExcerpts.java:1096)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.readBinLogRecords(BinLogTest.java:498)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.testCleanupOnOversize(BinLogTest.java:407)
...
[junit-timeout] java.lang.Throwable: 1e53135d-main Release ref-count=1
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.recordRelease(ReferenceCounter.java:88)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:79)
[junit-timeout] at net.openhft.chronicle.bytes.AbstractBytes.release(AbstractBytes.java:469)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueStore.writeEOF(SingleChronicleQueueStore.java:463)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.checkMoveToNextCycle(SingleChronicleQueueExcerpts.java:1437)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.inACycleNone(SingleChronicleQueueExcerpts.java:1416)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.inACycle(SingleChronicleQueueExcerpts.java:1356)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.readingDocument(SingleChronicleQueueExcerpts.java:1168)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.readDocument(SingleChronicleQueueExcerpts.java:1096)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.readBinLogRecords(BinLogTest.java:498)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.testCleanupOnOversize(BinLogTest.java:407)
...
[junit-timeout] java.lang.Throwable: 1e53135d-main Release ref-count=0
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.recordRelease(ReferenceCounter.java:88)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:79)
[junit-timeout] at net.openhft.chronicle.bytes.AbstractBytes.release(AbstractBytes.java:469)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.close(SingleChronicleQueueExcerpts.java:1117)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue.lambda$close$4(SingleChronicleQueue.java:537)
[junit-timeout] at java.base/java.util.WeakHashMap.forEach(WeakHashMap.java:1026)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue.close(SingleChronicleQueue.java:537)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.readBinLogRecords(BinLogTest.java:506)
[junit-timeout] at org.apache.cassandra.utils.binlog.BinLogTest.testCleanupOnOversize(BinLogTest.java:407)
...
[junit-timeout] java.lang.Throwable: 1e53135d-main/queue-thread-local-cleaner-daemon Release ref-count=0
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.recordRelease(ReferenceCounter.java:88)
[junit-timeout] at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:74)
[junit-timeout] at net.openhft.chronicle.bytes.AbstractBytes.release(AbstractBytes.java:469)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.StoreComponentReferenceHandler.processWireQueue(StoreComponentReferenceHandler.java:74)
[junit-timeout] at net.openhft.chronicle.queue.impl.single.StoreComponentReferenceHandler.lambda$static$0(StoreComponentReferenceHandler.java:43)
[junit-timeout] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
[junit-timeout] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[junit-timeout] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit-timeout] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit-timeout] at java.base/java.lang.Thread.run(Thread.java:834)
{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org