How can I compute durations of nested method calls ?

[splunker_jim]

Hi there,

I'm new to Splunk, so apologies if this question has been answered before. I would like to compute the elapsed time / duration to determine simple performance statistics.

The log file has entries like the following (I converted the log entries into a tabular format for the purpose of this post):

Table 1

_time   sequence    event
======= ========    =============
t00         1       Request Enter
t01         2       Method Enter
t02         3       Method Exit
t03         4       Method Enter
t04         5       Method Enter
t05         6       Method Enter
t06         7       Method Exit
t07         8       Method Exit
t08         9       Method Exit
t09         10      Request Exit

t10         1       Request Enter
t11         2       Method Enter
t12         3       Method Exit
t13         4       Method Enter
t14         5       Method Exit
t15         6       Method Enter
t15         7       Method Enter
t16         8       Method Exit
t17         9       Method Exit
t19         10      Request Exit

For the above log, I would like to compute the elapsed time / duration as shown in the table below.

Table 2

_time   sequence    event           Elapsed     Comment
======= ========    =============   ========    ============
t00     1           Request Enter   
t01     2           Method Enter    d01         = t01 - t00
t02     3           Method Exit     d02         = t02 - t01
t03     4           Method Enter    d03         = t03 - t02
t04     5           Method Enter    d04         = t04 - t03
t05     6           Method Enter    d05         = t05 - t04
t06     7           Method Exit     d06         = t06 - t05
t07     8           Method Exit     d07         = t07 - t04 <--
t08     9           Method Exit     d08         = t08 - t03 <--
t09     10          Request Exit    d09         = t09 - t00 <--

t10     1           Request Enter   d10         = t10 - t09
t11     2           Method Enter    d11         = t11 - t10
t12     3           Method Exit     d12         = t12 - t11
t13     4           Method Enter    d13         = t13 - t12
t14     5           Method Exit     d14         = t14 - t13
t15     6           Method Enter    d15         = t15 - t14
t16     7           Method Enter    d16         = t16 - t15
t17     8           Method Exit     d17         = t17 - t16
t18     9           Method Exit     d18         = t18 - t15 <--
t19     10          Request Exit    d19         = t19 - t10 <--

The column that I'm interested in computing is the 'Elapsed' column shown in the above table. The 'Comment' column is for instructional purposes of this post and depicts the formula pattern.

As you can see, most of the durations are simple delta _time computations. However, there are a few (indicated by <--) that compute the difference with a log entry occurring much earlier (this is case for nested method calls).

I would also like keep the representation order of the log entries as shown in Table 2.

Any help from folks experienced with such computation is appreciated.

Thanks in advance

jim

[araitz]

The specialized computations really point to scripting this using REST calls and some custom business logic to handle the special cases. I can't really see any way around it. I suppose if the list and the special computations are static, you could use something like mvindex to do some gymnastics, but it just seems like a more supportable route to write a python script.