topic Transaction with Multiple events in Splunk Search

Transaction with Multiple events

JoeSco27 — Mon, 28 Sep 2020 19:45:12 GMT

I am using the transaction command to group transactions on the field tx_id. Each successful transaction will begin with the field tx_state=FPA and end with tx_state=FUS. Each transaction will have any number of values for tx_state until the transation is completed. Is there a way to track the time it took to go from one event to the next within a transaction based on how long it took to go from tx_state to the next tx_state? Currently my search is as follows.

** host=dtsever01 source=/tmp/messages.log sourcetype=messages tx_id=* | transaction tx_id startswith="FPA" endswith="FUS"

I have found that the following search will produce the time differentials between events, but only if there are exactly these 4 events in a transaction:

 host=dtsever01 source=/tmp/messages.log sourcetype=messages tx_id=*
 | eval FPA=if(tx_state="FPA",_time,null()) 
 | eval MLS=if(tx_state="MLS",_time,null()) 
 | eval DSS=if(tx_state="DSS",_time,null()) 
 | eval FUS=if(tx_state="FUS",_time,null()) 
 | transaction tx_id startswith="FPA" endswith="FUS"| search credit_bureau
 |eval MLS_Completion=MLS-FPA
 | eval DSS_Completion=DSS-MLS
 | eval FUS_Completion=FUS-DSS
 | eval Total_Time=FUS-FPA
 | stats avg(MLS_Completion) as MLS_AVG, avg(DSS_Completion) as DSS_AVG, avg(FUS_Completion) as FUS_AVG, avg(Total_Time) as Total_Time by tx_id ""

My goal is to get a timechart that shows the time it took between the tx_state's by tx_id.

Re: Transaction with Multiple events

JoeSco27 — Mon, 28 Sep 2020 19:45:14 GMT

Currently, the visualization this search returns is a line chart with the x-axis being the different tx_ids the y-axis being the value (time) and each line represents MLS_AVG, DSS_AVG, FUS_AVG, and Total_Time. I would like each line to be tx_id and the x-axis being the differnet events in the transaction (MLS_AVG, DSS_AVG, FUS_AVG)

Thank you

Re: Transaction with Multiple events

wpreston — Wed, 06 May 2015 17:54:26 GMT

You can do this using mvlist, mvexpand and streamstats. Here is the full search:

host=dtsever01 source=/tmp/messages.log sourcetype=messages tx_id=* | eval phaseTime=mvzip(tx_state,_time) | transaction tx_id startswith="FPA" endswith="FUS" mvlist=phaseTime | search credit_bureau | mvexpand phaseTime  | rex field=phaseTime "(?&lt;tx_phase&gt;.*),(?&lt;tx_phase_time&gt;.*)" | streamstats current=f window=1 last(tx_phase_time) as prevTime by tx_id | eval elapsedTime=if(isnull(prevTime),null(),tx_phase_time - prevTime) | chart avg(elapsedTime) avg(duration) by tx_id tx_phase

And here is the search broken down by each step explaining what's happening. First create a field that contains the phase of the transaction and the time so that we can work with this later:

host=dtsever01 source=/tmp/messages.log sourcetype=messages tx_id=* | eval phaseTime=mvzip(tx_state,_time)

Next, create your transaction, being sure to set the mvlist option for the field we just created. This will keep phaseTime in the correct order:

... | transaction tx_id startswith="FPA" endswith="FUS" mvlist=phaseTime | search credit_bureau ...

Now expand your transaction based on the phaseTime. This creates a new event for every distinct value of phaseTime:

... | mvexpand phaseTime ...

Next extract phaseTime into phase and time for each of the new events:

... | rex field=phaseTime "(?&lt;tx_phase&gt;.*),(?&lt;tx_phase_time&gt;.*)"

Now use streamstats to pull in the previous event's time by transaction id:

... | streamstats current=f window=1 last(tx_phase_time) as prevTime by tx_id

Lastly, use eval to figure the time elapsed during each step of the transaction:

... | eval elapsedTime=if(isnull(prevTime),null(),tx_phase_time - prevTime)

and compute your statistics:

... | chart avg(elapsedTime) avg(duration) by tx_id tx_phase

Re: Transaction with Multiple events

wpreston — Wed, 06 May 2015 17:56:49 GMT

something is happening with formatting on some of the characters. Splunk Answers is not handling greater than and less than characters in code blocks. Substitute in the symbols when you perform your search.

greater than = &gt;
less than = &lt;

Re: Transaction with Multiple events

JoeSco27 — Wed, 06 May 2015 18:17:26 GMT

Thank you so much for the help. I am getting negative numbers for duration because it is taking the tx_state in alphaNumerical order and not in order that they appear. Is there a way to fix that?

Re: Transaction with Multiple events

JoeSco27 — Mon, 28 Sep 2020 19:45:23 GMT

I also should have added, each step in the process has its own timestamp tx_ts. I am providing an example transaction for better understanding.

i|1430867532|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:12.949000||FPA|0|extmule_bureau_credco|CRD|none
u|1430867543|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:23.514000||MLR|1|||
u|1430867553|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:33.958000|||2|||
u|1430867563|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:43.220000||MLS|3|dtservice_bureau_save||
u|1430867563|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:43.812000||DSS||||
u|1430867567|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:47.423000|||4|||
u|1430867568|55494e4ce4b0fea9d18164d3|2015-05-05 23:12:48.614000||FUS||||

The third field is the transaction ID (tx_id), next is timestamp (tx_ts), the next field that matters is the tx_state (FPA, MLR, MLS, DSS, FUS). Even though there are multiple i just want to know the time it took to get from FPA to MLS, MLS to DSS, & DSS to FUS for each tx_id

Re: Transaction with Multiple events

wpreston — Thu, 07 May 2015 12:29:15 GMT

I'm assuming that the timestamp is what you're using at index time as each event's time? Here, try this search instead. It only creates a phaseTime field if the tx_state is one of the values that you care about (FPA, MLS, DSS, FUS). It should also take care of the ordering problem with tx_state. The mvlist option in transaction makes sure that the field indicated is stored in arrival order instead of transaction's default behavior (storing all mv fields lexigraphically). Try this and let me know how it works. Don't forget to put in the Greater Than and Less Than symbols in the rex command.

host=dtsever01 source=/tmp/messages.log sourcetype=messages tx_id=* | eval phaseTime=if(tx_state="FPA" OR tx_state="MLS" OR tx_state="DSS" OR tx_state="FUS",mvzip(tx_state,_time),null()) | transaction tx_id startswith="FPA" endswith="FUS" mvlist=phaseTime | search credit_bureau | mvexpand phaseTime  | rex field=phaseTime "(?&lt;tx_state&gt;.*),(?&lt;tx_state_time&gt;.*)" | streamstats current=f window=1 last(tx_state_time) as prevTime by tx_id | eval elapsedTime=if(isnull(prevTime),null(),tx_state_time - prevTime) | chart avg(elapsedTime) avg(duration) by tx_id tx_state

Re: Transaction with Multiple events

JoeSco27 — Thu, 07 May 2015 15:00:50 GMT

I still see negative numbers for FPA when looking at that data:

tx_id DSS FPA FUS MLS
554a6ed6e4b0fea9d1816525 1.254500 -20.044000 16.710500 2.079000
554a6fcbe4b0fea9d1816526 0.222000 -1.704000 1.159500 0.322500
554a6fcbe4b0fea9d1816527 0.196500 -6.602000 3.988500 2.417000

Whereas the order should be FPA, MLS, DSS, FUS

Re: Transaction with Multiple events

wpreston — Thu, 07 May 2015 15:32:58 GMT

what additional search commands are you running? Can you post the full search string that gave you these negative numbers?