topic Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds in Splunk Search

How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

justinsplunk_12 — Wed, 30 Sep 2020 02:49:02 GMT

Hi all,
I'm working with a sample log snippet below.

The overall goal is to get stats about long-running operations. I am trying to display the etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds (etime>20).

I've tried using "transaction" with conn but I do not know how to manipulate the data afterwards.

I am trying to get an output that looks similar to,

conn         bind_id               search_filter    etime
65110583     "uid=hello,o=test"    "(uid=abc*)"     165

::Log snippet::

2019-10-15T08:20:06+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:20:05 -0400] conn=65110583 op=-1 msgId=-1 -  connection from 10.10.10.10:1234 to 10.10.10.15
2019-10-15T08:20:06+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:20:05 -0400] conn=65110583 op=0 msgId=1 - BIND dn="uid=hello,o=test"
2019-10-15T08:20:06+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:20:05 -0400] conn=65110583 op=0 msgId=1 - RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=hello,o=test"
2019-10-15T08:20:06+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:20:06 -0400] conn=65110583 op=1 msgId=2 - SRCH base="ou=everyone,o=test" scope=2 filter="(uid=abc*)" attrs="cn"
2019-10-15T08:20:10+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:20:08 -0400] conn=65110583 op=1 msgId=2 -  SORT uid (269746)
2019-10-15T08:23:01+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:22:51 -0400] conn=65110583 op=1 msgId=2 - RESULT err=0 tag=101 nentries=269746 etime=165 notes=U
2019-10-15T08:28:42+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:28:34 -0400] conn=65110583 op=2 msgId=3 - UNBIND
2019-10-15T08:28:42+00:00 serverABC ACCESSLOG[15/Oct/2019]: 04:28:34 -0400] conn=65110583 op=2 msgId=-1 - closing from 10.10.10.10:1234 - U1 - Connection closed by unbind client -

Thank you.

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

woodcock — Mon, 04 Nov 2019 16:45:39 GMT

Like this:

index="YouShouldAlwaysSpecifyAnIndex" AND sourcetype="AndSourcetypeToo"
| stats range(_time) AS duration max(etime) AS etime_max sum(etime) AS etime_total BY conn bind_id search_filter
| fieldformat duration=tostring(duration, "duration")
| fieldformat etime_max=tostring(etime_max, "duration")
| fieldformat etime_total=tostring(etime_total, "duration")

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

mayurr98 — Mon, 04 Nov 2019 17:05:11 GMT

try this :

index=<your_index> 
| rex "dn=\"(?<bind_id>[^\"]+)" 
| rex "conn=(?<conn>\d+)" 
| rex "filter=\"\((?<search_filter>[^\)]+)" 
| rex "etime=(?<etime>\d+)" 
| stats values(bind_id) as bind_id max(etime) as etime_max values(search_filter) as search_filter by conn 
|  where etime_max > 20

If all the required fields are already extracted then don't use the rex expressions.

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

justinsplunk_12 — Wed, 30 Sep 2020 02:52:42 GMT

thank you @mayurr98. this worked for most of the connections. Others have multiple searches in one connection start to end and so I find i need to group by conn and msgId. Im just trying to figure out how to now associate bind_id with the conn. I was thinking maybe some sort of subsearch, appendcols, or join ? Not sure.
For example:

index=xyz host=serverABC
| rex "BIND dn=(?.)\smethod"
| rex "filter=(?.)\sattrs"
| stats values(bind_id) as bind_id max(etime) as etime_max values(search_filter) as search_filter by conn msgId
| where etime_max > 20

output:
conn msgId bind_id etime_max search_filter
11001119 3 22 "(uid=abc*)"
11001119 2 25 "(uid=123*)"

2019-11-05T07:24:27+00:00 serverABC ACCESSLOG[05/Nov/2019]: 02:24:24 -0500] conn=11001119 op=0 msgId=1 - BIND dn="uid=hello,o=test"
2019-11-05T07:24:27+00:00 serverABC ACCESSLOG[05/Nov/2019]: 02:24:24 -0500] conn=11001119 op=0 msgId=1 - RESULT err=0 tag=97 nentries=0 etime=0 "uid=hello,o=test"
2019-11-05T07:24:27+00:00 serverABC ACCESSLOG[05/Nov/2019]: 02:24:24 -0500] conn=11001119 op=1 msgId=2 - SRCH base="ou=none,o=test" scope=2 filter="(uid=xyz*)" attrs="cn"
2019-11-05T07:24:27+00:00 serverABC ACCESSLOG[05/Nov/2019]: 02:24:24 -0500] conn=11001119 op=1 msgId=2 - RESULT err=0 tag=101 nentries=1 etime=25
2019-11-05T07:24:27+00:00 serverABC ACCESSLOG[05/Nov/2019]: 02:24:24 -0500] conn=11001119 op=2 msgId=3 - SRCH base="ou=everyone,o=test" scope=2 filter="(uid=abc*)" attrs="cn"
2019-11-05T07:24:38+00:00 serverABC ACCESSLOG[05/Nov/2019]: 02:24:28 -0500] conn=11001119 op=2 msgId=3 - RESULT err=0 tag=101 nentries=7187 etime=22

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

mayurr98 — Tue, 05 Nov 2019 19:42:09 GMT

how does your output look like in this case?

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

justinsplunk_12 — Wed, 30 Sep 2020 02:52:44 GMT

Sorry theres some weird formatting for the splunk search i replied with. The bind_id is blank but everything else is correct.

The output is like this:
conn msgId bind_id etime_max search_filter
11001119 3 22 "(uid=abc*)"
11001119 2 25 "(uid=123*)"

Desired output:
conn msgId bind_id etime_max search_filter
11001119 3 "uid=hello,o=test" 22 "(uid=abc*)"
11001119 2 "uid=hello,o=test" 25 "(uid=123*)"

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

mayurr98 — Tue, 05 Nov 2019 21:38:30 GMT

add this after stats command:

| eventstats values(bind_id) as bind_id by conn  
|  where etime_max > 20

Re: How to pull stats to display etime, bind_id, conn, and the search_filter for any operation that takes longer than 20 seconds

justinsplunk_12 — Tue, 05 Nov 2019 21:54:52 GMT

ahh, it works and it looks so simple. I guess i was making it harder than it needed to be with trying to use transaction etc. thank you!