Splunk Search

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

mrafiq17
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?

nikita_p
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

bangalorep
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

mrafiq17
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

bangalorep
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

mrafiq17
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

bangalorep
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

mrafiq17
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

somesoni2
Revered Legend

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
Get Updates on the Splunk Community!

Check out this month’s brand new Splunk Lantern articles

Splunk Lantern is a customer success center providing advice from Splunk experts on valuable data insights, ...

Happy CX Day to our Community Superheroes!

Happy 10th Birthday CX Day!What is CX Day? It’s a global celebration recognizing innovation and success in the ...

Routing Data to Different Splunk Indexes in the OpenTelemetry Collector

This blog post is part of an ongoing series on OpenTelemetry. The OpenTelemetry project is the second largest ...