[BUG] UnexpectedJsonEventException reading task that failed

[uriofferup]

What is the bug?

Failed to serialize JSON response when reading a task that failed to execute.

How can one reproduce the bug?

Run any operation using waitForCompletiong(false) that fail to execute (for example due to versioning issue).
Then read the taskId returned:

GetTasksRequest getTasksRequest = GetTasksRequest.of(t -> t.taskId(osTask.getTaskId()));
GetTasksResponse getTasksResponse = openSearchClient.tasks().get(getTasksRequest);

What is the expected behavior?

Deserialize the response into the GetTasksResponse object.

What is your host/environment?

AWS Lambda
ElasticSearch 7.10

Do you have any screenshots?

Executing /_tasks/
Gets this:

{
  "completed": true,
  "task": {
    "node": "xjAO-PN5TKarvcLhJmHfcA",
    "id": 47102523527,
    "type": "transport",
    "action": "indices:data/write/update/byquery",
    "status": {
      "total": 152,
      "updated": 151,
      "created": 0,
      "deleted": 0,
      "batches": 6,
      "version_conflicts": 1,
      "noops": 0,
      "retries": {
        "bulk": 0,
        "search": 0
      },
      "throttled_millis": 0,
      "requests_per_second": -1,
      "throttled_until_millis": 0,
      "slices": [
        {
          "slice_id": 0,
          "total": 26,
          "updated": 26,
          "created": 0,
          "deleted": 0,
          "batches": 1,
          "version_conflicts": 0,
          "noops": 0,
          "retries": {
            "bulk": 0,
            "search": 0
          },
          "throttled_millis": 0,
          "requests_per_second": -1,
          "throttled_until_millis": 0
        },
        {
          "slice_id": 1,
          "total": 23,
          "updated": 23,
          "created": 0,
          "deleted": 0,
          "batches": 1,
          "version_conflicts": 0,
          "noops": 0,
          "retries": {
            "bulk": 0,
            "search": 0
          },
          "throttled_millis": 0,
          "requests_per_second": -1,
          "throttled_until_millis": 0
        },
        {
          "slice_id": 2,
          "total": 29,
          "updated": 29,
          "created": 0,
          "deleted": 0,
          "batches": 1,
          "version_conflicts": 0,
          "noops": 0,
          "retries": {
            "bulk": 0,
            "search": 0
          },
          "throttled_millis": 0,
          "requests_per_second": -1,
          "throttled_until_millis": 0
        },
        {
          "slice_id": 3,
          "total": 19,
          "updated": 18,
          "created": 0,
          "deleted": 0,
          "batches": 1,
          "version_conflicts": 1,
          "noops": 0,
          "retries": {
            "bulk": 0,
            "search": 0
          },
          "throttled_millis": 0,
          "requests_per_second": -1,
          "throttled_until_millis": 0
        },
        {
          "slice_id": 4,
          "total": 30,
          "updated": 30,
          "created": 0,
          "deleted": 0,
          "batches": 1,
          "version_conflicts": 0,
          "noops": 0,
          "retries": {
            "bulk": 0,
            "search": 0
          },
          "throttled_millis": 0,
          "requests_per_second": -1,
          "throttled_until_millis": 0
        },
        {
          "slice_id": 5,
          "total": 25,
          "updated": 25,
          "created": 0,
          "deleted": 0,
          "batches": 1,
          "version_conflicts": 0,
          "noops": 0,
          "retries": {
            "bulk": 0,
            "search": 0
          },
          "throttled_millis": 0,
          "requests_per_second": -1,
          "throttled_until_millis": 0
        }
      ]
    },
    "description": "update-by-query [phoenix-2023-07-01-all_categories] updated with Script{type=inline, lang='painless', idOrCode='ctx._source.owner=[\"last_active\":params.last_active];', options={}, params={last_active=2023-10-10T21:14:20Z}}",
    "start_time_in_millis": 1697057871665,
    "running_time_in_nanos": 75386100,
    "cancellable": true,
    "headers": {}
  },
  "response": {
    "took": 73,
    "timed_out": false,
    "total": 152,
    "updated": 151,
    "created": 0,
    "deleted": 0,
    "batches": 6,
    "version_conflicts": 1,
    "noops": 0,
    "retries": {
      "bulk": 0,
      "search": 0
    },
    "throttled": "0s",
    "throttled_millis": 0,
    "requests_per_second": -1,
    "throttled_until": "0s",
    "throttled_until_millis": 0,
    "slices": [
      {
        "slice_id": 0,
        "total": 26,
        "updated": 26,
        "created": 0,
        "deleted": 0,
        "batches": 1,
        "version_conflicts": 0,
        "noops": 0,
        "retries": {
          "bulk": 0,
          "search": 0
        },
        "throttled": "0s",
        "throttled_millis": 0,
        "requests_per_second": -1,
        "throttled_until": "0s",
        "throttled_until_millis": 0
      },
      {
        "slice_id": 1,
        "total": 23,
        "updated": 23,
        "created": 0,
        "deleted": 0,
        "batches": 1,
        "version_conflicts": 0,
        "noops": 0,
        "retries": {
          "bulk": 0,
          "search": 0
        },
        "throttled": "0s",
        "throttled_millis": 0,
        "requests_per_second": -1,
        "throttled_until": "0s",
        "throttled_until_millis": 0
      },
      {
        "slice_id": 2,
        "total": 29,
        "updated": 29,
        "created": 0,
        "deleted": 0,
        "batches": 1,
        "version_conflicts": 0,
        "noops": 0,
        "retries": {
          "bulk": 0,
          "search": 0
        },
        "throttled": "0s",
        "throttled_millis": 0,
        "requests_per_second": -1,
        "throttled_until": "0s",
        "throttled_until_millis": 0
      },
      {
        "slice_id": 3,
        "total": 19,
        "updated": 18,
        "created": 0,
        "deleted": 0,
        "batches": 1,
        "version_conflicts": 1,
        "noops": 0,
        "retries": {
          "bulk": 0,
          "search": 0
        },
        "throttled": "0s",
        "throttled_millis": 0,
        "requests_per_second": -1,
        "throttled_until": "0s",
        "throttled_until_millis": 0
      },
      {
        "slice_id": 4,
        "total": 30,
        "updated": 30,
        "created": 0,
        "deleted": 0,
        "batches": 1,
        "version_conflicts": 0,
        "noops": 0,
        "retries": {
          "bulk": 0,
          "search": 0
        },
        "throttled": "0s",
        "throttled_millis": 0,
        "requests_per_second": -1,
        "throttled_until": "0s",
        "throttled_until_millis": 0
      },
      {
        "slice_id": 5,
        "total": 25,
        "updated": 25,
        "created": 0,
        "deleted": 0,
        "batches": 1,
        "version_conflicts": 0,
        "noops": 0,
        "retries": {
          "bulk": 0,
          "search": 0
        },
        "throttled": "0s",
        "throttled_millis": 0,
        "requests_per_second": -1,
        "throttled_until": "0s",
        "throttled_until_millis": 0
      }
    ],
    "failures": [
      {
        "index": "phoenix-2023-07-01-all_categories",
        "type": "_doc",
        "id": "050aecc6-55d2-3ff4-9c6a-7672b8c31e8e",
        "cause": {
          "type": "version_conflict_engine_exception",
          "reason": "[050aecc6-55d2-3ff4-9c6a-7672b8c31e8e]: version conflict, required seqNo [392388470], primary term [1]. current document has seqNo [399875031] and primary term [1]",
          "index_uuid": "jOv6Zv19Td-EY0IJBE09qw",
          "shard": "3",
          "index": "phoenix-2023-07-01-all_categories"
        },
        "status": 409
      }
    ]
  }
}

Error Obtained is:

org.opensearch.client.json.UnexpectedJsonEventException: Unexpected JSON event 'START_OBJECT' instead of '[KEY_NAME, VALUE_STRING, VALUE_NUMBER, VALUE_TRUE, VALUE_FALSE]'
	at org.opensearch.client.json.JsonpUtils.ensureAccepts(JsonpUtils.java:82) ~[task/:?]
	at org.opensearch.client.json.JsonpDeserializerBase$ArrayDeserializer.deserialize(JsonpDeserializerBase.java:352) ~[task/:?]
	at org.opensearch.client.json.JsonpDeserializerBase$ArrayDeserializer.deserialize(JsonpDeserializerBase.java:322) ~[task/:?]
	at org.opensearch.client.json.JsonpDeserializer.deserialize(JsonpDeserializer.java:88) ~[task/:?]
	at org.opensearch.client.json.ObjectDeserializer$FieldObjectDeserializer.deserialize(ObjectDeserializer.java:85) ~[task/:?]
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:189) ~[task/:?]
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:150) ~[task/:?]
	at org.opensearch.client.json.JsonpDeserializer.deserialize(JsonpDeserializer.java:88) ~[task/:?]
	at org.opensearch.client.json.ObjectBuilderDeserializer.deserialize(ObjectBuilderDeserializer.java:92) ~[task/:?]
	at org.opensearch.client.json.DelegatingDeserializer$SameType.deserialize(DelegatingDeserializer.java:56) ~[task/:?]
	at org.opensearch.client.json.ObjectDeserializer$FieldObjectDeserializer.deserialize(ObjectDeserializer.java:85) ~[task/:?]
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:189) ~[task/:?]
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:150) ~[task/:?]
	at org.opensearch.client.json.JsonpDeserializer.deserialize(JsonpDeserializer.java:88) ~[task/:?]
	at org.opensearch.client.json.ObjectBuilderDeserializer.deserialize(ObjectBuilderDeserializer.java:92) ~[task/:?]
	at org.opensearch.client.json.DelegatingDeserializer$SameType.deserialize(DelegatingDeserializer.java:56) ~[task/:?]
	at org.opensearch.client.transport.rest_client.RestClientTransport.decodeResponse(RestClientTransport.java:325) ~[task/:?]
	at org.opensearch.client.transport.rest_client.RestClientTransport.getHighLevelResponse(RestClientTransport.java:291) ~[task/:?]
	at org.opensearch.client.transport.rest_client.RestClientTransport.performRequest(RestClientTransport.java:144) ~[task/:?]
	at org.opensearch.client.opensearch.tasks.OpenSearchTasksClient.get(OpenSearchTasksClient.java:123) ~[task/:?]

Do you have any additional context?

Object org.opensearch.client.opensearch.tasks.Status has a field failures defined as a String[].

[dblock]

Without looking at the underlying implementation - which version of the client is this? I also see that you're using the OpenSearch client against ElasticSearch 7.10, please try OpenSearch 1.x and 2.x. If you can reproduce this against OpenSearch 2.x try implementing a YAML REST test?

[uriofferup]

We are using version 2.6.0 of OpenSearch Java Client.
I will try to repro this in OpenSearch Server. Thank you.

[olamelin]

We are experiencing the exact same thing. We are trying to get task with a task id. Most of the time it works but sometimes it fails with the exact same stack trace. We have not yet found the root cause of the issue but this report will help us where to look.
We are also using opensearch-java:2.6.0 and we can reproduce this issue when running Opensearch in docker with the image image: opensearchproject/opensearch:2.7.0

[olamelin]

And as @uriofferup mentioned the task that fails contains an array of json objects and not strings as it is defined in the failures in the response.
This is the json of a task that fails the parsing acquired by calling GET _tasks/-EGpqKfgRNydv1V6yc09vg:298365. Trying to get the same task via the java client the exception is thrown

{
  "completed": true,
  "task": {
    "node": "-EGpqKfgRNydv1V6yc09vg",
    "id": 298365,
    "type": "transport",
    "action": "indices:data/write/update/byquery",
    "status": {
      "total": 1,
      "updated": 0,
      "created": 0,
      "deleted": 0,
      "batches": 1,
      "version_conflicts": 1,
      "noops": 0,
      "retries": {
        "bulk": 0,
        "search": 0
      },
      "throttled_millis": 0,
      "requests_per_second": -1,
      "throttled_until_millis": 0
    },
    "description": """redacted""",
    "start_time_in_millis": 1698853787531,
    "running_time_in_nanos": 13688917,
    "cancellable": true,
    "cancelled": false,
    "headers": {}
  },
  "response": {
    "took": 13,
    "timed_out": false,
    "total": 1,
    "updated": 0,
    "created": 0,
    "deleted": 0,
    "batches": 1,
    "version_conflicts": 1,
    "noops": 0,
    "retries": {
      "bulk": 0,
      "search": 0
    },
    "throttled": "0s",
    "throttled_millis": 0,
    "requests_per_second": -1,
    "throttled_until": "0s",
    "throttled_until_millis": 0,
    "failures": [
      {
        "index": "redacted",
        "id": "43da0a67-2750-459d-bd4a-b403b8010425",
        "cause": {
          "type": "version_conflict_engine_exception",
          "reason": "[43da0a67-2750-459d-bd4a-b403b8010425]: version conflict, required seqNo [315295], primary term [1]. current document has seqNo [315331] and primary term [1]",
          "index": "redacted",
          "shard": "0",
          "index_uuid": "uB06NblRQ-OtGtCttxtgnA"
        },
        "status": 409
      }
    ]
  }
}

For completeness the exception stack trace

org.opensearch.client.json.UnexpectedJsonEventException: Unexpected JSON event 'START_OBJECT' instead of '[KEY_NAME, VALUE_STRING, VALUE_NUMBER, VALUE_TRUE, VALUE_FALSE]'
	at org.opensearch.client.json.JsonpUtils.ensureAccepts(JsonpUtils.java:82)
	at org.opensearch.client.json.JsonpDeserializerBase$ArrayDeserializer.deserialize(JsonpDeserializerBase.java:352)
	at org.opensearch.client.json.JsonpDeserializerBase$ArrayDeserializer.deserialize(JsonpDeserializerBase.java:322)
	at org.opensearch.client.json.JsonpDeserializer.deserialize(JsonpDeserializer.java:88)
	at org.opensearch.client.json.ObjectDeserializer$FieldObjectDeserializer.deserialize(ObjectDeserializer.java:85)
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:189)
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:150)
	at org.opensearch.client.json.JsonpDeserializer.deserialize(JsonpDeserializer.java:88)
	at org.opensearch.client.json.ObjectBuilderDeserializer.deserialize(ObjectBuilderDeserializer.java:92)
	at org.opensearch.client.json.DelegatingDeserializer$SameType.deserialize(DelegatingDeserializer.java:56)
	at org.opensearch.client.json.ObjectDeserializer$FieldObjectDeserializer.deserialize(ObjectDeserializer.java:85)
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:189)
	at org.opensearch.client.json.ObjectDeserializer.deserialize(ObjectDeserializer.java:150)
	at org.opensearch.client.json.JsonpDeserializer.deserialize(JsonpDeserializer.java:88)
	at org.opensearch.client.json.ObjectBuilderDeserializer.deserialize(ObjectBuilderDeserializer.java:92)
	at org.opensearch.client.json.DelegatingDeserializer$SameType.deserialize(DelegatingDeserializer.java:56)
	at org.opensearch.client.transport.rest_client.RestClientTransport.decodeResponse(RestClientTransport.java:325)
	at org.opensearch.client.transport.rest_client.RestClientTransport.getHighLevelResponse(RestClientTransport.java:291)
	at org.opensearch.client.transport.rest_client.RestClientTransport.performRequest(RestClientTransport.java:144)
	at org.opensearch.client.opensearch.tasks.OpenSearchTasksClient.get(OpenSearchTasksClient.java:123)
	at org.opensearch.client.opensearch.tasks.OpenSearchTasksClient.get(OpenSearchTasksClient.java:137)

[dblock]

Looks like a task with this error can't be parsed. Try to turn this into a (failing) unit test?

[Bfindlay]

We started encountering this on the 2.8.0 client as well. It looks to be because the failures are trying to be deserialized as strings, but they contain an TaskFailure object.
I have put this into a PR if you want to check it out
#727

[dblock]

Thanks for the PR! Do you know whether this was a bug introduced in 2.8.0, or an unexpected server-side change?

[Bfindlay]

@dblock We just migrated from high level client and so far have only tested with 2.7.0 and 2.8.0 and the issue existed in both versions. I am not sure where the original bug was introduced.

[uriofferup]

I found the issue using version 2.6.0 of OpenSearch Java Client.

[uriofferup]

Thanks @Bfindlay for the PR.

[dblock]

@Bfindlay want to finish #727?