Choppy Audio and Dropped Calls on Fiber

We have a FreePBX system only 30 phones on fiber internet and SIP Trunks. They are experiencing intermittent dropped calls and choppy audio at times. I called the SIP carrier and asked about codecs and ports. I asked if they would be using 10000-20000 UDP and they commented that they could and would use any ports. No limits. As my firewall is set to 10000-20000 and the Asterisk SIP settings also has this same port setup could this be the source of the dropped calls or does the FreePBX tell the SIP carrier during the 5060 greeting which ports to use?

We are running Asterisk 13.15 and FreePBX 10.13.66-20

Thank you!

As always, a log extract from around the time of the call might be illuminating. There are many network issues outside of FreePBX that can cause dropped calls and choppy audio.

I believe these are the logfiles for the end of call

ExecIf(“SIP/Clearrate-00062c33”, “0?Gosub(ext-intercom,*80121,1())”) in new stack
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:9] ExecIf(“SIP/Clearrate-00062c33”, “0?MacroExit()”) in new stack
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] WARNING[1657][C-00026e28] pbx_functions.c: Can’t find trailing parenthesis for function ‘DB(DEVICE/121/dial’?
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:10] ExecIf(“SIP/Clearrate-00062c33”, “0?ChanSpy(SIP/121,q)”) in new stack
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] WARNING[1657][C-00026e28] pbx_functions.c: Can’t find trailing parenthesis for function ‘DB(DEVICE/121/dial’?
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:11] ExecIf(“SIP/Clearrate-00062c33”, “0?MacroExit()”) in new stack
[2018-02-28 08:41:21] ERROR[1657][C-00026e28] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:12] Gosub(“SIP/Clearrate-00062c33”, “sub-record-check,s,1(exten,121,dontcare)”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/Clearrate-00062c33”, “10?initialized”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (sub-record-check,s,10)
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/Clearrate-00062c33”, “Recordings initialized”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(ARG3=dontcare)”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/Clearrate-00062c33”, “REC_POLICY_MODE_SAVE=”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/Clearrate-00062c33”, “1?Set(REC_STATUS=NO)”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/Clearrate-00062c33”, “5?checkaction”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/Clearrate-00062c33”, “1?sub-record-check,exten,1”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:1] NoOp(“SIP/Clearrate-00062c33”, “Exten Recording Check between 9899281392 and 121”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:2] Set(“SIP/Clearrate-00062c33”, “CALLTYPE=external”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:3] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(CALLTYPE=)”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:4] Set(“SIP/Clearrate-00062c33”, “CALLEE=dontcare”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:5] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(CALLEE=dontcare)”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:6] GotoIf(“SIP/Clearrate-00062c33”, “1?callee”) in new stack
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2018-02-28 08:41:21] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:11] Gosub(“SIP/Clearrate-00062c33”, “recordcheck,1(dontcare,external,121)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/Clearrate-00062c33”, “Starting recording check against dontcare”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/Clearrate-00062c33”, “dontcare”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [exten@sub-record-check:12] Return(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:13] GotoIf(“SIP/Clearrate-00062c33”, “1?macrodial”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-exten-vm,s,19)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:19] GosubIf(“SIP/Clearrate-00062c33”, “0?clrheader,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-exten-vm:20] Macro(“SIP/Clearrate-00062c33”, “dial-one,15,Ttr,121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:1] Set(“SIP/Clearrate-00062c33”, “DEXTEN=121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:2] Set(“SIP/Clearrate-00062c33”, “__CRM_SOURCE=9899281392”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:3] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(EXTTOCALL=121)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:4] Set(“SIP/Clearrate-00062c33”, “DIALSTATUS_CW=”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“SIP/Clearrate-00062c33”, “0?screen,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:6] GosubIf(“SIP/Clearrate-00062c33”, “0?cf,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:7] GotoIf(“SIP/Clearrate-00062c33”, “1?skip1”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“SIP/Clearrate-00062c33”, “0?nodial”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:11] GotoIf(“SIP/Clearrate-00062c33”, “0?continue”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:12] Set(“SIP/Clearrate-00062c33”, “EXTHASCW=ENABLED”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“SIP/Clearrate-00062c33”, “0?next1:cwinusebusy”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:25] GotoIf(“SIP/Clearrate-00062c33”, “0?next3:continue”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:27] GotoIf(“SIP/Clearrate-00062c33”, “0?nodial”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:28] GosubIf(“SIP/Clearrate-00062c33”, “1?dstring,1():dlocal,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:1] Set(“SIP/Clearrate-00062c33”, “DSTRING=”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:2] Set(“SIP/Clearrate-00062c33”, “DEVICES=121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf(“SIP/Clearrate-00062c33”, “0?Return()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(DEVICES=21)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:5] Set(“SIP/Clearrate-00062c33”, “LOOPCNT=1”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:6] Set(“SIP/Clearrate-00062c33”, “ITER=1”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:7] Set(“SIP/Clearrate-00062c33”, “THISDIAL=SIP/121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf(“SIP/Clearrate-00062c33”, “1?zap2dahdi,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/Clearrate-00062c33”, “0?Return()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/Clearrate-00062c33”, “NEWDIAL=”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/Clearrate-00062c33”, “LOOPCNT2=1”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/Clearrate-00062c33”, “ITER2=1”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/Clearrate-00062c33”, “THISPART2=SIP/121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(THISPART2=DAHDI/121)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/Clearrate-00062c33”, “NEWDIAL=SIP/121&”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/Clearrate-00062c33”, “ITER2=2”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/Clearrate-00062c33”, “0?begin2”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/Clearrate-00062c33”, “THISDIAL=SIP/121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf(“SIP/Clearrate-00062c33”, “1?docheck”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-dial-one,dstring,14)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“SIP/Clearrate-00062c33”, “0?skipset”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:15] Set(“SIP/Clearrate-00062c33”, “DSTRING=SIP/121&”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:16] Set(“SIP/Clearrate-00062c33”, “ITER=2”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“SIP/Clearrate-00062c33”, “0?begin”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf(“SIP/Clearrate-00062c33”, “0?Return()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:19] Set(“SIP/Clearrate-00062c33”, “DSTRING=SIP/121”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [dstring@macro-dial-one:20] Return(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:29] GotoIf(“SIP/Clearrate-00062c33”, “0?nodial”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:30] GotoIf(“SIP/Clearrate-00062c33”, “0?skiptrace”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:31] GosubIf(“SIP/Clearrate-00062c33”, “1?ctset,1():ctclear,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [ctset@macro-dial-one:1] Set(“SIP/Clearrate-00062c33”, “DB(CALLTRACE/121)=9899281392”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [ctset@macro-dial-one:2] Return(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:32] Set(“SIP/Clearrate-00062c33”, “D_OPTIONS=TtrM(auto-blkvm)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:33] NoOp(“SIP/Clearrate-00062c33”, "Blind Transfer: SIP/125-00062c34, Attended Transfer: , User: , Alert Info: ") in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:34] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(ALERT_INFO=)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:35] ExecIf(“SIP/Clearrate-00062c33”, “1?Set(ALERT_INFO=)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:36] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(ALERT_INFO=)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:37] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:38] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:39] GosubIf(“SIP/Clearrate-00062c33”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:40] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:41] GosubIf(“SIP/Clearrate-00062c33”, “0?qwait,1()”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:42] Set(“SIP/Clearrate-00062c33”, “__CWIGNORE=”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:43] Set(“SIP/Clearrate-00062c33”, “__KEEPCID=TRUE”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:44] GotoIf(“SIP/Clearrate-00062c33”, “0?usegoto,1”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:45] GotoIf(“SIP/Clearrate-00062c33”, “1?godial”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-dial-one,s,50)
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:50] Macro(“SIP/Clearrate-00062c33”, “dialout-one-predial-hook,”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:51] ExecIf(“SIP/Clearrate-00062c33”, “1?Set(D_OPTIONS=trM(auto-blkvm)I)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:52] NoOp(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-dial-one:53] Dial(“SIP/Clearrate-00062c33”, “SIP/121,15,trM(auto-blkvm)Ib(func-apply-sipheaders^s^1)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] netsock2.c: Using SIP RTP TOS bits 184
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] netsock2.c: Using SIP RTP CoS mark 5
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_stack.c: SIP/121-00062c39 Internal Gosub(func-apply-sipheaders,s,1) start
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“SIP/121-00062c39”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“SIP/121-00062c39”, “Applying SIP Headers to channel”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“SIP/121-00062c39”, “SIPHEADERKEYS=”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@func-apply-sipheaders:4] While(“SIP/121-00062c39”, “0”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_while.c: Jumping to priority 8
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@func-apply-sipheaders:9] Return(“SIP/121-00062c39”, “”) in new stack
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_stack.c: Spawn extension (from-internal, 121, 1) exited non-zero on ‘SIP/121-00062c39’
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_stack.c: SIP/121-00062c39 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_dial.c: Called SIP/121
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_dial.c: Connected line update to SIP/Clearrate-00062c33 prevented.
[2018-02-28 08:41:22] VERBOSE[1657][C-00026e28] app_dial.c: SIP/121-00062c39 is ringing
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] app_dial.c: Connected line update to SIP/Clearrate-00062c33 prevented.
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] app_dial.c: SIP/121-00062c39 answered SIP/Clearrate-00062c33
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:1] Set(“SIP/121-00062c39”, “__MACRO_RESULT=”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:2] Set(“SIP/121-00062c39”, “CFIGNORE=”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:3] Set(“SIP/121-00062c39”, “MASTER_CHANNEL(CFIGNORE)=”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:4] Set(“SIP/121-00062c39”, “FORWARD_CONTEXT=from-internal”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:5] Set(“SIP/121-00062c39”, “MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:6] Macro(“SIP/121-00062c39”, “blkvm-clr,”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-blkvm-clr:1] Set(“SIP/121-00062c39”, “SHARED(BLKVM,SIP/Clearrate-00062c33)=”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-blkvm-clr:2] Set(“SIP/121-00062c39”, “GOSUB_RETVAL=”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/121-00062c39”, “”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:7] ExecIf(“SIP/121-00062c39”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=121)”) in new stack
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-auto-blkvm:8] ExecIf(“SIP/121-00062c39”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Angela)”) in new stack
[2018-02-28 08:41:27] VERBOSE[1840][C-00026e28] bridge_channel.c: Channel SIP/121-00062c39 joined ‘simple_bridge’ basic-bridge
[2018-02-28 08:41:27] VERBOSE[1657][C-00026e28] bridge_channel.c: Channel SIP/Clearrate-00062c33 joined ‘simple_bridge’ basic-bridge
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] bridge_channel.c: Channel SIP/Clearrate-00062c33 left ‘simple_bridge’ basic-bridge
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] app_macro.c: Spawn extension (macro-dial-one, s, 53) exited non-zero on ‘SIP/Clearrate-00062c33’ in macro ‘dial-one’
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] app_macro.c: Spawn extension (macro-exten-vm, s, 20) exited non-zero on ‘SIP/Clearrate-00062c33’ in macro ‘exten-vm’
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] bridge_channel.c: Channel SIP/121-00062c39 left ‘simple_bridge’ basic-bridge
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] app_stack.c: SIP/121-00062c39 Internal Gosub(crm-hangup,s,1) start
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx.c: Executing [s@crm-hangup:1] NoOp(“SIP/121-00062c39”, “Sending Hangup to CRM”) in new stack
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx.c: Executing [s@crm-hangup:2] NoOp(“SIP/121-00062c39”, “HANGUP CAUSE: 16”) in new stack
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx.c: Executing [s@crm-hangup:3] ExecIf(“SIP/121-00062c39”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Spawn extension (ext-local, 121, 2) exited non-zero on ‘SIP/Clearrate-00062c33’
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [h@ext-local:1] Macro(“SIP/Clearrate-00062c33”, “hangupcall,”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“SIP/Clearrate-00062c33”, “1?theend”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx.c: Executing [s@crm-hangup:4] NoOp(“SIP/121-00062c39”, “MASTER CHANNEL: 1519825282.406861 = 1519825145.406853”) in new stack
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx.c: Executing [s@crm-hangup:5] GotoIf(“SIP/121-00062c39”, “1?return”) in new stack
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx_builtins.c: Goto (crm-hangup,s,8)
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] pbx.c: Executing [s@crm-hangup:8] Return(“SIP/121-00062c39”, “”) in new stack
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] app_stack.c: Spawn extension (macro-dial-one, s, 1) exited non-zero on ‘SIP/121-00062c39’
[2018-02-28 08:42:12] VERBOSE[1840][C-00026e28] app_stack.c: SIP/121-00062c39 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(CDR(recordingfile)=)”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@macro-hangupcall:4] Hangup(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/Clearrate-00062c33’ in macro ‘hangupcall’
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/Clearrate-00062c33’
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] app_stack.c: SIP/Clearrate-00062c33 Internal Gosub(crm-hangup,s,1) start
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:1] NoOp(“SIP/Clearrate-00062c33”, “Sending Hangup to CRM”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:2] NoOp(“SIP/Clearrate-00062c33”, “HANGUP CAUSE: 16”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:3] ExecIf(“SIP/Clearrate-00062c33”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:4] NoOp(“SIP/Clearrate-00062c33”, “MASTER CHANNEL: 1519825145.406853 = 1519825145.406853”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:5] GotoIf(“SIP/Clearrate-00062c33”, “0?return”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:6] Set(“SIP/Clearrate-00062c33”, “__CRM_HANGUP=1”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:7] AGI(“SIP/Clearrate-00062c33”, “sangomacrm.agi”) in new stack
[2018-02-28 08:42:12] VERBOSE[1657][C-00026e28] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-02-28 08:42:13] VERBOSE[1657][C-00026e28] res_agi.c: <SIP/Clearrate-00062c33>AGI Script sangomacrm.agi completed, returning 0
[2018-02-28 08:42:13] VERBOSE[1657][C-00026e28] pbx.c: Executing [s@crm-hangup:8] Return(“SIP/Clearrate-00062c33”, “”) in new stack
[2018-02-28 08:42:13] VERBOSE[1657][C-00026e28] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/Clearrate-00062c33’
[2018-02-28 08:42:13] VERBOSE[1657][C-00026e28] app_stack.c: SIP/Clearrate-00062c33 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

Well, that didn’t help at all. I will tell you that choppy calls are not a symptom of port problems - they are usually network issues or codec issues.

Describe the choppiness you are hearing. When are you hearing it? It looks like this call got sent to voicemail - is the message on disk choppy, or are the prompts choppy, or are the conversations choppy?

This still sounds like a network problem. Have you looked at your network utilization? Are your phone deregistering? Is there a lot of other traffic on your fiber connection? Are you seeing packet loss from the PBX to a remote server when you run a ping? Have you segregated your phones onto their own network? Do you have other network management devices on the network (routers, firewalls, switches, etc.) that might be contributing to a problem? Are you seeing warnings about duplicate IP addresses on your network anywhere?

There are just SO many things that could be going wrong, and since we can’t actually see your network, you’re going to have to help us figure it out.

on advice of a number of our carriers we have upped the port range to 40k on the sip setting page

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