Elasticsearch: NPE and error "failed to merge"

Created on 11 Nov 2016  路  20Comments  路  Source: elastic/elasticsearch

Elasticsearch version: 5.0.0

Plugins installed: []

JVM version: Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_102/25.102-b14

OS version: Mac OS X/10.12.1/x86_64

Description of the problem including expected versus actual behavior:

I was bulk importing data into ES in development when the (single) node failed with a NullPointerException (see below).

At the moment, I'm not sure what happened. I try to investigate an update the issue if I find more information.

Restarting the node resolved the issue. No data was lost.

Provide logs (if relevant):

[2016-11-11T16:40:44,084][ERROR][o.e.i.e.InternalEngine$EngineMergeScheduler] [99cr2z0] [store2-v5][0] failed to merge
java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) [lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-11T16:40:44,125][WARN ][o.e.i.e.Engine           ] [99cr2z0] [store2-v5][0] failed engine [merge failed]
org.apache.lucene.index.MergePolicy$MergeException: java.lang.NullPointerException
    at org.elasticsearch.index.engine.InternalEngine$EngineMergeScheduler$2.doRun(InternalEngine.java:1242) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
Caused by: java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-11T16:40:44,138][WARN ][o.e.i.c.IndicesClusterStateService] [99cr2z0] [[store2-v5][0]] marking and sending shard failed due to [shard failure, reason [merge failed]]
org.apache.lucene.index.MergePolicy$MergeException: java.lang.NullPointerException
    at org.elasticsearch.index.engine.InternalEngine$EngineMergeScheduler$2.doRun(InternalEngine.java:1242) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
Caused by: java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-11T16:40:44,141][WARN ][o.e.c.a.s.ShardStateAction] [99cr2z0] [store2-v5][0] received shard failed for shard id [[store2-v5][0]], allocation id [w6E_VGiDSJm4nxHlu6NQfA], primary term [0], message [shard failure, reason [merge failed]], failure [MergeException[java.lang.NullPointerException]; nested: NullPointerException; ]
org.apache.lucene.index.MergePolicy$MergeException: java.lang.NullPointerException
    at org.elasticsearch.index.engine.InternalEngine$EngineMergeScheduler$2.doRun(InternalEngine.java:1242) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
Caused by: java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-11T16:40:44,171][INFO ][o.e.c.r.a.AllocationService] [99cr2z0] Cluster health status changed from [GREEN] to [RED] (reason: [shards failed [[store2-v5][0]] ...]).
[2016-11-11T16:40:49,195][ERROR][o.e.g.TransportNodesListGatewayStartedShards] [99cr2z0] [store2-v5][0] unable to acquire shard lock
org.elasticsearch.env.ShardLockObtainFailedException: [store2-v5][0]: obtaining shard lock timed out after 5000ms
    at org.elasticsearch.env.NodeEnvironment$InternalShardLock.acquire(NodeEnvironment.java:711) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.env.NodeEnvironment.shardLock(NodeEnvironment.java:630) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.store.Store.tryOpenIndex(Store.java:418) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.gateway.TransportNodesListGatewayStartedShards.nodeOperation(TransportNodesListGatewayStartedShards.java:143) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.gateway.TransportNodesListGatewayStartedShards.nodeOperation(TransportNodesListGatewayStartedShards.java:60) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.nodes.TransportNodesAction.nodeOperation(TransportNodesAction.java:144) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.nodes.TransportNodesAction$NodeTransportHandler.messageReceived(TransportNodesAction.java:271) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.nodes.TransportNodesAction$NodeTransportHandler.messageReceived(TransportNodesAction.java:267) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
:CorInfrCore >bug v5.2.0
Source
picture olivere

All 20 comments

I think this is a Lucene bug; there is a missing null check in CompletionFieldsConsumer.java ... I'll open an issue.

It can happen if a given field (that you are building suggestions on) was never indexed into a particular segment.

mikemccand picture mikemccand on 11 Nov 2016

It can happen if a given field (that you are building suggestions on) was never indexed into a particular segment.

Do you think there is a way to work around this temporarily?

nik9000 picture nik9000 on 11 Nov 2016

It can happen if a given field (that you are building suggestions on) was never indexed into a particular segment.

Hmm I'm trying, but failing, so far, to make a Lucene test that reproduces this. @olivere can you describe how you are using the ES completion suggester? Is it enabled for more than one field? Do some documents have those fields but others do not? Do you have deleted documents, and is it possible e.g. that you deleted many documents that had the suggestion fields, leaving only documents that do not?

Do you think there is a way to work around this temporarily?

Alas, I'm not sure yet. If my guesses so far are right, it happens because all documents in one segment are missing the field, so one workaround might be to ensure all documents include the field.

Sorry, I hope to know more once I can reproduce it in Lucene...

mikemccand picture mikemccand on 11 Nov 2016

Hmm... to be honest: I have completion suggesters in my mapping, but not in the documents I was bulk indexing. The bulk indexing process should have been the only process that was running at the time of the exception. The bulk indexer is shuffling data over from one type to another in the same index: No deletions, no updates, just bulk index requests. Is it possible that it's caused by something that ES does in the background?

Unfortunately I don't have access to the mapping right now. But I can send it to you tomorrow if that helps. There's multiple completion suggesters for about 3 different types. We're in the process of updating an ES 1.x mapping to ES 5.x, so I'm not even sure if something's wrong on our side (I'm personally not a pro with suggesters tbh).

olivere picture olivere on 11 Nov 2016

Okay. As promised here's some details about the mapping.

The index has 7 types, 4 of them with one or more fields that use completion suggest. The mapping for those completion fields is defined as e.g.:

...
    "catalog" : {
      "properties" : {
        "catalogNameSuggest" : {
          "type" : "completion",
          "analyzer" : "suggest",
          "preserve_separators" : false,
          "preserve_position_increments" : true,
          "max_input_length" : 50
        },
        "catalogPINSuggest" : {
          "type" : "completion",
          "analyzer" : "suggest",
          "preserve_separators" : false,
          "preserve_position_increments" : true,
          "max_input_length" : 50
        },
        "catalogSlugSuggest" : {
          "type" : "completion",
          "analyzer" : "suggest",
          "preserve_separators" : false,
          "preserve_position_increments" : true,
          "max_input_length" : 50
        },
...

... with the suggest analyzer defined as ...

          "suggest" : {
            "type" : "custom",
            "tokenizer" : "keyword",
            "filter" : [
              "lowercase",
              "asciifolding"
            ]
          },

At the time the exception occured I was scrolling through documents of type product (no suggest fields), modifying and bulk indexing them into type live (again, no suggest fields). Lots of documents were removed from type live about 30s before the exception.

After the restart, there was one error message in the log. Hopefully that is a potential candidate that caused the issue. It was an update to a doc of type catalog which has completion suggest fields--see above):

[2016-11-11T16:47:39,148][INFO ][o.e.n.Node               ] [99cr2z0] started
[2016-11-11T16:47:39,529][INFO ][o.e.g.GatewayService     ] [99cr2z0] recovered [8] indices into cluster_state
[2016-11-11T16:48:39,893][WARN ][r.suppressed             ] path: /store2-v5/catalog/14, params: {index=store2-v5, id=14, type=catalog}
org.elasticsearch.action.UnavailableShardsException: [store2-v5][0] primary shard is not active Timeout: [1m], request: [index {[store2-v5][catalog][14], source[{"catalogId":14,"type":"corporate","merchantId":9,"projectId":1,"projectMPCC":"meplato","slug":"haus-baumarkt-kueche-fuer-mps","catalogSlugSuggest":{"input":"haus-baumarkt-kueche-fuer-mps"},"name":"Haus, Baumarkt, K眉che","catalogNameSuggest":{"input":"Haus, Baumarkt, K眉che"},"pin":"3007ECA973","catalogPINSuggest":{"input":["3007ECA973","Haus, Baumarkt, K眉che"]},"validFrom":"2016-03-13","validUntil":"2016-12-31","lastImported":"2016-03-13T07:55:51Z","lastPublished":"2016-11-11T15:46:46.420019897Z","publishedVersion":9,"country":"DE","language":"de","currency":"EUR","eclassesLevel1":["21","22","23","24","29","41"],"eclassesLevel2":["2104","2254","2311","2315","2431","2909","4101","4102","4108"],"unspscsLevel1":[],"unspscsLevel2":[],"created":"2016-03-13T07:53:59Z","updated":"2016-11-11T15:46:46.420313882Z","lockedForDownload":false,"sageNumber":"","sageContract":"","supportsOciDetail":false,"supportsOciDetailadd":false,"supportsOciValidate":false,"supportsOciSourcing":false,"supportsOciBackgroundsearch":false,"supportsOciQuantitycheck":false,"supportsOciDownloadjson":false,"keepOriginalBlobs":false}]}]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase.retryBecauseUnavailable(TransportReplicationAction.java:811) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase.retryIfUnavailable(TransportReplicationAction.java:651) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase.doRun(TransportReplicationAction.java:604) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$ReroutePhase$2.onTimeout(TransportReplicationAction.java:765) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.cluster.ClusterStateObserver$ContextPreservingListener.onTimeout(ClusterStateObserver.java:350) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.cluster.ClusterStateObserver$ObserverClusterStateListener.onTimeout(ClusterStateObserver.java:240) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.cluster.service.ClusterService$NotifyTimeout.run(ClusterService.java:936) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:444) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-11T16:48:40,265][INFO ][o.e.c.r.a.AllocationService] [99cr2z0] Cluster health status changed from [RED] to [GREEN] (reason: [shards started [[store2-v5][0]] ...]).

I also looked into the log before the exception. There were only a few GC-related messages:

[2016-11-11T16:39:32,592][INFO ][o.e.m.j.JvmGcMonitorService] [99cr2z0] [gc][214306] overhead, spent [401ms] collecting in the last [1s]
[2016-11-11T16:39:41,789][INFO ][o.e.m.j.JvmGcMonitorService] [99cr2z0] [gc][214315] overhead, spent [434ms] collecting in the last [1.1s]

Let me know if I can help somehow.

olivere picture olivere on 12 Nov 2016

Thank you for all the details @olivere ... it could be because there are 7 types, differing in which fields completion suggester is enabled for, that this leads to the issue where segments are missing some fields.

I'm not sure you hit that UnavailableShardsException; it may or may not be related to this NPE.

mikemccand picture mikemccand on 12 Nov 2016

@mikemccand Just FYI: I'm now in the situation where I can restart ES and will always hit the wall with the NPE. Don't know if that's an expected result.

Here's the log after restarting:

[2016-11-14T15:05:23,713][INFO ][o.e.n.Node               ] [] initializing ...
[2016-11-14T15:05:23,843][INFO ][o.e.e.NodeEnvironment    ] [99cr2z0] using [1] data paths, mounts [[/ (/dev/disk1)]], net usable_space [164.2gb], net total_space [930.7gb], spins? [unknown], types [hfs]
[2016-11-14T15:05:23,843][INFO ][o.e.e.NodeEnvironment    ] [99cr2z0] heap size [3.9gb], compressed ordinary object pointers [true]
[2016-11-14T15:05:23,862][INFO ][o.e.n.Node               ] [99cr2z0] node name [99cr2z0] derived from node ID; set [node.name] to override
[2016-11-14T15:05:23,865][INFO ][o.e.n.Node               ] [99cr2z0] version[5.0.0], pid[19274], build[253032b/2016-10-26T04:37:51.531Z], OS[Mac OS X/10.12.1/x86_64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_102/25.102-b14]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [aggs-matrix-stats]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [ingest-common]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [lang-expression]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [lang-groovy]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [lang-mustache]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [lang-painless]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [percolator]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [reindex]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [transport-netty3]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] loaded module [transport-netty4]
[2016-11-14T15:05:24,628][INFO ][o.e.p.PluginsService     ] [99cr2z0] no plugins loaded
[2016-11-14T15:05:26,434][INFO ][o.e.n.Node               ] [99cr2z0] initialized
[2016-11-14T15:05:26,434][INFO ][o.e.n.Node               ] [99cr2z0] starting ...
[2016-11-14T15:05:26,631][INFO ][o.e.t.TransportService   ] [99cr2z0] publish_address {127.0.0.1:9300}, bound_addresses {[fe80::1]:9300}, {[::1]:9300}, {127.0.0.1:9300}
[2016-11-14T15:05:29,682][INFO ][o.e.c.s.ClusterService   ] [99cr2z0] new_master {99cr2z0}{99cr2z0mRj6mvJ5Vvufpwg}{IeZqdK5xQESmw9sC19coeA}{127.0.0.1}{127.0.0.1:9300}, reason: zen-disco-elected-as-master ([0] nodes joined)
[2016-11-14T15:05:29,703][INFO ][o.e.h.HttpServer         ] [99cr2z0] publish_address {127.0.0.1:9200}, bound_addresses {[fe80::1]:9200}, {[::1]:9200}, {127.0.0.1:9200}
[2016-11-14T15:05:29,703][INFO ][o.e.n.Node               ] [99cr2z0] started
[2016-11-14T15:05:30,089][INFO ][o.e.g.GatewayService     ] [99cr2z0] recovered [8] indices into cluster_state

Everything's fine until I do index data by moving from one type to another.

First this happens:

[2016-11-14T15:05:57,820][INFO ][o.e.c.r.a.AllocationService] [99cr2z0] Cluster health status changed from [RED] to [GREEN] (reason: [shards started [[store2-v5][0]] ...]).
[2016-11-14T15:05:58,793][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [7] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [7]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,793][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [4] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [4]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,793][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [8] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [8]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,794][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [9] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [9]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,793][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [3] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [3]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,795][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [10] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [10]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,793][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [5] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [5]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
[2016-11-14T15:05:58,798][DEBUG][o.e.a.s.TransportSearchScrollAction] [99cr2z0] [6] Failed to execute query phase
org.elasticsearch.transport.RemoteTransportException: [99cr2z0][127.0.0.1:9300][indices:data/read/search[phase/query/scroll]]
Caused by: org.elasticsearch.search.SearchContextMissingException: No search context found for id [6]
    at org.elasticsearch.search.SearchService.findContext(SearchService.java:495) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:277) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.search.SearchTransportService.lambda$registerRequestHandler$8(SearchTransportService.java:286) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportRequestHandler.messageReceived(TransportRequestHandler.java:33) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]

Then I'll hit the NPE again:

[2016-11-14T15:06:24,735][ERROR][o.e.i.e.InternalEngine$EngineMergeScheduler] [99cr2z0] [store2-v5][0] failed to merge
java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) [lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-14T15:06:24,745][WARN ][o.e.i.e.Engine           ] [99cr2z0] [store2-v5][0] failed engine [already closed by tragic event on the index writer]
java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-14T15:06:24,747][WARN ][o.e.i.c.IndicesClusterStateService] [99cr2z0] [[store2-v5][0]] marking and sending shard failed due to [shard failure, reason [already closed by tragic event on the index writer]]
java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-14T15:06:24,748][WARN ][o.e.c.a.s.ShardStateAction] [99cr2z0] [store2-v5][0] received shard failed for shard id [[store2-v5][0]], allocation id [w6E_VGiDSJm4nxHlu6NQfA], primary term [0], message [shard failure, reason [already closed by tragic event on the index writer]], failure [NullPointerException[null]]
java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-14T15:06:24,747][DEBUG][o.e.a.b.TransportShardBulkAction] [99cr2z0] [store2-v5][0] failed to execute bulk item (index) index {[store2-v5][live][700107356@39], source[{"id":"700107356@39","merchantId":1,"projectId":1,"catalogId":39,"spn":"700107356","name":"Electronic HP Care Pack 6-Hour Call-To-Repair Proactive Care Service - Servicee","description":"Electronic HP Care Pack 6-Hour Call-To-Repair Proactive Care Service - Serviceerweiterung - Arbeitszeit und Ersatzteile - 3 Jahre - Vor-Ort - 24x7","keywords":["Garantieerweiterungen / Servicepacks / F眉r / Netzwerkprodukte / HP / Electronic / Care / Pack / 6-Hour / Call-To-Repair / Proactive / Service / - / Serviceerweiterung / Arbeitszeit / und / Ersatzteile / 3 / Jahre / Vor-Ort / 24x7"],"categories":null,"eclasses":null,"unspscs":null,"price":1788.39,"meplatoPrice":0,"listPrice":0,"scalePrices":null,"currency":"EUR","country":"DE","priceQty":1,"ou":"EA","cuPerOu":0,"cu":"","leadtime":3,"quantityMin":1,"quantityMax":null,"quantityInterval":1,"taxCode":"0.190000","taxRate":0.19,"conditions":[{"kind":"core_product","text":"Y"}],"gtin":"","asin":"","bpn":"","mpn":"U8N20E","manufacturer":"HP","manufactcode":"","service":false,"image":"http://img.misco.eu/resources/images/products/100/HWP/U8/U8N20E//U8N20E_200x200.jpg","thumbnail":"http://img.misco.eu/resources/images/products/100/HWP/U8/U8N20E//U8N20E_40x40.jpg","datasheet":"","safetysheet":"","blobs":[{"kind":"thumbnail","source":"http://img.misco.eu/resources/images/products/100/HWP/U8/U8N20E//U8N20E_40x40.jpg"},{"kind":"normal","source":"http://img.misco.eu/resources/images/products/100/HWP/U8/U8N20E//U8N20E_200x200.jpg"}],"hazmats":[{"kind":"Gefahrgutklasse","text":"N"},{"kind":"Gefahrstoff","text":"N"}],"matgroup":"","erpGroupSupplier":"","extSchemaType":"","extCategoryId":"","extCategory":"","extProductId":"","custField1":"","custField2":"","custField3":"","custField4":"","custField5":"","custFields":[{"name":"SIEMENS.COUNTRYOFORIGIN","value":"CN"},{"name":"SIEMENS.PREFEREDCOUNTRIES","value":"DE"},{"name":"SIEMENS.NETWEIGHT","value":"0"},{"name":"SIEMENS.WEIGHTUOM","value":"KGM"}],"references":null,"features":null,"availability":null,"messages":null,"tags":null,"excluded":false,"catalogManaged":false,"created":"2016-06-14T13:06:15Z","updated":"2016-06-14T13:06:15Z"}]}
org.elasticsearch.index.engine.IndexFailedEngineException: Index failed for [live#700107356@39]
    at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:417) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:552) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:542) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.index.TransportIndexAction.executeIndexRequestOnPrimary(TransportIndexAction.java:191) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.bulk.TransportShardBulkAction.shardIndexOperation(TransportShardBulkAction.java:351) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.bulk.TransportShardBulkAction.index(TransportShardBulkAction.java:158) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.bulk.TransportShardBulkAction.handleItem(TransportShardBulkAction.java:137) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.bulk.TransportShardBulkAction.onPrimaryShard(TransportShardBulkAction.java:123) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.bulk.TransportShardBulkAction.onPrimaryShard(TransportShardBulkAction.java:74) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportWriteAction.shardOperationOnPrimary(TransportWriteAction.java:78) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportWriteAction.shardOperationOnPrimary(TransportWriteAction.java:50) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryShardReference.perform(TransportReplicationAction.java:902) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryShardReference.perform(TransportReplicationAction.java:872) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.ReplicationOperation.execute(ReplicationOperation.java:113) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.onResponse(TransportReplicationAction.java:319) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.onResponse(TransportReplicationAction.java:254) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$1.onResponse(TransportReplicationAction.java:838) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$1.onResponse(TransportReplicationAction.java:835) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.shard.IndexShardOperationsLock.acquire(IndexShardOperationsLock.java:142) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.shard.IndexShard.acquirePrimaryOperationLock(IndexShard.java:1651) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction.acquirePrimaryShardReference(TransportReplicationAction.java:847) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$AsyncPrimaryAction.doRun(TransportReplicationAction.java:271) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:250) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.replication.TransportReplicationAction$PrimaryOperationTransportHandler.messageReceived(TransportReplicationAction.java:242) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
Caused by: org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
    at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:740) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:754) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1371) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.InternalEngine.update(InternalEngine.java:541) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.engine.InternalEngine.innerIndex(InternalEngine.java:519) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:408) ~[elasticsearch-5.0.0.jar:5.0.0]
    ... 31 more
Caused by: java.lang.NullPointerException
    at org.apache.lucene.search.suggest.document.CompletionFieldsConsumer.write(CompletionFieldsConsumer.java:89) ~[lucene-suggest-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:54]
    at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsWriter.write(PerFieldPostingsFormat.java:198) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.codecs.FieldsConsumer.merge(FieldsConsumer.java:105) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:216) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:101) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4312) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3889) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
    at org.elasticsearch.index.engine.ElasticsearchConcurrentMergeScheduler.doMerge(ElasticsearchConcurrentMergeScheduler.java:99) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626) ~[lucene-core-6.2.0.jar:6.2.0 764d0f19151dbff6f5fcd9fc4b2682cf934590c5 - mike - 2016-08-20 05:39:36]
[2016-11-14T15:06:24,751][INFO ][o.e.c.r.a.AllocationService] [99cr2z0] Cluster health status changed from [GREEN] to [RED] (reason: [shards failed [[store2-v5][0]] ...]).
[2016-11-14T15:06:29,756][ERROR][o.e.g.TransportNodesListGatewayStartedShards] [99cr2z0] [store2-v5][0] unable to acquire shard lock
org.elasticsearch.env.ShardLockObtainFailedException: [store2-v5][0]: obtaining shard lock timed out after 5000ms
    at org.elasticsearch.env.NodeEnvironment$InternalShardLock.acquire(NodeEnvironment.java:711) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.env.NodeEnvironment.shardLock(NodeEnvironment.java:630) ~[elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.index.store.Store.tryOpenIndex(Store.java:418) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.gateway.TransportNodesListGatewayStartedShards.nodeOperation(TransportNodesListGatewayStartedShards.java:143) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.gateway.TransportNodesListGatewayStartedShards.nodeOperation(TransportNodesListGatewayStartedShards.java:60) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.nodes.TransportNodesAction.nodeOperation(TransportNodesAction.java:144) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.nodes.TransportNodesAction$NodeTransportHandler.messageReceived(TransportNodesAction.java:271) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.action.support.nodes.TransportNodesAction$NodeTransportHandler.messageReceived(TransportNodesAction.java:267) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.RequestHandlerRegistry.processMessageReceived(RequestHandlerRegistry.java:69) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.transport.TransportService$6.doRun(TransportService.java:548) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:504) [elasticsearch-5.0.0.jar:5.0.0]
    at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-5.0.0.jar:5.0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_102]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_102]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]

Anything I can do to further assist?

olivere picture olivere on 14 Nov 2016

Hi @olivere, could you possibly zip up one of the shards and post somewhere that I could download from?

mikemccand picture mikemccand on 14 Nov 2016

@mikemccand Aaah, too bad. I was experimenting a bit more and lost the index. :-( I'm confident to maneuver myself into the same situation and promise to create a backup immediately... and let you know.

olivere picture olivere on 14 Nov 2016

Phew, I was finally able to reproduce with a Lucene test: https://issues.apache.org/jira/browse/LUCENE-7562

Thank you @olivere ... I no longer need the shard.

I believe the issue happens when every document containing a given suggestion field has been removed from all segments currently being merged. What's confusing is that the first merge in this situation runs fine, but another merge w/ that segment against other segments that were also created by similar merges (or didn't have this field to begin with) will lead to the NPE. Though I am confused why in your case you were not bulk indexing nor deleting documents that had the suggestion field ...

mikemccand picture mikemccand on 15 Nov 2016

@mikemccand Thank you very much for solving this! :-)

olivere picture olivere on 15 Nov 2016
👍1

@olivere Thank you for uncovering it!

mikemccand picture mikemccand on 16 Nov 2016
🎉1

@mikemccand can we expect a fix for this in 5.0.2?

s1monw picture s1monw on 16 Nov 2016

@mikemccand can we expect a fix for this in 5.0.2?

Well, we need to kick off a Lucene bug fix release (6.2.2, 6.3.1), which I agree we should do soon, but I was planning on waiting a bit more to see what other Lucene bug fixes we should fold in.

I.e. the cases that provoke this bug (deleting whole types that had unique completion fields) seems uncommon and didn't seem severe enough to warrant triggering the Lucene bug fix releases today?

mikemccand picture mikemccand on 16 Nov 2016

Is there any chance to see the fixed Lucene versions in the next 5.x release?

olivere picture olivere on 22 Dec 2016

@olivere I think that is likely; Lucene will probably soon start the 6.4.0 release process, and there are a number of improvements in that release, including this bug fix, that we want to expose for ES's next release. But I can't promise the timing will work out!

mikemccand picture mikemccand on 22 Dec 2016

Hmm... wasn't this fixed in Lucene 6.4.0 (which v5.2.0 is using)? Is it correct this has been relabeled to v5.2.1?

olivere picture olivere on 2 Feb 2017

thanks @olivere - relabelled and closing as fixed by https://github.com/elastic/elasticsearch/pull/22724

clintongormley picture clintongormley on 2 Feb 2017

The Lucene fix was backported to Lucene 5.5.4, so will be in the Elasticsearch 2.4.5 release: https://github.com/elastic/elasticsearch/pull/23162

mikemccand picture mikemccand on 14 Feb 2017

Hi, Is there a workaround for this? We are using AWS ES and they are on ES Version 5.1 and we're not sure when they'll migrate to a fixed version of ES. We are running into this issue, any help would be awesome!

shakdoesgithub picture shakdoesgithub on 15 Apr 2017
Was this page helpful?
0 / 5 - 0 ratings

Related issues

dadoonet picture dadoonet  路  3Comments
clintongormley picture clintongormley  路  3Comments
makeyang picture makeyang  路  3Comments
jpountz picture jpountz  路  3Comments
jasontedor picture jasontedor  路  3Comments