Elapsed filter. Broken?

[Kryten]

Hi,

One of the most useful filters for my use case is 'elapsed'. We made heavy use of it in our older Logstash configurations.

However in our testing with LS 2.3.x and 2.4.x the behaviour of the elapsed filter is, at best, unreliable. We are seeing lots of instances of the close event being recorded as not having a starting event. Even though the start tag event IS there and was seemingly processed ok.

It's pretty catastrophic.

We've tried running on one worker filter thread and we've ensured that periodic flush is set to true... but it still happens. No rhyme or reason why. The occasional event is handled properly ... but the vast majority of the time the elapsed_time field is lost.

Does anyone know of any reliable workarounds?

As it stands we may now need to develop something to extract the starting document from ES then extract the subsequent documents for the closing tags, do some dateline calcs on the time stamps from each then post results back... but it'll be slow!

Would be grateful for any thoughts, suggestions or workarounds. Thanks.

[pierhugues (Pier-Hugues Pellerin)]

Hello @Kryten,

This seems a weird behavior to me, at first look the code look threadsafe to me so it should work with multiple workers. If you look at the problematic events, any tags associated with them?

The plugin usually tag the event when a flush or an error occur.

  ELAPSED_TAG = "elapsed"
  EXPIRED_ERROR_TAG = PREFIX + "expired_error"
  END_WITHOUT_START_TAG = PREFIX + "end_without_start"
  MATCH_TAG = PREFIX + "match"