BUG Voicemails not saving after latest update

[erth64net]

We're seeing some odd behavior with voicemails. After adding a SIP user (6010) via the web interface, then calling extension 6010 & leaving a message, two unexpected events occur:

1. Voicemail isn't saved & MWI indicator on otherwise factory default SPA514G doesn't light. No email address was configured for that extension.
2. After leaving a voicemail, if you press #, and then 1 to accept the message...wait 2 seconds, and you'll be greeted with a very odd long message, stating things such as "Congratulations, you have successfully installed Asterisk...dial 500 to test an inter-asterisk exchange...."

How do we correct these issues?

Using a largely stock build on a 1GB rPi:
Linux incrediblepi2 3.18.7-v7+ #755 SMP PREEMPT Thu Feb 12 17:20:48 GMT 2015 armv7l GNU/Linux
Asterisk/11.16.0
Asterisk GUI-version : SVN-branch-2.0-r5220

 

[Jonathan W]

I'm seeing the same issue of voicemails not getting through and after pressing # at the end of recording a voicemail it says thanks and goes straight into the "Congratulations, you have successfully installed..."
Fresh install on a Raspberry Pi 2. OS and Asterix versions:
Linux incrediblepi 3.18.11-v7+ #781 SMP PREEMPT Tue Apr 21 18:07:59 BST 2015 armv7l GNU/Linux
Asterisk/11.17.1
Asterisk GUI-version : SVN-branch-2.0-r5220

I did get more voicemails to record by adjusting the volume threshold from the default 128 down to 8. Got most except the whisperers at 32, so I just bumped it down to be safe.

I still get bumped out to the Congratulations after pressing # though, and would love to know where that is coming from.

 

[Jonathan W]

I've found more info on this issue. I ran some tests while watching the Asterisk command line to see what was happening with each call to end up in the congratulations message. Here's the output from a test using Polycom phones calling extension 26. My comments along the way start with a #

 == Using SIP RTP CoS mark 5
    -- Executing [26@DLPN_DialPlanMain:1] Macro("SIP/26-00000207", "stdexten,26,SIP/26") in new stack
    -- Executing [s@macro-stdexten:1] Set("SIP/26-00000207", "__DYNAMIC_FEATURES=sms-dictator#record-me#conference#sms-blast") in new stack
    -- Executing [s@macro-stdexten:2] Set("SIP/26-00000207", "ORIG_ARG1=26") in new stack
    -- Executing [s@macro-stdexten:3] GotoIf("SIP/26-00000207", "0?6:4") in new stack
    -- Goto (macro-stdexten,s,4)
    -- Executing [s@macro-stdexten:4] Dial("SIP/26-00000207", "SIP/26,20,tThHkK") in new stack
  == Using SIP RTP CoS mark 5
    -- Called SIP/26
# Extension 26 is on DND so returns Busy
    -- Got SIP response 486 "Busy Here" back from 10.1.10.198:5060
    -- SIP/26-00000208 is busy
  == Everyone is busy/congested at this time (1:1/0/0)
    -- Executing [s@macro-stdexten:5] Goto("SIP/26-00000207", "s-BUSY,1") in new stack
    -- Goto (macro-stdexten,s-BUSY,1)
# Plays the busy voicemail message
    -- Executing [s-BUSY@macro-stdexten:1] VoiceMail("SIP/26-00000207", "26,b") in new stack
      > 0x72a330e0 -- Probation passed - setting RTP source address to 10.1.10.198:2264
    -- <SIP/26-00000207> Playing '/var/spool/asterisk/voicemail/default/26/busy.slin' (language 'en')
    -- <SIP/26-00000207> Playing 'vm-intro.gsm' (language 'en')
    -- <SIP/26-00000207> Playing 'beep.gsm' (language 'en')
    -- Recording the message
    -- x=0, open writing:  /var/spool/asterisk/voicemail/default/26/tmp/ZRGyPe format: wav, 0xe109bc
    -- x=1, open writing:  /var/spool/asterisk/voicemail/default/26/tmp/ZRGyPe format: wav49, 0xe15004
    -- User ended message by pressing #
    -- <SIP/26-00000207> Playing 'auth-thankyou.gsm' (language 'en')
  == Parsing '/var/spool/asterisk/voicemail/default/26/INBOX/msg0000.txt': Found
  == Parsing '/var/spool/asterisk/voicemail/default/26/INBOX/msg0000.txt': Found
# Here is seems to be calling step 2 of the busy function with the "default,s,1" as the last step
    -- Executing [s-BUSY@macro-stdexten:2] Goto("SIP/26-00000207", "default,s,1") in new stack
# So now it's jumping to "default,s,1"
    -- Goto (default,s,1)
  == Channel 'SIP/26-00000207' jumping out of macro 'stdexten'
    -- Executing [s@default:1] wait("SIP/26-00000207", "1")
    -- Executing [s@default:1] answer("SIP/26-00000207", "")
    -- Digit timeout set to 5.000
    -- Response timeout set to 10.000
# Here's the problem! This seems to be in extensions.lua
    -- Executing [s@default:1] background("SIP/26-00000207", "demo-congrats")
    -- <SIP/26-00000207> Playing 'demo-congrats.gsm' (language 'en')
# Then I hang up.
  == Spawn extension (default, s, 1) exited non-zero on 'SIP/26-00000207'
    -- Executing [h@default:1] Hangup("SIP/26-00000207", "") in new stack
  == Spawn extension (default, h, 1) exited non-zero on 'SIP/26-00000207'

So after all of this I commented out the two lines in extensions.lua correspond to demo-congrats and added a hang-up call. I no longer get the congrats message, but still can't understand where the initial call to extensions.lua is coming from. It appears bandaged in our system, but I'd love to know the root cause.