[ML] Data frame silently fails to index if aggs return a string

[sophiec20]

Found in 7.2.0-BC5

The following data frame preview contains a typo in responsetime. Composite aggs returns avg(resposetime) as a string "NaN" .

GET _data_frame/transforms/_preview
{
  "id": "farequote-airline-100",
  "source" : { "index": [ "farequote-*" ] },
  "dest"     : {  "index": "df-farequote-airline-100" },
  "pivot": {
    "group_by": {
      "airline": { "terms": { "field": "airline" }}
    },
    "aggregations": {
      "last_updated": { "max": { "field": "@timestamp" } },
      "mean_response": { "avg": {  "field": "resposetime" } },
      "count": { "value_count": { "field": "airline" } }
    }
  }
}

returns

{
  "preview" : [
    {
      "last_updated" : "2019-02-11T23:59:02.000Z",
      "count" : 8728.0,
      "mean_response" : "NaN",
      "airline" : "AAL"
    },
...

The data frame silently fails to index these values resulting in an entirely empty dest index.

However there are no errors in elasticsearch logs. There are no warnings or errors in data frame notifications, and the stats make it appear that the data frame transform was successful.

{
  "count" : 1,
  "transforms" : [
    {
      "id" : "farequote-airline-100",
      "state" : {
        "task_state" : "stopped",
        "indexer_state" : "stopped",
        "checkpoint" : 1,
        "progress" : {
          "total_docs" : 86274,
          "docs_remaining" : 0,
          "percent_complete" : 100.0
        }
      },
      "stats" : {
        "pages_processed" : 2,
        "documents_processed" : 86274,
        "documents_indexed" : 19,
        "trigger_count" : 1,
        "index_time_in_ms" : 136,
        "index_total" : 1,
        "index_failures" : 0,
        "search_time_in_ms" : 25,
        "search_total" : 2,
        "search_failures" : 0
      },
      "checkpointing" : {
        "operations_behind" : 0
      }
    }
  ]
}

We require better handling for these errors under conditions such as when:

1. something like a typo causes complete failure of the data frame (note, if the other aggs worked, perhaps this should have completed without resposetime)
2. aggregations may sporadically return strings (NaN or Infinity) .. these should not silently fail. Is it possible to keep counts of these as index_failures or other stat?

Messages should additionally be logged to data frame notifications, where appropriate, to ease operational management.

[elasticmachine]

Pinging @elastic/ml-core

[davidkyle]

The data frame silently fails to index these values resulting in an entirely empty dest index.

I can't reproduce this on master or the 7.2 bc6. I can see documents written to the index with a null value for the mean_respose field:

      "_source" : {
          "last_updated" : null,
          "count" : 8728.0,
          "mean_response" : null,
          "airline" : "AAL"
        }

[sophiec20]

I'll retry on BC6.

Note that we have also seen silent failures when the deduced mapping was half_float and the sum(value) overflowed. cc @benwtrent

[benwtrent]

@sophiec20 yes, 7.3 is now writing an audit when there are bulk indexing issues. If desired, it can be backported to 7.2. However, I am not sure that is necessary because the UI is not displaying audit messages yet.

[sophiec20]

@benwtrent Not worth a backport to 7.2 at this time. Do these failures get counted by _stats?

[benwtrent]

@sophiec20 no, it will only write a warning log entry.

[benwtrent]

For the sum specific issue: #43213
Alerting when there are bulk index issues: #43106
Handling null values better for aggs: #42966

@sophiec20 and @davidkyle I think these three PRs address the concerns in this issue.

[sophiec20]

@benwtrent yes, those 3 PRs do address many of the concerns around silently failing..

Before we close this I have one more question, under what conditions does stats index_failures get incremented?

[benwtrent]

index_failures gets incremented if there is an exception thrown during the bulk indexing process. I am not 100% sure why this type of behavior is the way it is, but the Rollups folks may have better input as to why we don't count a bulk indexing failure as an index_failure (it seems to me like we should).

[benwtrent]

@polyfractal @jimczi what do y'all think? Should BulkIndex failures increment the index_failure statistic for the AsyncTwoPhaseIndexer? It seems to me like they should. Otherwise there is no obvious indication that such a failure happened.

[jimczi]

Should BulkIndex failures increment the index_failure statistic for the AsyncTwoPhaseIndexer?

I am not sure because it currently contains the number of times that the job failed due to a failure in bulk indexing. If the entire bulk request fails we stop the job and increment the counter whereas if only individual documents failed we ignore and continue the processing. So maybe we should treat all indexing errors as fatal and stop the job ? Most of these errors should be transient so resuming a job a with a backoff policy should be enough. For rollups it is acceptable to loose some documents (debatable but we've made this decision long time ago ;)) but there is no way to go back in time to replay those missing documents so I'd prefer to fail rather than incrementing a counter and move to indexer state.