FreePBX extension voicemail not work any more

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 [[email protected]: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 [[email protected]: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 [[email protected]:12] NoOp("DAHDI/1-1", "ringall array  ") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:13] Set("DAHDI/1-1", "__FMGL_DIAL=") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:14] Set("DAHDI/1-1", "LOOPCNT=2") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:15] Set("DAHDI/1-1", "ITER=1") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:16] Set("DAHDI/1-1", "__EXTTOCALL=100") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:17] NoOp("DAHDI/1-1", "Working with 100") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:20] Set("DAHDI/1-1", "ITER=2") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:16] Set("DAHDI/1-1", "__EXTTOCALL=200") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:17] NoOp("DAHDI/1-1", "Working with 200") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:20] Set("DAHDI/1-1", "ITER=3") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:21] GotoIf("DAHDI/1-1", "0?ndloopbegin") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:1] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:24] ExecIf("DAHDI/1-1", "0?Set(ds=DAHDI/3&PJSIP/200/sip:[email protected]: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 [[email protected]:25] Dial("DAHDI/1-1", "DAHDI/3&PJSIP/200/sip:[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:3] Set("DAHDI/3-1", "TECH=DAHDI") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:4] Set("DAHDI/3-1", "SIPHEADERKEYS=") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:3] Set("PJSIP/200-0000001a", "TECH=PJSIP") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:4] Set("PJSIP/200-0000001a", "SIPHEADERKEYS=") in new stack
[2020-07-30 14:09:06] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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:[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp("DAHDI/3-1", "HANGUP CAUSE: 0") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp("PJSIP/200-0000001a", "HANGUP CAUSE: 0") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:26] Set("DAHDI/1-1", "DIALSTATUS=NOANSWER") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:27] GosubIf("DAHDI/1-1", "0?NOANSWER,1()") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:29] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:1] Return("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:20] Set("DAHDI/1-1", "RingGroupMethod=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:21] GotoIf("DAHDI/1-1", "0?nodest") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:22] Set("DAHDI/1-1", "__NODEST=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:23] Macro("DAHDI/1-1", "blkvm-clr,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:2] Set("DAHDI/1-1", "GOSUB_RETVAL=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:3] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:1] Macro("DAHDI/1-1", "vm,200,NOANSWER,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:1] Macro("DAHDI/1-1", "user-callerid,SKIPTTL") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:2] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:3] Set("DAHDI/1-1", "HOTDESCKCHAN=1-1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:4] Set("DAHDI/1-1", "HOTDESKEXTEN=1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]cro-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 [[email protected]: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 [[email protected]: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 [[email protected]:8] GotoIf("DAHDI/1-1", "0?report") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:9] ExecIf("DAHDI/1-1", "1?Set(REALCALLERIDNUM=)") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:10] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:11] GotoIf("DAHDI/1-1", "0?limit") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:12] Set("DAHDI/1-1", "AMPUSERCIDNAME=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:44] Set("DAHDI/1-1", "CALLERID(number)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:45] Set("DAHDI/1-1", "CALLERID(name)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:48] Set("DAHDI/1-1", "CDR(cnum)=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:49] Set("DAHDI/1-1", "CHANNEL(language)=en") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:2] Set("DAHDI/1-1", "VMGAIN=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:3] Macro("DAHDI/1-1", "blkvm-check,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:1] Set("DAHDI/1-1", "GOSUB_RETVAL=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:3] MacroExit("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:1] Set("DAHDI/1-1", "__EXTTOCALL=200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:2] Set("DAHDI/1-1", "__CRM_VOICEMAIL=200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:3] Set("DAHDI/1-1", "MEXTEN=200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:4] Set("DAHDI/1-1", "MMODE=NOANSWER") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:5] Set("DAHDI/1-1", "RETVM=") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:6] Set("DAHDI/1-1", "MODE=unavail") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:7] Macro("DAHDI/1-1", "get-vmcontext,200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:1] Set("DAHDI/1-1", "VMCONTEXT=default") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:300] NoOp("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:8] Set("DAHDI/1-1", "MODE=unavail") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:9] NoOp("DAHDI/1-1", "MODE IS: unavail") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] Macro("DAHDI/1-1", "get-vmcontext,200") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:1] Set("DAHDI/1-1", "VMCONTEXT=default") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]:300] NoOp("DAHDI/1-1", "") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:2] VoiceMail("DAHDI/1-1", "[email protected],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 [[email protected]:1] Macro("DAHDI/1-1", "hangupcall,") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp("DAHDI/1-1", "HANGUP CAUSE: 16") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:5] GotoIf("DAHDI/1-1", "0?return") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]:6] Set("DAHDI/1-1", "__CRM_HANGUP=1") in new stack
[2020-07-30 14:09:21] VERBOSE[5949][C-0000001b] pbx.c: Executing [[email protected]: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 [[email protected]: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

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.

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)

What is the failover destination in the ring group?

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

Thanks for your help.

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