We are looking at login times and how long it takes a user to login to our Citrix servers. We have the following log that captures the user, Status (STARTED OR FINISHED), and timestamp. Ideally, we would like to chart the time between the two statuses by user but are having issues with the search. I imagine it would be something like this but I am not sure if the duration is being calculated correctly or if I have the right idea for "transaction"
index=citrix sourcetype="wts_log" | transaction UserName Status host | timechart avg(duration) by UserName
Here is an example of the log
I think you're on the right track, but will need to change your transaction definition a little bit. When you give transaction a field list, it is essentially trying to match on all of those field values. When you tell it to use the Status field, it is going to try to match the values of Status in your events, so Status=STARTED will match other events with a Status=STARTED.
Instead, I'd suggest paring your field list down to UserName and host, and using the startswith and endswith arguments:
index=citrix sourcetype="wts_log" | transaction UserName host startswith="STARTED" endswith="FINISHED" | timechart avg(duration) by UserName
startswith and endswith tell Splunk clearly when to start and end a transaction, which makes the correlation of events much easier and faster.
thanks! i have updated the question above.. Now we would like to be more granular to show the duration at different parts of the the authentication process ie steps 1-4 . Is it possible to calculate this all with in the STARTED - FINISHED?
Sure, this can be done too. I'm posting a new answer because I can't comment from my workplace for some reason. To calculate times within a transaction, you should eval the times before initiating the transaction, eval your time differences within each transaction, then use stats to find the time differences average or whatever you need. For example:
index=citrix sourcetype="wts_log" | eval Start_Time=if(Status="STARTED",_time,null()) | eval Step_1_Time=if(Status="Step1_Complete",_time,null()) | eval Step_2_Time=if(Status="Step2_Complete",_time,null()) | eval Step_3_Time=if(Status="Step3_Complete",_time,null()) | eval Step_4_Time=if(Status="Step4_Complete",_time,null()) | eval Finish_Time=if(Status="FINISH",_time,null()) | transaction UserName host startswith="STARTED" endswith="FINISHED" | eval Step_1_Completion=Step_1_Time-Start_Time | eval Step_2_Completion=Step_2_Time-Start_Time | eval Step_3_Completion=Step_3_Time-Start_Time | eval Step_4_Completion=Step_4_Time-Start_Time | stats avg(Step_1_Completion) as Step_1_Completion_Average, avg(Step_2_Completion) as Step_2_Completion_Average, avg(Step_3_Completion) as Step_3_Completion_Average, avg(Step_4_Completion) as Step_4_Completion_Average
The search is longer now, but you can figure all kinds of inter-transaction timing with this kind of search. Hope it helps!