Elastic Stack 7.0 date_time_parse_exception

Not sure what happened, but overnight I started getting this logged constantly in my Logstash-plain.log. No changes have been made in the last week or two since upgrading everything to version 7. About 3k entries in the log for this over the course of 10 hours. Ingesting about 1,200e/s so this isn't incredibly frequent but it's still a lot.

[2019-07-02T00:00:13,517][WARN ][logstash.outputs.elasticsearch] Could not index event to Elasticsearch. {:status=>400, :action=>["index", {:_id=>nil, :_index=>"winlogbeat-7.1.1-2019.07.02", :_type=>"_doc", :routing=>nil}, #<LogStash::Event:0x770c96bf>], :response=>{"index"=>{"_index"=>"winlogbeat-7.1.1-2019.07.02", "_type"=>"_doc", "_id"=>"2tUOsWsB57SKtg8xAFFT", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"failed to parse field [winlog.event_data.param1] of type [date] in document with id '2tUOsWsB57SKtg8xAFFT'", "caused_by"=>{"type"=>"illegal_argument_exception", "reason"=>"failed to parse date field [Application Experience] with format [strict_date_optional_time||epoch_millis]", "caused_by"=>{"type"=>"date_time_parse_exception", "reason"=>"Failed to parse with all enclosed parsers"}}}}}}

Assuming you rotate indexes daily, and do not have a mapping template that defines all the fields, elasticsearch will index the very first event of the day and build its own mapping. If the first event has a field called [winlog][event_data][param1] that looks like a date, then elasticsearch will expect every subsequent event to also have a date in that field.

The fix would be to create a template that tells elasticsearch to expect a string in that field.

I guess including my output pipeline would have helped. Is it possible this is happening because I am using 7.1.1 agents with 7.0 Elastic Stack? It was an oversight when I downloaded and deployed the agents.

  elasticsearch {
    id => "Beat Output"
    hosts => "192.168.1.0:9200"
    template_overwrite => true
    index => "%{[@metadata][beat]}-%{[@metadata][version]}-%{+YYYY.MM.dd}" 
  }

So is there a way to resolve this? I tried the below and it threw an error.

PUT winlogbeat-7.1.1-2019.07.02/_mapping
{
  "properties": {
    "winlog": {
      "properties": {
        "event_data": {
          "properties": {
            "param1": {
              "type": "text",
              "fields": {
                "keyword": {
                  "type": "keyword"
                }
              }
            }
          }
        }
      }
    }
  }
}
{
  "error": {
    "root_cause": [
      {
        "type": "illegal_argument_exception",
        "reason": "mapper [winlog.event_data.param1] of different type, current_type [date], merged_type [text]"
      }
    ],
    "type": "illegal_argument_exception",
    "reason": "mapper [winlog.event_data.param1] of different type, current_type [date], merged_type [text]"
  },
  "status": 400
}

I don't think you can change the mapping without re-indexing. Basically you need the mapping to be in a template which will get applied when the index rolls over, before any new mappings are inferred from arriving data.

Ok, so I changed my elasticsearch output index so that a new index is generated. I've verified the new index has a proper mapping of text. In addition, I've created a new template to resolve future indices that are created.

How do I tell Elasticsearch to reindex the previous, "bad index" into a new index using the new template?

Well, if you have the original source data, then run it through logstash again. If not you can use logstash with an elasticsearch input to copy data from the old index to the new.

Source data comes from Winlogbeat and extremely noisey DC logs, about 200MBs gets cycled through every 15 minutes. Our noisest server has already generated 40 million events today.

I will take a look at the elasticsearch input and see what I can do, since we only keep these records for a short time, it may not even be worth it.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.