Substring function throws server exception

[dai-chen]

Plugin throws 500 server exception for the following query:

POST _opendistro/_sql?format=jdbc
{
  "query": "SELECT SUBSTRING(`kibana_sample_data_flights`.`OriginWeather`, 1, 1024) AS `OriginWeather` FROM `kibana_sample_data_flights`"
}

{
  "error": {
    "reason": "There was internal problem at backend",
    "details": "all shards failed",
    "type": "SearchPhaseExecutionException"
  },
  "status": 500
}

Elaticsearch log:

[2019-12-30T15:11:29,123][ERROR][c.a.o.s.e.f.PrettyFormatRestExecutor] [186590df9563.ant.amazon.com] Error happened in pretty formatter
org.elasticsearch.action.search.SearchPhaseExecutionException: all shards failed
	at org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseFailure(AbstractSearchAsyncAction.java:314) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.AbstractSearchAsyncAction.executeNextPhase(AbstractSearchAsyncAction.java:139) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseDone(AbstractSearchAsyncAction.java:273) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.InitialSearchPhase.onShardFailure(InitialSearchPhase.java:105) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.InitialSearchPhase.access$200(InitialSearchPhase.java:50) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.InitialSearchPhase$2.onFailure(InitialSearchPhase.java:273) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.SearchExecutionStatsCollector.onFailure(SearchExecutionStatsCollector.java:73) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListenerResponseHandler.handleException(ActionListenerResponseHandler.java:59) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.search.SearchTransportService$ConnectionCountingHandler.handleException(SearchTransportService.java:424) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.transport.TransportService$ContextRestoreResponseHandler.handleException(TransportService.java:1120) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.transport.TransportService$DirectResponseChannel.processException(TransportService.java:1229) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.transport.TransportService$DirectResponseChannel.sendResponse(TransportService.java:1203) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.transport.TaskTransportChannel.sendResponse(TaskTransportChannel.java:60) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.support.ChannelActionListener.onFailure(ChannelActionListener.java:56) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListener$1.onFailure(ActionListener.java:70) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:64) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.lambda$rewriteShardRequest$7(SearchService.java:1043) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionRunnable$1.doRun(ActionRunnable.java:45) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:44) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:773) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) ~[elasticsearch-7.4.2.jar:7.4.2]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:835) [?:?]
Caused by: org.elasticsearch.script.ScriptException: runtime error
	at org.elasticsearch.painless.PainlessScript.convertToScriptException(PainlessScript.java:94) ~[?:?]
	at org.elasticsearch.painless.PainlessScript$Script.execute(def substring_1 = doc['OriginWeather'].value.substring(0, 26);return substring_1;:45) ~[?:?]
	at org.elasticsearch.search.fetch.subphase.ScriptFieldsFetchSubPhase.hitsExecute(ScriptFieldsFetchSubPhase.java:67) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:177) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:384) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:364) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.lambda$executeQueryPhase$1(SearchService.java:340) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListener.lambda$map$2(ActionListener.java:145) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:62) ~[elasticsearch-7.4.2.jar:7.4.2]
	... 9 more
Caused by: java.lang.StringIndexOutOfBoundsException: begin 0, end 26, length 5
	at java.lang.String.checkBoundsBeginEnd(String.java:3410) ~[?:?]
	at java.lang.String.substring(String.java:1883) ~[?:?]
	at org.elasticsearch.painless.PainlessScript$Script.execute(def substring_1 = doc['OriginWeather'].value.substring(0, 26);return substring_1;:45) ~[?:?]
	at org.elasticsearch.search.fetch.subphase.ScriptFieldsFetchSubPhase.hitsExecute(ScriptFieldsFetchSubPhase.java:67) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.fetch.FetchPhase.execute(FetchPhase.java:177) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.executeFetchPhase(SearchService.java:384) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.executeQueryPhase(SearchService.java:364) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.search.SearchService.lambda$executeQueryPhase$1(SearchService.java:340) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListener.lambda$map$2(ActionListener.java:145) ~[elasticsearch-7.4.2.jar:7.4.2]
	at org.elasticsearch.action.ActionListener$1.onResponse(ActionListener.java:62) ~[elasticsearch-7.4.2.jar:7.4.2]
	... 9 more

[dai-chen]

From the explain, the end index (26 as below) seems being calculated outside painless script:

sql/src/main/java/com/amazon/opendistroforelasticsearch/sql/utils/SQLFunctions.java

Line 743 in 4744915

int end = Math.min(start + len, getPropertyOrValue(field).length());

. This works for string literal but the length is dynamic when substring applied to field name. This may be the cause.

Explain:

{
  "from" : 0,
  "size" : 200,
  "_source" : {
    "includes" : [ ],
    "excludes" : [ ]
  },
  "script_fields" : {
    "OriginWeather" : {
      "script" : {
        "source" : "def substring_1 = doc['OriginWeather'].value.substring(0, 26);return substring_1;",
        "lang" : "painless"
      },
      "ignore_failure" : false
    }
  }
}

[chloe-zh]

@dai-chen Yes you are right. The length should be calculated in the script. I will make a quick fix to it.