How to search the top 5 entries within a transaction by duration?

[vman_me]

I am trying to find the top 5 events within a transaction by duration.
The transactions are marked by "found section" and "After render" and I need to determine the top 5 events within each section by their duration. The sections might encompass several transactions with similar events in the middle called Components.

Here is my current search:

base search | transaction startswith="found section" endswith="After render_to_response"  | top 5 Components by Section

which needs more work...
I am very new to Splunk, any pointers appreciated,

• V

[lguinn2 · Accepted solution]

If there is only one "transaction" per Section, then this should work:

base search
| sort Section _time
| eventstats earliest(_time) as startTime by Section
| eval duration = _time - startTime
| stats sum(duration) as duration by Section Component
| sort Section Component -duration
| stats list(duration) as duration list(Component) as Component by Section
| eval duration=mvindex(duration,0,4)
| eval Component=mvindex(Component,0,4)

First, this establishes the starting time for each section and names it "startTime." The duration of each component is computed from this startTime. Next, the results are sorted so that the highest durations appear first in the list. Then the results are grouped and the mvindex command is used to "pick out" the first 5 results for each section.

[vman_me]

Ok, I added a duration per Section and then tried to sort by that field:

... | sort -sduration Section -duration Component |..

which seems to work fine for the Section and its duration but the Component part doesnt get sorted...

Do I need to change drastically the solution or is there something to sort the Component subtable?

Thanks,

- V

[vman_me]

Good stuff...
There is more that one transaction (Component) per Section and I am able to compute the duration by using "window=1" on streamstats after sorting by time as well. However, I did try your solution and it seems to work well, but for some reason only get 3 sections (lexicographically) not sure why. Any idea?
(More interesting would be to pick the top 3 Sections by time as well...)
Thanks,
- V

[vman_me]

Ok it looks good... just changed the sorting order in last sort to:
sort Section -duration Component
and i do get all sections...
Just need to pick the top 3 Sections now...

This can be fun 🙂
Cheers, - V

[fdi01]

try like :

base search gro | transaction Section startswith="found section" endswith="After render_to_response" |stats sum(duration) as duration list(Components) as Components by Section |sort -duration| table Section Components duration | head 5

[vman_me]

Good ideas... However, 'duration' seems to vanish after the sort operation. In any case, the transaction statement only calculates the duration for the Sections, and its desired to have it by Component, and use that for the top 5 rankings within Section.
Perhaps I need to calculate the duration of every line (Component) first and then proceed to the Section calculations.
Is 'transaction' the best way to calculate duration of each log entry, given that they are sequential in timestamp?

• V

[lguinn2]

Thanks for the explanation about the time - could you post a couple of sample events? (with identifying information edited, of course)

I am thinking about how to answer this using time duration instead of count.

[vman_me]

Nothing special to these logs. The format is more or less like this

timestamp IPaddr Component

In reality "found section" and "After render" are the first two words of Component, a text description.
I could tweak the format if that could help for the end goal,
The transaction operation works well in grouping the section, now just need to get the duration for each intermediary log event, all in sequence through the timestamp. Then find the top 5 for each Section. Each Section group appears in different parts of the stream (so their component durations would be need to be aggregated before picking top 5 of each Section)

Thanks,
- V

[lguinn2]

So each event (from "found section" to "After render") actually contains the Section field? Are there multiple transactions for a section - in other words, are there multiple sets of "found section" to "After render"?

[lguinn2]

I think this will do it, but please comment if the mvexpand doesn't work...

base search 
| transaction Section startswith="found section" endswith="After render_to_response"  
| table Section Components
| mvexpand Components
| top 5 Components by Section

Also, I think you should be using the Section field in the transaction command, but I could be wrong about that.

If you have 20 different sections, this will give you 20 "top fives" - one for each section. If you want just one Top 5, perhaps one of these variations on the top command will give you what you want. Try them to see the differences.

| top 5 Components Section

| top 5 Section Components

| top 5 Components

[vman_me]

I guess the (time) duration needs to be calculated from the previous timestamp and the current one. They are sequential log messages.

Thanks
- V

[vman_me]

Good stuff, Its close... but I'd like top 5 in time duration, not in count...

I guess it would be like considering every log within a Section as a transaction itself and then determine duration and rank it by top 5 per Section.

Also, i get '1' for the count of the first Section components and I can see there are more than 1... distributed across the Section transactions

Thanks,
- V