Voicemail can not detect hangup

Hi, all

If PSTN call in, destination extension will enter voicemail if not answered. But if I hangup during voicemail recording, the phone line will be occupied and keep recoding until 5 minutes later. How can I let voicemail stop recoding if phone hang up? Here is the log. As you can see 14:08 start to record and I hangup 5 seconds later. But the recording is still going until 14:13.

Thanks,

[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:1] NoOp("DAHDI/1-1", "Entering from-dahdi with DID == ") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:2] Ringing("DAHDI/1-1", "") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:3] Set("DAHDI/1-1", "DID=s") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:4] NoOp("DAHDI/1-1", "DID is now s") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:5] GotoIf("DAHDI/1-1", "1?dahdiok:checkzap") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (from-analog,s,9)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:9] NoOp("DAHDI/1-1", "Is a DAHDi Channel") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:10] Set("DAHDI/1-1", "CHAN=1-1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:11] Set("DAHDI/1-1", "CHAN=1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@from-analog:12] Macro("DAHDI/1-1", "from-dahdi-1,s,1") in new stack
[2020-08-03 14:07:47] WARNING[3558][C-00000001] app_macro.c: Macro() is deprecated and will be removed from a future version of Asterisk.
[2020-08-03 14:07:47] WARNING[3558][C-00000001] app_macro.c: Dialplan should be updated to use Gosub instead.
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-from-dahdi-1:1] NoOp("DAHDI/1-1", "Entering macro-from-dahdi-1 with DID = s and setting to: 89214377") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-from-dahdi-1:2] Set("DAHDI/1-1", "__FROM_DID=89214377") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-from-dahdi-1:3] Goto("DAHDI/1-1", "from-trunk,89214377,1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (from-trunk,89214377,1)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] app_macro.c: Channel 'DAHDI/1-1' jumping out of macro 'from-dahdi-1'
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [89214377@from-trunk:1] NoOp("DAHDI/1-1", "Catch-All DID Match - Found 89214377 - You probably want a DID for this.") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [89214377@from-trunk:2] Set("DAHDI/1-1", "__FROM_DID=89214377") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [89214377@from-trunk:3] Goto("DAHDI/1-1", "ext-did,s,1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (ext-did,s,1)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:1] Set("DAHDI/1-1", "__DIRECTION=INBOUND") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:2] Gosub("DAHDI/1-1", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:1] GotoIf("DAHDI/1-1", "0?initialized") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:2] Set("DAHDI/1-1", "__REC_STATUS=INITIALIZED") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:3] Set("DAHDI/1-1", "NOW=1596434867") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:4] Set("DAHDI/1-1", "__DAY=03") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:5] Set("DAHDI/1-1", "__MONTH=08") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:6] Set("DAHDI/1-1", "__YEAR=2020") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:7] Set("DAHDI/1-1", "__TIMESTR=20200803-140747") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:8] Set("DAHDI/1-1", "__FROMEXTEN=unknown") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:9] Set("DAHDI/1-1", "__MON_FMT=wav") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:10] NoOp("DAHDI/1-1", "Recordings initialized") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:11] ExecIf("DAHDI/1-1", "0?Set(ARG3=dontcare)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:12] Set("DAHDI/1-1", "REC_POLICY_MODE_SAVE=") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:13] ExecIf("DAHDI/1-1", "0?Set(REC_STATUS=NO)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:14] GotoIf("DAHDI/1-1", "2?checkaction") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (sub-record-check,s,17)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@sub-record-check:17] GotoIf("DAHDI/1-1", "1?sub-record-check,in,1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (sub-record-check,in,1)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [in@sub-record-check:1] NoOp("DAHDI/1-1", "Inbound Recording Check to s") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [in@sub-record-check:2] Set("DAHDI/1-1", "FROMEXTEN=unknown") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [in@sub-record-check:3] ExecIf("DAHDI/1-1", "0?Set(FROMEXTEN=)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [in@sub-record-check:4] Gosub("DAHDI/1-1", "recordcheck,1(dontcare,in,s)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("DAHDI/1-1", "Starting recording check against dontcare") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("DAHDI/1-1", "dontcare") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [recordcheck@sub-record-check:3] Return("DAHDI/1-1", "") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [in@sub-record-check:5] Return("DAHDI/1-1", "") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:3] Set("DAHDI/1-1", "CHANNEL(tonezone)=tw") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:4] ExecIf("DAHDI/1-1", "0?Set(__FROM_DID=s)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:5] Set("DAHDI/1-1", "returnhere=1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:6] Gosub("DAHDI/1-1", "app-blacklist-check,s,1()") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("DAHDI/1-1", "0?blacklisted") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@app-blacklist-check:2] Set("DAHDI/1-1", "CALLED_BLACKLIST=1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@app-blacklist-check:3] Return("DAHDI/1-1", "") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:7] Set("DAHDI/1-1", "CDR(did)=89214377") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:8] GotoIf("DAHDI/1-1", "0?") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:9] ExecIf("DAHDI/1-1", "1 ?Set(CALLERID(name)=)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:10] Set("DAHDI/1-1", "__MOHCLASS=") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:11] Set("DAHDI/1-1", "__REVERSAL_REJECT=FALSE") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:12] GotoIf("DAHDI/1-1", "1?post-reverse-charge") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (ext-did,s,14)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:14] NoOp("DAHDI/1-1", "") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:15] Set("DAHDI/1-1", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:16] Set("DAHDI/1-1", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:17] Set("DAHDI/1-1", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:18] Set("DAHDI/1-1", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:19] NoOp("DAHDI/1-1", "CallerID Entry Point") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:20] Set("DAHDI/1-1", "__CRM_DIRECTION=INBOUND") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:21] Set("DAHDI/1-1", "__CRM_SOURCE=") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:22] Set("DAHDI/1-1", "__CRM_LINKEDID=1596434857.0") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:23] AGI("DAHDI/1-1", "agi://127.0.0.1/sangomacrm.agi,true") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] res_agi.c: <DAHDI/1-1>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:24] ExecIf("DAHDI/1-1", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ext-did:25] Goto("DAHDI/1-1", "ivr-1,s,1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (ivr-1,s,1)
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:1] Set("DAHDI/1-1", "TIMEOUT_LOOPCOUNT=0") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:2] Set("DAHDI/1-1", "INVALID_LOOPCOUNT=0") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:3] Set("DAHDI/1-1", "_IVR_CONTEXT_ivr-1=") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:4] Set("DAHDI/1-1", "_IVR_CONTEXT=ivr-1") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:5] Set("DAHDI/1-1", "__IVR_RETVM=") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:6] GotoIf("DAHDI/1-1", "0?skip") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:7] Answer("DAHDI/1-1", "") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:8] Set("DAHDI/1-1", "IVR_MSG=custom/amjet_ivr") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:9] Set("DAHDI/1-1", "TIMEOUT(digit)=3") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] func_timeout.c: Digit timeout set to 3.000
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:10] ExecIf("DAHDI/1-1", "1?Background(custom/amjet_ivr)") in new stack
[2020-08-03 14:07:47] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'custom/amjet_ivr.slin' (language 'en')
[2020-08-03 14:07:56] VERBOSE[3558][C-00000001] pbx.c: Executing [s@ivr-1:11] WaitExten("DAHDI/1-1", "10,") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [3@ivr-1:1] Set("DAHDI/1-1", "__ivrreturn=0") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [3@ivr-1:2] Goto("DAHDI/1-1", "ext-local,vmu200,1") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (ext-local,vmu200,1)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmu200@ext-local:1] Macro("DAHDI/1-1", "vm,200,NOANSWER,") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-vm:1] Macro("DAHDI/1-1", "user-callerid,SKIPTTL") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:1] Set("DAHDI/1-1", "TOUCH_MONITOR=1596434857.0") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:2] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:3] Set("DAHDI/1-1", "HOTDESCKCHAN=1-1") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:4] Set("DAHDI/1-1", "HOTDESKEXTEN=1") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:5] Set("DAHDI/1-1", "HOTDESKCALL=0") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:6] ExecIf("DAHDI/1-1", "0?Set(HOTDESKCALL=1)") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:7] ExecIf("DAHDI/1-1", "0?Set(CALLERID(name)=)") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:8] GotoIf("DAHDI/1-1", "0?report") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:9] ExecIf("DAHDI/1-1", "1?Set(REALCALLERIDNUM=)") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:10] Set("DAHDI/1-1", "AMPUSER=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:11] GotoIf("DAHDI/1-1", "0?limit") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:12] Set("DAHDI/1-1", "AMPUSERCIDNAME=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:13] ExecIf("DAHDI/1-1", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:14] GotoIf("DAHDI/1-1", "1?report") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,23)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:23] NoOp("DAHDI/1-1", "Macro Depth is 2") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:24] GotoIf("DAHDI/1-1", "1?report2:macroerror") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,25)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:25] GotoIf("DAHDI/1-1", "1?continue") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,44)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:44] Set("DAHDI/1-1", "CALLERID(number)=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:45] Set("DAHDI/1-1", "CALLERID(name)=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:46] GotoIf("DAHDI/1-1", "1?cnum") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-user-callerid,s,48)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:48] Set("DAHDI/1-1", "CDR(cnum)=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-user-callerid:49] Set("DAHDI/1-1", "CHANNEL(language)=en") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-vm:2] Set("DAHDI/1-1", "VMGAIN=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-vm:3] Macro("DAHDI/1-1", "blkvm-check,") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-blkvm-check:1] Set("DAHDI/1-1", "GOSUB_RETVAL=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-blkvm-check:2] ExecIf("DAHDI/1-1", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-blkvm-check:3] MacroExit("DAHDI/1-1", "") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-vm:4] GotoIf("DAHDI/1-1", "1?vmx,1") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-vm,vmx,1)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:1] Set("DAHDI/1-1", "__EXTTOCALL=200") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:2] Set("DAHDI/1-1", "__CRM_VOICEMAIL=200") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:3] Set("DAHDI/1-1", "MEXTEN=200") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:4] Set("DAHDI/1-1", "MMODE=NOANSWER") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:5] Set("DAHDI/1-1", "RETVM=") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:6] Set("DAHDI/1-1", "MODE=unavail") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:7] Macro("DAHDI/1-1", "get-vmcontext,200") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:1] Set("DAHDI/1-1", "VMCONTEXT=default") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("DAHDI/1-1", "0?200:300") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("DAHDI/1-1", "") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:8] Set("DAHDI/1-1", "MODE=unavail") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:9] NoOp("DAHDI/1-1", "MODE IS: unavail") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:10] GotoIf("DAHDI/1-1", "1?chknomsg") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-vm,vmx,12)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:12] GotoIf("DAHDI/1-1", "0?s-NOANSWER,1") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:13] GotoIf("DAHDI/1-1", "1?notdirect") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-vm,vmx,15)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:15] NoOp("DAHDI/1-1", "Checking if ext 200 is enabled: ") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [vmx@macro-vm:16] GotoIf("DAHDI/1-1", "1?s-NOANSWER,1") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-vm,s-NOANSWER,1)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s-NOANSWER@macro-vm:1] Macro("DAHDI/1-1", "get-vmcontext,200") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:1] Set("DAHDI/1-1", "VMCONTEXT=default") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:2] GotoIf("DAHDI/1-1", "0?200:300") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-get-vmcontext,s,300)
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-get-vmcontext:300] NoOp("DAHDI/1-1", "") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] pbx.c: Executing [s-NOANSWER@macro-vm:2] VoiceMail("DAHDI/1-1", "200@default,u") in new stack
[2020-08-03 14:08:02] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'vm-theperson.ulaw' (language 'en')
[2020-08-03 14:08:05] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'digits/2.ulaw' (language 'en')
[2020-08-03 14:08:05] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'digits/0.ulaw' (language 'en')
[2020-08-03 14:08:06] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'digits/0.ulaw' (language 'en')
[2020-08-03 14:08:07] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'vm-isunavail.ulaw' (language 'en')
[2020-08-03 14:08:08] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'vm-intro.ulaw' (language 'en')
[2020-08-03 14:08:14] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'beep.ulaw' (language 'en')
[2020-08-03 14:08:14] VERBOSE[3558][C-00000001] app_voicemail.c: Recording the message
[2020-08-03 14:08:14] VERBOSE[3558][C-00000001] app.c: x=0, open writing:  /var/spool/asterisk/voicemail/default/200/tmp/KliwP9 format: wav, 0x7fb528039450
[2020-08-03 14:13:15] VERBOSE[3558][C-00000001] app.c: Took too long, cutting it short...
[2020-08-03 14:13:15] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'auth-thankyou.ulaw' (language 'en')
[2020-08-03 14:13:15] VERBOSE[3558][C-00000001] pbx.c: Executing [s-NOANSWER@macro-vm:3] Goto("DAHDI/1-1", "exit-SUCCESS,1") in new stack
[2020-08-03 14:13:15] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-vm,exit-SUCCESS,1)
[2020-08-03 14:13:15] VERBOSE[3558][C-00000001] pbx.c: Executing [exit-SUCCESS@macro-vm:1] GotoIf("DAHDI/1-1", "0?exit-RETURN,1") in new stack
[2020-08-03 14:13:15] VERBOSE[3558][C-00000001] pbx.c: Executing [exit-SUCCESS@macro-vm:2] Playback("DAHDI/1-1", "goodbye") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] file.c: <DAHDI/1-1> Playing 'goodbye.ulaw' (language 'en')
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [exit-SUCCESS@macro-vm:3] Hangup("DAHDI/1-1", "") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] app_macro.c: Spawn extension (macro-vm, exit-SUCCESS, 3) exited non-zero on 'DAHDI/1-1' in macro 'vm'
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Spawn extension (ext-local, vmu200, 1) exited non-zero on 'DAHDI/1-1'
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [h@ext-local:1] Macro("DAHDI/1-1", "hangupcall,") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("DAHDI/1-1", "1?theend") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("DAHDI/1-1", "0?Set(CDR(recordingfile)=)") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-hangupcall:4] NoOp("DAHDI/1-1", " montior file= ") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("DAHDI/1-1", "1?skipagi") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@macro-hangupcall:7] Hangup("DAHDI/1-1", "") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'DAHDI/1-1' in macro 'hangupcall'
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'DAHDI/1-1'
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) start
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:1] NoOp("DAHDI/1-1", "Sending Hangup to CRM") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:2] NoOp("DAHDI/1-1", "HANGUP CAUSE: 16") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:3] ExecIf("DAHDI/1-1", "1?Set(__CRM_VOICEMAIL=SUCCESS)") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:4] NoOp("DAHDI/1-1", "MASTER CHANNEL: 1596434857.0 = 1596434857.0") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:5] GotoIf("DAHDI/1-1", "0?return") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:6] Set("DAHDI/1-1", "__CRM_HANGUP=1") in new stack
[2020-08-03 14:13:16] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:7] AGI("DAHDI/1-1", "agi://127.0.0.1/sangomacrm.agi") in new stack
[2020-08-03 14:13:17] VERBOSE[3558][C-00000001] res_agi.c: <DAHDI/1-1>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2020-08-03 14:13:17] VERBOSE[3558][C-00000001] pbx.c: Executing [s@crm-hangup:8] Return("DAHDI/1-1", "") in new stack
[2020-08-03 14:13:17] VERBOSE[3558][C-00000001] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on 'DAHDI/1-1'
[2020-08-03 14:13:17] VERBOSE[3558][C-00000001] app_stack.c: DAHDI/1-1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-08-03 14:13:17] VERBOSE[3558][C-00000001] sig_analog.c: Hanging up on 'DAHDI/1-1'
[2020-08-03 14:13:17] VERBOSE[3558][C-00000001] chan_dahdi.c: Hungup 'DAHDI/1-1'

https://wiki.freepbx.org/display/F2/Voicemail+Admin+-+Advanced+Settings

https://wiki.freepbx.org/display/FPG/Voicemail+Admin+-+Dialplan+Behavior

Check theses out to see if it helps.

If comtech’s suggested info doesn’t lead to a solution, can you tell us if you’re having any disconnect issues on regular non-voicemail calls? For example, if an external caller calls in and talks to an extension, and the extension hangs up, does the call also hangup properly on the caller’s end?

Hi, wmoon

I just tried to call from external to internal extension. When my extension hang up, external call did not hang up. Both voip phone and tranditional tested, same result. Is there any setting for hang up that I should take care of? Is there any different between US and Taiwan phone system for hang up signal?

Thanks,

Far end disconnect supervision applies to analog lines over dahdi, by default it will detect and act on good old Bell/AT&T methods and even that needs a ‘subscription’ on the line, there a many other working solution, you will need to hunt down a Taiwanese peer who has the recipe,

Failing all else use busy-detect and busy-count tuned for the ‘howler’ your telco probably sends after a few minutes. (a howler refers to the loud noise that was sent to alert a subscriber on a party line in the 1950’s who inadvertantly left the mic off hook, the lines where ground start and shared, so no way to individually signal a hangup)

1 Like

I agree with dicko that this sounds like a disconnect supervision issue. It’s possible Taiwan offers the same disconnect supervision as the US, and something is misconfigured on your system. But it’s also possible that Taiwan functions differently, and the goal would be to figure out what the right settings are, or if some service needs to be enabled at the provider. It would help to look for other examples of Asterisk based systems that were setup with analog lines in Taiwan to see what their dahdi configs look like. In the US, for proper disconnecting, it would typically require the analog channels be set up with kewlstart signaling, and telco provide disconnect supervision on the lines.

In regards to what dicko mentioned about relying on a howler tone if there are no other options, do you hear anything like that? For example, after the external caller hangs up, and you’re still on the silent line, do you eventually hear anything, like a repeating tone after a few minutes?

It would also be helpful to see what you currently have in chan_dahdi.conf and dahdi-channels.conf, both found in /etc/asterisk.

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