Hi Guys,
I’m investigating an issue. We are using the commerical module voicemail notifications that monitors a mailbox.
I’ve configured it so that on failure or on success an email is sent.
I’m getting complaints that sometimes no email is sent after listening and accepting the voicemail.
When I check the mail log I can see that no attempt was made to send an email.
How can this happen?
Here is part of the log which seamed relevant to me.
[2018-11-29 19:15:09] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (0)
[2018-11-29 19:15:09] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'silence/1.slin16' (escape_digits=) (sample_offset 0) (language 'en')
[2018-11-29 19:15:09] VERBOSE[3888][C-00000819] bridge_channel.c: Channel Local/XXXXXXXXXX@vmnotify-main-00002b69;2 left 'simple_bridge' basic-bridge <78bfd054-9a14-4204-8edb-4308de746cdc>
[2018-11-29 19:15:09] VERBOSE[3888][C-00000819] bridge_channel.c: Channel Local/XXXXXXXXXX@from-internal-00002b6a;2 left 'simple_bridge' basic-bridge <0971c1a1-9b30-4448-a68c-fe6ad3cf6562>
[2018-11-29 19:15:09] VERBOSE[3888][C-00000819] bridge_channel.c: Channel Local/XXXXXXXXXX@vmnotify-main-00002b69;2 swapped with Local/XXXXXXXXXX@from-internal-00002b6a;2 into 'simple_bridge' basic-bridge <0971c1a1-9b30-4448-a68c-fe6ad3cf6562>
[2018-11-29 19:15:09] VERBOSE[3888][C-00000819] bridge_channel.c: Channel Local/XXXXXXXXXX@from-internal-00002b6a;1 left 'simple_bridge' basic-bridge <78bfd054-9a14-4204-8edb-4308de746cdc>
[2018-11-29 19:15:09] VERBOSE[3748][C-00000819] app_macro.c: Spawn extension (macro-dialout-trunk, s, 24) exited non-zero on 'Local/XXXXXXXXXX@from-internal-00002b6a;2' in macro 'dialout-trunk'
[2018-11-29 19:15:09] VERBOSE[3748][C-00000819] pbx.c: Spawn extension (outbound-allroutes, XXXXXXXXXX, 7) exited non-zero on 'Local/XXXXXXXXXX@from-internal-00002b6a;2'
[2018-11-29 19:15:10] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'vmnotify-greeting.slin' (escape_digits=) (sample_offset 0) (language 'en')
[2018-11-29 19:15:13] VERBOSE[3745] file.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'digits/4.slin16' (language 'en')
[2018-11-29 19:15:14] VERBOSE[3745] file.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'digits/0.slin16' (language 'en')
[2018-11-29 19:15:15] VERBOSE[3745] file.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'digits/3.slin16' (language 'en')
[2018-11-29 19:15:15] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (0)
[2018-11-29 19:15:15] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'vmnotify-instructions.slin' (escape_digits=123) (sample_offset 0) (language 'en')
[2018-11-29 19:15:19] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (rcinput:)
[2018-11-29 19:15:20] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (0)
[2018-11-29 19:15:20] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing '/var/lib/asterisk/sounds/vmnotify/403/29/msg0000.slin' (escape_digits=123) (sample_offset 0) (language 'en')
[2018-11-29 19:16:07] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (offset:)
[2018-11-29 19:16:07] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (pbinput:)
[2018-11-29 19:16:07] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (0)
[2018-11-29 19:16:07] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'vmnotify-instructions2.slin' (escape_digits=123) (sample_offset 0) (language 'en')
[2018-11-29 19:16:12] VERBOSE[3745] res_agi.c: AGI Script Executing Application: (NoOp) Options: (0)
[2018-11-29 19:16:12] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'vmnotify-thankyou.slin' (escape_digits=) (sample_offset 0) (language 'en')
[2018-11-29 19:16:13] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1> Playing 'vmnotify-goodbye.slin' (escape_digits=) (sample_offset 0) (language 'en')
[2018-11-29 19:16:14] VERBOSE[3884][C-00000819] bridge_channel.c: Channel SIP/TELENET-00001be7 left 'simple_bridge' basic-bridge <0971c1a1-9b30-4448-a68c-fe6ad3cf6562>
[2018-11-29 19:16:14] VERBOSE[3746][C-00000819] bridge_channel.c: Channel Local/XXXXXXXXXX@vmnotify-main-00002b69;2 left 'simple_bridge' basic-bridge <0971c1a1-9b30-4448-a68c-fe6ad3cf6562>
[2018-11-29 19:16:14] VERBOSE[3746][C-00000819] pbx.c: Spawn extension (vmnotify-main, XXXXXXXXXX, 2) exited non-zero on 'Local/XXXXXXXXXX@vmnotify-main-00002b69;2'
[2018-11-29 19:16:14] VERBOSE[3745] res_agi.c: <Local/XXXXXXXXXX@vmnotify-main-00002b69;1>AGI Script vmnotify-main.php completed, returning 4
[2018-11-29 19:16:14] NOTICE[3745] pbx_spool.c: Call completed to Local/XXXXXXXXXX@vmnotify-main
[2018-11-29 19:17:44] VERBOSE[4242] pbx_spool.c: Attempting call on Local/1@vmnotify-dummy for application AGI(vmnotify-audit.php) (Retry 1)
[2018-11-29 19:17:44] VERBOSE[4247][C-0000081a] pbx.c: Executing [1@vmnotify-dummy:1] Answer("Local/1@vmnotify-dummy-00002b6b;2", "") in new stack
[2018-11-29 19:17:44] VERBOSE[4242] dial.c: Called 1@vmnotify-dummy
[2018-11-29 19:17:44] VERBOSE[4242] dial.c: Local/1@vmnotify-dummy-00002b6b;1 answered
[2018-11-29 19:17:44] VERBOSE[4242] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/vmnotify-audit.php
[2018-11-29 19:17:44] VERBOSE[4242] res_agi.c: AGI Script Executing Application: (NoOp) Options: (1)
[2018-11-29 19:17:44] VERBOSE[4242] res_agi.c: <Local/1@vmnotify-dummy-00002b6b;1> Playing 'vmnotify-too-late.slin' (escape_digits=) (sample_offset 0) (language 'en')
[2018-11-29 19:17:44] VERBOSE[4247][C-0000081a] pbx.c: Executing [1@vmnotify-dummy:2] Wait("Local/1@vmnotify-dummy-00002b6b;2", "300") in new stack
[2018-11-29 19:17:48] VERBOSE[4242] res_agi.c: <Local/1@vmnotify-dummy-00002b6b;1>AGI Script vmnotify-audit.php completed, returning 4
[2018-11-29 19:17:48] NOTICE[4242] pbx_spool.c: Call completed to Local/1@vmnotify-dummy
[2018-11-29 19:17:48] VERBOSE[4247][C-0000081a] pbx.c: Spawn extension (vmnotify-dummy, 1, 2) exited non-zero on 'Local/1@vmnotify-dummy-00002b6b;2'
My system is completely up to date and I’m on v14, asterisk 13