AIOOBE when using docvalue_fields on a ip_range field

[ddolcimascolo]

Elasticsearch version (bin/elasticsearch --version): 7.9.3

Plugins installed: []

JVM version (java -version): Bundled JDK (JDK 11)

OS version (uname -a if on a Unix-like system): Ubuntu 18.04

Description of the problem including expected versus actual behavior:

Elasticsearch throws an AIOOBE when using docvalue_fields on a ip_range field. Maybe that's unsupported but it should not blow up with a HTTP 500 error code. Is it actually supported ?

Steps to reproduce:

This Kibana script can be run in Dev Tools to reproduce

PUT /ip_range_doc_values
{
  "mappings": {
    "properties": {
      "network": {
        "type": "ip_range"
      }
    }
  }
}

PUT /ip_range_doc_values/_bulk
{ "index": {} }
{ "network": "10.0.0.0/8" }
{ "index": {} }
{ "network": "1.2.3.4/32" }
{ "index": {} }
{ "network": "172.16.0.0/12" }

POST /ip_range_doc_values/_search
{
  "docvalue_fields": [
    "network"
  ]
}

Provide logs (if relevant):

[2021-06-15T10:20:22,407][WARN ][r.suppressed             ] [es-001.stordata.dev] path: /ip_range_doc_values/_search, params: {pretty=true, index=ip_range_doc_values}
org.elasticsearch.action.search.SearchPhaseExecutionException: all shards failed
        at org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseFailure(AbstractSearchAsyncAction.java:551) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:309) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseDone(AbstractSearchAsyncAction.java:582) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.AbstractSearchAsyncAction.onShardFailure(AbstractSearchAsyncAction.java:393) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.AbstractSearchAsyncAction.access$100(AbstractSearchAsyncAction.java:68) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.AbstractSearchAsyncAction$1.onFailure(AbstractSearchAsyncAction.java:245) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.SearchExecutionStatsCollector.onFailure(SearchExecutionStatsCollector.java:73) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.ActionListenerResponseHandler.handleException(ActionListenerResponseHandler.java:59) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.SearchTransportService$ConnectionCountingHandler.handleException(SearchTransportService.java:403) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.TransportService$6.handleException(TransportService.java:638) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.handleException(TransportService.java:1172) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundHandler.lambda$handleException$2(InboundHandler.java:235) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.common.util.concurrent.EsExecutors$DirectExecutorService.execute(EsExecutors.java:226) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundHandler.handleException(InboundHandler.java:233) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundHandler.handlerResponseError(InboundHandler.java:225) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundHandler.messageReceived(InboundHandler.java:115) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundHandler.inboundMessage(InboundHandler.java:78) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.TcpTransport.inboundMessage(TcpTransport.java:692) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundPipeline.forwardFragments(InboundPipeline.java:142) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundPipeline.doHandleBytes(InboundPipeline.java:117) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.InboundPipeline.handleBytes(InboundPipeline.java:82) [elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.transport.netty4.Netty4MessageChannelHandler.channelRead(Netty4MessageChannelHandler.java:76) [transport-netty4-client-7.9.3.jar:7.9.3]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:271) [netty-handler-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:615) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:578) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.49.Final.jar:4.1.49.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.49.Final.jar:4.1.49.Final]
        at java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: org.elasticsearch.ElasticsearchException$1: Index 99 out of bounds for length 99
        at org.elasticsearch.ElasticsearchException.guessRootCauses(ElasticsearchException.java:644) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:307) [elasticsearch-7.9.3.jar:7.9.3]
        ... 39 more
Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 99 out of bounds for length 99
        at org.apache.lucene.util.UnicodeUtil.UTF8toUTF16(UnicodeUtil.java:602) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
        at org.apache.lucene.util.BytesRef.utf8ToString(BytesRef.java:137) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
        at org.elasticsearch.search.DocValueFormat$1.format(DocValueFormat.java:117) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.DocValueFormat$1.format(DocValueFormat.java:94) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.fetch.subphase.FetchDocValuesPhase.hitsExecute(FetchDocValuesPhase.java:153) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:188) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:464) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:444) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.SearchService.access$200(SearchService.java:136) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.SearchService$2.lambda$onResponse$0(SearchService.java:396) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.search.SearchService.lambda$runAsync$0(SearchService.java:412) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:44) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:737) ~[elasticsearch-7.9.3.jar:7.9.3]
        at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-7.9.3.jar:7.9.3]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[?:?]
        at java.lang.Thread.run(Thread.java:832) ~[?:?]

Cheers, David

[ddolcimascolo]

For the sake of completeness: I just reproduced the same exception using the same Kibana script with Elasticsearch 7.13.2

[elasticmachine]

Pinging @elastic/es-search (Team:Search)

[cbuescher]

@ddolcimascolo thanks for the report and the reproduction, I can confirm this. I don't know if retrieving ip_range by docvalue_fields should work but even if not the exception should be different then I think. As a workaround you can retrieve the ip_range values by using the fields option I think.

[ddolcimascolo]

Thx for confirming @cbuescher I can't currently use fields because we're still on 7.9

[cbuescher]

For the record, fetching this via docvalue_fields doesn't seem to have been supported previously, on 6.8 and on 7.2 I get

       "reason": {
          "type": "illegal_argument_exception",
          "reason": "Fielddata is not supported on field [network] of type [ip_range]"
        }

So this issue is probably more about making the exception nicer if possible, so I'm marking it as an enhancement, but a bug, unless you can point me to previous behaviour where this was possible?

@ddolcimascolo please note that we usually don't backport any enhancements or fixes to earlier minors, so updating is still advised if you really need this.

[cbuescher]

Actually, re-reading the issue I think because this now returns a 500 error code we should treat it as a bug and try to return a nicer error as before.

[ddolcimascolo]

Yeah, I really opened the issue because of the 500 error. Getting a nice error message about the unsupported operation you're trying to do is so much better :)

And yes, switching to fields is on my pipe already.

Thanks, David

[cbuescher]

I checked this reproduction on 7.17 again and fwiw there's still an AIOOB exception causing an error but we get a 400 response overall:

Response

``` { "error": { "root_cause": [ { "type": "illegal_argument_exception", "reason": "Failed trying to format bytes as UTF8. Possibly caused by a mapping mismatch" } ], "type": "search_phase_execution_exception", "reason": "all shards failed", "phase": "query", "grouped": true, "failed_shards": [ { "shard": 0, "index": "ip_range_doc_values", "node": "JWcnZ6miQciPbPqTsGywSg", "reason": { "type": "illegal_argument_exception", "reason": "Failed trying to format bytes as UTF8. Possibly caused by a mapping mismatch", "caused_by": { "type": "array_index_out_of_bounds_exception", "reason": "Index 33 out of bounds for length 33" } } } ], "caused_by": { "type": "illegal_argument_exception", "reason": "Failed trying to format bytes as UTF8. Possibly caused by a mapping mismatch", "caused_by": { "type": "illegal_argument_exception", "reason": "Failed trying to format bytes as UTF8. Possibly caused by a mapping mismatch", "caused_by": { "type": "array_index_out_of_bounds_exception", "reason": "Index 33 out of bounds for length 33" } } } }, "status": 400 } ```

On our current main branch we don't get the AIOOB anymore but still some exception from the RAW docvalue formatter. I think generally range fields store doc values, but I think the ip range field in particular isn't decoding this back correctly atm. I need to do a bit of digging how other range types implement this and if its feasible to add for ip_range or not. The workaround of using the "fields" API would still be the preferred option here I think.

[cbuescher]

None of the range types (just checked "integer_range" and "date_range") seem to really work well with "docvalue_fields". "date_range" gives me an unsupported_operation_exception while "integer_range" returns some weird control characters. This seems to never have been supported really in the past. I'm not sure we want to add support for this now with wider adoption of the "fields" API that works okay for both cases. Maybe we should think about giving clearer errors in all range type cases.

[elasticsearchmachine]

Pinging @elastic/es-search-foundations (Team:Search Foundations)