topic Re: How to find the duration of individual steps in a transaction search? in Splunk Search

How to find the duration of individual steps in a transaction search?

writetosathya — Wed, 15 Feb 2017 18:54:42 GMT

Hi, I need to find the duration taken by each step of a single transaction.

We are trying to find out the duration of individual "StepId" ** within a single transaction all joined by **"callback" field - i.e there are multiple "stepId" all joined by a single ** "Callback"**

I am trying the below search

** my search **| transaction callback | table callback stepId duration

I am getting the result as cumulative duration of all the steps as a single field - Is there a way to get the duration of individual stepId's?

Below is my Sample Log

10.136.180.249 - - [15/Feb/2017:10:59:59 -0500] "GET /SampleUI/step?stepId=GUID-4-9D91BA9AE27F4EA69856B99F090EC365&amp;sessionId=31474be3-b803-4d71-999f-8fb17c63cb73&amp;displayFormReferenceKey=5e1d1521-932a-4378-a4f3-7628031739f5&amp;sourceUrl=undefined&amp;callback=jQuery1112045955571818351104_1487174397781&amp;_=148717439778 HTTP/1.1" 200 986

10.136.180.249 - - [15/Feb/2017:11:01:03 -0500] "GET /SampleUI/step?stepId=GUID-27-4ABE861B01EB42AAAE034A863CC5A2EE&amp;sessionId=31474be3-b803-4d71-999f-8fb17c63cb73&amp;displayFormReferenceKey=0b8de127-b24d-4ffd-8930-60c3916ce1d0&amp;sourceUrl=undefined&amp;callback=jQuery1112045955571818351104_1487174397781&amp;_=14871743977 HTTP/1.1" 200 3747

10.136.180.249 - - [15/Feb/2017:11:01:05 -0500] "GET /SampleUI/step?stepId=GUID-30-2D27398D62624694849559DDC3C49090&amp;sessionId=31474be3-b803-4d71-999f-8fb17c63cb73&amp;displayFormReferenceKey=e125423c-2ae3-42c6-bcde-acc96255f702&amp;sourceUrl=undefined&amp;callback=jQuery1112045955571818351104_1487174397781&amp;_=14871743977 HTTP/1.1" 200 1628 

10.136.180.249 - - [15/Feb/2017:11:01:06 -0500] "GET /SampleUI/step?stepId=GUID-33-D0987CBE8DAF422A9A71174DFDEF0CF4&amp;sessionId=31474be3-b803-4d71-999f-8fb17c63cb73&amp;displayFormReferenceKey=f5cd1b64-99ea-4637-a9d4-beae474ed4a5&amp;sourceUrl=undefined&amp;callback=jQuery1112045955571818351104_1487174397781&amp;_=14871743977 HTTP/1.1" 200 362

Re: How to find the duration of individual steps in a transaction search?

somesoni2 — Wed, 15 Feb 2017 19:18:39 GMT

Give this a try

Fixed type

** my search ** | sort 0 callback _time | delta _time as stepduration | fillnull value="NA" stepduration | transaction callback | table callback stepId stepduration duration

OR (may be faster)

** my search ** | sort 0 callback _time | delta _time as stepduration | stats min(_time) as start list(stepId) as stepId list(stepduration ) as stepduration max(_time) as end by callback | eval duration=end-_time | table callback stepId stepduration duration

Updated

Try this

** my search ** | sort 0 callback _time | streamstats current=f window=1 valeus(_time) as prev_time by callback | eval stepduration=_time-prev_time | transaction callback | table callback stepId stepduration duration

Re: How to find the duration of individual steps in a transaction search?

writetosathya — Wed, 15 Feb 2017 19:42:57 GMT

Hi Somesh,

Thanks for the quick reply - I tried out both approaches however I am still getting the values in the same format where the duration value is aggregated for all the stepsID's - I wanted to see if we can calculate duration of each of step ID's

Tried doing a transaction with both fields like

** my search **| transaction callback stepId | table callback stepId duration - does not work as well

can you please guide?

Re: How to find the duration of individual steps in a transaction search?

somesoni2 — Wed, 15 Feb 2017 19:48:55 GMT

The first option has a missing stepduration field in the last table. I've updated it so try again.

Also try the 3rd option that I put. If it still doesn't work, tell me if you see valid values in the field stepduration for following query.

** my search ** | table _time callback stepId | sort 0 callback _time | streamstats current=f window=1 valeus(_time) as prev_time by callback | eval stepduration=_time-prev_time

Re: How to find the duration of individual steps in a transaction search?

writetosathya — Wed, 15 Feb 2017 21:04:45 GMT

Somesh,

Thanks a lot for your valuable time - I really appreciate it! - I am getting the split now

There seems to be a data mismatch though- This is the result set I am getting from the query

GUID-27-4ABE861B01EB42AAAE034A863CC5A2EE --- 1
GUID-30-2D27398D62624694849559DDC3C49090 --- 2
GUID-33-D0987CBE8DAF422A9A71174DFDEF0CF4 --- 64
GUID-4-9D91BA9AE27F4EA69856B99F090EC365

However the time duration if I do a manual calculation is

GUID-33-D0987CBE8DAF422A9A71174DFDEF0CF4

GUID-27-4ABE861B01EB42AAAE034A863CC5A2EE --- 2
GUID-30-2D27398D62624694849559DDC3C49090 --- 1
GUID-4-9D91BA9AE27F4EA69856B99F090EC365 --- 64

As this is a web access log and hence the times we have captured as stepduration is actually be the time for the step immediately previous to that .

I understand that you have already given your valuable time so I will try my best to figure what could be skewing the results I am a splunk newbie 🙂 .

Thanks.

Re: How to find the duration of individual steps in a transaction search?

somesoni2 — Wed, 15 Feb 2017 21:13:04 GMT

Ok.. the transaction command is sorting both the mv field, so the order is skewed. You basically need to merge stepduration calculation logic of option 3 with transaction calculation of option 2. Like this

** my search ** | sort 0 callback _time | streamstats current=f window=1 valeus(_time) as prev_time by callback | eval stepduration=coalesce(_time-prev_time,"NA") | | stats min(_time) as start list(stepId) as stepId list(stepduration ) as stepduration max(_time) as end by callback | eval duration=end-_time | table callback stepId stepduration duration

Re: How to find the duration of individual steps in a transaction search?

writetosathya — Thu, 16 Feb 2017 19:35:24 GMT

Hi somesh,

Thanks for your help again- This one worked 🙂

Again appeciate your guidance,