Skip to content

[BUG] Zombie tasks on PPL cancellation #5647

Description

@Swiddis

What is the bug?

> xh post localhost:9200/_tasks/FovWqwb5RtO-KonC0xqPkQ:17897/_cancel
HTTP/1.1 200 OK
Content-Encoding: gzip
Content-Length: 354
Content-Type: application/json; charset=UTF-8
X-Opensearch-Version: OpenSearch/3.8.0-SNAPSHOT (opensearch)

{
    "nodes": {
        "FovWqwb5RtO-KonC0xqPkQ": {
            "name": "integTest-0",
            "transport_address": "127.0.0.1:9300",
            "host": "127.0.0.1",
            "ip": "127.0.0.1:9300",
            "roles": [
                "cluster_manager",
                "data",
                "ingest",
                "remote_cluster_client"
            ],
            "attributes": {
                "testattr": "test",
                "shard_indexing_pressure_enabled": "true"
            },
            "tasks": {
                "FovWqwb5RtO-KonC0xqPkQ:17897": {
                    "node": "FovWqwb5RtO-KonC0xqPkQ",
                    "id": 17897,
                    "type": "transport",
                    "action": "cluster:admin/opensearch/ppl",
                    "start_time_in_millis": 1784762788739,
                    "running_time_in_nanos": 11242608694,
                    "cancellable": true,
                    "cancelled": true,
                    "headers": {},
                    "cancellation_time_millis": 1784762799982
                }
            }
        }
    }
}

> xh localhost:9200/_cat/tasks
HTTP/1.1 200 OK
Content-Encoding: gzip
Content-Length: 280
Content-Type: text/plain; charset=UTF-8
X-Opensearch-Version: OpenSearch/3.8.0-SNAPSHOT (opensearch)

cluster:admin/opensearch/ppl          FovWqwb5RtO-KonC0xqPkQ:17897 -                            transport 1784762788739 23:26:28 19.1s       127.0.0.1 integTest-0
indices:data/read/search              FovWqwb5RtO-KonC0xqPkQ:17900 -                            transport 1784762788753 23:26:28 19.1s       127.0.0.1 integTest-0
indices:data/read/search[phase/query] FovWqwb5RtO-KonC0xqPkQ:17901 FovWqwb5RtO-KonC0xqPkQ:17900 direct    1784762788753 23:26:28 19.1s       127.0.0.1 integTest-0
cluster:monitor/tasks/lists           FovWqwb5RtO-KonC0xqPkQ:17957 -                            transport 1784762807907 23:26:47 249.7micros 127.0.0.1 integTest-0
cluster:monitor/tasks/lists[n]        FovWqwb5RtO-KonC0xqPkQ:17958 FovWqwb5RtO-KonC0xqPkQ:17957 direct    1784762807907 23:26:47 138.1micros 127.0.0.1 integTest-0

How can one reproduce the bug?
Steps to reproduce the behavior:

  1. Run a query with a long table-scan search time, such as
source=logs
| rex field=raw_log "nginx: (?<clientip>\\d+\\.\\d+\\.\\d+\\.\\d+)" max_match=1
| rex field=clientip "^(?<subnet>\\d+\\.\\d+)\\.\\d+\\.\\d+$" max_match=1
| stats count() as requests, sum(is_error) as errors by subnet
| eval error_rate = round(100.0 * errors / requests, 2)
| where error_rate > 10.0
| sort - error_rate
  1. Cancel it
  2. Zombie!
    This is because our current cancellation checks only happen between DSL pages. This is usually fine because DSL returns fast, but in the case of lots of pathological scripts, this leaves behind long-running search tasks.

What is the expected behavior?
Cancel the underlying search task, which will in turn propagate up to the ppl task automatically.

What is your host/environment?
Mainline

Do you have any screenshots?
N/A

Do you have any additional context?

In #5628, I added polling so cancellation does successfully interrupt the PPL task, but it does not interrupt the underlying search task. (Thankfully the search task is usually not as long as the entire PPL task so the delay is typically only a few seconds. For the majority of queries it's under 200ms, which is why this hasn't been commented on sooner.)

The cancellation does eventually go through after the DSL page returns (which in the worst case will be the timeout time), it's not a failed cancellation from PPL's side, the search task simply is not receiving the notification.

{
  "error": {
    "code": "UNKNOWN",
    "context": {
      "stage": "executing",
      "stage_description": "Running the query"
    },
    "details": "java.sql.SQLException: exception while executing query: The task is cancelled.",
    "location": [
      "while running the query"
    ],
    "reason": "java.sql.SQLException: exception while executing query: The task is cancelled.",
    "type": "RuntimeException"
  },
  "status": 500
}

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions