Risto,
Absolutely.
The following pattern should catch it:
^.*\[(20[234][0-9]-[0-9]{2}-[0-3][0-9])-([0-2][0-9]:[0-5][0-9]:[0-5][0-9]).*VERBOSE\[([0-9]{3,6})\]\[(C-[0-9a-f]{8})\].*
pbx.c: Spawn extension \(.*\) exited non-zero on.*
Here's a few lines leading up to it (interesting because here is a Read()
operation where the caller does not make a choice but instead hangs up while
the system is waiting for a response):
[2022-02-08-06:21:22:] VERBOSE[24858][C-00004037] pbx.c: Executing
[8005551234@ivr-MainMenu:45] Read("SIP/CHANNELNAME-000138ac",
"BalanceRepeatPressed,prompts/004h&prompts/004i&prompts/043,1,,,15") in new
stack
[2022-02-08-06:21:22:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
maximum of 1 digits.
[2022-02-08-06:21:22:] VERBOSE[24858][C-00004037] file.c:
<SIP/CHANNELNAME-000138ac> Playing 'prompts/004h.slin' (language 'en')
[2022-02-08-06:21:25:] VERBOSE[24858][C-00004037] file.c:
<SIP/CHANNELNAME-000138ac> Playing 'prompts/004i.slin' (language 'en')
[2022-02-08-06:21:28:] VERBOSE[24858][C-00004037] file.c:
<SIP/CHANNELNAME-000138ac> Playing 'prompts/043.slin' (language 'en')
[2022-02-08-06:21:33:] VERBOSE[24858][C-00004037] app_read.c: User disconnected
[2022-02-08-06:21:33:] VERBOSE[24858][C-00004037] pbx.c: Executing
[h@ivr-MainMenu:1] NoOp("SIP/CHANNELNAME-000138ac", "Hangup handler
GlobalCallCount=0 CHANNELNAME=0 ") in new stack
[2022-02-08-06:21:33:] VERBOSE[24858][C-00004037] pbx.c: Executing
[h@ivr-MainMenu:2] NoOp("SIP/CHANNELNAME-000138ac", "SurveyType is ") in new
stack
[2022-02-08-06:21:33:] VERBOSE[24858][C-00004037] pbx.c: Executing
[h@ivr-MainMenu:3] ExecIf("SIP/CHANNELNAME-000138ac", "1?Hangup()") in new
stack
[2022-02-08-06:21:33:] VERBOSE[24858][C-00004037] pbx.c: Spawn extension
(ivr-MainMenu, h, 3) exited non-zero on 'SIP/CHANNELNAME-000138ac'
--
Jim Van Meggelen
ClearlyCore Inc.
+1-416-639-6001 (DID)
+1-877-253-2716 (Canada)
+1-866-644-7729 (USA)
+1-416-425-6111 x6001
[email protected]
[ http://www.clearlycore.com/ | http://www.clearlycore.com ]
Asterisk: The Definitive Guide
FIFTH EDITION NOW AVAILABLE TO DOWNLOAD:
[ https://cdn.oreillystatic.com/pdf/Asterisk_The_Definitive_Guide.pdf |
https://cdn.oreillystatic.com/pdf/Asterisk_The_Definitive_Guide.pdf ]
> From: "Risto Vaarandi" <[email protected]>
> To: "Jim Van Meggelen" <[email protected]>
> Cc: "simple-evcorr-users" <[email protected]>
> Sent: Thursday, 31 March, 2022 10:35:49
> Subject: Re: [Simple-evcorr-users] Parsing Asterisk log files for downstream
> reporting - so far so good!
> hi Jim,
> can you provide an example of the log event that indicates the end of the
> call?
> kind regards,
> risto
> Kontakt Jim Van Meggelen (< [ mailto:[email protected] |
> [email protected] ] >) kirjutas kuupäeval N, 31. märts 2022 kell
> 15:45:
>> Risto,
>> Thank you for the reply.
>> You are correct that the C-[0-9a-f]{8} string uniquely identifies each call,
>> and
>> is present on all log lines.
>> We cannot safely assume the maximum call length; some calls could reasonably
>> be
>> 30 minutes or even more. We will be able to identify the end of call, though,
>> so a pattern/rule can look for that.
>> I'm very interested in your thoughts. Thanks again.
>> --
>> Jim Van Meggelen
>> ClearlyCore Inc.
>> +1-416-639-6001 (DID)
>> +1-877-253-2716 (Canada)
>> +1-866-644-7729 (USA)
>> +1-416-425-6111 x6001
>> [ mailto:[email protected] | [email protected] ]
>> [ http://www.clearlycore.com/ | http://www.clearlycore.com ]
>> Asterisk: The Definitive Guide
>> FIFTH EDITION NOW AVAILABLE TO DOWNLOAD:
>> [ https://cdn.oreillystatic.com/pdf/Asterisk_The_Definitive_Guide.pdf |
>> https://cdn.oreillystatic.com/pdf/Asterisk_The_Definitive_Guide.pdf ]
>>> From: "Risto Vaarandi" < [ mailto:[email protected] |
>>> [email protected] ] >
>>> To: "Jim Van Meggelen" < [ mailto:[email protected] |
>>> [email protected] ] >
>>> Cc: [ mailto:[email protected] |
>>> [email protected] ]
>>> Sent: Thursday, 31 March, 2022 05:48:44
>>> Subject: Re: [Simple-evcorr-users] Parsing Asterisk log files for downstream
>>> reporting - so far so good!
>>> hi Jim,
>>> I do have couple of things in mind that might help addressing this issue,
>>> but
>>> before coming up with any suggestions, may I ask some questions? As I
>>> understand, the phone call is uniquely identified by the numeral that
>>> follows
>>> the C character (C-00004037 in your example) which is present in all log
>>> messages for that particular call.
>>> However, is there also a specific log message that denotes the end of the
>>> call?
>>> If there is no message indicating the end-of-call, can we assume that the
>>> call
>>> has ended if there have been no messages for that call ID for the last 5 or
>>> 10
>>> minutes?
>>> kind regards,
>>> risto
>>> Kontakt Jim Van Meggelen (< [ mailto:[email protected] |
>>> [email protected] ] >) kirjutas kuupäeval N, 31. märts 2022
>>> kell
>>> 07:41:
>>>> I have an atypical use for SEC, in which I'm parsing Asterisk log files to
>>>> produce CSV peg counts for downstream usage reporting.
>>>> This is working well and I'm loving this tool!
>>>> However, I've run into a problem that I cannot seem to find a way around.
>>>> The log file produces events that are tied to a unique ID for each
>>>> channel/call
>>>> ( C-00000000 ), and using that, plus the timestamp, I can produce output
>>>> that
>>>> is correlated with a call, and chronological. So far so good.
>>>> However, there's one event that is difficult to work with, because it can
>>>> happen
>>>> more than once on a typical phone call, needs to correlate with an event
>>>> that
>>>> happens a few lines prior, but carries no identifying correlation.
>>>> Here's an example of the output I'm working with (curated for brevity and
>>>> relevance, and specific to a single unique ID; there are actually hundreds
>>>> of
>>>> lines of output per-call):
>>>> [2022-02-08-06:17:53:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-welcome:9] Read("SIP/CHANNELNAME-000138ac",
>>>> "EarlyChoice,prompts/001,1,,0,0.01") in new stack
>>>> [2022-02-08-06:17:53:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:17:53:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/001.slin' (language 'en')
>>>> [2022-02-08-06:17:55:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:17:55:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-welcome:13] Read("SIP/CHANNELNAME-000138ac",
>>>> "EarlyChoice,prompts/001,1,,0,0.01") in new stack
>>>> [2022-02-08-06:17:55:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:17:55:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/001.slin' (language 'fr')
>>>> [2022-02-08-06:17:58:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:17:58:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-welcome:17] Read("SIP/CHANNELNAME-000138ac",
>>>> "LanguageChoice,prompts/002,1,,,0.01") in new stack
>>>> [2022-02-08-06:17:58:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:17:58:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/002.slin' (language 'en')
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-welcome:21] Read("SIP/CHANNELNAME-000138ac",
>>>> "LanguageChoice,prompts/002,1,,1,15") in new stack
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/002.slin' (language 'fr')
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> '1'
>>>> --
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-welcome:34] Read("SIP/CHANNELNAME-000138ac",
>>>> "ActivationHelp,prompts/902&prompts/063,1,,,15,") in new stack
>>>> [2022-02-08-06:18:01:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/902.slin' (language 'en')
>>>> [2022-02-08-06:18:16:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/063.slin' (language 'en')
>>>> [2022-02-08-06:18:32:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> '3'
>>>> --
>>>> [2022-02-08-06:19:36:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:2] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/044,1,,,0.01") in new stack
>>>> [2022-02-08-06:19:36:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:19:36:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/044.slin' (language 'en')
>>>> [2022-02-08-06:19:46:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:19:55:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:8] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/045,1,,,0.01") in new stack
>>>> [2022-02-08-06:19:55:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:19:55:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/045.slin' (language 'en')
>>>> [2022-02-08-06:19:57:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:20:02:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:11] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/045a,1,,,0.01") in new stack
>>>> [2022-02-08-06:20:02:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:20:02:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/045a.slin' (language 'en')
>>>> [2022-02-08-06:20:04:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:20:07:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:15] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/046,1,,,0.01") in new stack
>>>> [2022-02-08-06:20:07:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:20:07:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/046.slin' (language 'en')
>>>> [2022-02-08-06:20:09:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:20:18:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:39] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/049,1,,,0.01") in new stack
>>>> [2022-02-08-06:20:18:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:20:18:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/049.slin' (language 'en')
>>>> [2022-02-08-06:20:21:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:20:26:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:45] Read("SIP/CHANNELNAME-000138ac",
>>>> "BalanceRepeatPressed,prompts/004h&prompts/004i&prompts/043,1,,,15") in new
>>>> stack
>>>> [2022-02-08-06:20:26:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:20:26:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/004h.slin' (language 'en')
>>>> [2022-02-08-06:20:29:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/004i.slin' (language 'en')
>>>> [2022-02-08-06:20:32:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> '1'
>>>> --
>>>> [2022-02-08-06:20:32:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:2] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/044,1,,,0.01") in new stack
>>>> [2022-02-08-06:20:32:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:20:32:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/044.slin' (language 'en')
>>>> [2022-02-08-06:20:42:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> --
>>>> [2022-02-08-06:20:51:] VERBOSE[24858][C-00004037] pbx.c: Executing
>>>> [8005551234@ivr-MainMenu:8] Read("SIP/CHANNELNAME-000138ac",
>>>> "ListenForZero,prompts/045,1,,,0.01") in new stack
>>>> [2022-02-08-06:20:51:] VERBOSE[24858][C-00004037] app_read.c: Accepting a
>>>> maximum of 1 digits.
>>>> [2022-02-08-06:20:51:] VERBOSE[24858][C-00004037] file.c:
>>>> <SIP/CHANNELNAME-000138ac> Playing 'prompts/045.slin' (language 'en')
>>>> [2022-02-08-06:20:53:] VERBOSE[24858][C-00004037] app_read.c: User entered
>>>> nothing.
>>>> The event I want to peg is each of the ' app_read.c: User entered '
>>>> events, but
>>>> they each need to correlate with the Read("SIP/CHANNELNAME ... event that
>>>> precedes them.
>>>> Here is a rule I've written specifically to attempt to catch a line
>>>> containing
>>>> Read("SIP/CHANNELNAME-000138ac",
>>>> "ActivationHelp,prompts/902&prompts/063,1,,,15,") :
>>>> (it's a bit of a mess because I've been trying differnt things to get it
>>>> to work
>>>> the way I need it to)
>>>> (the regexp is probably overly elaborate, but [ http://regex101.com/ |
>>>> regex101.com ] makes it too fun not to!)
>>>> type=PAIR
>>>> desc=IVR caller offered activation or statement inquiry
>>>> ptype=RegExp
>>>> action=create IVR_activation_offered_$4 ; \
>>>> write - $4 activation or statement inquiry offered
>>>> pattern=^.*\[(20[234][0-9]-[0-9]{2}-[0-3][0-9])-([0-2][0-9]:[0-5][0-9]:[0-5][0-9]).*VERBOSE\[([0-9]{3,6})\]\[(C-[0-9a-f]{8})\].*Executing
>>>> \[(.+)\@(flexiti-ivr-welcome:[0-9]{1,3})\] (.+)\(\"([A-Z]{3,10})\/(.+)\",
>>>> \"ActivationHelp,prompts.*
>>>> ptype2=regexp
>>>> pattern2=^.*\[(20[234][0-9]-[0-9]{2}-[0-3][0-9])-([0-2][0-9]:[0-5][0-9]:[0-5][0-9]).*VERBOSE\[([0-9]{3,6})\]\[(C-[0-9a-f]{8})\].*
>>>> app_read.c: User entered '?(nothing|[0-9]*)'?.*
>>>> desc2=Flexiti IVR - caller selection at activation or statement inquiry
>>>> action2=assign %i -ivr ; \
>>>> write %p%i.csv $1,$2,$4,,,,,,,,,$5 ; closef %p%i.csv ; \
>>>> write - $4 ACTIVATION_STATEMENT %p %i $1 User entered: $5
>>>> This works, but then keeps matching the pattern2 throughout the call,
>>>> whereas
>>>> what I want is to match the ActivationHelp, then match the very first 'User
>>>> entered' following that, and then stop matching for this rule. There will
>>>> be
>>>> other similar matches too (but not ' ActivationHelp '), and those too need
>>>> to
>>>> correlate with one and only the first ' User entered ' that follows them.
>>>> I'm sure it's something simple I'm missing, but I've been banging my head
>>>> against the wall on this and I just can't see where my error is.
>>>> I'm still learning SEC, so there's a lot I just don't get, and this is
>>>> right at
>>>> the limits of my skills.
>>>> Any and all advice would be gratefully appreciated.
>>>> Jim
>>>> --
>>>> Jim Van Meggelen
>>>> ClearlyCore Inc.
>>>> +1-416-639-6001 (DID)
>>>> +1-877-253-2716 (Canada)
>>>> +1-866-644-7729 (USA)
>>>> +1-416-425-6111 x6001
>>>> [ mailto:[email protected] | [email protected]
>>>> ]
>>>> [ http://www.clearlycore.com/ | http://www.clearlycore.com ]
>>>> Asterisk: The Definitive Guide
>>>> FIFTH EDITION NOW AVAILABLE TO DOWNLOAD:
>>>> [ https://cdn.oreillystatic.com/pdf/Asterisk_The_Definitive_Guide.pdf |
>>>> https://cdn.oreillystatic.com/pdf/Asterisk_The_Definitive_Guide.pdf ]
>>>> _______________________________________________
>>>> Simple-evcorr-users mailing list
>>>> [ mailto:[email protected] |
>>>> [email protected] ]
>>>> [ https://lists.sourceforge.net/lists/listinfo/simple-evcorr-users |
>>>> https://lists.sourceforge.net/lists/listinfo/simple-evcorr-users ]
_______________________________________________
Simple-evcorr-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/simple-evcorr-users
