Hello all, I have been trying to get chat working with XMPP. I have tried uninstalling and reinstalling XMPP, MongoDB, and NPM to no avail. When I use a third party XMPP client. Cannot even connect to the server. When I use X-Lite the presence feature works fine and chat will allow me to send messages but they are not received on the other end. I show the XMPP is running on the dashboard. I am running FreePBX 14.0.1.4 with asterisk 14.6.1. When I send a message I notice there are errors in the asterisk log, however when I try to research the problem I cannot seem to find any hints to what is going on. The log is attached below:
I had to remove sections of the error log.
[2017-09-13 00:35:10] NOTICE[3963] res_pjsip/pjsip_distributor.c: Request 'REGISTER' from '"1011" <sip:[email protected]>' failed for '195.154.241.108:5330' (callid: 324802403) - No matching endpoint found
[2017-09-13 00:35:10] NOTICE[3963] res_pjsip/pjsip_distributor.c: Request 'REGISTER' from '"1011" <sip:[email protected]>' failed for '195.154.241.108:5330' (callid: 324802403) - Failed to authenticate
[2017-09-13 00:35:34] VERBOSE[3980] res_pjsip/pjsip_configuration.c: Contact 212/sip:[email protected]:27428;rinstance=3BBBF198 is now Reachable. RTT: 84.620 msec
[2017-09-13 00:35:34] VERBOSE[3980] res_pjsip/pjsip_configuration.c: Endpoint 212 is now Reachable
[2017-09-13 00:35:54] VERBOSE[3980] res_pjsip/pjsip_configuration.c: Contact 110/sip:[email protected]:54748;rinstance=3b7b97fd845968a7 is now Reachable. RTT: 60.836 msec
[2017-09-13 00:35:54] VERBOSE[3980] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@from-internal:1] GotoIf("Message/ast_msg_queue", "0?ext-local,111,1:followme-check,111,1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-check,111,1)
[2017-09-13 00:36:11] ERROR[3912][C-00000001] func_global.c: Channel 'Message/ast_msg_queue' not found! Variable 'BLKVM' not set to 'TRUE'.
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-setifempty:6] Set("Message/ast_msg_queue", "GOSUB_RETVAL=TRUE") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-setifempty:7] MacroExit("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:10] GotoIf("Message/ast_msg_queue", "1?skipov") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,13)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:13] Set("Message/ast_msg_queue", "RRNODEST=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:14] Set("Message/ast_msg_queue", "__NODEST=111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:15] GosubIf("Message/ast_msg_queue", "0?sub-fmsetcid,s,1()") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:16] GotoIf("Message/ast_msg_queue", "1?skipprepend") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,18)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:18] Set("Message/ast_msg_queue", "RecordMethod=Group") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:19] Gosub("Message/ast_msg_queue", "sub-record-check,s,1(exten,111,)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:1] GotoIf("Message/ast_msg_queue", "0?initialized") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:2] Set("Message/ast_msg_queue", "__REC_STATUS=INITIALIZED") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:3] Set("Message/ast_msg_queue", "NOW=1505262971") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:4] Set("Message/ast_msg_queue", "__DAY=13") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:5] Set("Message/ast_msg_queue", "__MONTH=09") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:6] Set("Message/ast_msg_queue", "__YEAR=2017") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:7] Set("Message/ast_msg_queue", "__TIMESTR=20170913-003611") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:8] Set("Message/ast_msg_queue", "__FROMEXTEN=unknown") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:9] Set("Message/ast_msg_queue", "__MON_FMT=wav") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:10] NoOp("Message/ast_msg_queue", "Recordings initialized") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:11] ExecIf("Message/ast_msg_queue", "1?Set(ARG3=dontcare)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:12] Set("Message/ast_msg_queue", "REC_POLICY_MODE_SAVE=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:13] ExecIf("Message/ast_msg_queue", "0?Set(REC_STATUS=NO)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:14] GotoIf("Message/ast_msg_queue", "5?checkaction") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@sub-record-check:17] GotoIf("Message/ast_msg_queue", "1?sub-record-check,exten,1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:1] NoOp("Message/ast_msg_queue", "Exten Recording Check between unknown and 111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:2] Set("Message/ast_msg_queue", "CALLTYPE=internal") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:3] ExecIf("Message/ast_msg_queue", "0?Set(CALLTYPE=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:4] Set("Message/ast_msg_queue", "CALLEE=dontcare") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:5] ExecIf("Message/ast_msg_queue", "0?Set(CALLEE=dontcare)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:6] GotoIf("Message/ast_msg_queue", "0?callee") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:7] GotoIf("Message/ast_msg_queue", "1?caller") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (sub-record-check,exten,13)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:13] Set("Message/ast_msg_queue", "RECMODE=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:14] ExecIf("Message/ast_msg_queue", "1?Set(RECMODE=dontcare)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:15] ExecIf("Message/ast_msg_queue", "1?Set(RECMODE=dontcare)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:16] Gosub("Message/ast_msg_queue", "recordcheck,1(dontcare,internal,111)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("Message/ast_msg_queue", "Starting recording check against dontcare") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("Message/ast_msg_queue", "dontcare") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:3] Return("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [exten@sub-record-check:17] Return("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:20] GotoIf("Message/ast_msg_queue", "1?skipdring") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,23)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:23] Set("Message/ast_msg_queue", "STRATEGY=ringallv2-prim") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:24] Set("Message/ast_msg_queue", "__RVOL=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:25] GotoIf("Message/ast_msg_queue", "1?skipsimple") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,28)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:28] Set("Message/ast_msg_queue", "RingGroupMethod=ringallv2-prim") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:29] Set("Message/ast_msg_queue", "_FMGRP=111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:30] GotoIf("Message/ast_msg_queue", "1?DIALGRP") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,34)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:34] ExecIf("Message/ast_msg_queue", "1?Set(DOPTS=TtrI):Set(DOPTS=m(Ring)TtI)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:35] Set("Message/ast_msg_queue", "__ALT_CONFIRM_MSG=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:36] GotoIf("Message/ast_msg_queue", "0)?doconfirm") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:37] GotoIf("Message/ast_msg_queue", "1?ringallv21") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,40)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:40] Macro("Message/ast_msg_queue", "dial,40,TtrI,311-211-111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:1] NoOp("Message/ast_msg_queue", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:2] Set("Message/ast_msg_queue", "__CRM_SOURCE=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:3] ExecIf("Message/ast_msg_queue", "0?Set(ALERT_INFO=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:10] NoOp("Message/ast_msg_queue", "Returned from dialparties with groups to dial") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:11] NoOp("Message/ast_msg_queue", "ringall array 311-211 ") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:12] Set("Message/ast_msg_queue", "__FMGL_DIAL=311-211") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:13] Set("Message/ast_msg_queue", "LOOPCNT=3") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:14] Set("Message/ast_msg_queue", "ITER=1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:15] Set("Message/ast_msg_queue", "EXTTOCALL=111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:16] NoOp("Message/ast_msg_queue", "Working with 111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:17] ExecIf("Message/ast_msg_queue", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:18] ExecIf("Message/ast_msg_queue", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:19] Set("Message/ast_msg_queue", "ITER=2") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:20] GotoIf("Message/ast_msg_queue", "1?ndloopbegin") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-dial,s,15)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:15] Set("Message/ast_msg_queue", "EXTTOCALL=311") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:16] NoOp("Message/ast_msg_queue", "Working with 311") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:17] ExecIf("Message/ast_msg_queue", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:18] ExecIf("Message/ast_msg_queue", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:19] Set("Message/ast_msg_queue", "ITER=3") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:20] GotoIf("Message/ast_msg_queue", "1?ndloopbegin") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-dial,s,15)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:15] Set("Message/ast_msg_queue", "EXTTOCALL=211") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:16] NoOp("Message/ast_msg_queue", "Working with 211") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:17] ExecIf("Message/ast_msg_queue", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:18] ExecIf("Message/ast_msg_queue", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:19] Set("Message/ast_msg_queue", "ITER=4") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:20] GotoIf("Message/ast_msg_queue", "0?ndloopbegin") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:21] Macro("Message/ast_msg_queue", "dial-ringall-predial-hook,") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial-ringall-predial-hook:1] MacroExit("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:22] Dial("Message/ast_msg_queue", "Local/FMPR-111@from-internal&Local/FMGL-311-211@from-internal,42,TtrIM(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2017-09-13 00:36:11] ERROR[3912][C-00000001] translate.c: Cannot determine best translation path since one capability supports no formats
[2017-09-13 00:36:11] WARNING[3912][C-00000001] channel.c: No translator path exists for channel type Local (native (g723|ulaw|alaw|gsm|g726|g726aal2|adpcm|slin|slin|slin|slin|slin|slin|slin|slin|slin|lpc10|g729|speex|speex|speex|ilbc|g722|siren7|siren14|testlaw|g719|opus|jpeg|png|h261|h263|h263p|h264|mpeg4|vp8|red|t140|silk|silk|silk|silk)) to (none)
[2017-09-13 00:36:11] WARNING[3912][C-00000001] app_dial.c: Unable to create channel of type 'Local' (cause 58 - Bearer capability not available)
[2017-09-13 00:36:11] ERROR[3912][C-00000001] translate.c: Cannot determine best translation path since one capability supports no formats
[2017-09-13 00:36:11] WARNING[3912][C-00000001] channel.c: No translator path exists for channel type Local (native (g723|ulaw|alaw|gsm|g726|g726aal2|adpcm|slin|slin|slin|slin|slin|slin|slin|slin|slin|lpc10|g729|speex|speex|speex|ilbc|g722|siren7|siren14|testlaw|g719|opus|jpeg|png|h261|h263|h263p|h264|mpeg4|vp8|red|t140|silk|silk|silk|silk)) to (none)
[2017-09-13 00:36:11] WARNING[3912][C-00000001] app_dial.c: Unable to create channel of type 'Local' (cause 58 - Bearer capability not available)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] app_dial.c: Everyone is busy/congested at this time (2:0/0/2)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:23] Set("Message/ast_msg_queue", "DIALSTATUS=CHANUNAVAIL") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:24] GosubIf("Message/ast_msg_queue", "0?CHANUNAVAIL,1()") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:25] NoOp("Message/ast_msg_queue", "Returning since nobody answered") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-dial:26] MacroExit("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:41] Goto("Message/ast_msg_queue", "nextstep") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (followme-sub,111,46)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:46] Set("Message/ast_msg_queue", "RingGroupMethod=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:47] GotoIf("Message/ast_msg_queue", "0?nodest") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:48] Set("Message/ast_msg_queue", "__NODEST=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:49] Set("Message/ast_msg_queue", "__PICKUPMARK=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:50] Macro("Message/ast_msg_queue", "blkvm-clr,") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-clr:1] Set("Message/ast_msg_queue", "SHARED(BLKVM,Message/ast_msg_queue)=") in new stack
[2017-09-13 00:36:11] ERROR[3912][C-00000001] func_global.c: Channel 'Message/ast_msg_queue' not found! Variable 'BLKVM' not set to ''.
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-clr:2] Set("Message/ast_msg_queue", "GOSUB_RETVAL=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:51] Set("Message/ast_msg_queue", "DIALSTATUS=CHANUNAVAIL") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:52] GotoIf("Message/ast_msg_queue", "0?dohangup") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [111@followme-sub:53] Goto("Message/ast_msg_queue", "ext-local,vmu111,1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (ext-local,vmu111,1)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmu111@ext-local:1] Macro("Message/ast_msg_queue", "vm,111,NOANSWER,") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-vm:1] Macro("Message/ast_msg_queue", "user-callerid,SKIPTTL") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:1] Set("Message/ast_msg_queue", "TOUCH_MONITOR=1505261897.0") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:2] Set("Message/ast_msg_queue", "AMPUSER=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("Message/ast_msg_queue", "0?report") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("Message/ast_msg_queue", "1?Set(__REALCALLERIDNUM=)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:5] Set("Message/ast_msg_queue", "AMPUSER=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("Message/ast_msg_queue", "0?limit") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:7] Set("Message/ast_msg_queue", "AMPUSERCIDNAME=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("Message/ast_msg_queue", "1?report") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,15)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:15] GotoIf("Message/ast_msg_queue", "1?continue") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,29)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:29] Set("Message/ast_msg_queue", "CALLERID(number)=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:30] Set("Message/ast_msg_queue", "CALLERID(name)=Work:Work:Work:") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:31] GotoIf("Message/ast_msg_queue", "0?cnum") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:32] Set("Message/ast_msg_queue", "CDR(cnam)=Work:Work:Work:") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:33] Set("Message/ast_msg_queue", "CDR(cnum)=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-user-callerid:34] Set("Message/ast_msg_queue", "CHANNEL(language)=en") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-vm:2] Set("Message/ast_msg_queue", "VMGAIN=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-vm:3] Macro("Message/ast_msg_queue", "blkvm-check,") in new stack
[2017-09-13 00:36:11] ERROR[3912][C-00000001] func_global.c: Channel 'Message/ast_msg_queue' not found! Variable 'BLKVM' will be blank.
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-check:1] Set("Message/ast_msg_queue", "GOSUB_RETVAL=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("Message/ast_msg_queue", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-blkvm-check:3] MacroExit("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-vm:4] GotoIf("Message/ast_msg_queue", "1?vmx,1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-vm,vmx,1)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:1] Set("Message/ast_msg_queue", "__EXTTOCALL=111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:2] Set("Message/ast_msg_queue", "__CRM_VOICEMAIL=111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:3] Set("Message/ast_msg_queue", "MEXTEN=111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:4] Set("Message/ast_msg_queue", "MMODE=NOANSWER") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:5] Set("Message/ast_msg_queue", "RETVM=") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:6] Set("Message/ast_msg_queue", "MODE=unavail") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:7] Macro("Message/ast_msg_queue", "get-vmcontext,111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:1] Set("Message/ast_msg_queue", "VMCONTEXT=default") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("Message/ast_msg_queue", "0?200:300") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:8] Set("Message/ast_msg_queue", "MODE=unavail") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:9] NoOp("Message/ast_msg_queue", "MODE IS: unavail") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:10] GotoIf("Message/ast_msg_queue", "1?chknomsg") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-vm,vmx,12)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:12] GotoIf("Message/ast_msg_queue", "0?s-NOANSWER,1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:13] GotoIf("Message/ast_msg_queue", "1?notdirect") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-vm,vmx,15)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:15] NoOp("Message/ast_msg_queue", "Checking if ext 111 is enabled: ") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [vmx@macro-vm:16] GotoIf("Message/ast_msg_queue", "1?s-NOANSWER,1") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-vm,s-NOANSWER,1)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s-NOANSWER@macro-vm:1] Macro("Message/ast_msg_queue", "get-vmcontext,111") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:1] Set("Message/ast_msg_queue", "VMCONTEXT=default") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("Message/ast_msg_queue", "0?200:300") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("Message/ast_msg_queue", "") in new stack
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail("Message/ast_msg_queue", "111@default,u") in new stack
[2017-09-13 00:36:11] ERROR[3912][C-00000001] channel.c: Unable to set format because channel Message/ast_msg_queue supports no formats
[2017-09-13 00:36:11] WARNING[3912][C-00000001] file.c: Unable to open vm-theperson (format (none)): Function not implemented
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] app_macro.c: Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'Message/ast_msg_queue' in macro 'vm'
[2017-09-13 00:36:11] VERBOSE[3912][C-00000001] pbx.c: Spawn extension (ext-local, vmu111, 1) exited non-zero on 'Message/ast_msg_queue'