[BUG] UnexpectedJsonEventException reading task that failed #666

uriofferup · 2023-10-13T20:11:04Z

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[].

The text was updated successfully, but these errors were encountered:

dblock · 2023-10-16T15:19:57Z

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 · 2023-10-16T19:39:59Z

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

olamelin · 2023-11-01T15:45:19Z

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 · 2023-11-01T16:03:47Z

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 · 2023-11-01T21:18:05Z

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

Bfindlay · 2023-11-15T11:20:02Z

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 · 2023-11-15T12:50:26Z

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

Bfindlay · 2023-11-15T12:53:52Z

@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 · 2023-11-15T17:53:58Z

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

uriofferup · 2023-11-15T17:54:18Z

Thanks @Bfindlay for the PR.

dblock · 2023-12-04T15:05:52Z

@Bfindlay want to finish #727?

Bfindlay · 2023-12-04T22:17:30Z

@dblock Yeah I will get to it sometime this week or next week.

uriofferup added bug Something isn't working untriaged labels Oct 13, 2023

Bfindlay mentioned this issue Nov 15, 2023

Fix GetTasksResponse TaskFailure deserialization #727

Draft

dblock removed the untriaged label Dec 4, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[BUG] UnexpectedJsonEventException reading task that failed #666

[BUG] UnexpectedJsonEventException reading task that failed #666

uriofferup commented Oct 13, 2023

dblock commented Oct 16, 2023

uriofferup commented Oct 16, 2023

olamelin commented Nov 1, 2023

olamelin commented Nov 1, 2023

dblock commented Nov 1, 2023

Bfindlay commented Nov 15, 2023

dblock commented Nov 15, 2023

Bfindlay commented Nov 15, 2023

uriofferup commented Nov 15, 2023

uriofferup commented Nov 15, 2023

dblock commented Dec 4, 2023

Bfindlay commented Dec 4, 2023

[BUG] UnexpectedJsonEventException reading task that failed #666

[BUG] UnexpectedJsonEventException reading task that failed #666

Comments

uriofferup commented Oct 13, 2023

What is the bug?

How can one reproduce the bug?

What is the expected behavior?

What is your host/environment?

Do you have any screenshots?

Do you have any additional context?

dblock commented Oct 16, 2023

uriofferup commented Oct 16, 2023

olamelin commented Nov 1, 2023

olamelin commented Nov 1, 2023

dblock commented Nov 1, 2023

Bfindlay commented Nov 15, 2023

dblock commented Nov 15, 2023

Bfindlay commented Nov 15, 2023

uriofferup commented Nov 15, 2023

uriofferup commented Nov 15, 2023

dblock commented Dec 4, 2023

Bfindlay commented Dec 4, 2023