# Help with elapsed time **URL:** \ **Category:** Logstash\ **Created:** [October 3, 2015, 4:49am UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571 "2015-10-03T04:49:25Z")\ **Posts on this page:** 7\ **Page:** 1
**Author:** ![Greppy](https://avatars.discourse-cdn.com/v4/letter/g/8e8cbc/32.png) [@Greppy](https://discuss.elastic.co/u/Greppy)\ **Post date:** [October 3, 2015, 4:49am UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/1 "2015-10-03T04:49:25Z")
For some reason, I can't get the Elapsed time filter to work just right. From the debug log it with logstash 1.5.4 it appears that my start and end event are getting picked up correctly along with the timestamps but the elapsed.time calculation is way off... Any thoughts on where I should look.. IE - Start Time=\>"2015-08-28T07:49:23.334Z" - End Time=\>"2015-08-28T07:49:57.904Z" - Elapsed.timestamp\_start" =\> "2015-08-28T07:49:23.334Z" - **Elapsed.time =\> 3096668.469****?????** Below is an output of debug logs: (removing some lines to reduce the post) **"@timestamp" =\> "2015-08-28T07:49:23.334Z",** "time" =\> "2015-08-28 07:49:23.334", "tags" =\> [ [0] "Time", [1] "Received", [2] "start\_tag" ], "start\_time" =\> "2015-08-28 07:49:23.334", "task\_id" =\> "0eb29fc3-06a6-4f15-a628-c910b9ad08e2", "debug" =\> "timestampMatched" Elapsed, 'end event' received {:end\_tag=\>"end\_tag", :unique\_id\_field=\>"task\_id", :level=\>:info "@version" =\> "1", **"@timestamp" =\> "2015-08-28T07:49:57.904Z",** "time" =\> "2015-08-28 07:49:57.904", "tags" =\> [ [0] "Time", [1] "end\_tag", [2] "elapsed", [3] "elapsed.match" ], "end\_time" =\> "2015-08-28 07:49:57.904", "task\_id" =\> "0eb29fc3-06a6-4f15-a628-c910b9ad08e2", **"elapsed.time" =\> 3096668.469,** "elapsed.timestamp\_start" =\> "2015-08-28T07:49:23.334Z", "debug" =\> "timestampMatched" ---
**Author:** ![Greppy](https://avatars.discourse-cdn.com/v4/letter/g/8e8cbc/32.png) [@Greppy](https://discuss.elastic.co/u/Greppy)\ **Post date:** [October 3, 2015, 5:05am UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/2 "2015-10-03T05:05:16Z")
Also here's a slimmed down version of my config: input { lumberjack {port =\> 5050 type =\> "logs" ssl\_certificate =\> "lumberjack.crt" ssl\_key =\> "lumberjack.key"} } filter{ multiline{ pattern =\> "^\ "previous" negate=\> true } mutate{ gsub=\> ["message","\r\n"," " ] } grok { break\_on\_match =\> false match =\> [ "message", "%{TIMESTAMP\_ISO8601:time}" ] add\_tag =\> "Time" } grok { match =\> ["message", "TRACE date="%{TIMESTAMP\_ISO8601:start\_time}".Received message._(Task: (?\._))"] add\_tag =\> ["start\_tag"] } grok { match =\> ["message", "TRACE date="%{TIMESTAMP\_ISO8601:end\_time}".Processed message._(Task: (?\._))"] add\_tag =\> ["end\_tag"] } elapsed { start\_tag =\> "start\_tag" end\_tag =\> "end\_tag" unique\_id\_field =\> "task\_id" timeout =\> "400" new\_event\_on\_match =\> false } date { timezone =\> "Etc/UCT" match =\> ["time", "YYYY-MM-dd HH:mm:ss.SSS"] target =\> "@timestamp" } } output { elasticsearch { action =\> "index" embedded =\> false embedded\_http\_port =\> "9200-9300" flush\_size =\> 5000 idle\_flush\_time =\> 1 index =\> "logstash-%{+YYYY.MM.dd}" manage\_template =\> true workers =\> 1 host =\> "localhost" } stdout { codec =\> rubydebug } } ---
**Author:** ![inderjeet26](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/inderjeet26/32/3870_2.png) [@inderjeet26](https://discuss.elastic.co/u/inderjeet26)\ **Post date:** [November 30, 2015, 10:34pm UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/3 "2015-11-30T22:34:45Z")
I am having this same issue, while suing the elapsed filter. The time is way off. It should be in seconds, but the number "elapsed\_time" =\> 18694775.362, suggests something very big in my case too!! ---
**Author:** ![DavidL](https://avatars.discourse-cdn.com/v4/letter/d/ecc23a/32.png) [@DavidL](https://discuss.elastic.co/u/DavidL)\ **Post date:** [February 9, 2016, 7:39pm UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/4 "2016-02-09T19:39:07Z")
Hi, I have the same issue, was this ever solved for you? thanks a lot for sharing. ---
**Author:** ![PaddyREC](https://avatars.discourse-cdn.com/v4/letter/p/ee7513/32.png) [@PaddyREC](https://discuss.elastic.co/u/PaddyREC)\ **Post date:** [February 17, 2016, 12:31pm UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/5 "2016-02-17T12:31:04Z")
I too running with same issue, any pointers are greatly appreciated. My log input is "|" separated like and filtering with CSV filter, details below ## Log file - 2015-01-28 07:20:21,517|hostnameA|requestId1|IN 2015-01-28 07:20:22,500|hostnameA|requestId1|OUT 2015-01-28 09:06:38,042|hostnameA|requestId2|IN 2015-01-28 09:06:39,767|hostnameA|requestId2|OUT ## Filter ``` csv{ columns => ["logdate","server","reqid","type"] separator => "|" } if[type] == "IN" { mutate { add_tag => ["serviceStarted"] } } else if[type] == "OUT" { mutate { add_tag => ["serviceTerminated"] } } elapsed { start_tag => "serviceStarted" end_tag => "serviceTerminated" unique_id_field => "reqid" timeout => 10000 new_event_on_match => false } ``` can any one help to identify the time diff b/n one pair of IN & OUT, ---
**Author:** ![jakpol](https://avatars.discourse-cdn.com/v4/letter/j/bbe5ce/32.png) [@jakpol](https://discuss.elastic.co/u/jakpol)\ **Post date:** [October 18, 2016, 12:22am UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/6 "2016-10-18T00:22:44Z")
Hi guys, i solved this issue easly by invoking the filter date before elapsed filter. Otherwise if elapsed is first it will take the first @timestamp for the current date. Hope it helps ---
**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\ **Post date:** [July 6, 2017, 4:33am UTC](https://discuss.elastic.co/t/help-with-elapsed-time/31571/7 "2017-07-06T04:33:52Z")