Voicemail failures between endpoints on FreePBX and phones Cisco Call Manager

Hello

We have a Cisco Call Manager cluster where the bulk of our phones reside.
We use FreePBX Asterisk as our voicemail, queuing and IVR system.
The two systems are connected via SIP Trunk.
We have added custom programming within extensions_custom.conf to support voicemail for our Cisco Phones. We also have a Custom destination “VM Pilot” which was designed for our FreePBX system to receive voicemail from the Cisco System.
We are piloting sangoma phones on the FreePBX system as an alternative PBX choice.
I have run into problems with voicemail between phones on the two separate systems.
I can place a call from a device on the Cisco PBX to a Sangoma phone that is registered on the FreePBX system and successfully leave a voicemail message on the Sangoma Phone.
MWI works fine. Vmail to email is functioning normally.

I cannot call from a Sangoma phone to a Cisco phone and leave a voicemail message.
The system acts like it is recording the voicemail message, however right at the end of leaving the voicemail message I get a prompt from the system “Thank you. I’m sorry an error has occured” and the call is disconnected.

Here is tail end of call log:

[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-vm:4] GotoIf(“SIP/3600-0002a455”, “1?vmx,1”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:1] Set(“SIP/3600-0002a455”, “__EXTTOCALL=7594”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:2] Set(“SIP/3600-0002a455”, “__CRM_VOICEMAIL=7594”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:3] Set(“SIP/3600-0002a455”, “MEXTEN=7594”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:4] Set(“SIP/3600-0002a455”, “MMODE=NOANSWER”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:5] Set(“SIP/3600-0002a455”, “RETVM=”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:6] Set(“SIP/3600-0002a455”, “MODE=unavail”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:7] Macro(“SIP/3600-0002a455”, “get-vmcontext,7594”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-get-vmcontext:1] Set(“SIP/3600-0002a455”, “VMCONTEXT=default”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/3600-0002a455”, “0?200:300”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp(“SIP/3600-0002a455”, “”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:8] Set(“SIP/3600-0002a455”, “MODE=unavail”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:9] NoOp(“SIP/3600-0002a455”, “MODE IS: unavail”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:10] GotoIf(“SIP/3600-0002a455”, “1?chknomsg”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:12] GotoIf(“SIP/3600-0002a455”, “0?s-NOANSWER,1”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:13] GotoIf(“SIP/3600-0002a455”, “1?notdirect”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:15] NoOp(“SIP/3600-0002a455”, "Checking if ext 7594 is enabled: ") in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [vmx@macro-vm:16] GotoIf(“SIP/3600-0002a455”, “1?s-NOANSWER,1”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s-NOANSWER@macro-vm:1] Macro(“SIP/3600-0002a455”, “get-vmcontext,7594”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-get-vmcontext:1] Set(“SIP/3600-0002a455”, “VMCONTEXT=default”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/3600-0002a455”, “0?200:300”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp(“SIP/3600-0002a455”, “”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail(“SIP/3600-0002a455”, “7594@default,sug(12)”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘/var/spool/asterisk/voicemail/default/7594/unavail.slin’ (language ‘en’)
[2019-08-20 15:18:09] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘beep.ulaw’ (language ‘en’)
[2019-08-20 15:18:18] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘auth-thankyou.ulaw’ (language ‘en’)
[2019-08-20 15:18:19] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s-NOANSWER@macro-vm:3] Goto(“SIP/3600-0002a455”, “exit-FAILED,1”) in new stack
[2019-08-20 15:18:19] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [exit-FAILED@macro-vm:1] Playback(“SIP/3600-0002a455”, “im-sorry&an-error-has-occurred”) in new stack
[2019-08-20 15:18:19] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘im-sorry.ulaw’ (language ‘en’)
[2019-08-20 15:18:20] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘an-error-has-occurred.ulaw’ (language ‘en’)
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [exit-FAILED@macro-vm:2] GotoIf(“SIP/3600-0002a455”, “0?exit-RETURN,1”) in new stack
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [exit-FAILED@macro-vm:3] Hangup(“SIP/3600-0002a455”, “”) in new stack
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] app_macro.c: Spawn extension (macro-vm, exit-FAILED, 3) exited non-zero on ‘SIP/3600-0002a455’ in macro ‘vm’
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] app_macro.c: Spawn extension (macro-exten-vm, s, 26) exited non-zero on ‘SIP/3600-0002a455’ in macro ‘exten-vm’
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Spawn extension (ext-local, 7594, 2) exited non-zero on ‘SIP/3600-0002a455’
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [h@ext-local:1] Macro(“SIP/3600-0002a455”, “hangupcall,”) in new stack
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“SIP/3600-0002a455”, “1?theend”) in new stack
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“SIP/3600-0002a455”, “0?Set(CDR(recordingfile)=)”) in new stack
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s@macro-hangupcall:4] Hangup(“SIP/3600-0002a455”, “”) in new stack
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/3600-0002a455’ in macro ‘hangupcall’
[2019-08-20 15:18:22] VERBOSE[18718][C-0000ec2d] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/3600-0002a455’

Does our custom file require tweaking?
Thank you for your assistance.
Kind regards,
Carol

Hi Carol:

I assume the SIP trunk between the two PBX’s is the same technology as the Sangoma phone (i.e. both are chan_sip) in which case what is likely happening is that the second leg of the call back to the FreePBX system for the vm is being interpreted as a call from the phone and not from the Cisco. If you use different SIP drivers for your phones and your trunk, that should fix, otherwise you need to investigate your peer trunk config so the From header on the inbound invite to the FreePBX system does not match a local extension on the system.

edit: looking over your call trace, I may be way off base here

I am off base, the above doesn’t apply. Relevant lines:

[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail(“SIP/3600-0002a455”, “7594@default,sug(12)”) in new stack
[2019-08-20 15:18:06] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘/var/spool/asterisk/voicemail/default/7594/unavail.slin’ (language ‘en’)
[2019-08-20 15:18:09] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘beep.ulaw’ (language ‘en’)
[2019-08-20 15:18:18] VERBOSE[18718][C-0000ec2d] file.c: <SIP/3600-0002a455> Playing ‘auth-thankyou.ulaw’ (language ‘en’)
[2019-08-20 15:18:19] VERBOSE[18718][C-0000ec2d] pbx.c: Executing [s-NOANSWER@macro-vm:3] Goto(“SIP/3600-0002a455”, “exit-FAILED,1”) in new stack

All appears to proceed properly until the end of the message when an Error happens. No idea what the error is, possibly there is no audio received.

1 Like

Thank you Lorne.
The channel sip drive on Freepbx is chan-sip.
The outgoing traffic across the trunk type is peer over port 5060, with allowing ulaw&alaw
The incoming traffics across the trunk type is peer over port 5062

Carol

If you change the extension channel driver on the FreePBX side to PJ-SIP, it might alleviate some of the problem. This way, the SIP stuff is ‘server-to-server’ and the extension stuff is a different (yet still SIP) protocol.

PJ-Sip is not activated on the server at this point. Is this a transparent change to turn it up or best to do during a maintenance window? Any impact I should be looking for to our production environment by turning up this protocol? The bulk of our extensions are custom extensions as used strictly for voicemail. The Sangoma devices are the only SIP devices on the system.

Thank you,

Yes, and probably yes. I’m a chicken, so that’s the way I’d do it. You should be able to convert the devices seamlessly, but you’ll want to make sure you set the 5060 port to Chan-SIP and 5160 to PJ-SIP. This is going to be a manual change under the Advanced SIP settings in the Advanced tab.

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.