Uploaded image for project: 'Jackrabbit Oak'
  1. Jackrabbit Oak
  2. OAK-10965

indexing job: Sporadic failure at the end of the dump phase

    XMLWordPrintableJSON

Details

    • Improvement
    • Status: Closed
    • Major
    • Resolution: Done
    • None
    • 1.68.0
    • indexing
    • None

    Description

      • The job was running on ARM64 VMs.
      • A retrial succeeded
      • I have never seen this issue until now and this part of the code has not been touched in months.
        This may be a concurrency issue that shows up only on ARM64. The classes that update the metrics are not thread safe and they are accessed by several threads.
      13:37:47.356 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Sort batch task finished. Entries processed: 5772567
      13:37:47.357 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Queue sizes: {"mongoDocQueue":1,"emptyBuffersQueue":0,"nonEmptyBuffersQueue":0,"sortedFilesQueue":0}
      13:37:47.357 [mongo-merge-sort-files] INFO  o.a.j.o.i.i.d.f.p.PipelinedMergeSortTask - Going to sort 4 files, total size 345.29 MiB
      13:37:47.357 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Transform stats: {"documentsTraversed":5103519,"documentsAccepted":5081867,"documentsRejected":21652,"documentsAcceptedPercentage":"99.58","documentsRejectedSplit":0,"documentsRejectedEmptyNodeState":21652,"entriesTraversed":5773276,"entriesAccepted":5772567,"entriesRejected":709,"entriesAcceptedPercentage":"99.99","entriesRejectedHiddenPaths":0,"entriesRejectedPathFiltered":709,"extractedEntriesTotalSize":3223846870,"avgEntrySize":558}
      13:37:47.357 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Top hidden paths rejected: {}
      13:37:47.357 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Top paths filtered: {"/var/linkchecker/https":619, "/var/linkchecker/http":90}
      13:37:47.357 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Top empty node state documents: {"7:/content/dam/collections/public":1103, "8:/content/dam/collections/public":1103, "12:/content/dam/guides_regression/translation":338, "9:/content/dam/fmdita-outputs/pdfs":244, "10:/content/dam/guides_regression/translation":220, "11:/content/dam/guides_regression/translation":169, "9:/content/dam/core-components-examples/library":161, "10:/content/dam/core-components-examples/library":129, "8:/content/dam/core-components-examples/library":106, "10:/content/dam/guides_regression/move_unique":91, "14:/content/dam/guides_regression/translation":90, "9:/content/dam/guides_regression/translation":88, "7:/content/dam/fmdita-outputs/pdfs":85, "8:/content/dam/dita-templates/topics":75, "8:/content/dam/guides_regression/contract-tests-it-copy":74, "9:/content/dam/w2d/Tables-Test":73, "8:/content/dam/fmdita-outputs/pdfs":71, "10:/content/dam/guides_regression/multimedia_report":70, "8:/content/dam/tarini/swfit":56, "10:/content/dam/guides_regression/move-it":56}. Histogram overflowed (max buckets 1000) some buckets may be missing
      13:38:04.866 [mongo-merge-sort-files] INFO  o.a.j.o.i.i.d.f.p.PipelinedMergeSortTask - Final merge completed in 00:00:17. Created file: /tmp/indexing-test11554940811546321273/flat-fs-1482827136747326585/store-sorted.json.lz4
      13:38:04.867 [mongo-merge-sort-files] INFO  indexing-task - [TASK:MONGO-MERGE-SORT-FILES:END] Metrics: {"duration":"00:00:17","durationSeconds":17,"intermediateFilesCount":4,"eagerMergesRuns":0,"filesMerged":4,"ffsSizeBytes":375976021,"ffsSize":"358.56 MiB"}
      13:38:04.868 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Merge-sort sort task finished. FFS: /tmp/indexing-test11554940811546321273/flat-fs-1482827136747326585/store-sorted.json.lz4, Size: 358.56 MiB
      13:38:04.868 [main] INFO  indexing-task - [TASK:PIPELINED-DUMP:END] Metrics: {"duration":"00:04:53","durationSeconds":293,"nodeStateEntriesExtracted":5772567}
      13:38:04.878 [main] INFO  indexing-task - [TASK:PIPELINED-DUMP:FAIL] Metrics: {"duration":"00:04:53","durationSeconds":293}, Error: java.lang.ArrayIndexOutOfBoundsException: Index 24 out of bounds for length 24
      13:38:04.878 [main] WARN  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Error dumping from MongoDB. Cancelling all tasks. Error: java.lang.ArrayIndexOutOfBoundsException: Index 24 out of bounds for length 24
      13:38:04.878 [main] INFO  o.a.j.o.i.i.d.f.p.PipelinedStrategy - Shutting down build FFS thread pool
      13:38:04.879 [main] INFO  indexing-task - [TASK:FULL_INDEX_CREATION:FAIL] Metrics: {"duration":"00:04:53","durationSeconds":293}, Error: java.lang.RuntimeException: java.lang.ArrayIndexOutOfBoundsException: Index 24 out of bounds for length 24
      13:38:04.986 [main] INFO  c.a.granite.indexing.tool.ReindexCmd - Cleared system property oak.indexer.sortedFilePath
      13:38:04.987 [main] ERROR c.adobe.granite.indexing.tool.Main - Can't perform operation
      java.lang.RuntimeException: java.lang.ArrayIndexOutOfBoundsException: Index 24 out of bounds for length 24
      	at org.apache.jackrabbit.oak.index.indexer.document.flatfile.pipelined.PipelinedStrategy.createSortedStoreFile(PipelinedStrategy.java:526)
      	at org.apache.jackrabbit.oak.index.indexer.document.flatfile.FlatFileNodeStoreBuilder.createdSortedStoreFiles(FlatFileNodeStoreBuilder.java:274)
      	at org.apache.jackrabbit.oak.index.indexer.document.flatfile.FlatFileNodeStoreBuilder.build(FlatFileNodeStoreBuilder.java:205)
      	at org.apache.jackrabbit.oak.index.indexer.document.DocumentStoreIndexerBase.buildFlatFileStoreList(DocumentStoreIndexerBase.java:209)
      	at org.apache.jackrabbit.oak.index.indexer.document.DocumentStoreIndexerBase.reindex(DocumentStoreIndexerBase.java:335)
      	at com.adobe.granite.indexing.tool.ReindexCmd.index(ReindexCmd.java:214)
      	at com.adobe.granite.indexing.tool.ReindexCmd.run(ReindexCmd.java:143)
      	at com.adobe.granite.indexing.tool.Main.execute(Main.java:174)
      	at com.adobe.granite.indexing.tool.Main.main(Main.java:77)
      Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 24 out of bounds for length 24
      	at java.base/java.util.stream.SortedOps$SizedRefSortingSink.accept(SortedOps.java:369)
      	at java.base/java.util.TreeMap$EntrySpliterator.forEachRemaining(TreeMap.java:3322)
      	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
      	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
      	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
      	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
      	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682)
      	at org.apache.jackrabbit.oak.plugins.index.ConsoleIndexingReporter.mapToString(ConsoleIndexingReporter.java:111)
      	at org.apache.jackrabbit.oak.plugins.index.ConsoleIndexingReporter.generateReport(ConsoleIndexingReporter.java:95)
      	at org.apache.jackrabbit.oak.index.indexer.document.flatfile.pipelined.PipelinedStrategy.createSortedStoreFile(PipelinedStrategy.java:513)
      	... 8 common frames omitted
      

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              nuno.santos Nuno Santos
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: