Solved: consecutive multi-line search, joined on common i...

achetreanu · ‎03-18-2014

As I dig through Splunk, I hope to find help with a query that can't wait.
I am trying to detect a certain 'cluster' of lines, i.e. I need to detect and count how many times I see these 2 lines consecutively (same host, same log file):

AAA-PROD-IVR1   DL  01:46:34.407|FYI|69/12345678 USR_PLAYPROMPT in Connected
AAA-PROD-IVR1   DL  01:46:38.167|FYI|69/12345678 GCEV_DISCONNECTED in Connected

I am detecting user hang-up on prompt and want to count how many times it happens.
Individually, the filters work:

host=*aaa-prod-ivr1* | rex "\w+\-\w+\-\w+\s+\w+\s+\d+\:\d+\:\d+\.\d+\|FYI\|(?P<call_id_ivr>\d+/\d+)\sUSR_PLAYPROMPT in Connected"


host=*aaa-prod-ivr1* | rex "\w+\-\w+\-\w+\s+\w+\s+\d+\:\d+\:\d+\.\d+\|FYI\|(?P<call_id_ivr>\d+/\d+)\sGCEV_DISCONNECTED in Connected"

How do I put them together? I only want to count them when they are consecutive, in the above order, when joined by call_id_ivr.

I tried (?m), (?s), (?ismx), placed them all over my search but I don't really get it working.
I tried this as well, and failed:

host=*aaa-prod-ivr1* | rex m/^"\w+\-\w+\-\w+\s+\w+\s+\d+\:\d+\:\d+\.\d+\|FYI\|(?P <call_id_ivr>\d+/\d+)\sUSR_PLAYPROMPT in Connected\w+\-\w+\-\w+\s+\w+\s+\d+\:\d+\:\d+\.\d+\|FYI\|(?P\<call_id_ivr >\d+/\d+)\sGCEV_DISCONNECTED in Connected$/m"

Failed because I can't define call_id_ivr twice.

host=*aaa-prod-ivr1* | rex m/^"\w+\-\w+\-\w+\s+\w+\s+\d+\:\d+\:\d+\.\d+\|FYI\|(?P<call_id_ivr>\d+/\d+)\sUSR_PLAYPROMPT in Connected\w+\-\w+\-\w+\s+\w+\s+\d+\:\d+\:\d+\.\d+\|FYI\|call_id_ivr\sGCEV_DISCONNECTED in Connected"$/m

Doesn't really join and filter.

Hope to get some help on this one. Thx!
A.C.

kristian_kolb · ‎03-18-2014

Your rex statements won't work, since each operation takes place on one event at a time. Perhaps you'd be more successful with the transaction command, e.g.

host=aaa-prod-ivr | rex "FYI|(?<call_id_ivr>\S+)" | transaction call_id_ivr max_events=2 startswith=USR_PLAYPROMPT endswith=GCEV_DISCONNECTED

May not fit perfectly, as the order is required, but there might be events that do not match the transaction criteria in between these two events. You can set other options as well, such as e.g max_span = 10s. You should really read up on the docs for transaction.

Another option may be streamstats.

UPDATE:

And here is one example of the streamstats approach;

host=*aaa-prod-ivr* | rex "FYI|(?<call_id_ivr>\S+)\s(?<status>\S+)"| streamstats current=t window=2 values(status) as AAA min(_time) as begin max(_time) as end by call_id_ivr, host | where mvindex(AAA,1) == "USR_PLAYPROMPT" AND mvindex(AAA,0) == "GCEV_DISCONNECTED" | convert ctime(begin) | convert ctime(end) | table host, call_id_ivr, AAA, begin, end

Added some extras like the timestamps, you could remove those if not needed. The important part is the streamstats and the where commands.

EDIT: updated the update to reflect on the fact that events are returned in reverse chronological order, i.e the DISCONNECT event is seen before the PLAYPROMPT event.

Hope this helps,

/K

View solution in original post

achetreanu · ‎03-19-2014

This worked in the end:

Thank you, K, for your awesome help!!

achetreanu · ‎03-19-2014

Thank you so much - the first one, that is simple, worked wonders. I only had to replace max_events=2 with maxevents=2, which was easy and intuitive.

I will go all greedy now and ask - in this simple filter, can i go back to the first event extract a field that isn't in the regex?

With your fist filter, I can tell how many times my users hang up on prompt played. What would be really cool is to make a top 10 "most hated prompts" - in the end that's what I am after.

The 3 consecutive logs tell me the full story - if I can extract the prompt name:

AAA-PROD-IVR1 DL 01:46:34.405|FYI|69/12345678 VoiceCallFlow c:\C1\Ivr\Prompts\welcome.vox
AAA-PROD-IVR1 DL 01:46:34.407|FYI|69/12345678 USR_PLAYPROMPT in Connected
AAA-PROD-IVR1 DL 01:46:38.167|FYI|69/12345678 GCEV_DISCONNECTED in Connected

I'm using your filter, modified as follows, which doesn't extract the prompt:
host=aaa-prod-ivr | rex "FYI|(?\S+)" | transaction call_id_ivr maxevents=3 startswith=vox endswith=GCEV_DISCONNECTED

I'm probably pushing it and this is not the right way to go about it but can i pipe more regex work on the first event of these outputs?

Thank you!
A.C.

kristian_kolb · ‎03-18-2014

Your rex statements won't work, since each operation takes place on one event at a time. Perhaps you'd be more successful with the transaction command, e.g.

host=aaa-prod-ivr | rex "FYI|(?<call_id_ivr>\S+)" | transaction call_id_ivr max_events=2 startswith=USR_PLAYPROMPT endswith=GCEV_DISCONNECTED

May not fit perfectly, as the order is required, but there might be events that do not match the transaction criteria in between these two events. You can set other options as well, such as e.g max_span = 10s. You should really read up on the docs for transaction.

Another option may be streamstats.

UPDATE:

And here is one example of the streamstats approach;

host=*aaa-prod-ivr* | rex "FYI|(?<call_id_ivr>\S+)\s(?<status>\S+)"| streamstats current=t window=2 values(status) as AAA min(_time) as begin max(_time) as end by call_id_ivr, host | where mvindex(AAA,1) == "USR_PLAYPROMPT" AND mvindex(AAA,0) == "GCEV_DISCONNECTED" | convert ctime(begin) | convert ctime(end) | table host, call_id_ivr, AAA, begin, end

Added some extras like the timestamps, you could remove those if not needed. The important part is the streamstats and the where commands.

EDIT: updated the update to reflect on the fact that events are returned in reverse chronological order, i.e the DISCONNECT event is seen before the PLAYPROMPT event.

Hope this helps,

/K

achetreanu · ‎03-18-2014

Note: some formatting looks off, changed by wiki tagging. Thx

consecutive multi-line search, joined on common id

Webinar Recap | Revolutionizing IT Operations: The Transformative Power of AI and ML ...

.conf24 | Registration Open!

ICYMI - Check out the latest releases of Splunk Edge Processor