FreePBX extension voicemail not work any more


(Vcba79) #1

Hi, all

I got a strange problem recently. I has extension 200 which is a grandstream phone. If I use IVR in inbound route and direct call to this extension’s voicemail, it works. If I set up ring group or direct call to this extension. the call will hang up when ringtime reached. Here is the full log

[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:8] GotoIf("DAHDI/1-1", "1?normdial") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-dial,s,11)
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:11] NoOp("DAHDI/1-1", "Returned from dialparties with groups to dial") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:12] NoOp("DAHDI/1-1", "ringall array  ") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:13] Set("DAHDI/1-1", "__FMGL_DIAL=") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:14] Set("DAHDI/1-1", "LOOPCNT=2") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:15] Set("DAHDI/1-1", "ITER=1") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:16] Set("DAHDI/1-1", "__EXTTOCALL=100") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:17] NoOp("DAHDI/1-1", "Working with 100") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:18] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:19] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:20] Set("DAHDI/1-1", "ITER=2") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:21] GotoIf("DAHDI/1-1", "1?ndloopbegin") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-dial,s,16)
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:16] Set("DAHDI/1-1", "__EXTTOCALL=200") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:17] NoOp("DAHDI/1-1", "Working with 200") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:18] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:19] ExecIf("DAHDI/1-1", "0?Set(HASH(__SIPHEADERS,Alert-Info)=Normal;volume=)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:20] Set("DAHDI/1-1", "ITER=3") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:21] GotoIf("DAHDI/1-1", "0?ndloopbegin") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:22] Macro("DAHDI/1-1", "dial-ringall-predial-hook,") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial-ringall-predial-hook:1] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:23] ExecIf("DAHDI/1-1", "0?Set(CWRING=r(callwaiting)):Set(CWRING=)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:24] ExecIf("DAHDI/1-1", "0?Set(ds=DAHDI/3&PJSIP/200/sip:200@10.1.2.100:5060,15,HhtrQ(NO_ANSWER)M(auto-blkvm)g)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:25] Dial("DAHDI/1-1", "DAHDI/3&PJSIP/200/sip:200@10.1.2.100:5060,15,HhtrQ(NO_ANSWER)M(auto-blkvm)b(func-apply-sipheaders^s^1),") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_stack.c: DAHDI/3-1 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("DAHDI/3-1", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("DAHDI/3-1", "Applying SIP Headers to channel DAHDI/3-1") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:3] Set("DAHDI/3-1", "TECH=DAHDI") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:4] Set("DAHDI/3-1", "SIPHEADERKEYS=") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:5] While("DAHDI/3-1", "0") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_while.c: Jumping to priority 13
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:14] Return("DAHDI/3-1", "") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'DAHDI/3-1'
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_stack.c: DAHDI/3-1 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_stack.c: PJSIP/200-0000001a Internal Gosub(func-apply-sipheaders,s,1) start
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("PJSIP/200-0000001a", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("PJSIP/200-0000001a", "Applying SIP Headers to channel PJSIP/200-0000001a") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:3] Set("PJSIP/200-0000001a", "TECH=PJSIP") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:4] Set("PJSIP/200-0000001a", "SIPHEADERKEYS=") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:5] While("PJSIP/200-0000001a", "0") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_while.c: Jumping to priority 13
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@func-apply-sipheaders:14] Return("PJSIP/200-0000001a", "") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'PJSIP/200-0000001a'
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_stack.c: PJSIP/200-0000001a Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_dial.c: Called DAHDI/3
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_dial.c: Called PJSIP/200/sip:200@10.1.2.100:5060
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_dial.c: DAHDI/3-1 is ringing
[2020-07-30 14:09:06] VERBOSE[8822] netsock2.c: Using SIP RTP Audio TOS bits 184
[2020-07-30 14:09:06] VERBOSE[8822] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2020-07-30 14:09:06] VERBOSE[8822] netsock2.c: Using SIP RTP Audio CoS mark 5
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_dial.c: PJSIP/200-0000001a connected line has changed. Saving it until answer for DAHDI/1-1
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_dial.c: PJSIP/200-0000001a is ringing
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] app_dial.c: PJSIP/200-0000001a is ringing
[2020-07-30 14:09:07] VERBOSE[5949][C-0000001b] app_dial.c: DAHDI/3-1 is ringing
[2020-07-30 14:09:12] VERBOSE[5949][C-0000001b] app_dial.c: DAHDI/3-1 is ringing
[2020-07-30 14:09:17] VERBOSE[5949][C-0000001b] app_dial.c: DAHDI/3-1 is ringing
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_dial.c: Nobody picked up in 15000 ms
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: DAHDI/3-1 Internal Gosub(crm-hangup,s,1) start
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:1] NoOp("DAHDI/3-1", "Sending Hangup to CRM") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:2] NoOp("DAHDI/3-1", "HANGUP CAUSE: 0") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:3] ExecIf("DAHDI/3-1", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:4] NoOp("DAHDI/3-1", "MASTER CHANNEL: 1596089346.63 = 1596089336.62") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:5] GotoIf("DAHDI/3-1", "1?return") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (crm-hangup,s,8)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:8] Return("DAHDI/3-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'DAHDI/3-1'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: DAHDI/3-1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] sig_analog.c: Hanging up on 'DAHDI/3-1'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] chan_dahdi.c: Hungup 'DAHDI/3-1'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: PJSIP/200-0000001a Internal Gosub(crm-hangup,s,1) start
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/200-0000001a", "Sending Hangup to CRM") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/200-0000001a", "HANGUP CAUSE: 0") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/200-0000001a", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/200-0000001a", "MASTER CHANNEL: 1596089346.64 = 1596089336.62") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/200-0000001a", "1?return") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (crm-hangup,s,8)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/200-0000001a", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: Spawn extension (from-internal, 1, 1) exited non-zero on 'PJSIP/200-0000001a'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: PJSIP/200-0000001a Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:26] Set("DAHDI/1-1", "DIALSTATUS=NOANSWER") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:27] GosubIf("DAHDI/1-1", "0?NOANSWER,1()") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:28] NoOp("DAHDI/1-1", "Returning since nobody answered") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-dial:29] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [1@ext-group:19] Gosub("DAHDI/1-1", "sub-record-cancel,s,1()") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@sub-record-cancel:1] Return("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [1@ext-group:20] Set("DAHDI/1-1", "RingGroupMethod=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [1@ext-group:21] GotoIf("DAHDI/1-1", "0?nodest") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [1@ext-group:22] Set("DAHDI/1-1", "__NODEST=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [1@ext-group:23] Macro("DAHDI/1-1", "blkvm-clr,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-blkvm-clr:1] Set("DAHDI/1-1", "SHARED(BLKVM,DAHDI/1-1)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-blkvm-clr:2] Set("DAHDI/1-1", "GOSUB_RETVAL=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [1@ext-group:24] Goto("DAHDI/1-1", "ext-local,vmu200,1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (ext-local,vmu200,1)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmu200@ext-local:1] Macro("DAHDI/1-1", "vm,200,NOANSWER,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-vm:1] Macro("DAHDI/1-1", "user-callerid,SKIPTTL") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:1] Set("DAHDI/1-1", "TOUCH_MONITOR=1596089336.62") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:2] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:3] Set("DAHDI/1-1", "HOTDESCKCHAN=1-1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:4] Set("DAHDI/1-1", "HOTDESKEXTEN=1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:5] Set("DAHDI/1-1", "HOTDESKCALL=0") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:6] ExecIf("DAHDI/1-1", "0?Set(HOTDESKCALL=1)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:7] ExecIf("DAHDI/1-1", "0?Set(CALLERID(name)=)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("DAHDI/1-1", "0?report") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:9] ExecIf("DAHDI/1-1", "1?Set(REALCALLERIDNUM=)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:10] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:11] GotoIf("DAHDI/1-1", "0?limit") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:12] Set("DAHDI/1-1", "AMPUSERCIDNAME=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("DAHDI/1-1", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:14] GotoIf("DAHDI/1-1", "1?report") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-user-callerid,s,23)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:23] NoOp("DAHDI/1-1", "Macro Depth is 2") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:24] GotoIf("DAHDI/1-1", "1?report2:macroerror") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-user-callerid,s,25)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:25] GotoIf("DAHDI/1-1", "1?continue") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-user-callerid,s,44)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:44] Set("DAHDI/1-1", "CALLERID(number)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:45] Set("DAHDI/1-1", "CALLERID(name)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:46] GotoIf("DAHDI/1-1", "1?cnum") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-user-callerid,s,48)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:48] Set("DAHDI/1-1", "CDR(cnum)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-user-callerid:49] Set("DAHDI/1-1", "CHANNEL(language)=en") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-vm:2] Set("DAHDI/1-1", "VMGAIN=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-vm:3] Macro("DAHDI/1-1", "blkvm-check,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-blkvm-check:1] Set("DAHDI/1-1", "GOSUB_RETVAL=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("DAHDI/1-1", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-blkvm-check:3] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-vm:4] GotoIf("DAHDI/1-1", "1?vmx,1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-vm,vmx,1)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:1] Set("DAHDI/1-1", "__EXTTOCALL=200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:2] Set("DAHDI/1-1", "__CRM_VOICEMAIL=200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:3] Set("DAHDI/1-1", "MEXTEN=200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:4] Set("DAHDI/1-1", "MMODE=NOANSWER") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:5] Set("DAHDI/1-1", "RETVM=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:6] Set("DAHDI/1-1", "MODE=unavail") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:7] Macro("DAHDI/1-1", "get-vmcontext,200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-get-vmcontext:1] Set("DAHDI/1-1", "VMCONTEXT=default") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("DAHDI/1-1", "0?200:300") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:8] Set("DAHDI/1-1", "MODE=unavail") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:9] NoOp("DAHDI/1-1", "MODE IS: unavail") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:10] GotoIf("DAHDI/1-1", "1?chknomsg") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-vm,vmx,12)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:12] GotoIf("DAHDI/1-1", "0?s-NOANSWER,1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:13] GotoIf("DAHDI/1-1", "1?notdirect") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-vm,vmx,15)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:15] NoOp("DAHDI/1-1", "Checking if ext 200 is enabled: ") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [vmx@macro-vm:16] GotoIf("DAHDI/1-1", "1?s-NOANSWER,1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-vm,s-NOANSWER,1)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s-NOANSWER@macro-vm:1] Macro("DAHDI/1-1", "get-vmcontext,200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-get-vmcontext:1] Set("DAHDI/1-1", "VMCONTEXT=default") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("DAHDI/1-1", "0?200:300") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail("DAHDI/1-1", "200@default,u") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] file.c: <DAHDI/1-1> Playing 'vm-theperson.ulaw' (language 'en')
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_macro.c: Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'DAHDI/1-1' in macro 'vm'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Spawn extension (ext-local, vmu200, 1) exited non-zero on 'DAHDI/1-1'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [h@ext-local:1] Macro("DAHDI/1-1", "hangupcall,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("DAHDI/1-1", "1?theend") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("DAHDI/1-1", "0?Set(CDR(recordingfile)=)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-hangupcall:4] NoOp("DAHDI/1-1", " montior file= /var/spool/asterisk/monitor/2020/07/30/in-s-unknown-20200730-140906-1596089336.62.wav") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("DAHDI/1-1", "1?skipagi") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@macro-hangupcall:7] Hangup("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'DAHDI/1-1' in macro 'hangupcall'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'DAHDI/1-1'
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) start
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:1] NoOp("DAHDI/1-1", "Sending Hangup to CRM") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:2] NoOp("DAHDI/1-1", "HANGUP CAUSE: 16") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:3] ExecIf("DAHDI/1-1", "1?Set(__CRM_VOICEMAIL=FAILED)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:4] NoOp("DAHDI/1-1", "MASTER CHANNEL: 1596089336.62 = 1596089336.62") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:5] GotoIf("DAHDI/1-1", "0?return") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:6] Set("DAHDI/1-1", "__CRM_HANGUP=1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:7] AGI("DAHDI/1-1", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2020-07-30 14:09:22] VERBOSE[5949][C-0000001b] res_agi.c: <DAHDI/1-1>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2020-07-30 14:09:22] VERBOSE[5949][C-0000001b] pbx.c: Executing [s@crm-hangup:8] Return("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:22] VERBOSE[5949][C-0000001b] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on 'DAHDI/1-1'
[2020-07-30 14:09:22] VERBOSE[5949][C-0000001b] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-07-30 14:09:22] VERBOSE[5949][C-0000001b] sig_analog.c: Hanging up on 'DAHDI/1-1'
[2020-07-30 14:09:22] VERBOSE[5949][C-0000001b] chan_dahdi.c: Hungup 'DAHDI/1-1'
[2020-07-30 14:09:22] VERBOSE[6005][C-0000001b] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2020-07-30 14:09:22] VERBOSE[6005][C-0000001b] app_mixmonitor.c: End MixMonitor Recording DAHDI/1-1

(Itzik) #2

Please provide a full call trace using pastebin

https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs-PartII

Also, it seems that it did go to voicemail, but hung up as soon as it started playing “The person at extension…”
Can please explain who is in that ring group? I’m a little confused with these Dahdi devices ringing.


(Vcba79) #3

There are 2 extensions in this ring group, 100 (a fxs line) and 200 (a grandstream sip phone). The full log is attached.

Thanks for your help,
20200730.tgz (8.6 KB)


(Itzik) #4

What is the failover destination in the ring group?


(Vcba79) #5

Destination if no answer: Voicemail (200 Grandstram GXP1610 Unavailable message)

Thanks for your help.


(system) closed #6

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