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

Fix random NOT_REACHED in TestLogStreamProcessorChronicle

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.3-SNAPSHOT
    • Fix Version/s: QualifiedToSchedule
    • Component/s: Streams, Tests

      Description

      Failed
      
      org.nuxeo.lib.stream.tests.computation.TestLogStreamProcessorChronicle.testComplexTopoManyRecordsOneThreadManyPartitions (from org.nuxeo.lib.stream.tests.computation.TestLogStreamProcessorKafkaNoSubscribe)
      Failing for the past 1 build (Since Failed#169 )
      Took 0.42 sec.
      add description
      	This test was not claimed. Claim it.
      Error Message
      
      NOT_REACHED index: 45c800000000
      
      Stacktrace
      
      java.lang.IllegalStateException: NOT_REACHED index: 45c800000000
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.originalToEnd(SingleChronicleQueueExcerpts.java:1640)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreTailer.toEnd(SingleChronicleQueueExcerpts.java:1546)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogOffsetTracker.readLastCommittedOffset(ChronicleLogOffsetTracker.java:123)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogOffsetTracker.getLastCommittedOffset(ChronicleLogOffsetTracker.java:109)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogTailer.toLastCommitted(ChronicleLogTailer.java:170)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogTailer.<init>(ChronicleLogTailer.java:82)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.createTailer(ChronicleLogAppender.java:309)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogManager.lambda$doCreateTailer$3(ChronicleLogManager.java:215)
      	at java.util.ArrayList.forEach(ArrayList.java:1257)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogManager.doCreateTailer(ChronicleLogManager.java:214)
      	at org.nuxeo.lib.stream.log.internals.AbstractLogManager.createTailer(AbstractLogManager.java:96)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.<init>(ComputationRunner.java:123)
      	at org.nuxeo.lib.stream.computation.log.ComputationPool.lambda$start$0(ComputationPool.java:100)
      	at java.util.ArrayList.forEach(ArrayList.java:1257)
      	at org.nuxeo.lib.stream.computation.log.ComputationPool.start(ComputationPool.java:99)
      	at java.util.ArrayList.forEach(ArrayList.java:1257)
      	at org.nuxeo.lib.stream.computation.log.LogStreamProcessor.start(LogStreamProcessor.java:82)
      	at org.nuxeo.lib.stream.tests.computation.TestStreamProcessor.testComplexTopo(TestStreamProcessor.java:237)
      	at org.nuxeo.lib.stream.tests.computation.TestStreamProcessor.testComplexTopoManyRecordsOneThreadManyPartitions(TestStreamProcessor.java:294)
      
      Standard Output
      
      16:36:39,990 [main] WARN  [ChronicleLogOffsetTracker] Fail to reach the end of offset queue: /tmp/junit638963215960687963/junit1857121424939507697/s1/offset-C2 because of: NOT_REACHED index: 45c800000000, retrying.
      16:36:40,000 [C1Pool-03,in:8,inCheckpoint:7,out:7,lastRead:1543509399999,lastTimer:0,wm:202310864021356545,loop:8,record] ERROR [ComputationRunner] C1: CHECKPOINT FAILURE: Resume may create duplicates.
      16:36:40,000 [C1Pool-03,in:8,inCheckpoint:7,out:7,lastRead:1543509399999,lastTimer:0,wm:202310864021356545,loop:8,record] ERROR [ComputationRunner] C1: Exception in processLoop: Index: 3, Size: 0
      java.lang.IndexOutOfBoundsException: Index: 3, Size: 0
      	at java.util.ArrayList.rangeCheck(ArrayList.java:657) ~[?:1.8.0_191]
      	at java.util.ArrayList.get(ArrayList.java:433) ~[?:1.8.0_191]
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:292) ~[classes/:?]
      	at org.nuxeo.lib.stream.log.LogAppender.append(LogAppender.java:62) ~[classes/:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.sendRecords(ComputationRunner.java:399) ~[classes/:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpoint(ComputationRunner.java:365) ~[classes/:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpointIfNecessary(ComputationRunner.java:354) ~[classes/:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:302) ~[classes/:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199) ~[classes/:?]
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158) [classes/:?]
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_191]
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_191]
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_191]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_191]
      	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
      16:36:40,001 [C1Pool-02,in:8,inCheckpoint:7,out:7,lastRead:1543509399999,lastTimer:0,wm:202310864020570113,loop:8,record] ERROR [ComputationRunner] C1: CHECKPOINT FAILURE: Resume may create duplicates.
      16:36:40,007 [C1Pool-02,in:8,inCheckpoint:7,out:7,lastRead:1543509399999,lastTimer:0,wm:202310864020570113,loop:8,record] ERROR [ComputationRunner] C1: Exception in processLoop: Index: 2, Size: 0 
      ...  many times
      16:36:40,009 [C3Pool-02,in:2,inCheckpoint:1,out:1,lastRead:1543509399982,lastTimer:0,wm:202310864019521537,loop:1,record] ERROR [ComputationRunner] C3: Exception in processLoop: null
      java.lang.NullPointerException: null
      	at net.openhft.chronicle.bytes.ref.BinaryLongReference.addValue(BinaryLongReference.java:93) ~[chronicle-bytes-2.17.3.jar:?]
      	at net.openhft.chronicle.bytes.ref.BinaryLongReference.addAtomicValue(BinaryLongReference.java:98) ~[chronicle-bytes-2.17.3.jar:?]
      	at net.openhft.chronicle.queue.impl.single.TableDirectoryListing.onFileCreated(TableDirectoryListing.java:69) ~[chronicle-queue-5.17.0.jar:?]
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue$StoreSupplier.acquire(SingleChronicleQueue.java:805) ~[chronicle-queue-5.17.0.jar:?]
      	at net.openhft.chronicle.queue.impl.WireStorePool.acquire(WireStorePool.java:98) ~[chronicle-queue-5.17.0.jar:?]
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setCycle2(SingleChronicleQueueExcerpts.java:289) ~[chronicle-queue-5.17.0.jar:?]
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setWireIfNull(SingleChronicleQueueExcerpts.java:375) ~[chronicle-queue-5.17.0.jar:?]
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:359) ~[chronicle-queue-5.17.0.jar:?]
      	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95) ~[chronicle-wire-2.17.5.jar:?]
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:297) ~[classes/:?]
      	at org.nuxeo.lib.stream.log.LogAppender.append(LogAppender.java:62) ~[classes/:?]
      
      

      Standard Error

      net.openhft.chronicle.core.StackTrace: 393bf975-C4Pool-02,in:1,inCheckpoint:0,out:0,lastRead:1543509399844,lastTimer:0,wm:202310864019521536,loop:0,record creation ref-count=1
      	at net.openhft.chronicle.core.ReferenceCounter.newRefCountHistory(ReferenceCounter.java:45)
      	at net.openhft.chronicle.core.ReferenceCounter.<init>(ReferenceCounter.java:35)
      	at net.openhft.chronicle.core.ReferenceCounter.onReleased(ReferenceCounter.java:40)
      	at net.openhft.chronicle.bytes.MappedFile.<init>(MappedFile.java:62)
      	at net.openhft.chronicle.bytes.MappedFile.of(MappedFile.java:177)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue.mappedFile(SingleChronicleQueue.java:706)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue.access$1400(SingleChronicleQueue.java:57)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue$StoreSupplier.lambda$new$0(SingleChronicleQueue.java:760)
      	at net.openhft.chronicle.queue.impl.single.ReferenceCountedCache.get(ReferenceCountedCache.java:38)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue$StoreSupplier.acquire(SingleChronicleQueue.java:787)
      	at net.openhft.chronicle.queue.impl.WireStorePool.acquire(WireStorePool.java:98)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setCycle2(SingleChronicleQueueExcerpts.java:289)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setWireIfNull(SingleChronicleQueueExcerpts.java:375)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:359)
      	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:297)
      	at org.nuxeo.lib.stream.log.LogAppender.append(LogAppender.java:62)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.sendRecords(ComputationRunner.java:399)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpoint(ComputationRunner.java:365)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpointIfNecessary(ComputationRunner.java:354)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:302)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	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)
      net.openhft.chronicle.core.StackTrace: 393bf975-C4Pool-02,in:1,inCheckpoint:0,out:0,lastRead:1543509399844,lastTimer:0,wm:202310864019521536,loop:0,record Reserve ref-count=2
      	at net.openhft.chronicle.core.ReferenceCounter.recordResevation(ReferenceCounter.java:79)
      	at net.openhft.chronicle.core.ReferenceCounter.reserve(ReferenceCounter.java:59)
      	at net.openhft.chronicle.bytes.MappedFile.reserve(MappedFile.java:395)
      	at net.openhft.chronicle.bytes.MappedBytes.reserve(MappedBytes.java:71)
      	at net.openhft.chronicle.bytes.MappedBytes.<init>(MappedBytes.java:63)
      	at net.openhft.chronicle.bytes.MappedBytes.<init>(MappedBytes.java:56)
      	at net.openhft.chronicle.bytes.MappedBytes.mappedBytes(MappedBytes.java:114)
      	at net.openhft.chronicle.queue.impl.single.ReferenceCountedCache.get(ReferenceCountedCache.java:43)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue$StoreSupplier.acquire(SingleChronicleQueue.java:787)
      	at net.openhft.chronicle.queue.impl.WireStorePool.acquire(WireStorePool.java:98)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setCycle2(SingleChronicleQueueExcerpts.java:289)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setWireIfNull(SingleChronicleQueueExcerpts.java:375)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:359)
      	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:297)
      	at org.nuxeo.lib.stream.log.LogAppender.append(LogAppender.java:62)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.sendRecords(ComputationRunner.java:399)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpoint(ComputationRunner.java:365)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpointIfNecessary(ComputationRunner.java:354)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:302)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	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)
      net.openhft.chronicle.core.StackTrace: 393bf975-C4Pool-02,in:1,inCheckpoint:0,out:0,lastRead:1543509399844,lastTimer:0,wm:202310864019521536,loop:0,record Release ref-count=1
      	at net.openhft.chronicle.core.ReferenceCounter.recordRelease(ReferenceCounter.java:101)
      	at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:92)
      	at net.openhft.chronicle.bytes.MappedFile.release(MappedFile.java:400)
      	at net.openhft.chronicle.queue.impl.single.ReferenceCountedCache.get(ReferenceCountedCache.java:46)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueue$StoreSupplier.acquire(SingleChronicleQueue.java:787)
      	at net.openhft.chronicle.queue.impl.WireStorePool.acquire(WireStorePool.java:98)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setCycle2(SingleChronicleQueueExcerpts.java:289)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setWireIfNull(SingleChronicleQueueExcerpts.java:375)
      	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:359)
      	at net.openhft.chronicle.wire.MarshallableOut.writeDocument(MarshallableOut.java:95)
      	at org.nuxeo.lib.stream.log.chronicle.ChronicleLogAppender.append(ChronicleLogAppender.java:297)
      	at org.nuxeo.lib.stream.log.LogAppender.append(LogAppender.java:62)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.sendRecords(ComputationRunner.java:399)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpoint(ComputationRunner.java:365)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.checkpointIfNecessary(ComputationRunner.java:354)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processRecord(ComputationRunner.java:302)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.processLoop(ComputationRunner.java:199)
      	at org.nuxeo.lib.stream.computation.log.ComputationRunner.run(ComputationRunner.java:158)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	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)
      net.openhft.chronicle.core.StackTrace: 393bf975-C4Pool-02,in:1,inCheckpoint:0,out:0,lastRead:1543509399844,lastTimer:0,wm:202310864019521536,loop:0,record Reserve ref-count=2
      	at net.openhft.chronicle.core.ReferenceCounter.recordResevation(ReferenceCounter.java:79)
      	at net.openhft.chronicle.core.ReferenceCounter.reserve(ReferenceCounter.java:59)
      	at net.openhft.chronicle.bytes.MappedFile.reserve(MappedFile.java:395)
      	at net.openhft.chronicle.bytes.MappedBytes.reserve(MappedBytes.java:71)
      

      Seen t&p master:
      https://qa.nuxeo.org/jenkins/job/TestAndPush/job/ondemand-testandpush-fguillaume-2/169/

      2 following tests are failing:

      • org.nuxeo.lib.stream.tests.computation.TestLogStreamProcessorChronicle.testComplexTopoOneRecord
      • org.nuxeo.lib.stream.tests.computation.TestLogStreamProcessorChronicle.testComplexTopoManyRecords

      because of the first error: A tailer for this queue and namespace already exists: C2:s1-02

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 day
                  1d