Unexpected Behaviour with Voicemail

GyasiCaesar · August 29, 2019, 5:39pm

I am having a very strange issue with voicemail on FreePBX 14.

I am using pjsip extensions and x-lite as the endpoint

If an extension has voicemail disabled it can dial *97 or *98 and use the menu to check voicemail fo any other extension on the server by supplying the correct box number and password.

Once i enable voicemail for an extension:

Dialing *97 from that extension results in an immediate hang up of the call. the voicemail menu is not played.

In the asterisk cli the following message is displayed.

Priority ‘mbexist’ must be a value > 0, or a valid label

Dialing *98 from that extension plays the voicemail menu and when any extension is specified the call is ended.

in the asterisk cli the following message is displayed.

Priority ‘good’ must be a value > 0, or a valid label

I’ve tried reloading the voicemail module and rebooting the server with no success.
any assistance would be greatly appreciated.

Thanks

PitzKey · August 29, 2019, 5:52pm

Try leaving a voicemail in any mailbox, then try calling it via *97/*98

If it still doesn’t go, post a full log.

GyasiCaesar · August 29, 2019, 6:33pm

I left a voicemail message for ext 2902.

I get the behaviou r above when i try to check the voicemail from that extension.

full.tgz (243.2 KB)

The log file is attached. It’s a .zip (extension changed to tgz)

Excerpt Below

[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:34] NoOp("PJSIP/2903-00000013", "Blind Transfer: , Attended Transfer: , User: 2903, Alert Info: ") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:35] ExecIf("PJSIP/2903-00000013", "1?Set(ALERT_INFO=)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:36] ExecIf("PJSIP/2903-00000013", "0?Set(ALERT_INFO=)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:37] ExecIf("PJSIP/2903-00000013", "0?Set(ALERT_INFO=)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:38] ExecIf("PJSIP/2903-00000013", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:39] ExecIf("PJSIP/2903-00000013", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:40] GosubIf("PJSIP/2903-00000013", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:41] ExecIf("PJSIP/2903-00000013", "0?Set(CHANNEL(musicclass)=)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:42] GosubIf("PJSIP/2903-00000013", "0?qwait,1()") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:43] Set("PJSIP/2903-00000013", "__CWIGNORE=") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:44] Set("PJSIP/2903-00000013", "__KEEPCID=TRUE") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:45] GotoIf("PJSIP/2903-00000013", "0?usegoto,1") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:46] GotoIf("PJSIP/2903-00000013", "0?godial") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:47] Gosub("PJSIP/2903-00000013", "sub-presencestate-display,s,1(2902)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@sub-presencestate-display:1] Goto("PJSIP/2903-00000013", "state-not_set,1") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (sub-presencestate-display,state-not_set,1)
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [state-not_set@sub-presencestate-display:1] Set("PJSIP/2903-00000013", "PRESENCESTATE_DISPLAY=") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [state-not_set@sub-presencestate-display:2] Return("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:48] Set("PJSIP/2903-00000013", "CONNECTEDLINE(name,i)=Jabari Gordon") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:49] Set("PJSIP/2903-00000013", "CONNECTEDLINE(num)=2902") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:50] Set("PJSIP/2903-00000013", "D_OPTIONS=HhTtrI") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:51] Macro("PJSIP/2903-00000013", "dialout-one-predial-hook,") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:52] ExecIf("PJSIP/2903-00000013", "0?Set(D_OPTIONS=HhtrII)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:53] NoOp("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:54] ExecIf("PJSIP/2903-00000013", "0?Set(D_OPTIONS=HhTtrIg)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:55] Dial("PJSIP/2903-00000013", "PJSIP/2902/sip:[email protected]:52900;rinstance=733b5f5e46e396be,15,HhTtrIb(func-apply-sipheaders^s^1)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] app_stack.c: PJSIP/2902-00000014 Internal Gosub(func-apply-sipheaders,s,1) start
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("PJSIP/2902-00000014", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("PJSIP/2902-00000014", "Applying SIP Headers to channel PJSIP/2902-00000014") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:3] Set("PJSIP/2902-00000014", "TECH=PJSIP") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:4] Set("PJSIP/2902-00000014", "SIPHEADERKEYS=") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:5] While("PJSIP/2902-00000014", "0") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] app_while.c: Jumping to priority 10
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] pbx.c: Executing [s@func-apply-sipheaders:11] Return("PJSIP/2902-00000014", "") in new stack
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] app_stack.c: Spawn extension (from-internal, 2902, 1) exited non-zero on 'PJSIP/2902-00000014'
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] app_stack.c: PJSIP/2902-00000014 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] app_dial.c: Called PJSIP/2902/sip:[email protected]:52900;rinstance=733b5f5e46e396be
[2019-08-29 14:17:21] VERBOSE[24861] netsock2.c: Using SIP RTP Audio TOS bits 184
[2019-08-29 14:17:21] VERBOSE[24861] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2019-08-29 14:17:21] VERBOSE[24861] netsock2.c: Using SIP RTP Audio CoS mark 5
[2019-08-29 14:17:21] VERBOSE[24896][C-00000012] app_dial.c: Connected line update to PJSIP/2903-00000013 prevented.
[2019-08-29 14:17:22] VERBOSE[24896][C-00000012] app_dial.c: PJSIP/2902-00000014 is ringing
[2019-08-29 14:17:22] VERBOSE[24896][C-00000012] app_dial.c: PJSIP/2902-00000014 is ringing
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] app_dial.c: Nobody picked up in 15000 ms
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:56] ExecIf("PJSIP/2903-00000013", "0?MacroExit()") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:57] ExecIf("PJSIP/2903-00000013", "0?Set(DIALSTATUS=)") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:58] GosubIf("PJSIP/2903-00000013", "0?s-NOANSWER,1()") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-dial-one:59] MacroExit("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:27] Set("PJSIP/2903-00000013", "SV_DIALSTATUS=NOANSWER") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:28] GosubIf("PJSIP/2903-00000013", "0?docfu,1()") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:29] GosubIf("PJSIP/2903-00000013", "0?docfb,1()") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:30] Set("PJSIP/2903-00000013", "DIALSTATUS=NOANSWER") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:31] ExecIf("PJSIP/2903-00000013", "0?MacroExit()") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:32] GotoIf("PJSIP/2903-00000013", "0?s-NOANSWER,1") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-exten-vm:33] Macro("PJSIP/2903-00000013", "vm,2902,NOANSWER,") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-vm:1] Macro("PJSIP/2903-00000013", "user-callerid,SKIPTTL") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/2903-00000013", "TOUCH_MONITOR=1567102641.19") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/2903-00000013", "AMPUSER=2903") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/2903-00000013", "12?report") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-user-callerid,s,16)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:16] NoOp("PJSIP/2903-00000013", "Macro Depth is 3") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("PJSIP/2903-00000013", "1?report2:macroerror") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/2903-00000013", "1?continue") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:37] Set("PJSIP/2903-00000013", "CALLERID(number)=2903") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:38] Set("PJSIP/2903-00000013", "CALLERID(name)=Eric Jemmott") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("PJSIP/2903-00000013", "0?cnum") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:40] Set("PJSIP/2903-00000013", "CDR(cnam)=Eric Jemmott") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:41] Set("PJSIP/2903-00000013", "CDR(cnum)=2903") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-user-callerid:42] Set("PJSIP/2903-00000013", "CHANNEL(language)=en") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-vm:2] Set("PJSIP/2903-00000013", "VMGAIN=") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-vm:3] Macro("PJSIP/2903-00000013", "blkvm-check,") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-blkvm-check:1] Set("PJSIP/2903-00000013", "GOSUB_RETVAL=") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("PJSIP/2903-00000013", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-blkvm-check:3] MacroExit("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-vm:4] GotoIf("PJSIP/2903-00000013", "1?vmx,1") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-vm,vmx,1)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:1] Set("PJSIP/2903-00000013", "__EXTTOCALL=2902") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:2] Set("PJSIP/2903-00000013", "__CRM_VOICEMAIL=2902") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:3] Set("PJSIP/2903-00000013", "MEXTEN=2902") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:4] Set("PJSIP/2903-00000013", "MMODE=NOANSWER") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:5] Set("PJSIP/2903-00000013", "RETVM=") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:6] Set("PJSIP/2903-00000013", "MODE=unavail") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:7] Macro("PJSIP/2903-00000013", "get-vmcontext,2902") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-get-vmcontext:1] Set("PJSIP/2903-00000013", "VMCONTEXT=default") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("PJSIP/2903-00000013", "0?200:300") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:8] Set("PJSIP/2903-00000013", "MODE=unavail") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:9] NoOp("PJSIP/2903-00000013", "MODE IS: unavail") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:10] GotoIf("PJSIP/2903-00000013", "1?chknomsg") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-vm,vmx,12)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:12] GotoIf("PJSIP/2903-00000013", "0?s-NOANSWER,1") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:13] GotoIf("PJSIP/2903-00000013", "1?notdirect") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-vm,vmx,15)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:15] NoOp("PJSIP/2903-00000013", "Checking if ext 2902 is enabled: ") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [vmx@macro-vm:16] GotoIf("PJSIP/2903-00000013", "1?s-NOANSWER,1") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-vm,s-NOANSWER,1)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s-NOANSWER@macro-vm:1] Macro("PJSIP/2903-00000013", "get-vmcontext,2902") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-get-vmcontext:1] Set("PJSIP/2903-00000013", "VMCONTEXT=default") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("PJSIP/2903-00000013", "0?200:300") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail("PJSIP/2903-00000013", "2902@default,u") in new stack
[2019-08-29 14:17:36] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'vm-theperson.ulaw' (language 'en')
[2019-08-29 14:17:38] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'digits/2.ulaw' (language 'en')
[2019-08-29 14:17:39] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'digits/9.ulaw' (language 'en')
[2019-08-29 14:17:40] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'digits/0.ulaw' (language 'en')
[2019-08-29 14:17:41] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'digits/2.ulaw' (language 'en')
[2019-08-29 14:17:42] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'vm-isunavail.ulaw' (language 'en')
[2019-08-29 14:17:43] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'vm-intro.ulaw' (language 'en')
[2019-08-29 14:17:48] VERBOSE[24896][C-00000012] file.c: <PJSIP/2903-00000013> Playing 'beep.ulaw' (language 'en')
[2019-08-29 14:17:49] VERBOSE[24896][C-00000012] app_voicemail.c: Recording the message
[2019-08-29 14:17:49] VERBOSE[24896][C-00000012] app.c: x=0, open writing:  /var/spool/asterisk/voicemail/default/2902/tmp/LCwor3 format: wav, 0x7fd5480026c0
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] app.c: User hung up
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] app_macro.c: Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'PJSIP/2903-00000013' in macro 'vm'
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] app_macro.c: Spawn extension (macro-exten-vm, s, 33) exited non-zero on 'PJSIP/2903-00000013' in macro 'exten-vm'
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Spawn extension (ext-local, 2902, 2) exited non-zero on 'PJSIP/2903-00000013'
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/2903-00000013", "hangupcall,") in new stack
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/2903-00000013", "1?theend") in new stack
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/2903-00000013", "0?Set(CDR(recordingfile)=)") in new stack
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/2903-00000013", " montior file= ") in new stack
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/2903-00000013", "1?skipagi") in new stack
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/2903-00000013", "") in new stack
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/2903-00000013' in macro 'hangupcall'
[2019-08-29 14:17:55] VERBOSE[24896][C-00000012] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/2903-00000013'
[2019-08-29 14:18:05] VERBOSE[21473] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '10.16.70.10'
[2019-08-29 14:18:05] VERBOSE[21473] netsock2.c: Using SIP RTP Audio TOS bits 184
[2019-08-29 14:18:05] VERBOSE[21473] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2019-08-29 14:18:05] VERBOSE[21473] netsock2.c: Using SIP RTP Audio CoS mark 5
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:1] Macro("PJSIP/2902-00000015", "user-callerid,") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/2902-00000015", "TOUCH_MONITOR=1567102685.21") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/2902-00000015", "AMPUSER=2902") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/2902-00000015", "0?report") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/2902-00000015", "1?Set(REALCALLERIDNUM=2902)") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/2902-00000015", "AMPUSER=2902") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/2902-00000015", "0?limit") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/2902-00000015", "AMPUSERCIDNAME=Jabari Gordon") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("PJSIP/2902-00000015", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("PJSIP/2902-00000015", "0?report") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/2902-00000015", "AMPUSERCID=2902") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:11] Set("PJSIP/2902-00000015", "__DIAL_OPTIONS=HhTtr") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:12] Set("PJSIP/2902-00000015", "CALLERID(all)="Jabari Gordon" <2902>") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("PJSIP/2902-00000015", "0?limit") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("PJSIP/2902-00000015", "0?Set(GROUP(concurrency_limit)=2902)") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("PJSIP/2902-00000015", "0?Set(CHANNEL(language)=)") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:16] NoOp("PJSIP/2902-00000015", "Macro Depth is 1") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("PJSIP/2902-00000015", "1?report2:macroerror") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/2902-00000015", "0?continue") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("PJSIP/2902-00000015", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:20] Set("PJSIP/2902-00000015", "__TTL=64") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:21] GotoIf("PJSIP/2902-00000015", "1?continue") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:37] Set("PJSIP/2902-00000015", "CALLERID(number)=2902") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:38] Set("PJSIP/2902-00000015", "CALLERID(name)=Jabari Gordon") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("PJSIP/2902-00000015", "0?cnum") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:40] Set("PJSIP/2902-00000015", "CDR(cnam)=Jabari Gordon") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:41] Set("PJSIP/2902-00000015", "CDR(cnum)=2902") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-user-callerid:42] Set("PJSIP/2902-00000015", "CHANNEL(language)=en") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:2] Set("PJSIP/2902-00000015", "CONNECTEDLINE(name-charset,i)=utf8") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:3] Set("PJSIP/2902-00000015", "CONNECTEDLINE(name,i)=My Voicemail") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:4] Set("PJSIP/2902-00000015", "CONNECTEDLINE(num,i)=2902") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:5] Answer("PJSIP/2902-00000015", "") in new stack
[2019-08-29 14:18:05] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:6] Wait("PJSIP/2902-00000015", "1") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:7] Macro("PJSIP/2902-00000015", "get-vmcontext,2902") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-get-vmcontext:1] Set("PJSIP/2902-00000015", "VMCONTEXT=default") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("PJSIP/2902-00000015", "0?200:300") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("PJSIP/2902-00000015", "") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:8] Set("PJSIP/2902-00000015", "VMBOXEXISTSSTATUS=SUCCESS") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:9] GotoIf("PJSIP/2902-00000015", "1?mbexist") in new stack
[2019-08-29 14:18:06] WARNING[24965][C-00000013] pbx.c: Priority 'mbexist' must be a number > 0, or valid label
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Spawn extension (from-internal, *97, 9) exited non-zero on 'PJSIP/2902-00000015'
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [h@from-internal:1] Macro("PJSIP/2902-00000015", "hangupcall") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/2902-00000015", "1?theend") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/2902-00000015", "0?Set(CDR(recordingfile)=)") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/2902-00000015", " montior file= ") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/2902-00000015", "1?skipagi") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/2902-00000015", "") in new stack
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/2902-00000015' in macro 'hangupcall'
[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/2902-00000015'

PitzKey · August 29, 2019, 8:06pm

[2019-08-29 14:18:06] VERBOSE[24965][C-00000013] pbx.c: Executing [*97@from-internal:9] GotoIf("PJSIP/2902-00000015", "1?mbexist") in new stack 
[2019-08-29 14:18:06] WARNING[24965][C-00000013] pbx.c: Priority 'mbexist' must be a number &gt; 0, or valid label

Do you have any custom settings in voicemail?

Is your PBX up to date?

GyasiCaesar · August 30, 2019, 12:30pm

Hi,

No custom settings.

voicemail.conf file attached.

Current Asterisk Version: 16.3.0
FreePBX 14.0.10.3
voicemail.tgz (909 Bytes)

Is there any setting in particular that I should investigate?

stevehillin · August 30, 2019, 1:48pm

Do you have a custom [from-internal] context defined anywhere, i.e.extensions_override_freepbx.conf or extensions_custom.conf?

GyasiCaesar · August 30, 2019, 3:35pm

No,

I haven’t modified the _override file and the only configurations in my _custom are for DUNDI.

Excerpt

switch => DUNDi/SV-SS_DUNDI

[dundi-extens]
include => ext-local
include => ext-intercom-users
include => ext-meeteme

GyasiCaesar · September 2, 2019, 1:08pm

Hi,
I rolled back some of the configuration made to the system and got the voicemail working again.

I’m not sure what broke it but I’ll test it after each configuration change moving forward.

thanks for the help

system · October 3, 2019, 1:08pm

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