# Calculate time difference between two log lines - Logstash

**URL:** <https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284>\
**Category:** Logstash\
**Created:** [December 17, 2021, 9:31am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284 "2021-12-17T09:31:08Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![giancringo](https://avatars.discourse-cdn.com/v4/letter/g/f05b48/32.png) [@giancringo](https://discuss.elastic.co/u/giancringo)\
**Post date:** [December 17, 2021, 9:31am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284/1 "2021-12-17T09:31:08Z")

</div>

Hello,  
I'm looking for a solution to calculate the difference between two time on two different log lines as below:

```auto
2020-06-11 15:31:22,817 [http-8080-0] INFO it.example.sign.sign.SignTool - [TYPE] trackingID: x12e65r7-0uggr56-jhgdxc-oij78hf5-12345rtyu @ 15:31:22.817000000, progress method opensession
2020-06-11 15:31:23,817 [http-8080-0] INFO it.example.sign.sign.SignTool - [TYPE] trackingID: x12e65r7-0uggr56-jhgdxc-oij78hf5-12345rtyu @ 15:31:23.617000000, completed method opensession

```

This is my grok filter that match the log lines:

```auto
%{DATE_EU:date} %{TIME:hour} \[%{GREEDYDATA:protocol_port}\] %{LOGLEVEL:log-level} %{GREEDYDATA:message} ( )?- (\[%{GREEDYDATA:type}\] )?trackingID: %{DATA:trackingID} @ %{TIME:method_time}, %{DATA:method_state} %{GREEDYDATA:message} %{USER:method_type}

```

I tried to match the time with the date filter and to use the elapsed filter but it didn't work.

Are there any solution to achieve my goal using elapsed or a ruby script?

---

<div class="post-metadata">

**Author:** ![AquaX](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/aquax/32/92006_2.png) [@AquaX](https://discuss.elastic.co/u/AquaX)\
**Post date:** [December 18, 2021, 11:21pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284/2 "2021-12-18T23:21:27Z")

</div>

Elapsed is the right filter to use for this...however there has to be a field that is unique and common to the thread in order for that to work properly (ie a thread or process number) plus you need to be able to define the start and stop.

Also, I would recommend changing "GREEDYDATA" to something more specific as GREEDYDATA is quite resource intensive. Use "NOTSPACE" or "DATA" if you can.

---

<div class="post-metadata">

**Author:** ![AquaX](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/aquax/32/92006_2.png) [@AquaX](https://discuss.elastic.co/u/AquaX)\
**Post date:** [December 18, 2021, 11:21pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284/3 "2021-12-18T23:21:55Z")

</div>

Can you post your logstash config including the elapsed config?

---

<div class="post-metadata">

**Author:** ![giancringo](https://avatars.discourse-cdn.com/v4/letter/g/f05b48/32.png) [@giancringo](https://discuss.elastic.co/u/giancringo)\
**Post date:** [December 20, 2021, 9:48am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284/4 "2021-12-20T09:48:58Z")

</div>

> [@AquaX](#):
>
> NOTSPACE"

Hi,  
thank you for the answer and for the advice.

Here my logstash config file:

```auto
input {
  file {
   path => "/home/elastic/grok_test/one_line.log"
   start_position => "beginning"
   sincedb_path => "/dev/null"
  }
}
filter {
   grok {
        match => ["message", "%{DATE_EU:date} %{TIME:hour} \[%{GREEDYDATA:protocol_port}\] %{LOGLEVEL:log-level} %{GREEDYDATA:message} ( )?- (\[%{GREEDYDATA:type}\] )?trackingID: %{DATA:trackingID} @ %{TIME:method_time}, %{DATA:method_state} %{GREEDYDATA:message} %{USER:method_type}"]
        add_tag => ["%{method_state}"]
        add_field => { "[@metadata][ts]" => "%{date} %{hour}" }
   }
date { match => ["[@metadata][ts]", "ISO8601" ] }
elapsed {
    unique_id_field => "trackingID"
    start_tag => "progress"
    end_tag => "completed"
    add_tag => ["time_elapsed"]
  }
  if "time_elapsed" in [tags] {
        ruby { code => 'event.set("elapsed_time_ms", 1000.0 * event.get("elapsed_time"))' }
    }
}
output { stdout { codec => rubydebug } }

```

---

<div class="post-metadata">

**Author:** ![AquaX](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/aquax/32/92006_2.png) [@AquaX](https://discuss.elastic.co/u/AquaX)\
**Post date:** [December 22, 2021, 2:56pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284/5 "2021-12-22T14:56:34Z")

</div>

> [@giancringo](#):
>
> ```auto
> add_field => { "[@metadata][ts]" => "%{date} %{hour}" }
> }
> date { match => ["[@metadata][ts]", "ISO8601" ] }
> 
> ```

I'm pretty sure this is your problem

Going from your example  
`%{date} %{hour}` would evaluate to: `20-06-11 15:31:23,817` which is NOT ISO8601 format.  
Change your date filter to: `date { match => ["[@metadata][ts]", "yy-MM-dd HH:mm:ss,SSS" ] }`

---

<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:** [January 19, 2022, 2:56pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-two-log-lines-logstash/292284/6 "2022-01-19T14:56:45Z")

</div>

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