# Logstash Elapsed filter not working

**URL:** <https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220>\
**Category:** Logstash\
**Created:** [July 20, 2022, 11:14pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220 "2022-07-20T23:14:55Z")\
**Posts on this page:** 10\
**Page:** 1

<div class="post-metadata">

**Author:** ![nakula](https://avatars.discourse-cdn.com/v4/letter/n/d78d45/32.png) [@nakula](https://discuss.elastic.co/u/nakula)\
**Post date:** [July 20, 2022, 11:14pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/1 "2022-07-20T23:14:55Z")

</div>

I am trying to find the different between the start time and end time of a transaction.  
I am using the sample log file as below..

2022-07-17T12:36:30.3081415Z Info 38 [xxx.frame.logging.serviceCols] ["Level3"] : Wires-301 : Start id : **897agsh** : WiresActor created for 301  
2022-07-17T12:38:30.3081415Z Info 38 [xxx.frame.logging.serviceCols] ["Level3"] : Wires-301 : 301started : did something 301  
2022-07-17T12:39:30.3081415Z Info 38 [xxx.frame.logging.serviceCols] ["Level3"] : Wires-301 : 301started : logged something 301  
2022-07-17T12:40:30.3081415Z Info 38 [xxx.frame.logging.serviceCols] ["Level3"] : Wires-301 : 301started : parked in to sideway 301  
2022-07-17T12:42:30.3081415Z Info 38 [xxx.frame.logging.serviceCols] ["Level3"] : Wires-301 : 301started : blocked for sometime 301  
2022-07-17T12:44:30.3081415Z Info 38 [xxx.frame.logging.serviceCols] ["Level3"] : Wires-301 : End id : **897agsh** : aslkjalksjlkjas 301

My intention is to read this log and find the difference of the timestamps. Bolded are the Unique Ids for this sample transaction.

My config file looks as below:

input {  
file {  
path =\> "C:/tools/logstash-8.3.1/config/logs/vv.log"  
start\_position =\> beginning  
sincedb\_path =\> "C:/tools/logstash-8.3.1/config/logs/level\_sincedb"  
}  
}  
filter {   
grok {  
match =\> { "message" =\> "%{TIMESTAMP\_ISO8601:timestamp} %{DATA:loglevel} %{DATA:codeline} [%{DATA:framework}.\<\>c] ["%{DATA:level}"] : %{DATA:symbot} : Start id : %{DATA:id} :" }  
add\_tag =\> "transactionstarted"  
}  
grok {  
match =\> { "message" =\> "%{TIMESTAMP\_ISO8601:timestamp} %{DATA:loglevel} %{DATA:codeline} [%{DATA:framework}] ["%{DATA:level}"] : %{DATA:wire} : End id : %{DATA:id}:" }  
add\_tag =\> "transactionended"  
}  
elapsed {  
start\_tag =\> "transactionstarted"  
end\_tag =\> "transactionended"  
unique\_id\_field =\> "id"  
new\_event\_on\_match =\> true  
}  
date {  
match =\> ["timestamp", ISO8601]  
}  
}  
output {  
elasticsearch { hosts =\> ["localhost:9200"] }  
stdout { codec =\> rubydebug }  
}

I can see the logs in the Kibana but not seeing the elapsed.Time or any other elapsed related fields.

Am I missing something here?

---

<div class="post-metadata">

**Author:** ![nakula](https://avatars.discourse-cdn.com/v4/letter/n/d78d45/32.png) [@nakula](https://discuss.elastic.co/u/nakula)\
**Post date:** [July 20, 2022, 11:32pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/2 "2022-07-20T23:32:27Z")

</div>

By the way, the output looks as below:

 ![image](https://us1.discourse-cdn.com/elastic/original/3X/b/8/b88e100077547bdd70f43f98a70b97cd4bdc1860.png)

---

<div class="post-metadata">

**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:** [July 21, 2022, 12:14am UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/3 "2022-07-21T00:14:06Z")

</div>

You very likely want the date filter before the elapsed filter.

---

<div class="post-metadata">

**Author:** ![Rios](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/rios/32/95745_2.png) [@Rios](https://discuss.elastic.co/u/Rios)\
**Post date:** [July 21, 2022, 1:50pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/4 "2022-07-21T13:50:54Z")

</div>

> [@nakula](#):
>
> filter {  
> grok {  
> match =\> { "message" =\> "%{TIMESTAMP\_ISO8601:timestamp} %{DATA:loglevel} %{DATA:codeline} [%{DATA:framework}.\<\>c] ["%{DATA:level}"] : %{DATA:symbot} : Start id : %{DATA:id} :" }  
> add\_tag =\> "transactionstarted"  
> }  
> grok {  
> match =\> { "message" =\> "%{TIMESTAMP\_ISO8601:timestamp} %{DATA:loglevel} %{DATA:codeline} [%{DATA:framework}] ["%{DATA:level}"] : %{DATA:wire} : End id : %{DATA:id}:" }  
> add\_tag =\> "transactionended"  
> }

Groks are not ok, should be:

```auto
grok {
match => { "message" => "%{TIMESTAMP_ISO8601:timestamp} %{DATA:loglevel} %{DATA:codeline} \[%{DATA:framework}\] \["%{DATA:level}"\] : %{DATA:symbot} : Start id : %{DATA:id}: %{GREEDYDATA:info}" }
add_tag => "transactionstarted"
}
grok {
match => { "message" => "%{TIMESTAMP_ISO8601:timestamp} %{DATA:loglevel} %{DATA:codeline} \[%{DATA:framework}\] \["%{DATA:level}"\] : %{DATA:wire} : End id : %{DATA:id} : %{GREEDYDATA:info}" }
add_tag => "transactionended"
}

```

---

<div class="post-metadata">

**Author:** ![nakula](https://avatars.discourse-cdn.com/v4/letter/n/d78d45/32.png) [@nakula](https://discuss.elastic.co/u/nakula)\
**Post date:** [July 21, 2022, 5:58pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/5 "2022-07-21T17:58:21Z")

</div>

Yes, I have corrected the grok filter and I am not seeing any grok parse errors.

With elapsed filter, I am expecting to see the time difference between 2 log lines (which make a transaction with a unique id), but I am not seeing the elapsed time.

It shows a tag "elapsed\_end\_without\_start" for the transactionended log.

 ![image](https://us1.discourse-cdn.com/elastic/original/3X/2/7/27a1eb13a4ae360bdf8c0568b83414b535c9df5d.png)

Why am I not seeing elapsed time even if the two log lines are more than 10 seconds apart?

---

<div class="post-metadata">

**Author:** ![nakula](https://avatars.discourse-cdn.com/v4/letter/n/d78d45/32.png) [@nakula](https://discuss.elastic.co/u/nakula)\
**Post date:** [July 21, 2022, 5:59pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/6 "2022-07-21T17:59:15Z")

</div>

Yes, I have moved it.

---

<div class="post-metadata">

**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:** [July 21, 2022, 6:58pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/7 "2022-07-21T18:58:52Z")

</div>

> [@nakula](#):
>
> new\_event\_on\_match =\> true

The elapsed time is not added to the end event, a new event is [created](https://github.com/logstash-plugins/logstash-filter-elapsed/blob/49a94536188acae0209f2dda4e163f68b8515bee/lib/logstash/filters/elapsed.rb#L238) that contains the start timestamp, the id, the elapsed time, and the tags "elapsed" and "elapsed\_match".

---

<div class="post-metadata">

**Author:** ![nakula](https://avatars.discourse-cdn.com/v4/letter/n/d78d45/32.png) [@nakula](https://discuss.elastic.co/u/nakula)\
**Post date:** [July 21, 2022, 7:48pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/8 "2022-07-21T19:48:30Z")

</div>

hi badger,  
where can I see that new event?  
How do I search for it?

---

<div class="post-metadata">

**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:** [July 21, 2022, 8:02pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/9 "2022-07-21T20:02:37Z")

</div>

Search for an event with the tag "elapsed\_match".

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [August 18, 2022, 8:03pm UTC](https://discuss.elastic.co/t/logstash-elapsed-filter-not-working/310220/10 "2022-08-18T20:03:37Z")

</div>

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