# Calculate time difference between 2 lines in log file

**URL:** <https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684>\
**Category:** Logstash\
**Created:** [March 25, 2019, 8:01am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684 "2019-03-25T08:01:30Z")\
**Posts on this page:** 7\
**Page:** 1

<div class="post-metadata">

**Author:** ![Thibaut\_M](https://avatars.discourse-cdn.com/v4/letter/t/d6d6ee/32.png) [@Thibaut\_M](https://discuss.elastic.co/u/Thibaut_M)\
**Post date:** [March 25, 2019, 8:01am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/1 "2019-03-25T08:01:30Z")

</div>

Hi everyone,

I retrived a log file that look like this :

```
2019-03-07 04:35:57.421 19EC | INFO ROOT: (Netto2600-Brutto2608)AllocatedBlockCount=0
2019-03-07 04:35:57.421 19EC | INFO ROOT: (Netto2600-Brutto2608)ReservedAddressSpace=0
2019-03-07 04:35:57.421 19EC | INFO TIMEDATA.DLL: Capacity allocated: Hashtable entries 20648881, Heap mem 805306368
2019-03-07 04:35:57.421 19EC | INFO DPREAD: Data import started: 07.03.19 04:35:57
2019-03-07 04:35:57.421 19EC | INFO DPREAD: Importing file: C:\path\to\file1
2019-03-07 04:35:57.452 19EC | INFO DPREAD: Completed importing file: C:\path\to\file1
2019-03-07 04:35:57.452 19EC | INFO DPREAD: Importing file: C:\path\to\file2
2019-03-07 04:36:43.545 19EC | INFO DPREAD: Completed importing file: C:\path\to\file2
2019-03-07 05:38:55.332 19EC | INFO TMDPDATA-INIT: Datasupply info: vwdpm.dcsDefault.2.0
2019-03-07 05:38:55.520 19EC | DEBUG TMDPDATA-GETFILEDATE: MdpFileIdentifier=[+]
2019-03-07 05:38:55.520 19EC | DEBUG TMDPDATA-GETFILEDATE: FileDate=[06.03.19]

```

What i want to do is to calculate the difference between the time of "Importing file" and "Completed importing". Could somone help me on this? Should i use logstash filter (like aggregate or elapsed)? Is this done directly in filebeat?

Thank you for your help 🙂

---

<div class="post-metadata">

**Author:** ![BennyInc](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/bennyinc/32/21751_2.png) [@BennyInc](https://discuss.elastic.co/u/BennyInc)\
**Post date:** [March 25, 2019, 10:02am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/2 "2019-03-25T10:02:43Z")

</div>

For Logstash the [elapsed filter plugin](https://www.elastic.co/guide/en/logstash/current/plugins-filters-elapsed.html) would be what you're looking for.  
You need to add tags to your events (start/end) and an ID (maybe your file name?) via some other filter means (possibly a grok or better yet [dissect filter](https://www.elastic.co/guide/en/logstash/current/plugins-filters-dissect.html)).

Filebeat cannot do that, you'd need to do this in an ingest pipeline instead. However I think there is no equivalent processor available so far: [https://www.elastic.co/guide/en/elasticsearch/reference/master/ingest-processors.html](https://www.elastic.co/guide/en/elasticsearch/reference/master/ingest-processors.html)

---

<div class="post-metadata">

**Author:** ![Thibaut\_M](https://avatars.discourse-cdn.com/v4/letter/t/d6d6ee/32.png) [@Thibaut\_M](https://discuss.elastic.co/u/Thibaut_M)\
**Post date:** [March 25, 2019, 12:18pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/3 "2019-03-25T12:18:27Z")

</div>

Hello BennyInc

I tried something like this :

```
grok {
	match => ["message", "%{DATE_EU:date} %{TIME:hour} +%{DATA:test} \| %{LOGLEVEL:level} +%{DATA:type}: +%{DATA:state_import}: %{GREEDYDATA:url}"]
	add_tag => ["%{state_import}"]
}

elapsed {
    unique_id_field => "test"
    start_tag => "Importing file"
    end_tag => "Completed importing file"
    add_tag => ["time_elapsed"]
  }
  
   if "time_elapsed" in [tags] {
    aggregate {
      task_id => "%{test}"
      code => "map['report'] = (event.get('elapsed_time')*1000).to_i"
      map_action => "create"
    }
} 

```

But in Kibana, i have "elapsed\_time" but it is set to 0, which should be not 0 and the time difference

---

<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:** [March 25, 2019, 2:43pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/4 "2019-03-25T14:43:38Z")

</div>

You need to parse the timestamp from the log before trying to use it in the elapsed filter.

```
    grok {
        match => ["message", "%{DATE_EU:date} %{TIME:hour} +%{DATA:test} \| %{LOGLEVEL:level} +%{DATA:type}: +%{DATA:state_import}: %{GREEDYDATA:url}"]
        add_tag => ["%{state_import}"]
        add_field => { "[@metadata][ts]" => "%{date} %{hour}" }
    }
    date { match => ["[@metadata][ts]", "ISO8601" ] }

```

What are you hoping to do with the aggregate filter?

---

<div class="post-metadata">

**Author:** ![Thibaut\_M](https://avatars.discourse-cdn.com/v4/letter/t/d6d6ee/32.png) [@Thibaut\_M](https://discuss.elastic.co/u/Thibaut_M)\
**Post date:** [March 26, 2019, 7:09am UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/5 "2019-03-26T07:09:42Z")

</div>

Hi,

I follow this link : [https://stackoverflow.com/questions/37353365/calculating-time-between-events/37359000](https://stackoverflow.com/questions/37353365/calculating-time-between-events/37359000)

My aggregate filter will take the elapsed\_time and will convert it to ms. Is it useless to have an aggregate filter in my case?

Thank you for your help

---

<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:** [March 26, 2019, 2:10pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/6 "2019-03-26T14:10:46Z")

</div>

> [@Thibaut\_M](#):
>
> My aggregate filter will take the elapsed\_time and will convert it to ms. Is it useless to have an aggregate filter in my case?

If you just want to convert seconds to millisecond a ruby filter will do it.

```
    if "time_elapsed" in [tags] {
        ruby { code => 'event.set("elapsed_time_ms", 1000.0 * event.get("elapsed_time"))' }
    }

```

In that stackoverflow answer the re-write of the initial solution using the event API is missing an essential event.set, so the aggregate filters are not doing anything.

---

<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:** [April 23, 2019, 2:10pm UTC](https://discuss.elastic.co/t/calculate-time-difference-between-2-lines-in-log-file/173684/7 "2019-04-23T14:10:49Z")

</div>

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