Task Manager troubleshooting

Theory: Kibana is configured to poll for tasks at a reduced rate.

Diagnosis: Evaluating the health stats, you can see the following output under stats.configuration.value:

{
  "request_capacity": 1000,
  "monitored_aggregated_stats_refresh_rate": 60000,
  "monitored_stats_running_average_window": 50,
  "monitored_task_execution_thresholds": {
    "default": {
      "error_threshold": 90,
      "warn_threshold": 80
    },
    "custom": {}
  },
  "poll_interval": 3000, 
  "max_workers": 10 
}

You can infer from this output that the Kibana instance polls for work every 3 seconds and can run 10 concurrent tasks.

Now suppose the output under stats.configuration.value is the following:

{
  "request_capacity": 1000,
  "monitored_aggregated_stats_refresh_rate": 60000,
  "monitored_stats_running_average_window": 50,
  "monitored_task_execution_thresholds": {
    "default": {
      "error_threshold": 90,
      "warn_threshold": 80
    },
    "custom": {}
  },
  "poll_interval": 60000, 
  "max_workers": 1 
}

You can infer from this output that the Kibana instance only polls for work once a minute and only picks up one task at a time. This throughput is unlikely to support mission critical services, such as Alerting or Reporting, and tasks will usually run late.

There are two possible reasons for such a configuration:

Theory: Kibana is not polling as frequently as it should

Diagnosis: Evaluating the health stats, you see the following output under stats.runtime.value.polling:

{
  "last_successful_poll": "2021-02-16T11:38:09.934Z", 
  "last_polling_delay": "2021-02-14T11:29:05.053Z",
  "duration": { 
    "p50": 13,
    "p90": 128,
    "p95": 143,
    "p99": 168
  },
  "claim_conflicts": { 
    "p50": 0,
    "p90": 0,
    "p95": 0,
    "p99": 2
  },
  "claim_mismatches": {
    "p50": 0,
    "p90": 0,
    "p95": 0,
    "p99": 0
  },
  "result_frequency_percent_as_number": { 
    "Failed": 0,
    "NoAvailableWorkers": 0,
    "NoTasksClaimed": 80,
    "RanOutOfCapacity": 0,
    "RunningAtCapacity": 0,
    "PoolFilled": 20
  }
}

You can infer from this output that the Kibana instance is polling regularly. This assessment is based on the following:

All of these stats are tracked as a running average, which means that they give a snapshot of a period of time (by default Kibana tracks up to 50 cycles), rather than giving a complete history.

Suppose the output under stats.runtime.value.polling.result_frequency_percent_as_number was the following:

{
  "Failed": 30, 
  "NoAvailableWorkers": 20, 
  "NoTasksClaimed": 10,
  "RanOutOfCapacity": 10, 
  "RunningAtCapacity": 10, 
  "PoolFilled": 20
}

You can infer from this output that Task Manager is not healthy, as the failure rate is high, and Task Manager is fetching tasks it has no capacity to run. Analyzing the Kibana Server Log should reveal the underlying issue causing the high error rate and capacity issues.

The high NoAvailableWorkers rate of 20% suggests that there are many tasks running for durations longer than the poll_interval. For details on analyzing long task execution durations, see the long running tasks theory.

Theory: Kibana is polling as frequently as it should, but that isn’t often enough to keep up with the workload

Diagnosis: Evaluating the health stats, you can see the following output of drift and load under stats.runtime.value:

{
  "drift": { 
    "p50": 99,
    "p90": 1245,
    "p95": 1845,
    "p99": 2878
  },
  "load": { 
    "p50": 0,
    "p90": 0,
    "p95": 10,
    "p99": 20
  },
}

You can infer from these stats that this Kibana has plenty of capacity, and any delays you might be experiencing are unlikely to be addressed by expanding the throughput.

Suppose the output of drift and load was the following:

{
  "drift": { 
    "p50": 2999,
    "p90": 3845,
    "p95": 3845.75,
    "p99": 4078
  },
  "load": { 
    "p50": 80,
    "p90": 100,
    "p95": 100,
    "p99": 100
  }
}

You can infer from these stats that this Kibana is using most of its capacity, but seems to keep up with the work most of the time. This assessment is based on the following:

For details on achieving higher throughput by adjusting your scaling strategy, see Scaling guidance.

Theory: Tasks run for too long, overrunning their schedule

Diagnosis: The Insufficient throughput to handle the scheduled workload theory analyzed a hypothetical scenario where both drift and load were unusually high.

Suppose an alternate scenario, where drift is high, but load is not, such as the following:

{
    "drift": { 
        "p50": 9799,
        "p90": 83845,
        "p95": 90328,
        "p99": 123845
    },
    "load": { 
        "p50": 40,
        "p90": 75,
        "p95": 80,
        "p99": 100
    }
}

In the preceding scenario, the tasks are running far too late, but you have sufficient capacity to run more concurrent tasks. A high capacity allows Kibana to run multiple different tasks concurrently. If a task is already running when its next schedule run is due, Kibana will avoid running it a second time, and instead wait for the first execution to complete.

If a task takes longer to execute than the cadence of its schedule, then that task will always overrun and experience a high drift. For example, suppose a task is scheduled to execute every 3 seconds, but takes 6 seconds to complete. It will consistently suffer from a drift of, at least, 3 seconds.

Evaluating the health stats in this hypothetical scenario, you see the following output under stats.runtime.value.execution.duration:

{
  "alerting:.index-threshold": { 
    "p50": 95,
    "p90": 1725,
    "p95": 2761,
    "p99": 2761
  },
  "alerting:.es-query": { 
    "p50": 7149,
    "p90": 40071,
    "p95": 45282,
    "p99": 121845
  },
  "actions:.index": {
    "p50": 166,
    "p90": 166,
    "p95": 166,
    "p99": 166
  }
}

You can infer from these stats that the high drift the Task Manager is experiencing is most likely due to Elasticsearch query alerts that are running for a long time.

Resolving this issue is context dependent and changes from case to case. In the preceding example, this would be resolved by modifying the queries in these alerts to make them faster, or improving the Elasticsearch throughput to speed up the exiting query.

Theory: Tasks take multiple attempts to succeed

Diagnosis: A high error rate could cause a task to appear to run late, when in fact it runs on time, but experiences a high failure rate.

Evaluating the preceding health stats, you see the following output under stats.runtime.value.execution.result_frequency_percent_as_number:

{
  "alerting:.index-threshold": { 
    "Success": 100,
    "RetryScheduled": 0,
    "Failed": 0,
    "status": "OK"
  },
  "alerting:xpack.uptime.alerts.monitorStatus": {
    "Success": 100,
    "RetryScheduled": 0,
    "Failed": 0,
    "status": "OK"
  },
  "actions:.index": { 
    "Success": 8,
    "RetryScheduled": 0,
    "Failed": 92,
    "status": "error" 
  }
}

You can infer from these stats that most actions:.index tasks, which back the ES Index Kibana action, fail. Resolving that would require deeper investigation into the Kibana Server Log, where the exact errors are logged, and addressing these specific errors.

Theory: Spikes in non-recurring tasks are consuming a high percentage of the available capacity

Diagnosis: Task Manager uses ad-hoc non-recurring tasks to load balance operations across multiple Kibana instances.

Evaluating the preceding health stats, you see the following output under stats.runtime.value.execution.persistence:

{
  "recurring": 88, 
  "non_recurring": 12, 
},

You can infer from these stats that the majority of executions consist of recurring tasks at 88%. You can use the execution.persistence stats to evaluate the ratio of consumed capacity, but on their own, you should not make assumptions about the sufficiency of the available capacity.

To assess the capacity, you should evaluate these stats against the load under stats.runtime.value:

{
    "load": { 
        "p50": 40,
        "p90": 40,
        "p95": 60,
        "p99": 80
    }
}

You can infer from these stats that it is very unusual for Task Manager to run out of capacity, so the capacity is likely sufficient to handle the amount of non-recurring tasks.

Suppose you have an alternate scenario, where you see the following output under stats.runtime.value.execution.persistence:

{
  "recurring": 60, 
  "non_recurring": 40, 
},

You can infer from these stats that even though most executions are recurring tasks, a substantial percentage of executions are non-recurring tasks at 40%.

Evaluating the load under stats.runtime.value, you see the following:

{
    "load": { 
        "p50": 70,
        "p90": 100,
        "p95": 100,
        "p99": 100
    }
}

You can infer from these stats that it is quite common for this Kibana instance to run out of capacity. Given the high rate of non-recurring tasks, it would be reasonable to assess that there is insufficient capacity in the Kibana cluster to handle the amount of tasks.

Keep in mind that these stats give you a glimpse at a moment in time, and even though there has been insufficient capacity in recent minutes, this might not be true in other times where fewer non-recurring tasks are used. We recommend tracking these stats over time and identifying the source of these tasks before making sweeping changes to your infrastructure.

Predicting the required throughput a deployment might need to support Task Manager is difficult, as features can schedule an unpredictable number of tasks at a variety of scheduled cadences.

Health monitoring provides statistics that make it easier to monitor the adequacy of the existing throughput. By evaluating the workload, the required throughput can be estimated, which is used when following the Task Manager Scaling guidance.

Evaluating the preceding health stats in the previous example, you see the following output under stats.workload.value:

{
  "count": 26, 
  "task_types": {
    "alerting:.index-threshold": {
      "count": 2, 
      "status": {
        "idle": 2
      }
    },
    "actions:.index": {
      "count": 14,
      "status": {
        "idle": 2,
        "running": 2,
        "failed": 10 
      }
    },
    "alerting:xpack.uptime.alerts.monitorStatus": {
      "count": 10,
      "status": {
        "idle": 10
      }
    },
  },
  "non_recurring": 0, 
  "owner_ids": 1, 
  "schedule": [ 
    ["10s", 2],
    ["1m", 2],
    ["90s", 2],
    ["5m", 8]
  ],
  "overdue_non_recurring": 0, 
  "overdue": 0, 
  "estimated_schedule_density": [ 
    0, 1, 0, 0, 0, 1, 0, 1, 0, 1,
    0, 0, 0, 1, 0, 0, 1, 1, 1, 0,
    0, 3, 0, 0, 0, 1, 0, 1, 0, 1,
    0, 0, 0, 1, 0, 0, 1, 1, 1, 0
  ],
  "capacity_requirements": { 
    "per_minute": 14,
    "per_hour": 240,
    "per_day": 0
  }
}

The workload section summarizes the work load across the cluster, listing the tasks in the system, their types, schedules, and current status.

You can infer from these stats that a default deployment should suffice. This assessment is based on the following:

Suppose the output of stats.workload.value looked something like this:

{
  "count": 2191, 
  "task_types": {
    "alerting:.index-threshold": {
      "count": 202,
      "status": {
        "idle": 183,
        "claiming": 2,
        "running": 19
      }
    },
    "alerting:.es-query": {
      "count": 225,
      "status": {
        "idle": 225,
      }
    },
    "actions:.index": {
      "count": 89,
      "status": {
        "idle": 24,
        "running": 2,
        "failed": 63
      }
    },
    "alerting:xpack.uptime.alerts.monitorStatus": {
      "count": 87,
      "status": {
        "idle": 74,
        "running": 13
      }
    },
  },
  "non_recurring": 0,
  "owner_ids": 1,
  "schedule": [ 
    ["10s", 38],
    ["1m", 101],
    ["90s", 55],
    ["5m", 89],
    ["20m", 62],
    ["60m", 106],
    ["1d", 61]
  ],
  "overdue_non_recurring": 0,
  "overdue": 0, 
  "estimated_schedule_density": [  
    10, 1, 0, 10, 0, 20, 0, 1, 0, 1,
    9, 0, 3, 10, 0, 0, 10, 10, 7, 0,
    0, 31, 0, 12, 16, 31, 0, 10, 0, 10,
    3, 22, 0, 10, 0, 2, 10, 10, 1, 0
  ],
  "capacity_requirements": {
    "per_minute": 329, 
    "per_hour": 4272, 
    "per_day": 61 
  }
}

You can infer several important attributes of your workload from this output:

These rough calculations give you a lower bound to the required throughput, which is at least 410 tasks per minute to ensure recurring tasks are executed, at their scheduled time. This throughput doesn’t account for nonrecurring tasks that might have been scheduled, nor does it account for tasks (recurring or otherwise) that might be scheduled in the future.

Given these inferred attributes, it would be safe to assume that a single Kibana instance with default settings would not provide the required throughput. It is possible that scaling horizontally by adding a couple more Kibana instances will.

For details on scaling Task Manager, see Scaling guidance.

Task Manager is constantly evaluating its runtime operations and workload. This enables Task Manager to make rough estimates about the sufficiency of its capacity.

As the name suggests, these are estimates based on historical data and should not be used as predictions. These estimations should be evaluated alongside the detailed Health monitoring stats before making changes to infrastructure. These estimations assume all Kibana instances are configured identically.

We recommend using these estimations when following the Task Manager Scaling guidance.

Evaluating the health stats in the previous example, you can see the following output under stats.capacity_estimation.value:

{
  "observed": {
    "observed_kibana_instances": 1, 
    "minutes_to_drain_overdue": 1, 
    "max_throughput_per_minute_per_kibana": 200,
    "max_throughput_per_minute": 200, 
    "avg_recurring_required_throughput_per_minute": 28, 
    "avg_recurring_required_throughput_per_minute_per_kibana": 28,
    "avg_required_throughput_per_minute": 28, 
    "avg_required_throughput_per_minute_per_kibana": 28
  },
  "proposed": {
    "min_required_kibana": 1, 
    "provisioned_kibana": 1, 
    "avg_recurring_required_throughput_per_minute_per_kibana": 28,
    "avg_required_throughput_per_minute_per_kibana": 28
  }
}

The capacity_estimation section is made up of two subsections:

You can infer from these estimates that the current system is under-utilized and has enough capacity to handle many more tasks than it currently does.

Suppose an alternate scenario, where you see the following output under stats.capacity_estimation.value:

{
  "observed": {
    "observed_kibana_instances": 2, 
    "max_throughput_per_minute_per_kibana": 200,
    "max_throughput_per_minute": 400, 
    "minutes_to_drain_overdue": 12, 
    "avg_recurring_required_throughput_per_minute": 354, 
    "avg_recurring_required_throughput_per_minute_per_kibana": 177, 
    "avg_required_throughput_per_minute": 434, 
    "avg_required_throughput_per_minute_per_kibana": 217
  },
  "proposed": {
    "min_required_kibana": 2, 
    "provisioned_kibana": 3, 
    "avg_recurring_required_throughput_per_minute_per_kibana": 118, 
    "avg_required_throughput_per_minute_per_kibana": 145 
  }
}

Evaluating by these estimates, we can infer some interesting attributes of our system:

You can infer from these estimates that the capacity in the current system is insufficient and at least one additional Kibana instance is required to keep up with the workload.

For details on scaling Task Manager, see Scaling guidance.

Problem:

Tasks are not running, and the server logs contain the following error message:

[warning][plugins][taskManager] Task Manager cannot operate when inline scripts are disabled in {es}

Solution:

Inline scripts are a hard requirement for Task Manager to function. To enable inline scripting, see the Elasticsearch documentation for configuring allowed script types setting.

Problem:

Tasks' property runAt is in the past.

Solution:

Wait a bit before declaring it as a lost cause, as Task Manager might just be falling behind on its work. You should take a look at the Kibana log and see what you can find that relates to Task Manager. In a healthy environment you should see a log line that indicates that Task Manager was successfully started when Kibana was:

server log [12:41:33.672] [info][plugins][taskManager][taskManager] TaskManager is identified by the Kibana UUID: 5b2de169-2785-441b-ae8c-186a1936b17d

If you see that message and no other errors that relate to Task Manager, it’s most likely that Task Manager is running fine and has simply not had the chance to pick the task up yet. If, on the other hand, the runAt is severely overdue, then it’s worth looking for other Task Manager or alerting-related errors, as something else may have gone wrong. It’s worth looking at the status field, as it might have failed, which would explain why it hasn’t been picked up or it might be running which means the task might simply be a very long running one.

Problem:

Tasks marked as failed.

Solution:

Broadly speaking the Alerting framework is meant to gracefully handle the cases where a task is failing by rescheduling a fresh run in the future. If this fails to happen, then that means something has gone wrong in the underlying implementation and this isn’t expected. Ideally you should try and find any log lines that relate to this rule and its task, and use these to help us investigate further.

Task manager will write log lines to the Kibana Log on certain occasions. Below are some common log lines and what they mean.

Task Manager has run out of Available Workers:

server log [12:41:33.672] [info][plugins][taskManager][taskManager] [Task Ownership]: Task Manager has skipped Claiming Ownership of available tasks at it has ran out Available Workers.
server log [12:41:33.672] [warn][plugins][taskManager][taskManager] taskManager plugin is now degraded: Task Manager is unhealthy - Reason: setting HealthStatus.Error because of expired hot timestamps

This log message tells us that Task Manager is not managing to keep up with the sheer amount of work it has been tasked with completing. This might mean that rules are not running at the frequency that was expected (instead of running every 5 minutes, it runs every 7-8 minutes, just as an example).

By default Task Manager is limited to 10 tasks and this can be bumped up by setting a higher number in the kibana.yml file using the xpack.task_manager.capacity configuration. It is important to keep in mind that a higher number of tasks running at any given time means more load on both Kibana and Elasticsearch; only change this setting if increasing load in your environment makes sense.

Another approach to addressing this might be to tell workers to run at a higher rate, rather than adding more of them, which would be configured using xpack.task_manager.poll_interval. This value dictates how often Task Manager checks to see if there’s more work to be done and uses milliseconds (by default it is 3000, which means an interval of 3 seconds).

Before changing either of these numbers it’s highly recommended to investigate what Task Manager can’t keep up - Are there an unusually high number of rules in the system? Are rules failing often, forcing Task Manager to re-run them constantly? Is Kibana under heavy load? There could be a variety of issues, none of which should be solved by simply changing these configurations.

Task TaskType failed in attempt to run:

server log [12:41:33.672] [info][plugins][taskManager][taskManager] Task TaskType "alerting:example.always-firing" failed in attempt to run: Unable to load resource ‘/api/something’

This log message tells us that when Task Manager was running one of our rules, it’s task errored and, as a result, failed. In this case we can tell that the rule that failed was of type alerting:example.always-firing and that the reason it failed was Unable to load resource ‘/api/something’ . This is a contrived example, but broadly, if you see a message with this kind of format, then this tells you a lot about where the problem might be.

For example, in this case, we’d expect to see a corresponding log line from the Alerting framework itself, saying that the rule failed. You should look in the Kibana log for a line similar to the log line below (probably shortly before the Task Manager log line):

Executing Rule "27559295-44e4-4983-aa1b-94fe043ab4f9" has resulted in Error: Unable to load resource ‘/api/something’

This would confirm that the error did in fact happen in the rule itself (rather than the Task Manager) and it would help us pin-point the specific ID of the rule which failed: 27559295-44e4-4983-aa1b-94fe043ab4f9

We can now use the ID to find out more about that rule by using the http endpoint to find that rule’s configuration and current state to help investigate what might have caused the issue.