# Aggregate filter plugin - timeout function bug **URL:** \ **Category:** Logstash\ **Created:** [October 11, 2021, 3:21pm UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383 "2021-10-11T15:21:59Z")\ **Posts on this page:** 8\ **Page:** 1
**Author:** ![MarcelOs](https://avatars.discourse-cdn.com/v4/letter/m/b5e925/32.png) [@MarcelOs](https://discuss.elastic.co/u/MarcelOs)\ **Post date:** [October 11, 2021, 3:21pm UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/1 "2021-10-11T15:21:59Z")
Hello everyone, I have some problems with the Timeout command from the aggregate filter plugin. I want to create a script that calculates the meantime between two log entries. There are examples of such a function ([https://www.elastic.co/guide/en/logstash/current/plugins-filter-aggregate.html#Plugins-filter-Aggregate-Example1](https://www.elastic.co/guide/en/logstash/current/plugins-filter-aggregate.html#Plugins-filter-Aggregate-Example1)). That has worked as far as possible. However, in order to save resources, I would like to use a timeout so that long intermediate times are canceled and -1 is given back. In most cases that works too. However, there is partly the situation where the Timeout command did not work. In the following I have an exemplary script for displaying the error: ```auto filter { #match My TestInputs grok { match => ["message", "%{NOTSPACE:id} - %{NOTSPACE:status}"] } # the Startpoint if ([status] == "start") { aggregate { task_id => "%{id}" code => "map['duartion_map'] = (event.get('@timestamp').to_f*1000).to_i" map_action => "create" timeout => 1 } } # the Endpoint if [status] == "end" { #Fill the field duration_field, so that is filled every time, even if the time difference is over the timeout mutate{ add_field => {duration_field => "-1"} } aggregate { task_id => "%{id}" code => "event.set('duration_field', (event.get('@timestamp').to_f*1000).to_i - map['duartion_map'])" map_action => "update" end_of_task => true } } } ``` I have entered a successive of the following records, for testing: 1 - Start. 1 - end 2 - Start. 2 - end ![Console Output Screenshot](https://us1.discourse-cdn.com/elastic/original/3X/8/9/89c8d350b923fdc1963f7a252a89dba29b69cbaf.png) However, when the script is issued, you can see that the timeout command has not worked for the second time, although nothing has been changed in the source code, and the logstash test server was not restarted. This problem can not be precisely reproduced and randomly occurs. I already had console outputs, which were about 1.5 seconds apart with the timeout worked. Does anyone know the problem and knows an idea that I can try to solve the problem? Kind regards ---
**Author:** ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)\ **Post date:** [October 11, 2021, 4:59pm UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/2 "2021-10-11T16:59:37Z")
> [@MarcelOs](#): > > `timeout => 1` The timeout is implemented using the [flush](https://github.com/logstash-plugins/logstash-filter-aggregate/blob/b333e4a73ee8b68711cf7287797d792e81a1014f/lib/logstash/filters/aggregate.rb#L317) method, which is called by logstash every five seconds, so if you set timeout to 1, the effective value will be anywhere from 1 to 5 seconds. ---
**Author:** ![MarcelOs](https://avatars.discourse-cdn.com/v4/letter/m/b5e925/32.png) [@MarcelOs](https://discuss.elastic.co/u/MarcelOs)\ **Post date:** [October 27, 2021, 1:03pm UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/3 "2021-10-27T13:03:45Z")
Thank you badger. Unfortunately, I realized that this wasn't my solution. I tried to set the timeout to 10 seconds and what can I say. Sometimes it works and sometimes logstash just ignores my timeout. For more information see code and log below: ```auto filter { #match My TestInputs grok { match => ["message", "%{NOTSPACE:id} - %{NOTSPACE:status}"] } # the Startpoint if ([status] == "start") { aggregate { task_id => "%{id}" code => "map['duartion_map'] = (event.get('@timestamp').to_f*1000).to_i" map_action => "create" timeout => 10 } } # the Endpoint if [status] == "end" { #Fill the field duration_field, so that is filled every time, even if the time difference is over the timeout mutate{ add_field => {duration_field => "-1"} } aggregate { task_id => "%{id}" code => "event.set('duration_field', (event.get('@timestamp').to_f*1000).to_i - map['duartion_map'])" map_action => "update" end_of_task => true } } } ``` And my output looks like ![Timeout Fail](https://us1.discourse-cdn.com/elastic/original/3X/0/6/06a1fccd4a8ba7092b5967cea4977c1804d4f9b8.png) What went wrong? Any idea? ---
**Author:** ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)\ **Post date:** [October 27, 2021, 3:41pm UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/4 "2021-10-27T15:41:05Z")
> [@MarcelOs](#): > > What went wrong? Any idea? Once again, the timeout is evaluated by a function that is called every five seconds. So a ten second timeout will actually be somewhere between 10 and 15 seconds. ---
**Author:** ![MarcelOs](https://avatars.discourse-cdn.com/v4/letter/m/b5e925/32.png) [@MarcelOs](https://discuss.elastic.co/u/MarcelOs)\ **Post date:** [October 28, 2021, 6:59am UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/5 "2021-10-28T06:59:00Z")
Ok thanks I understand. Then an example from another system. In this case, sometimes it happens that the timeout command does not work. Usually the timeout is set to 120 seconds. If this is exceeded, the "edi\_basic\_latency" field is set to 120000. This seems to work so far as the most common value by far is 120000, as shown below. ![Top values](https://us1.discourse-cdn.com/elastic/original/3X/4/1/411828b5b44ad4d81b56cb9950576ebaf8ecd0c6.png) In the following example you can now see that there are some records that are well over 120 seconds long. In this case at 180 seconds! ![Timeout](https://us1.discourse-cdn.com/elastic/original/3X/a/c/acf087bf2a57d2feb625ab3daf45e54846d33cc2.png) So what is the problem in this case? It is much more than 120seconds plus 5 seconds. ---
**Author:** ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)\ **Post date:** [October 28, 2021, 5:29pm UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/6 "2021-10-28T17:29:41Z")
If the aggregate timeout is set to 120 seconds I cannot think of a reason why it would take more than 125 seconds to fire. ---
**Author:** ![MarcelOs](https://avatars.discourse-cdn.com/v4/letter/m/b5e925/32.png) [@MarcelOs](https://discuss.elastic.co/u/MarcelOs)\ **Post date:** [October 29, 2021, 7:22am UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/7 "2021-10-29T07:22:44Z")
Maybe it is possible to change the update time so that the flush method doesn't call every 5 seconds? And if yes how can i check/change the update time from the flush method? ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [November 26, 2021, 7:22am UTC](https://discuss.elastic.co/t/aggregate-filter-plugin-timeout-function-bug/286383/8 "2021-11-26T07:22:47Z")
This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.