Task vis_telemetry "oss_telemetry-vis_telemetry" failed in attempt to run warning in Kibana logs

[bhavyarm]

Kibana version: 6.7.0 BC3

Elasticsearch version: 6.7.0 BC3

Server OS version: darwin_x86_64

Browser version: chrome latest

Browser OS version: os x

Original install method (e.g. download page, yum, from source, etc.): from staging

Describe the bug: This is apparently an ignorable error. Logging it to make sure we all know about it.

I was switching between OSS and default distro of the stack in my local. I had the default distro up and then I shut it down to run OSS stack to check the sanity. After I was done with it - I brought the default distro back up and noticed this warning:

log   [15:11:26.492] [warning][task_manager] Task vis_telemetry "oss_telemetry-vis_telemetry" failed in attempt to run: [version_conflict_engine_exception] [_doc][oss_telemetry-vis_telemetry]: version conflict, required seqNo [77], primary term [5]. current document has seqNo [78] and primary term [5], with { index_uuid="GzsgyC8HQS2-WC7vlWw-1g" & shard="0" & index=".kibana_task_manager" }

@tsullivan here you go. Thanks!

[elasticmachine]

Pinging @elastic/kibana-app

[tsullivan]

This is an ignorable error, as it will not affect any user actions.

version conflict, required seqNo [77], primary term [5]. current document has seqNo [78] and primary term [5]

I'm looking into why running this background task is failing because of this error

[tsullivan]

My suspicion is that when this problem triggers, it's when we're trying to update the task doc with the result of the previous run. The next time the task runs, it will want to have the previous run result in its run context.

Brief lifecycle of a recurring task:

• A plugin schedules the task; the new task doc gets stored with status of idle
• A Task Poller finds the idle task waiting for ownership, gives it to a Task Runner
• Task Runner claims the task; update the task document status to running
• The task run finishes; the Task Runner gets the run result and updates it:
  • set the task document again with status to idle
  • set the run result to the task "state" for the next run

Still need to look on whether indexing operations could be happening out of order. Are we not checking to ensure the task has been claimed before trying to update the state with the run result?

One-off tasks do not have the final update step.

cc @njd5475

[w33ble]

I just ran into this warning, on master, commit 215c8ea. In case it's helpful, here's the error message and the two task documents that are in that index.

server    log   [17:22:30.414] [info][listening] Server running at http://localhost:5603/kxi
server    log   [17:22:30.437] [info][status][plugin:spaces@8.0.0] Status changed from yellow to green - Ready
server    log   [17:22:31.427] [warning][task_manager] Task maps_telemetry "Maps-maps_telemetry" failed in attempt to run: [version_conflict_engine_exception] [_doc][Maps-maps_telemetry]: version conflict, required seqNo [729], primary term [4]. current document has seqNo [732] and primary term [4], with { index_uuid="7xtuoT_7S2etLxNzkQQkdQ" & shard="0" & index=".kibana_task_manager" }
optmzr    log   [17:23:41.325] [info][optimize:dynamic_dll_plugin] Need to compile the client vendors dll

Maps telemetry task

{
  "_index" : ".kibana_task_manager",
  "_type" : "_doc",
  "_id" : "Maps-maps_telemetry",
  "_version" : 370,
  "_seq_no" : 733,
  "_primary_term" : 4,
  "found" : true,
  "_source" : {
    "type" : "task",
    "task" : {
      "taskType" : "maps_telemetry",
      "state" : """{"runs":1,"stats":{"mapsTotalCount":0,"timeCaptured":"2019-03-08T17:22:30.498Z","attributesPerMap":{"dataSourcesCount":{"min":0,"max":0,"avg":0},"layersCount":{"min":0,"max":0,"avg":0},"layerTypesCount":{},"emsVectorLayersCount":{}}}}""",
      "params" : "{}",
      "attempts" : 0,
      "scheduledAt" : "2019-03-08T17:22:30.076Z",
      "runAt" : "2019-03-09T07:00:00.000Z",
      "status" : "idle"
    },
    "kibana" : {
      "uuid" : "5b2de169-2785-441b-ae8c-186a1936b17d",
      "version" : 8000099,
      "apiVersion" : 1
    }
  }
}

Vis telemetry task

{
  "_index" : ".kibana_task_manager",
  "_type" : "_doc",
  "_id" : "oss_telemetry-vis_telemetry",
  "_version" : 366,
  "_seq_no" : 735,
  "_primary_term" : 4,
  "found" : true,
  "_source" : {
    "type" : "task",
    "task" : {
      "taskType" : "vis_telemetry",
      "state" : """{"runs":1}""",
      "params" : "{}",
      "attempts" : 1,
      "scheduledAt" : "2019-03-08T17:22:30.240Z",
      "runAt" : "2019-03-09T07:00:00.000Z",
      "status" : "idle"
    },
    "kibana" : {
      "uuid" : "5b2de169-2785-441b-ae8c-186a1936b17d",
      "version" : 8000099,
      "apiVersion" : 1
    }
  }
}

[tsullivan]

Thanks @w33ble that does help.

The status is "status" : "idle". The good news is this warning doesn't cause the task to be marked as failed and the recurrence schedule will still run as configured.

[tsullivan]

@epixa @njd5475 any thoughts?

[elasticmachine]

Pinging @elastic/kibana-platform

[epixa]

@njd5475 Can you look into reproducing this?

[elasticmachine]

Pinging @elastic/kibana-stack-services

[tsullivan]

@mikecote has talked about resolving this issue. The pain point for the code is letting the consumer pass in an _id string to prevent scheduling the same task whenever a Kibana instants starts. The consumers should wrap their call in a try/catch if they do that. @mikecote is working on a new method called scheduleWithID or similar, to do the try/catch for everyone that is fine with ignoring this ignorable error.

[mikecote]

Yup, scheduleIfNotExists seemed to be the right approach with a try / catch. Will forward issue to @gmmorris.

[tylersmalley]

This has been happening for a while and is causing a lot of invalid concerns for folks. Can we prioritize this fix?

Closed duplicate #49209
Also https://discuss.elastic.co/t/type-log-timestamp-2019-11-07t1721z-tags-warning-telemetry-pid-24726-message-error-scheduling-task-received-task-oss-telemetry-vis-telemetry-version-conflict-document-already-exists-current-version-3-version-conflict/207119