Splunk Search

Can splunk help me further analyze/refine the durations of my transactions?

Explorer

Hi,

We've created two transactions to correlate logs spanning several components. We needed to define alias terms since a common identifier does not exist across all components we are searching.

Unfortunately, the transaction itself and its overall duration isn't all we're after in terms of analysis and metrics reporting.

We really want to analyze the transaction duration into sub-intervals of duration. i.e. duration of transaction = interval1 + interval2 + interval3

or

time spent performing transactions of this type (which spans many layers) can be decomposed into time spent in layer1 + time spent in layer2 + time spent in layer3

Could someone advise : - whether "transaction" is what we should be really using to accomplish the above? - whether there is an alternate operations we should turn to for that type of analysis? [I've noted that there is a common trap of folks gravitating towards the use of the "transaction" operation iso the "stats" operation but I am not "seeing" how "stats" applies in our case either.]

If we simplify our single complex transaction into a sequence of many simpler transactions instead, then is there a way of joining the simpler transactions together when it comes to reporting?

Thanks.

Tags (1)
1 Solution

Super Champion

Here is one possible approach. You could use one or more eval statements to mark the points in time in which you would like to use for your different durations, and then calculate the durations using an eval after the transaction command.

You didn't provide any sample events, so I'll make something up thats pretty trivial, but should get the point across. (I've numbered these events for discussion purposes. The 1234 in this example is a "pid" field)

[1]   Tue Jul  6 09:16:00 [1234] Start event
[2]   Tue Jul  6 09:16:10 [1234] phase1.  do some work
[3]   Tue Jul  6 09:16:40 [1234] phase2.  do some other stuff...
[4]   Tue Jul  6 09:17:00 [1234] done.

So by default, the timestamp of your transaction-based event will be for event #1. And your duration will be the difference between event 4 and 1. So let's we can add in timestamps for event 2 and 3 so we can can calculate the duration of phase1.

 ... | eval phase1_time=if(searchmatch("phase1"), _time, null()) | eval phase2_time=if(searchmatch("phase2", _time, null()) | transaction fields="pid" startswith="start event" endswith="done" | eval phase1_duration=phase2_time-phase1_time

The searchmatch function works well for this trivial example, but you have the full range of eval functions available to you. If you are not familiar with them, I would recommend checking out Functions for eval and where.

If you want the duration of phase 2, you could get that by first getting the time of the last event (which is _time + duration), and then comparing that against the timestamp of event 3, like so:

| eval phase2_duration=(_time+duration)-phase2_time

Hope that gives you something to start with.

View solution in original post

Super Champion

Here is one possible approach. You could use one or more eval statements to mark the points in time in which you would like to use for your different durations, and then calculate the durations using an eval after the transaction command.

You didn't provide any sample events, so I'll make something up thats pretty trivial, but should get the point across. (I've numbered these events for discussion purposes. The 1234 in this example is a "pid" field)

[1]   Tue Jul  6 09:16:00 [1234] Start event
[2]   Tue Jul  6 09:16:10 [1234] phase1.  do some work
[3]   Tue Jul  6 09:16:40 [1234] phase2.  do some other stuff...
[4]   Tue Jul  6 09:17:00 [1234] done.

So by default, the timestamp of your transaction-based event will be for event #1. And your duration will be the difference between event 4 and 1. So let's we can add in timestamps for event 2 and 3 so we can can calculate the duration of phase1.

 ... | eval phase1_time=if(searchmatch("phase1"), _time, null()) | eval phase2_time=if(searchmatch("phase2", _time, null()) | transaction fields="pid" startswith="start event" endswith="done" | eval phase1_duration=phase2_time-phase1_time

The searchmatch function works well for this trivial example, but you have the full range of eval functions available to you. If you are not familiar with them, I would recommend checking out Functions for eval and where.

If you want the duration of phase 2, you could get that by first getting the time of the last event (which is _time + duration), and then comparing that against the timestamp of event 3, like so:

| eval phase2_duration=(_time+duration)-phase2_time

Hope that gives you something to start with.

View solution in original post

Super Champion

Glad to hear it!

0 Karma

Explorer

BTW this type of solution (using eval) seems to have worked quite well for us for most of our key events - thanks again for the guidance, Lowell.

Now that we have the "raw" data in a form that has most of the information we were looking for, I'll spend some time on the reporting side to see that we can wrap the information up in usable metrics.

Explorer

It has - thanks for this - will report back when we've nailed it. Cheers.

0 Karma

Explorer

I think I may have found something to work with a previous post: "Delta between timestamp within a transaction search"...missed that one!

0 Karma

Super Champion

Yeah, I've posted an answer with a very similar type of solution. From the information you've posted, it sounds like your solution could be much simpler though. The reason is that comparing times between specific events is actually easier than build a delta for a multi-value field of timestamps.

0 Karma
State of Splunk Careers

Access the Splunk Careers Report to see real data that shows how Splunk mastery increases your value and job satisfaction.

Find out what your skills are worth!