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

Lucene MergeException after Elasticsearch 6.3.0 upgrade

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 10.2-SNAPSHOT
    • Fix Version/s: 10.2
    • Component/s: Elasticsearch

      Description

      This pb affect only a specific CI job where elasticsearch is dockerized.
      The nuxeo is created (start from scratch), the mapping updated then on data insertion a merge exception is thrown.
      The health status goes into a green/red loop and end into red.

      The elasticsearch log errors:

      [2018-06-26T10:09:40,454][INFO ][o.e.n.Node               ] [dZQ-7Yb] started
      ...
      [2018-06-26T10:10:23,010][INFO ][o.e.c.r.a.AllocationService] [dZQ-7Yb] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[nuxeo][0]] ...]).
      [2018-06-26T10:10:23,028][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] create_mapping [doc]
      [2018-06-26T10:10:29,787][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [audit/Acbn7DFuR22FW-6YwlXr5A] update_mapping [entry]
      [2018-06-26T10:10:30,458][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [audit/Acbn7DFuR22FW-6YwlXr5A] update_mapping [entry]
      [2018-06-26T10:10:30,687][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:30,833][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:30,944][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,018][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,191][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,240][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,294][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,355][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,423][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,488][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,534][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,592][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,664][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,740][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,846][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:31,964][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:32,081][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:10:48,324][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [audit/Acbn7DFuR22FW-6YwlXr5A] update_mapping [entry]
      [2018-06-26T10:12:34,055][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:12:35,009][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:12:36,417][INFO ][o.e.c.m.MetaDataMappingService] [dZQ-7Yb] [nuxeo/6eYqvs-BS0K4X01NkwrVRQ] update_mapping [doc]
      [2018-06-26T10:12:59,907][WARN ][o.e.i.e.Engine           ] [dZQ-7Yb] [nuxeo][0] failed engine [merge failed]
      org.apache.lucene.index.MergePolicy$MergeException: java.lang.IllegalStateException: found existing value for PerFieldPostingsFormat.format, field=note:note.fulltext, old=Lucene50, new=Lucene50
              at org.elasticsearch.index.engine.InternalEngine$EngineMergeScheduler$2.doRun(InternalEngine.java:2113) [elasticsearch-6.3.0.jar:6.3.0]
              at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:724) [elasticsearch-6.3.0.jar:6.3.0]
              at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-6.3.0.jar:6.3.0]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135) [?:?]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
              at java.lang.Thread.run(Thread.java:844) [?:?]
      Caused by: java.lang.IllegalStateException: found existing value for PerFieldPostingsFormat.format, field=note:note.fulltext, old=Lucene50, new=Lucene50
              at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.buildFieldsGroupMapping(PerFieldPostingsFormat.java:226) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.merge(PerFieldPostingsFormat.java:152) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:230) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:115) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4443) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4083) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:624) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-6.3.0.jar:6.3.0]
              at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:661) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
      [2018-06-26T10:12:59,913][WARN ][o.e.i.c.IndicesClusterStateService] [dZQ-7Yb] [[nuxeo][0]] marking and sending shard failed due to [shard failure, reason [merge failed]]
      ...
      [2018-06-26T10:14:55,500][INFO ][o.e.c.r.a.AllocationService] [dZQ-7Yb] Cluster health status changed from [GREEN] to [RED] (reason: [shards failed [[nuxeo][0]] ...]).
      [2018-06-26T10:14:56,382][INFO ][o.e.c.r.a.AllocationService] [dZQ-7Yb] Cluster health status changed from [RED] to [GREEN] (reason: [shards started [[nuxeo][0]] ...]).
      ...
      [2018-06-26T10:14:59,982][WARN ][o.e.c.r.a.AllocationService] [dZQ-7Yb] failing shard [failed shard, shard [nuxeo][0], node[dZQ-7YbFStObu58MmB7ZVg], [P], s[STARTED], a[id=aSxsxcyjQamMf4u5oht_hA], message [shard failure, reason [already closed by tragic event on the index writer]], failure [IllegalStateException[found existing value for PerFieldPostingsFormat.format, field=collection:documentIds, old=Lucene50, new=Lucene50]], markAsStale [true]]
      java.lang.IllegalStateException: found existing value for PerFieldPostingsFormat.format, field=collection:documentIds, old=Lucene50, new=Lucene50
              at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.buildFieldsGroupMapping(PerFieldPostingsFormat.java:226) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.merge(PerFieldPostingsFormat.java:152) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:230) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:115) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4443) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4083) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:624) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
              at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-6.3.0.jar:6.3.0]
              at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:661) ~[lucene-core-7.3.1.jar:7.3.1 ae0705edb59eaa567fe13ed3a222fdadc7153680 - caomanhdat - 2018-05-09 09:27:24]
      [2018-06-26T10:14:59,982][INFO ][o.e.c.r.a.AllocationService] [dZQ-7Yb] Cluster health status changed from [GREEN] to [RED] (reason: [shards failed [[nuxeo][0]] ...]).
      
      

      3 fields are reported in error:

      • collection:documentIds
      • dc:description.fulltext
      • note:note.fulltext

      They have the following mapping:

                "collection:documentIds" : {
                  "type" : "keyword",
                  "copy_to" : [
                    "all_field"
                  ],
                  "ignore_above" : 256
                },
      
                "dc:description" : {
                  "type" : "keyword",
                  "fields" : {
                    "fulltext" : {
                      "type" : "text",
                      "boost" : 1.5,
                      "analyzer" : "fulltext"
                    }
                  },
                  "copy_to" : [
                    "all_field"
                  ],
                  "ignore_above" : 32765
                },
      
                "note:note" : {
                  "type" : "keyword",
                  "fields" : {
                    "fulltext" : {
                      "type" : "text",
                      "analyzer" : "fulltext"
                    }
                  },
                  "copy_to" : [
                    "all_field"
                  ],
                  "ignore_above" : 256
                },
      

      Drop and reindex do work, still the document injection raise the pb again.

        Attachments

          Issue Links

            Activity

              People

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

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

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