Splunk Search
Highlighted

Finding time between two events of a transaction

Path Finder

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

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Champion

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.

View solution in original post

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Path Finder

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.

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Path Finder

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

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Champion

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?

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Path Finder

Yes Maciep.

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Champion

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

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Path Finder

Yes, Perfect. Thanks Maciep 🙂

0 Karma
Highlighted

Re: Finding time between two events of a transaction

SplunkTrust
SplunkTrust

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.

0 Karma
Highlighted

Re: Finding time between two events of a transaction

Path Finder

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.

0 Karma