PainlessExplainError is cryptic inside elasticsearch log

[rjernst]

PainlessExplainError is used when Debug.explain is called within a painless script. In json responses, this gives a toString of the passed in object. However, the Error is logged, but PainlessExplainError always has a null message. Either these errors should somehow be skipped when logging (as they are "expected") or we should generated a useful message to pass to the super Error ctor.

[rjernst]

/cc @elastic/es-core-infra

[AlexAxeman]

It seems to me that the error should not be logged. It's just a side effect of using Error for another purpose than to indicate a serious problem. I've looked through the code, but I can't find where we could check for PainlessExplainError and skip logging. Any idea where I could look?

[rjernst]

Here's some more context. The "logging" I was referring to (apparently, as I don't quite remember what I saw when writing this issue) was the rest response:

❯ curl -u 'elastic-admin:elastic-password' -XPOST -H 'Content-Type: application/json' 'http://localhost:9200/_search?pretty' -d '{"query": {
    "script_score": {
      "query": { "match_all": {} },
"script": { "source": "Debug.explain(\"foo\"); return 1;" }
}}}'
{
  "error" : {
    "root_cause" : [
      {
        "type" : "script_exception",
        "reason" : "runtime error",
        "painless_class" : "java.lang.String",
        "to_string" : "foo",
        "java_class" : "java.lang.String",
        "script_stack" : [
          "Debug.explain(\"foo\"); ",
          "              ^---- HERE"
        ],
        "script" : "Debug.explain(\"foo\"); return 1;",
        "lang" : "painless",
        "position" : {
          "offset" : 14,
          "start" : 0,
          "end" : 22
        }
      }
    ],
    "type" : "search_phase_execution_exception",
    "reason" : "all shards failed",
    "phase" : "query",
    "grouped" : true,
    "failed_shards" : [
      {
        "shard" : 0,
        "index" : "index",
        "node" : "Ozi6S31yRaa3pXbpFpAcSA",
        "reason" : {
          "type" : "script_exception",
          "reason" : "runtime error",
          "painless_class" : "java.lang.String",
          "to_string" : "foo",
          "java_class" : "java.lang.String",
          "script_stack" : [
            "Debug.explain(\"foo\"); ",
            "              ^---- HERE"
          ],
          "script" : "Debug.explain(\"foo\"); return 1;",
          "lang" : "painless",
          "position" : {
            "offset" : 14,
            "start" : 0,
            "end" : 22
          },
          "caused_by" : {
            "type" : "painless_explain_error",
            "reason" : null
          }
        }
      }
    ]
  },
  "status" : 400
}

So the confusion is with the caused_by in the list of shard failures. The reason is null for the PainlessExplainError because that class uses the default super ctor, which uses a null message. One way to solve this could be to special case PainlessExplainError in getCause() for ScriptException, however that won't actually work because PainlessExplainError is internal to painless. We may want instead to allow ScriptException to have a null cause, and the change the call to convert the "error" to ScriptException to pass a null cause.

[jdconrad]

PainlessExplainError is constructed directly as part of the Java ASM generated for a script. As @rjernst mentions these could checked for as part of an instanceof instruction on the Throwable in PainlessScriptEngine.convertToScriptException. In that method we can change the behavior. As for not logging it all, I don't think we necessarily want to do that as there may be users find having these messages logged useful.

[larissabinatti]

is this issue still open? I'm new and would like to do it

[larissabinatti]

Hello, how can i replicate this error? What should I do to make it appear? Thanks

[stu-elastic]

Hi @larissabinatti try the reproduction provided by @rjernst in #28820 (comment)

[elasticsearchmachine]

Pinging @elastic/es-core-infra (Team:Core/Infra)