Seeing number_format_exception on a non-numeric data field

[enyuhsu]

Our production logstash has been working for months until 7/13, starting almost exactly at 6pm UTC (the timestamp is significant).

The error message we saw was:
Failed action. {:status=>400, :action=>["index", {:_id=>nil, :_index=>"logstash-2017.07.13", :_type=>"api", :_routing=>nil}, 2017-07-13T20:59:03.000Z 0:0:0:0:0:0:0:1 1499979543 a], :response=>{"create"=>{"_index"=>"logstash-2017.07.13", "_type"=>"api", "_id"=>"AV1W1bbXW-ZGHDu61hrH", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"failed to parse [view]", "caused_by"=>{"type"=>"number_format_exception", "reason"=>"For input string: \"places\""}}}}}

The error then mysteriously stopped by itself 6 hours later, at around midnight.

I extracted one of the logs from that time range and ran it through logstash locally, and realized something strange.

Here's my logstash filter:

filter {
  grok {
    match => { "message" => "%{INT:timestamp}	%{GREEDYDATA:view}" }
  }
  date {
    match => [ "timestamp", "UNIX" ]
  }
}

This log fails:
1499979543 places and produces the above error.

However, changing any one of these small details causes logstash to pass the log correctly, including:

1. Changing the timestamp input to be outside of the 7/13 6pm-11:59pm UTC time range. For example 1499879543 places gets parsed correctly (notice one of the 9s became an 8).
2. Changing the field name view to something else, e.g. views or vie.
3. Removing the date filter
4. Changing the data type of view from GREEDYDATA to INT and replacing places in the log to a number.

We are using logstash version 2.3.2.

Does anyone have any idea what's going on here?

[paz]

This is not a Logstash error, it's an ElasticSearch error that gets propagated back to Logstash.
It stopping around midnight also points to that direction, since that's when the new index is created (as you use daily indices).

Do you use a preset mapping/template on ElasticSearch or did you leave it dynamic so it handles the mapping on it's own?

[enyuhsu]

Ah, you're totally right! Thanks! Our template is dynamic. How could that have caused this issue?

[paz]

With dynamic mapping, the type for each field in each index is decided upon the first time a document with that field is received.
When ElasticSearch receives a document with a field seen for the first time in an index, it decides whether it is a string/integer/date/etc. and applies the appropriate mapping.

So in your case, the first value for the view field that got indexed on 2017/07/13 could look like a number and ElasticSearch decided it is a number.
At some point, obvious non-number values were sent to it and it threw those exceptions. That's why the error went away when a) you changed the field name, and) the daily index itself changed.

You can always define your strict templates/mappings for indices in order to avoid future errors.