topic Re: Finding time between two events of a transaction in Splunk Search

Finding time between two events of a transaction

Kukkadapu — Wed, 09 Mar 2016 18:14:53 GMT

Hi,
My events have the following structure

_time=time id=[id] event=[event]

For example:
2016-03-09 01:47:41 id=1234 event=1
2016-03-09 01:47:42 id=1234 event=1
2016-03-09 01:47:43 id=1234 event=1
2016-03-09 01:47:44 id=1234 event=1
2016-03-09 01:47:45 id=1234 event=1
2016-03-09 01:47:46 id=1234 event=3
2016-03-09 01:47:47 id=1234 event=3
2016-03-09 01:47:48 id=1234 event=3
2016-03-09 01:47:49 id=1234 event=1
2016-03-09 01:47:50 id=1234 event=3
2016-03-09 01:47:51 id=1234 event=4
2016-03-09 01:47:52 id=1234 event=5
2016-03-09 01:47:53 id=1234 event=2
2016-03-09 01:47:54 id=1234 event=2
2016-03-09 01:47:55 id=1234 event=1

2016-03-09 01:47:56 id=1234 event=1
2016-03-09 01:47:57 id=1234 event=1
2016-03-09 01:47:58 id=1234 event=1
2016-03-09 01:47:59 id=1234 event=2
2016-03-09 01:47:60 id=1234 event=5

| mvcombine delim=" " event
| nomv event

Output
1 1 1 1 1 3 3 3 1 3 4 5 2 2 1 1 1 1 2 5

I need the time taken from event=1 to event=3
I've used the following query but then it shows four transactions instead of two(In the data above we can see that there are only two places where the event changed from 1 to 3).

| transaction Id startswith=eval(event=1) endswith=eval(event=3) maxevents=2

Can you let me know how to get the time taken between the events?

Thanks

Re: Finding time between two events of a transaction

maciep — Thu, 10 Mar 2016 23:59:45 GMT

So in your example above, would this be 1 of the 2 times it switches from 1 to 3?

2016-03-09 01:47:45 id=1234 event=1
2016-03-09 01:47:46 id=1234 event=3

If so, maybe something like this

[your base search]
| sort id _time
| autoregress event as prevEvent p=1
| autoregress _time as prevTime p=1
| delta _time as delta_seconds p=1
| where event=3 AND prevEvent=1
| table id event _time prevTime prevEvent
| convert ctime(prevTime)

So sort in ascending time order (and group id's together in case there are multiple). Then for each event, use autoregress to store the event and time of the previous event. And also use delta to give the difference (in seconds) between the current event and the last event. Then filter for any rows where event is 3 and the previous event was 1. And table out the info.

Re: Finding time between two events of a transaction

Kukkadapu — Fri, 11 Mar 2016 00:08:46 GMT

Maciep, Thanks for the reply.

1 to 3 is switched two times

2016-03-09 01:47:45 id=1234 event=1
2016-03-09 01:47:46 id=1234 event=3

AND

2016-03-09 01:47:49 id=1234 event=1
2016-03-09 01:47:50 id=1234 event=3

I need the average time - The average time is going to be 1 second

Thanks.

Re: Finding time between two events of a transaction

Kukkadapu — Fri, 11 Mar 2016 00:25:53 GMT

This worked 🙂 Thanks Maciep.

And can you help me how to have a timechart for event 1 and event 3 where it changed from event 1 to 3 (So I can display a line chart for both event 1 and event 3 ). That would be great.

Thanks

Re: Finding time between two events of a transaction

maciep — Fri, 11 Mar 2016 11:58:45 GMT

I'm not sure I can visualize what you want to see. You want a count of events 1 & 3 that were involved in the switch over time?

Re: Finding time between two events of a transaction

Richfez — Fri, 11 Mar 2016 12:11:16 GMT

For this part, it might be you can do this with only a tiny change to your original search. The idea would be to filter out the transactions that weren't a 1-3 transition. Then just feed it to timechart.

| transaction Id startswith=eval(event=1) endswith=eval(event=3) maxevents=2
| search eventcount=2
| timechart count

Totally untested and just a guess, but that may be all you need.

Re: Finding time between two events of a transaction

Kukkadapu — Fri, 11 Mar 2016 16:06:25 GMT

Yes Maciep.

Re: Finding time between two events of a transaction

Kukkadapu — Fri, 11 Mar 2016 16:07:43 GMT

Rich , Thanks for the reply. I've tried this earlier. If I use startswith and endswith , it's giving me a count of four instead of two.

Re: Finding time between two events of a transaction

maciep — Sat, 12 Mar 2016 02:26:51 GMT

ok, not sure if this the prettiest/best, but I think it gets the job done, but there might be a better approach

[your base search]
 | sort id _time
 | autoregress event as prevEvent p=1
 | autoregress _time as prevTime p=1
 | delta _time as delta_seconds p=1
 | where event=3 AND prevEvent=1
 | eval tempEvent=split("1,3",",") 
 | mvexpand tempEvent 
 | eval _time = if(tempEvent=1,prevTime,_time) 
 | timechart count by tempEvent

So after the original search, we have two time fields in each row, the time of event 3 and the time of the previous event 1. If we want to map both of those times in a chart, then we need to separate them to separate events again.

So the search is creating a new multi-value field called temp Event that just contains "1" and "3". Then it uses mvexpand to break that new field into two separate events. And for one of those two new events, _time is set to the prevTime. And so now we can use timechart to map those counts across time.

Hopefully this is kind of what you're after

Re: Finding time between two events of a transaction

Kukkadapu — Mon, 14 Mar 2016 17:11:14 GMT

Yes, Perfect. Thanks Maciep 🙂