Throttle filter picking up old instead of new value

[Sjaak01 (Sjaak)]

Hi,

I'm struggling a bit with the throttle filter. After the period expires I expect the throttle filter to save the first new event, but instead its saving the last old event.

input {
  file {
    path => "/home/test/Desktop/test/kvh/test.txt"
    sincedb_path => "/dev/null"
    start_position => "beginning"
}
}


filter {


  mutate {
    gsub => [
      "message", "[+$>*]", ""
    ]
  }


	grok { 
		match => { "message" => [ 
				"%{GREEDYDATA:TIME} GPRMC,%{GREEDYDATA:GPS}"
					] }

		tag_on_failure => [ grok_failure" ] 
	     }


if "grok_failure" in [tags] {
  drop { }
}


mutate {
  add_field => {
    "GPRMC" => "%{TIME} GPRMC,%{GPS}"
  }
  remove_field => ["TIME", "GPS", "path", "@version", "host", "message"]
}


  throttle {
    before_count => -1
    after_count => 1
    period => 60
    max_age => 180
  	key => "GPRMC"
   	add_tag => "throttled"
  }
  if "throttled" in [tags] {
    drop { }
  }
}

Ignore the grok filter for a moment and lets say me input is error1, error2 etc.

What I see happening is this:

• I have a empty file and start logstash.
• I copy error1 to the file. Error1 appears in stdout, this is correct.
• I paste error1 again within 60 seconds, nothing appears, I paste error2 within one minute, nothing appears. This is correct.
• 60+ seconds after I pasted the first error1 I paste error3 into the file. Error2 appears in the output.

I don't believe this is correct and instead want the first value after throttle period has passed to be logged and not the last value from the previous period.

What am I doing wrong? I tried changing beginning to end and the sincedb path in the file input just in case but that doesn't appear to be the issue. As far as I can tell the throttle filter is correct.

[Sjaak01 (Sjaak)]

I've made a test script that generates random data for testing. I've noticed that besides the issue described above the 60 second period is also not always respected and in some instances events get through even though 60 seconds hasn't passed yet.

stdout

         "GPRMC" => "2018-01-06 13:23:45 GPRMC,073126.000,C,3444.4604,C,13521.2644,C,0.15,116.79,261217,,,D64",
    "@timestamp" => 2018-01-06T04:23:45.890Z
}
{
         "GPRMC" => "2018-01-06 13:24:42 GPRMC,073126.000,C,3444.4604,C,13521.2644,C,0.11,116.79,261217,,,D64",
    "@timestamp" => 2018-01-06T04:24:43.021Z