Splunk Search

Get the time difference between 2 different events based on common fields

Explorer

I have a log that shows when the particular event was fired

2019-01-14 19:20:21,849 [DEBUG] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : DataLoadingStartedEvent{actionId=553, feedId=37, poolId=37}

And another log that shows when the event fired event has completed

2019-01-14 19:20:22,029 [DEBUG] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : DataLoadingCompletedEvent{actionId=553, feedId=37, poolId=37}

There are many similar such events. I need to calculate the time it took to finish based on the actionId and poolId.
Both the start and finish event needs to have the same actionId and poolId.To calculate the finish time we need to find the difference between DataLoadingStartedEvent and DataLoadingCompletedEvent . How can I achieve this?

Contributor

Hi,
You can also achieve this by converting your starttime and endtime into epoch and then you can do the subtraction between them and then you can again convert time to strp format

0 Karma

Communicator

Hello,
You could use the transaction command with the endswith and startwisth options

here's the documentation on transaction with other options you could use to optimize your search
https://docs.splunk.com/Documentation/Splunk/7.2.0/SearchReference/Transaction

0 Karma

Explorer

Hi bangalorep,

I have tried the transaction command, it's not accurate. I have found that around 60% was correct while other events did have a closing event but still came as events where no closing events existed. Below is the query

** DataLoading*Event | transaction actionId poolId startswith="DataLoadingStartedEvent" endswith="DataLoadingCompletedEvent" keepevicted=true|search closed_txn=0 AND evicted>=0|eval diff=tostring(now()-_time,"duration") | table diff

0 Karma

Communicator

Hello,
If you use the transaction command the duration is automatically calculated. You could search for duration and add it as an interesting field on the list of fields to the left side

0 Karma

Explorer

Hi,

The duration would not be calculated as the transaction is not complete. Hence I had to find the time difference by deducting current time from the event time.

0 Karma

Communicator

In your search what is this part for? |search closed_txn=0 AND evicted>=0

You could instead run a search like NOT duration = * and the calculate the duration of the remaining events.

0 Karma

Explorer

Hi somesoni2,
Thank you for the answer.

I have seen multiple pairs. I am getting the duration wrong as there are multiple pairs as I didn't inform earlier. I used the transaction command and I am getting the correct duration.

DataLoading*Event |transaction actionId poolId startswith="DataLoadingStartedEvent" endswith="DataLoadingCompletedEvent"|eval time=(duration/60)|table actionId poolId time

Regarding the partial events, I have noticed that the startedevent has fired while the completedevent is not present. In such cases, I would we need to go an hour earlier and look for the action id along with the poolid for the startedevent and then get the time from completedevent to calculate the duration. I tried subsearch, but I am not able to form a query.

Could you please help?

0 Karma

SplunkTrust
SplunkTrust

Could you tell more about these events, like, will there be multiple such pair for a specific actionId and poolId, what you want to do if your selected time range includes partial events (e.g. only includes DataLoadingStartedEvent OR DataLoadingCompletedEvent )?

Generally, you'd do something like this (assuming you've setup a field extraction for extraction e.g. eventType=DataLoadingStartedEvent OR DataLoadingCompletedEvent)

index=foo sourcetype=bar eventType=DataLoadingStartedEvent OR eventType=DataLoadingCompletedEvent
| eval startTime=if(eventType=DataLoadingStartedEvent,_time,null())
| eval endTime=if(eventType=DataLoadingCompletedEvent,_time,null())
| stats min(startTime) as startTime max(endTime) as endTime by  actionId poolId  
| eval duration=endTime-startTime 
0 Karma