# Calculate elapsed time without "start" or "end" message

**URL:** https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734
**Category:** Logstash
**Created:** [June 16, 2017, 2:54pm UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734 "2017-06-16T14:54:45Z")
**Posts on this page:** 6
**Page:** 1

<div class="post-metadata">

### Author: ![abrejuin](https://avatars.discourse-cdn.com/v4/letter/a/cab0a1/32.png) [@abrejuin](https://discuss.elastic.co/u/abrejuin)
#### Post date: [June 16, 2017, 2:54pm UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734/1 "2017-06-16T14:54:46Z")

</div>

Hello,

I have some logs generated by a jobs.  
Each job occur have a unique id but there is no specific start message and no specific end message.

I am wondering how can I measured elapsed time between first and last log with a unique id.

I took a look on Elapsed and aggregate plugin but I don't think I can do what I want with those plugins.

Thanks a lot for your help.

Best regards,  
Antoine

---

<div class="post-metadata">

### Author: ![Kryten](https://avatars.discourse-cdn.com/v4/letter/k/58956e/32.png) [@Kryten](https://discuss.elastic.co/u/Kryten)
#### Post date: [June 16, 2017, 4:22pm UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734/2 "2017-06-16T16:22:42Z")

</div>

Does the first line in the log constitute a start event that could be used? Does the last line in the log constitute the end event? If so, use those....

It's reasonable that elapsed requires a start and end event in order to work. An example of the log might be helpful.

---

<div class="post-metadata">

### Author: ![abrejuin](https://avatars.discourse-cdn.com/v4/letter/a/cab0a1/32.png) [@abrejuin](https://discuss.elastic.co/u/abrejuin)
#### Post date: [June 19, 2017, 7:09am UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734/3 "2017-06-19T07:09:54Z")

</div>

Hello,

Yes, the first line in the log constitute a start. As soon as there is an id in the log it means the beginning of the log.  
Please find below some examples:

[2017-06-19 04:40:14,296] [INFO] [Job: PDF Printing #4240] -- Start update of timed out PDF requests  
[2017-06-19 04:40:14,374] [INFO] [Job: PDF Printing #4240] -- Finish update of timed out PDF requests  
[2017-06-19 04:40:14,374] [INFO] [Job: PDF Printing #4240] -- Start update of PDF services  
[2017-06-19 04:40:14,859] [INFO] [Job: PDF Printing #4240] -- Finish update of PDF services  
[2017-06-19 04:40:14,859] [INFO] [Job: PDF Printing #4240] -- Start deletion of obsolete PDF requests  
[2017-06-19 04:40:14,937] [INFO] [Job: PDF Printing #4240] -- Finish deletion of obsolete PDF requests  
[2017-06-19 04:40:14,937] [INFO] [Job: PDF Printing #4240] -- Refresh PDF Queue, in case we loose some some PDF Requests.  
[2017-06-19 04:40:14,937] [INFO] [Job: PDF Printing #4240] -- Resetting PDFRequest queue.  
[2017-06-19 04:40:14,937] [INFO] [Job: PDF Printing #4240] -- Refresh PDF Queue complete.  
[2017-06-19 04:40:14,937] [INFO] [Job: PDF Printing #4240] -- Flushing changes  
[2017-06-19 04:40:14,937] [INFO] [Job: PDF Printing #4240] -- Saving 10 Nodes as user.  
[2017-06-19 04:40:14,984] [INFO] [Job: PDF Printing #4240] -- Changes flushed.

[2017-06-19 04:40:15,187] [INFO] [Job: Document Processing #4242] -- Start update of timed out Document Processing requests  
[2017-06-19 04:40:15,265] [INFO] [Job: Document Processing #4242] -- Finish update of timed out Document Processing requests  
[2017-06-19 04:40:15,265] [INFO] [Job: Document Processing #4242] -- Start deletion of obsolete Document Processing requests  
[2017-06-19 04:40:15,328] [INFO] [Job: Document Processing #4242] -- Finish deletion of obsolete Document Processing requests  
[2017-06-19 04:40:15,328] [INFO] [Job: Document Processing #4242] -- Changes flushed.

[2017-06-19 05:05:08,678] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 0%.  
[2017-06-19 05:05:13,725] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 0%.  
[2017-06-19 05:05:18,772] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 0%.  
[2017-06-19 05:05:23,850] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 0%.  
[2017-06-19 05:24:53,894] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 0%.  
[2017-06-19 05:24:58,941] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 0%.  
[2017-06-19 05:25:03,128] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job monitor progress: 100%.  
[2017-06-19 05:25:03,128] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Extract Store refresh job progress monitor stopped.  
[2017-06-19 05:25:03,206] [INFO] [Job: Extract Store QuotationSlicer refresh job #4269] -- Changes flushed.

Thanks a lot for your help

---

<div class="post-metadata">

### Author: ![abrejuin](https://avatars.discourse-cdn.com/v4/letter/a/cab0a1/32.png) [@abrejuin](https://discuss.elastic.co/u/abrejuin)
#### Post date: [June 20, 2017, 1:04pm UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734/4 "2017-06-20T13:04:40Z")

</div>

Can anyone help me on this ?

Thanks

---

<div class="post-metadata">

### Author: ![abrejuin](https://avatars.discourse-cdn.com/v4/letter/a/cab0a1/32.png) [@abrejuin](https://discuss.elastic.co/u/abrejuin)
#### Post date: [June 22, 2017, 10:21am UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734/5 "2017-06-22T10:21:02Z")

</div>

Finally I did this in Logstash :

if [profileType] == "Job" {  
if "Changes flushed" in [logmessage] {  
mutate { add\_tag =\> ["taskEnded"] }  
}  
else if "" in [idmodule] {  
mutate { add\_tag =\> ["taskStarted"] }  
}  
}  
elapsed {  
start\_tag =\> "taskStarted"  
end\_tag =\> "taskEnded"  
timeout =\> 60  
new\_event\_on\_match =\> false  
unique\_id\_field =\> "idmodule"  
}

Indeed, "idmodule" appears only when a job starts.  
I thought it was good like that but sometimes I have "0" in elasped time for job "Extract Store ..", I don't know why.

---

<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: [July 20, 2017, 10:21am UTC](https://discuss.elastic.co/t/calculate-elapsed-time-without-start-or-end-message/89734/6 "2017-07-20T10:21:22Z")

</div>

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