Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-25830

Fix random SCQIndexing in TestPatternBoundedQueuingChronicle and TestLogStreamProcessorChronicle

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Duplicate
    • Affects Version/s: 10.3-SNAPSHOT
    • Fix Version/s: 11.3
    • Component/s: Streams

      Description

      Seen
      https://qa.nuxeo.org/jenkins/job/master/job/nuxeo-master-fullbuild-part1-multidb/Slave=MULTIDB_LINUX,dbprofile=pgsql,jdk=java-8-openjdk/921

      org.nuxeo.lib.stream.tests.pattern.TestPatternBoundedQueuingChronicle.producersAndConsumersConcurrently
Failing for the past 1 build (Since Unstable#921 )
Took 45 sec.
add description
Error Message

expected:<15000> but was:<1000>

Stacktrace

java.lang.AssertionError: expected:<15000> but was:<1000>
	at org.junit.Assert.fail(Assert.java:88)
	at org.junit.Assert.failNotEquals(Assert.java:834)
	at org.junit.Assert.assertEquals(Assert.java:645)
	at org.junit.Assert.assertEquals(Assert.java:631)
	at org.nuxeo.lib.stream.tests.pattern.TestPatternBoundedQueuing.producersAndConsumersConcurrently(TestPatternBoundedQueuing.java:121)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
Standard Output

05:00:18,815 [Nuxeo-ProducerPool-00] WARN  [AbstractCallablePool] Start Nuxeo-Producer Pool on 15 thread(s).
05:00:18,815 [Nuxeo-ConsumerPool-00] WARN  [AbstractCallablePool] Start Nuxeo-Consumer Pool on 10 thread(s).
05:00:18,833 [Nuxeo-Producer-02-0-Random message 0] ERROR [AbstractCallablePool] Exception catch in runner: null
java.lang.AssertionError
	at net.openhft.chronicle.queue.impl.single.SCQIndexing.sequenceForPosition(SCQIndexing.java:498)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueStore.sequenceForPosition(SingleChronicleQueueStore.java:294)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.checkWritePositionHeaderNumber(SingleChronicleQueueExcerpts.java:410)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.resetPosition(SingleChronicleQueueExcerpts.java:334)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setCycle2(SingleChronicleQueueExcerpts.java:292)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setWireIfNull(SingleChronicleQueueExcerpts.java:369)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:353)
	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:295)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.producerLoop(ProducerRunner.java:94)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:79)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:44)
	at org.nuxeo.lib.stream.pattern.consumer.internals.AbstractCallablePool.lambda$runPool$1(AbstractCallablePool.java:99)
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
05:00:23,946 [Nuxeo-ConsumerPool-00] WARN  [ConsumerPool] Consumers status: threads: 10, failure 0, messages committed: 145, elapsed: 5.12s, throughput: 28.34 msg/s
05:00:34,136 [Nuxeo-Producer-05-9-Random message 9] WARN  [Slf4jExceptionHandler$2] Couldn't acquire write lock after 15000ms for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t, overriding the lock. Lock was held by PID 4684
05:00:34,137 [Nuxeo-Producer-04-5-Random message 5] WARN  [Slf4jExceptionHandler$2] Couldn't acquire write lock after 15000ms for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t, overriding the lock. Lock was held by PID 4684
05:00:34,137 [Nuxeo-Producer-04-5-Random message 5] WARN  [Slf4jExceptionHandler$2] Forced unlock for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t
java.lang.Exception
	at net.openhft.chronicle.queue.impl.table.AbstractTSQueueLock.forceUnlock(AbstractTSQueueLock.java:55)
	at net.openhft.chronicle.queue.impl.single.TableStoreWriteLock.lock(TableStoreWriteLock.java:57)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:348)
	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:295)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.producerLoop(ProducerRunner.java:94)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:79)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:44)
	at org.nuxeo.lib.stream.pattern.consumer.internals.AbstractCallablePool.lambda$runPool$1(AbstractCallablePool.java:99)
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
05:00:34,137 [Nuxeo-Producer-13-8-Random message 8] WARN  [Slf4jExceptionHandler$2] Couldn't acquire write lock after 15000ms for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t, overriding the lock. Lock was held by PID 4684
05:00:34,136 [Nuxeo-Producer-12-6-Random message 6] WARN  [Slf4jExceptionHandler$2] Couldn't acquire write lock after 15000ms for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t, overriding the lock. Lock was held by PID 4684
05:00:34,136 [Nuxeo-Producer-08-17-Random message 17] WARN  [Slf4jExceptionHandler$2] Couldn't acquire write lock after 15000ms for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t, overriding the lock. Lock was held by PID 4684
05:00:34,136 [Nuxeo-Producer-09-12-Random message 12] WARN  [Slf4jExceptionHandler$2] Couldn't acquire write lock after 15000ms for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t, overriding the lock. Lock was held by PID 4684
05:00:34,139 [Nuxeo-Producer-09-12-Random message 12] WARN  [Slf4jExceptionHandler$2] Forced unlock for the lock file:/tmp/junit3446738101135102557/junit2087494618816117982/logName/P-01/metadata.cq4t
java.lang.Exception
	at net.openhft.chronicle.queue.impl.table.AbstractTSQueueLock.forceUnlock(AbstractTSQueueLock.java:55)
	at net.openhft.chronicle.queue.impl.single.TableStoreWriteLock.lock(TableStoreWriteLock.java:57)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:348)
	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:295)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.producerLoop(ProducerRunner.java:94)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:79)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:44)
	at org.nuxeo.lib.stream.pattern.consumer.internals.AbstractCallablePool.lambda$runPool$1(AbstractCallablePool.java:99)
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Standard Error

java.lang.AssertionError: ~~~~~~~~~~~~~~ thread: Nuxeo-Producer-03-34-Random message 34 pos: 132608 header: 76441827934222 seq1: 14 seq2: 15
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.checkWritePositionHeaderNumber(SingleChronicleQueueExcerpts.java:421)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:349)
	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:295)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.producerLoop(ProducerRunner.java:94)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:79)
	at org.nuxeo.lib.stream.pattern.producer.internals.ProducerRunner.call(ProducerRunner.java:44)
	at org.nuxeo.lib.stream.pattern.consumer.internals.AbstractCallablePool.lambda$runPool$1(AbstractCallablePool.java:99)
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1590)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

        Attachments

          Issue Links

          duplicates

          Bug - A problem which impairs or prevents the functions of the product. NXP-27559 Chronicle-Queue unit tests randomly failing in Jenkins X

          • Minor - Minor loss of function, or other problem where easy workaround is present.
          • Resolved
          is related to

          Task - A task that needs to be done. NXP-30444 Fix Nuxeo 10.10 build

          • Major - Major loss of function.
          • Resolved

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                bdelbosc Benoit Delbosc
                Participants:
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: