Splunk Search

Display multiple event duration as columns with sequence number

I'm trying to calculate duration of stepAStart to stepAEnd and display them as columns with sequence number (eg StepA1, StepA2 ...). There is no steps between StepAStart and StepAEnd and the event pair may occur multiple times. The same for StepBStart and StepBEnd.

20150421 10:20:10 Step=stepStart, Tid=1234
20150421 10:20:11 Step=stepAStart, Tid=1234
20150421 10:20:12 Step=stepAEnd, Tid=1234
20150421 10:20:13 Step=stepBStart, Tid=1234
20150421 10:20:14 Step=stepBEnd, Tid=1234
20150421 10:20:15 Step=stepAStart, Tid=1234
20150421 10:20:16 Step=stepAEnd, Tid=1234
20150421 10:20:17 Step=stepBStart, Tid=1234
20150421 10:20:18 Step=stepBEnd, Tid=1234
20150421 10:20:19 Step=stepAStart, Tid=1234
20150421 10:20:20 Step=stepAEnd, Tid=1234
20150421 10:20:21 Step=stepEnd, Tid=1234

The result should be

Tid StepStartEndDuration StepA1 StepA2 StepA3 StepB1 StepB2

1234 11 1 1 1 1 1

I tried the following but it returned multiple rows. How do I pivot the result?

source="PerfMetrics"
|sort _time
|delta _time as StepTime p=1
|eval StepATime = if(Step="stepAEnd",StepTime,0)
|eval StepBTime = if(Step="stepBEnd",StepTime,0)
|transaction TId
|eval StepStartEndDuration = duration
|table StepStartEndDuration, StepATime, StepBTime

Tags (3)
0 Karma
1 Solution

Splunk Employee
Splunk Employee

Let me just express my appreciation for your question. I love Splunk and sometimes challenging questions like this highlight the flexibility of the Search Processing Language (SPL).

In this case we have taken your data set and modified the time stamps to ensure some things are clear. Most notably, the date in seconds has been modified to point out the following:

  • Total transaction time is 15 seconds
  • Step A1 takes one (1) second
  • Step A2 takes two (2) seconds
  • Step A3 takes three (3) second
  • Step B1 takes one (1) second
  • Step B2 takes two (2) seconds

    20150421 10:20:10 Step=stepStart, Tid=1234
    20150421 10:20:11 Step=stepAStart, Tid=1234
    20150421 10:20:12 Step=stepAEnd, Tid=1234
    20150421 10:20:13 Step=stepBStart, Tid=1234
    20150421 10:20:14 Step=stepBEnd, Tid=1234
    20150421 10:20:15 Step=stepAStart, Tid=1234
    20150421 10:20:17 Step=stepAEnd, Tid=1234
    20150421 10:20:18 Step=stepBStart, Tid=1234
    20150421 10:20:20 Step=stepBEnd, Tid=1234
    20150421 10:20:21 Step=stepAStart, Tid=1234
    20150421 10:20:24 Step=stepAEnd, Tid=1234
    20150421 10:20:25 Step=stepEnd, Tid=1234
    Once we indexed the data, we used an in-line regular expression to obtain the type of the Step being taken.

    sourcetype="answers-1429817656" 
    

    | rex "Step=(?step[A])(?:Start|End)"
    | rex "Step=(?step[B])(?:Start|End)"
    We then captured each transaction. Because the steps are sequential we used reverse to reflect human ordering. We also assigned an ascending id using accum to keep them in check for later.

    | transaction startswith="*Start" endswith="*End"
    | reverse
    | eval id=1 | accum id
    If you are trying this, at this point, you should see something like this:

alt text


From this point we manipulated the data to reflect your desired format. Firstly we reduced the data set to reflect the necessary fields in a nice table. Secondly we calculated the value for each step type and assign a variable. Here is that recipe:

| stats list(duration) AS duration list(StepA) AS StepA list(StepB) AS StepB list(Step) AS Step by Tid id 
| eval ida=if(isnotnull(StepA),1,null()) | accum ida 
| eval idb=if(isnotnull(StepB),1,null()) | accum idb 
| eval Step=if(isnotnull(StepA),StepA.ida,if(isnotnull(StepB),StepB.idb,Step)) 

We were then inspired to (╯°□°)╯︵ ┻━┻

| xyseries Tid Step duration

This should provide you the following results:

alt text

I hope this helps you,

--gc

View solution in original post

Splunk Employee
Splunk Employee

Let me just express my appreciation for your question. I love Splunk and sometimes challenging questions like this highlight the flexibility of the Search Processing Language (SPL).

In this case we have taken your data set and modified the time stamps to ensure some things are clear. Most notably, the date in seconds has been modified to point out the following:

  • Total transaction time is 15 seconds
  • Step A1 takes one (1) second
  • Step A2 takes two (2) seconds
  • Step A3 takes three (3) second
  • Step B1 takes one (1) second
  • Step B2 takes two (2) seconds

    20150421 10:20:10 Step=stepStart, Tid=1234
    20150421 10:20:11 Step=stepAStart, Tid=1234
    20150421 10:20:12 Step=stepAEnd, Tid=1234
    20150421 10:20:13 Step=stepBStart, Tid=1234
    20150421 10:20:14 Step=stepBEnd, Tid=1234
    20150421 10:20:15 Step=stepAStart, Tid=1234
    20150421 10:20:17 Step=stepAEnd, Tid=1234
    20150421 10:20:18 Step=stepBStart, Tid=1234
    20150421 10:20:20 Step=stepBEnd, Tid=1234
    20150421 10:20:21 Step=stepAStart, Tid=1234
    20150421 10:20:24 Step=stepAEnd, Tid=1234
    20150421 10:20:25 Step=stepEnd, Tid=1234
    Once we indexed the data, we used an in-line regular expression to obtain the type of the Step being taken.

    sourcetype="answers-1429817656" 
    

    | rex "Step=(?step[A])(?:Start|End)"
    | rex "Step=(?step[B])(?:Start|End)"
    We then captured each transaction. Because the steps are sequential we used reverse to reflect human ordering. We also assigned an ascending id using accum to keep them in check for later.

    | transaction startswith="*Start" endswith="*End"
    | reverse
    | eval id=1 | accum id
    If you are trying this, at this point, you should see something like this:

alt text


From this point we manipulated the data to reflect your desired format. Firstly we reduced the data set to reflect the necessary fields in a nice table. Secondly we calculated the value for each step type and assign a variable. Here is that recipe:

| stats list(duration) AS duration list(StepA) AS StepA list(StepB) AS StepB list(Step) AS Step by Tid id 
| eval ida=if(isnotnull(StepA),1,null()) | accum ida 
| eval idb=if(isnotnull(StepB),1,null()) | accum idb 
| eval Step=if(isnotnull(StepA),StepA.ida,if(isnotnull(StepB),StepB.idb,Step)) 

We were then inspired to (╯°□°)╯︵ ┻━┻

| xyseries Tid Step duration

This should provide you the following results:

alt text

I hope this helps you,

--gc

View solution in original post

Thank you so much Gilberto. You have been great help. I'm really amazed what Splunk can do. I'm interested to learn more. Another question - when I have more than 10 occurrences of stepAs or stepBs I got column sequence as below
Tid, StepB1, StepB10, StepB11, StepB2, ..., StepB9, Step (for StepStart/StepEnd), StepA1, StepA10, Step2,...,Step9.
I added a sort before the last statement and that did not help. Is there a way to display the columns like
Tid, Step (for StepStart/StepEnd), StepA01, ...StepA11, StepB01, ..., StepB11

0 Karma

Splunk Employee
Splunk Employee

The horizontal display of fields is governed by an alpha-numeric ordering. I would expect to see

Tid, StepA1, StepA2 ... StepA11, StepB1 ... StepB9, StepStart StepEnd

If you reassign the field value prior to the xyseries piece, then you can get it done. Like this:

| eval Step=if(isnotnull(StepA),StepA.ida,if(isnotnull(StepB),StepB.idb,Step))
| eval Step=if(Step=="stepEnd","StepStart/StepEnd",Step)
| xyseries Tid Step duration
0 Karma