SRTP Problem? -

Today I have enabled SIP TLS and SRTP on about 10 Sangoma S500 phones. (Latest firmware installed)

During testing I noticed the following in the logs:

[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_dial.c: PJSIP/2194-00000008 is ringing
[2018-07-19 17:34:07] VERBOSE[9480][C-00000005] app_dial.c: PJSIP/2194-00000008 answered PJSIP/2197-00000007
[2018-07-19 17:34:07] VERBOSE[9578][C-00000005] bridge_channel.c: Channel PJSIP/2194-00000008 joined 'simple_bridge' basic-bridge <9a8b1cef-85e8-4a28-a586-f5d048ec0166>
[2018-07-19 17:34:07] VERBOSE[9480][C-00000005] bridge_channel.c: Channel PJSIP/2197-00000007 joined 'simple_bridge' basic-bridge <9a8b1cef-85e8-4a28-a586-f5d048ec0166>
[2018-07-19 17:34:17] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:17] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:22] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:22] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:27] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:27] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:32] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
[2018-07-19 17:34:32] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation

Just wondering if this is anything I need to worry about and fix?? The call seems to work OK and I had two way audio.

I will paste the full log below incase it is of any use:

[2018-07-19 17:34:01] VERBOSE[8369] pbx_variables.c: Setting global variable 'SIPDOMAIN' to 'pbx-01.cspencerltd.co.uk'
[2018-07-19 17:34:01] VERBOSE[8369] netsock2.c: Using SIP RTP Audio TOS bits 184
[2018-07-19 17:34:01] VERBOSE[8369] netsock2.c: Using SIP RTP Audio CoS mark 5
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/2197-00000007", "1?ext-local,2194,1:followme-check,2194,1") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (ext-local,2194,1)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Set("PJSIP/2197-00000007", "__RINGTIMER=15") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Macro("PJSIP/2197-00000007", "exten-vm,2194,2194,0,0,0") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Macro("PJSIP/2197-00000007", "user-callerid,") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Set("PJSIP/2197-00000007", "TOUCH_MONITOR=1532018041.11") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Set("PJSIP/2197-00000007", "AMPUSER=2197") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] GotoIf("PJSIP/2197-00000007", "0?report") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/2197-00000007", "1?Set(REALCALLERIDNUM=2197)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] Set("PJSIP/2197-00000007", "AMPUSER=2197") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] GotoIf("PJSIP/2197-00000007", "0?limit") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] Set("PJSIP/2197-00000007", "AMPUSERCIDNAME=Steve Allen") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:8] ExecIf("PJSIP/2197-00000007", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2197-00000007", "0?report") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] Set("PJSIP/2197-00000007", "AMPUSERCID=2197") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:11] Set("PJSIP/2197-00000007", "__DIAL_OPTIONS=HhTtr") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:12] Set("PJSIP/2197-00000007", "CALLERID(all)="Steve Allen" <2197>") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:13] GotoIf("PJSIP/2197-00000007", "0?limit") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2197-00000007", "0?Set(GROUP(concurrency_limit)=2197)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/2197-00000007", "0?Set(CHANNEL(language)=)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:16] NoOp("PJSIP/2197-00000007", "Macro Depth is 2") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:17] GotoIf("PJSIP/2197-00000007", "1?report2:macroerror") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/2197-00000007", "0?continue") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:19] ExecIf("PJSIP/2197-00000007", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:20] Set("PJSIP/2197-00000007", "__TTL=64") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:21] GotoIf("PJSIP/2197-00000007", "1?continue") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:37] Set("PJSIP/2197-00000007", "CALLERID(number)=2197") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:38] Set("PJSIP/2197-00000007", "CALLERID(name)=Steve Allen") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:39] GotoIf("PJSIP/2197-00000007", "0?cnum") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:40] Set("PJSIP/2197-00000007", "CDR(cnam)=Steve Allen") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:41] Set("PJSIP/2197-00000007", "CDR(cnum)=2197") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:42] Set("PJSIP/2197-00000007", "CHANNEL(language)=en_GB") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Set("PJSIP/2197-00000007", "RingGroupMethod=none") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] Set("PJSIP/2197-00000007", "__EXTTOCALL=2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] Set("PJSIP/2197-00000007", "__PICKUPMARK=2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] Set("PJSIP/2197-00000007", "RT=15") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/2197-00000007", "0?Macro(vm,2194,DIRECTDIAL,)") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] ExecIf("PJSIP/2197-00000007", "0?MacroExit()") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:8] ExecIf("PJSIP/2197-00000007", "0?Gosub(ext-intercom,*802194,1())") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/2197-00000007", "0?MacroExit()") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] ExecIf("PJSIP/2197-00000007", "0?ChanSpy(PJSIP/2194,q)") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:11] ExecIf("PJSIP/2197-00000007", "0?MacroExit()") in new stack
[2018-07-19 17:34:01] ERROR[9480][C-00000005] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:12] ExecIf("PJSIP/2197-00000007", "0?Macro(vm,2194,DIRECTDIAL,)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/2197-00000007", "0?MacroExit()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2197-00000007", "0?Gosub(ext-intercom,*802194,1())") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/2197-00000007", "0?MacroExit()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:16] ExecIf("PJSIP/2197-00000007", "0?ChanSpy(PJSIP/2194,q)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:17] ExecIf("PJSIP/2197-00000007", "0?MacroExit()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:18] Gosub("PJSIP/2197-00000007", "sub-record-check,s,1(exten,2194,dontcare)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/2197-00000007", "0?initialized") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Set("PJSIP/2197-00000007", "__REC_STATUS=INITIALIZED") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] Set("PJSIP/2197-00000007", "NOW=1532018041") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] Set("PJSIP/2197-00000007", "__DAY=19") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] Set("PJSIP/2197-00000007", "__MONTH=07") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] Set("PJSIP/2197-00000007", "__YEAR=2018") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] Set("PJSIP/2197-00000007", "__TIMESTR=20180719-173401") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:8] Set("PJSIP/2197-00000007", "__FROMEXTEN=2197") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:9] Set("PJSIP/2197-00000007", "__MON_FMT=wav") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/2197-00000007", "Recordings initialized") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:11] ExecIf("PJSIP/2197-00000007", "0?Set(ARG3=dontcare)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:12] Set("PJSIP/2197-00000007", "REC_POLICY_MODE_SAVE=") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/2197-00000007", "0?Set(REC_STATUS=NO)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:14] GotoIf("PJSIP/2197-00000007", "5?checkaction") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:17] GotoIf("PJSIP/2197-00000007", "1?sub-record-check,exten,1") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/2197-00000007", "Exten Recording Check between 2197 and 2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Set("PJSIP/2197-00000007", "CALLTYPE=internal") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2197-00000007", "0?Set(CALLTYPE=)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] Set("PJSIP/2197-00000007", "CALLEE=dontcare") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] ExecIf("PJSIP/2197-00000007", "0?Set(CALLEE=dontcare)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] GotoIf("PJSIP/2197-00000007", "0?callee") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] GotoIf("PJSIP/2197-00000007", "1?caller") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (sub-record-check,exten,13)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:13] Set("PJSIP/2197-00000007", "RECMODE=dontcare") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2197-00000007", "0?Set(RECMODE=dontcare)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/2197-00000007", "1?Set(RECMODE=dontcare)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:16] Gosub("PJSIP/2197-00000007", "recordcheck,1(dontcare,internal,2194)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/2197-00000007", "Starting recording check against dontcare") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Goto("PJSIP/2197-00000007", "dontcare") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] Return("PJSIP/2197-00000007", "") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:17] Return("PJSIP/2197-00000007", "") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:19] GotoIf("PJSIP/2197-00000007", "1?macrodial") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-exten-vm,s,25)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:25] GosubIf("PJSIP/2197-00000007", "0?clrheader,1()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:26] Macro("PJSIP/2197-00000007", "dial-one,15,HhTtr,2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Set("PJSIP/2197-00000007", "DEXTEN=2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] UserEvent("PJSIP/2197-00000007", "zulu-inbound-call,type:macro-dial-one,from:2197,to:2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2197-00000007", "0?Set(__EXTTOCALL=2194)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] Set("PJSIP/2197-00000007", "DIALSTATUS_CW=") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] GosubIf("PJSIP/2197-00000007", "0?screen,1()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] GosubIf("PJSIP/2197-00000007", "0?cf,1()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] GotoIf("PJSIP/2197-00000007", "1?skip1") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] GotoIf("PJSIP/2197-00000007", "0?nodial") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:11] GotoIf("PJSIP/2197-00000007", "0?continue") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:12] Set("PJSIP/2197-00000007", "EXTHASCW=ENABLED") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:13] GotoIf("PJSIP/2197-00000007", "0?next1:cwinusebusy") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:25] GotoIf("PJSIP/2197-00000007", "0?next3:continue") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:27] GotoIf("PJSIP/2197-00000007", "0?nodial") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:28] GosubIf("PJSIP/2197-00000007", "1?dstring,1():dlocal,1()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Set("PJSIP/2197-00000007", "DSTRING=") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Set("PJSIP/2197-00000007", "DEVICES=2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2197-00000007", "0?Return()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/2197-00000007", "0?Set(DEVICES=194)") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] Set("PJSIP/2197-00000007", "LOOPCNT=1") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] Set("PJSIP/2197-00000007", "ITER=1") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] Set("PJSIP/2197-00000007", "THISDIAL=PJSIP/2194") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:8] GosubIf("PJSIP/2197-00000007", "1?zap2dahdi,1()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] ExecIf("PJSIP/2197-00000007", "0?Return()") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Set("PJSIP/2197-00000007", "NEWDIAL=") in new stack
[2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] 

Looks like I need to split the paste over two posts. Rest of the log is below.

Forgot to mention, the server is up to date with system updates and module updates.

2nd part of the log:

Set("PJSIP/2197-00000007", "LOOPCNT2=1") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] Set("PJSIP/2197-00000007", "ITER2=1") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] Set("PJSIP/2197-00000007", "THISPART2=PJSIP/2194") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/2197-00000007", "0?Set(THISPART2=DAHDIIP/2194)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:7] Set("PJSIP/2197-00000007", "NEWDIAL=PJSIP/2194&") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:8] Set("PJSIP/2197-00000007", "ITER2=2") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2197-00000007", "0?begin2") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] Set("PJSIP/2197-00000007", "THISDIAL=PJSIP/2194") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:11] Return("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2197-00000007", "0?docheck") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/2197-00000007", "Debug: Found PJSIP Destination PJSIP/2194") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:11] GotoIf("PJSIP/2197-00000007", "0?doset") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:12] NoOp("PJSIP/2197-00000007", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:13] Set("PJSIP/2197-00000007", "THISDIAL=PJSIP/2194/sip:[email protected]:5060;transport=TLS") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2197-00000007", "0?Set(DIALSTATUS=CHANUNAVAIL)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:15] GotoIf("PJSIP/2197-00000007", "0?skipset") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:16] Set("PJSIP/2197-00000007", "DSTRING=PJSIP/2194/sip:[email protected]:5060;transport=TLS&") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:17] Set("PJSIP/2197-00000007", "ITER=2") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/2197-00000007", "0?begin") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:19] ExecIf("PJSIP/2197-00000007", "0?Return()") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:20] Set("PJSIP/2197-00000007", "DSTRING=PJSIP/2194/sip:[email protected]:5060;transport=TLS") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:21] Return("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:29] GotoIf("PJSIP/2197-00000007", "0?nodial") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:30] GotoIf("PJSIP/2197-00000007", "0?skiptrace") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:31] GosubIf("PJSIP/2197-00000007", "1?ctset,1():ctclear,1()") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Set("PJSIP/2197-00000007", "DB(CALLTRACE/2194)=2197") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Return("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:32] Set("PJSIP/2197-00000007", "D_OPTIONS=HhTtr") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:33] GosubIf("PJSIP/2197-00000007", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:34] NoOp("PJSIP/2197-00000007", "Blind Transfer: , Attended Transfer: , User: 2197, Alert Info: ") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:35] ExecIf("PJSIP/2197-00000007", "1?Set(ALERT_INFO=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:36] ExecIf("PJSIP/2197-00000007", "0?Set(ALERT_INFO=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:37] ExecIf("PJSIP/2197-00000007", "0?Set(ALERT_INFO=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:38] ExecIf("PJSIP/2197-00000007", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:39] ExecIf("PJSIP/2197-00000007", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:40] GosubIf("PJSIP/2197-00000007", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:41] ExecIf("PJSIP/2197-00000007", "0?Set(CHANNEL(musicclass)=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:42] GosubIf("PJSIP/2197-00000007", "0?qwait,1()") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:43] Set("PJSIP/2197-00000007", "__CWIGNORE=") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:44] Set("PJSIP/2197-00000007", "__KEEPCID=TRUE") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:45] GotoIf("PJSIP/2197-00000007", "0?usegoto,1") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:46] GotoIf("PJSIP/2197-00000007", "0?godial") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:47] Gosub("PJSIP/2197-00000007", "sub-presencestate-display,s,1(2194)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Goto("PJSIP/2197-00000007", "state-not_set,1") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (sub-presencestate-display,state-not_set,1)
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Set("PJSIP/2197-00000007", "PRESENCESTATE_DISPLAY=") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] Return("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:48] Set("PJSIP/2197-00000007", "CONNECTEDLINE(name,i)=David Turtill") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:49] Set("PJSIP/2197-00000007", "CONNECTEDLINE(num)=2194") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:50] Set("PJSIP/2197-00000007", "D_OPTIONS=HhTtrI") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:51] Macro("PJSIP/2197-00000007", "dialout-one-predial-hook,") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] MacroExit("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:52] ExecIf("PJSIP/2197-00000007", "0?Set(D_OPTIONS=HhtrII)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:53] GotoIf("PJSIP/2197-00000007", "1?zulunourl") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-dial-one,s,55)
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:55] ExecIf("PJSIP/2197-00000007", "0?Set(ZULU_TYPE=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:56] GotoIf("PJSIP/2197-00000007", "1?skippopup") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-dial-one,s,59)
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:59] UserEvent("PJSIP/2197-00000007", "zulu-call,eventtype:calling,extension:2194,type:,url:,cnam:Steve Allen,cnum:2197,lid:1532018041.11,from:2197,to:2194,user:") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:60] NoOp("PJSIP/2197-00000007", "Zulu Finished") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:61] Set("PJSIP/2197-00000007", "_zuludialopts=") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:62] AGI("PJSIP/2197-00000007", "zulureplace-one.agi,DSTRING,90") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/zulureplace-one.agi
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] res_agi.c: zulureplace-one.agi,DSTRING,90: DIALSTRING: PJSIP/2194/sip:[email protected]:5060;transport=TLS
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] res_agi.c: zulureplace-one.agi,DSTRING,90: DIALOPTS: HhTtrI
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] res_agi.c: zulureplace-one.agi,DSTRING,90: TIMEOUT: 15
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] res_agi.c: zulureplace-one.agi,DSTRING,90: NEWDIALSTRING: PJSIP/2194/sip:[email protected]:5060;transport=TLS
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] res_agi.c: <PJSIP/2197-00000007>AGI Script zulureplace-one.agi completed, returning 0
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:63] NoOp("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:64] ExecIf("PJSIP/2197-00000007", "0?Set(D_OPTIONS=HhTtrIg)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:65] Dial("PJSIP/2197-00000007", "PJSIP/2194/sip:[email protected]:5060;transport=TLS,15,HhTtrIb(func-apply-sipheaders^s^1)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_stack.c: PJSIP/2194-00000008 Internal Gosub(func-apply-sipheaders,s,1) start
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] UserEvent("PJSIP/2194-00000008", "zulu-call-b,type:func-apply-sipheaders,to:2194,from:2197") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:2] NoOp("PJSIP/2194-00000008", "Applying SIP Headers to channel") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] Set("PJSIP/2194-00000008", "SIPHEADERKEYS=") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/2194-00000008", "0?Set(Rheader=1)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] While("PJSIP/2194-00000008", "0") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_while.c: Jumping to priority 8
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/2194-00000008", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:10] Return("PJSIP/2194-00000008", "") in new stack
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_stack.c: Spawn extension (from-internal, 2194, 1) exited non-zero on 'PJSIP/2194-00000008'
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_stack.c: PJSIP/2194-00000008 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_dial.c: Called PJSIP/2194/sip:[email protected]:5060;transport=TLS
        [2018-07-19 17:34:01] VERBOSE[8370] netsock2.c: Using SIP RTP Audio TOS bits 184
        [2018-07-19 17:34:01] VERBOSE[8370] netsock2.c: Using SIP RTP Audio CoS mark 5
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_dial.c: Connected line update to PJSIP/2197-00000007 prevented.
        [2018-07-19 17:34:01] VERBOSE[9480][C-00000005] app_dial.c: PJSIP/2194-00000008 is ringing
        [2018-07-19 17:34:07] VERBOSE[9480][C-00000005] app_dial.c: PJSIP/2194-00000008 answered PJSIP/2197-00000007
        [2018-07-19 17:34:07] VERBOSE[9578][C-00000005] bridge_channel.c: Channel PJSIP/2194-00000008 joined 'simple_bridge' basic-bridge <9a8b1cef-85e8-4a28-a586-f5d048ec0166>
        [2018-07-19 17:34:07] VERBOSE[9480][C-00000005] bridge_channel.c: Channel PJSIP/2197-00000007 joined 'simple_bridge' basic-bridge <9a8b1cef-85e8-4a28-a586-f5d048ec0166>
        [2018-07-19 17:34:17] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:17] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:22] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:22] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:27] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:27] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:32] VERBOSE[9578][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:32] VERBOSE[9480][C-00000005] res_srtp.c: SRTCP unprotect failed because of unable to perform desired validation
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] bridge_channel.c: Channel PJSIP/2197-00000007 left 'simple_bridge' basic-bridge <9a8b1cef-85e8-4a28-a586-f5d048ec0166>
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] app_macro.c: Spawn extension (macro-dial-one, s, 65) exited non-zero on 'PJSIP/2197-00000007' in macro 'dial-one'
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] app_macro.c: Spawn extension (macro-exten-vm, s, 26) exited non-zero on 'PJSIP/2197-00000007' in macro 'exten-vm'
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Spawn extension (ext-local, 2194, 2) exited non-zero on 'PJSIP/2197-00000007'
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] Macro("PJSIP/2197-00000007", "hangupcall,") in new stack
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/2197-00000007", "1?theend") in new stack
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx_builtins.c: Goto (macro-hangupcall,s,3)
        [2018-07-19 17:34:35] VERBOSE[9578][C-00000005] bridge_channel.c: Channel PJSIP/2194-00000008 left 'simple_bridge' basic-bridge <9a8b1cef-85e8-4a28-a586-f5d048ec0166>
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2197-00000007", "0?Set(CDR(recordingfile)=)") in new stack
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:4] NoOp("PJSIP/2197-00000007", "PJSIP/2194-00000008 monior file= ") in new stack
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:5] AGI("PJSIP/2197-00000007", "attendedtransfer-rec-restart.php,PJSIP/2194-00000008,") in new stack
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] res_agi.c: <PJSIP/2197-00000007>AGI Script attendedtransfer-rec-restart.php completed, returning 0
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Executing [[email protected]:6] Hangup("PJSIP/2197-00000007", "") in new stack
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'PJSIP/2197-00000007' in macro 'hangupcall'
        [2018-07-19 17:34:35] VERBOSE[9480][C-00000005] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/2197-00000007'

I am having intermittent problems this morning. 2 of the phones that I have enabled SIP TLS and SRTP on are now having one way audio problems. They can hear the other caller but the caller can not hear them.

If I reboot the phones calls work fine. Here are the logs after the phone has been rebooted:

I’ve had to split the log output over two posts because of character limits:

Log Part 1

[2018-07-23 08:57:54] VERBOSE[3701] pbx_variables.c: Setting global variable 'SIPDOMAIN' to 'pbx-01.cspencerltd.co.uk'
[2018-07-23 08:57:54] VERBOSE[3701] netsock2.c: Using SIP RTP Audio TOS bits 184
[2018-07-23 08:57:54] VERBOSE[3701] netsock2.c: Using SIP RTP Audio CoS mark 5
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/2190-000002a9", "1?ext-local,2197,1:followme-check,2197,1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (ext-local,2197,1)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Set("PJSIP/2190-000002a9", "__RINGTIMER=15") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Macro("PJSIP/2190-000002a9", "exten-vm,2197,2197,0,0,0") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Macro("PJSIP/2190-000002a9", "user-callerid,") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Set("PJSIP/2190-000002a9", "TOUCH_MONITOR=1532332674.1767") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "AMPUSER=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] GotoIf("PJSIP/2190-000002a9", "0?report") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/2190-000002a9", "1?Set(REALCALLERIDNUM=2190)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] Set("PJSIP/2190-000002a9", "AMPUSER=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] GotoIf("PJSIP/2190-000002a9", "0?limit") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] Set("PJSIP/2190-000002a9", "AMPUSERCIDNAME=Simon Wood") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] ExecIf("PJSIP/2190-000002a9", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2190-000002a9", "0?report") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] Set("PJSIP/2190-000002a9", "AMPUSERCID=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] Set("PJSIP/2190-000002a9", "__DIAL_OPTIONS=HhTtr") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:12] Set("PJSIP/2190-000002a9", "CALLERID(all)="Simon Wood" <2190>") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] GotoIf("PJSIP/2190-000002a9", "0?limit") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2190-000002a9", "0?Set(GROUP(concurrency_limit)=2190)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/2190-000002a9", "0?Set(CHANNEL(language)=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:16] NoOp("PJSIP/2190-000002a9", "Macro Depth is 2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:17] GotoIf("PJSIP/2190-000002a9", "1?report2:macroerror") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/2190-000002a9", "0?continue") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:19] ExecIf("PJSIP/2190-000002a9", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:20] Set("PJSIP/2190-000002a9", "__TTL=64") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:21] GotoIf("PJSIP/2190-000002a9", "1?continue") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:37] Set("PJSIP/2190-000002a9", "CALLERID(number)=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:38] Set("PJSIP/2190-000002a9", "CALLERID(name)=Simon Wood") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:39] GotoIf("PJSIP/2190-000002a9", "0?cnum") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:40] Set("PJSIP/2190-000002a9", "CDR(cnam)=Simon Wood") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:41] Set("PJSIP/2190-000002a9", "CDR(cnum)=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:42] Set("PJSIP/2190-000002a9", "CHANNEL(language)=en_GB") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "RingGroupMethod=none") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] Set("PJSIP/2190-000002a9", "__EXTTOCALL=2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] Set("PJSIP/2190-000002a9", "__PICKUPMARK=2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] Set("PJSIP/2190-000002a9", "RT=15") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/2190-000002a9", "0?Macro(vm,2197,DIRECTDIAL,)") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] ExecIf("PJSIP/2190-000002a9", "0?MacroExit()") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] ExecIf("PJSIP/2190-000002a9", "0?Gosub(ext-intercom,*802197,1())") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/2190-000002a9", "0?MacroExit()") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] ExecIf("PJSIP/2190-000002a9", "0?ChanSpy(PJSIP/2197,q)") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] ExecIf("PJSIP/2190-000002a9", "0?MacroExit()") in new stack
[2018-07-23 08:57:54] ERROR[14724][C-00000141] pbx_functions.c: Function SIP_HEADER not registered
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:12] ExecIf("PJSIP/2190-000002a9", "0?Macro(vm,2197,DIRECTDIAL,)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/2190-000002a9", "0?MacroExit()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2190-000002a9", "0?Gosub(ext-intercom,*802197,1())") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/2190-000002a9", "0?MacroExit()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:16] ExecIf("PJSIP/2190-000002a9", "0?ChanSpy(PJSIP/2197,q)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:17] ExecIf("PJSIP/2190-000002a9", "0?MacroExit()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:18] Gosub("PJSIP/2190-000002a9", "sub-record-check,s,1(exten,2197,dontcare)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/2190-000002a9", "0?initialized") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "__REC_STATUS=INITIALIZED") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] Set("PJSIP/2190-000002a9", "NOW=1532332674") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] Set("PJSIP/2190-000002a9", "__DAY=23") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] Set("PJSIP/2190-000002a9", "__MONTH=07") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] Set("PJSIP/2190-000002a9", "__YEAR=2018") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] Set("PJSIP/2190-000002a9", "__TIMESTR=20180723-085754") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] Set("PJSIP/2190-000002a9", "__FROMEXTEN=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] Set("PJSIP/2190-000002a9", "__MON_FMT=wav") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/2190-000002a9", "Recordings initialized") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] ExecIf("PJSIP/2190-000002a9", "0?Set(ARG3=dontcare)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:12] Set("PJSIP/2190-000002a9", "REC_POLICY_MODE_SAVE=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] ExecIf("PJSIP/2190-000002a9", "0?Set(REC_STATUS=NO)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:14] GotoIf("PJSIP/2190-000002a9", "5?checkaction") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:17] GotoIf("PJSIP/2190-000002a9", "1?sub-record-check,exten,1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/2190-000002a9", "Exten Recording Check between 2190 and 2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "CALLTYPE=internal") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2190-000002a9", "0?Set(CALLTYPE=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] Set("PJSIP/2190-000002a9", "CALLEE=dontcare") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] ExecIf("PJSIP/2190-000002a9", "0?Set(CALLEE=dontcare)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] GotoIf("PJSIP/2190-000002a9", "0?callee") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] GotoIf("PJSIP/2190-000002a9", "1?caller") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (sub-record-check,exten,13)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] Set("PJSIP/2190-000002a9", "RECMODE=dontcare") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2190-000002a9", "0?Set(RECMODE=dontcare)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:15] ExecIf("PJSIP/2190-000002a9", "1?Set(RECMODE=dontcare)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:16] Gosub("PJSIP/2190-000002a9", "recordcheck,1(dontcare,internal,2197)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] NoOp("PJSIP/2190-000002a9", "Starting recording check against dontcare") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Goto("PJSIP/2190-000002a9", "dontcare") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:17] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:19] GotoIf("PJSIP/2190-000002a9", "1?macrodial") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-exten-vm,s,25)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:25] GosubIf("PJSIP/2190-000002a9", "0?clrheader,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:26] Macro("PJSIP/2190-000002a9", "dial-one,15,HhTtr,2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Set("PJSIP/2190-000002a9", "DEXTEN=2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] UserEvent("PJSIP/2190-000002a9", "zulu-inbound-call,type:macro-dial-one,from:2190,to:2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2190-000002a9", "0?Set(__EXTTOCALL=2197)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] Set("PJSIP/2190-000002a9", "DIALSTATUS_CW=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] GosubIf("PJSIP/2190-000002a9", "0?screen,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] GosubIf("PJSIP/2190-000002a9", "0?cf,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] GotoIf("PJSIP/2190-000002a9", "1?skip1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] GotoIf("PJSIP/2190-000002a9", "0?nodial") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] GotoIf("PJSIP/2190-000002a9", "0?continue") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:12] Set("PJSIP/2190-000002a9", "EXTHASCW=ENABLED") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] GotoIf("PJSIP/2190-000002a9", "0?next1:cwinusebusy") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:25] GotoIf("PJSIP/2190-000002a9", "0?next3:continue") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:27] GotoIf("PJSIP/2190-000002a9", "0?nodial") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:28] GosubIf("PJSIP/2190-000002a9", "1?dstring,1():dlocal,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Set("PJSIP/2190-000002a9", "DSTRING=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "DEVICES=992197&2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2190-000002a9", "0?Return()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/2190-000002a9", "0?Set(DEVICES=92197&2197)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] Set("PJSIP/2190-000002a9", "LOOPCNT=2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] Set("PJSIP/2190-000002a9", "ITER=1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] Set("PJSIP/2190-000002a9", "THISDIAL=PJSIP/992197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] GosubIf("PJSIP/2190-000002a9", "1?zap2dahdi,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] ExecIf("PJSIP/2190-000002a9", "0?Return()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "NEWDIAL=") in new stack

Log Part 2

[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] Set("PJSIP/2190-000002a9", "LOOPCNT2=1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] Set("PJSIP/2190-000002a9", "ITER2=1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] Set("PJSIP/2190-000002a9", "THISPART2=PJSIP/992197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/2190-000002a9", "0?Set(THISPART2=DAHDIIP/992197)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] Set("PJSIP/2190-000002a9", "NEWDIAL=PJSIP/992197&") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] Set("PJSIP/2190-000002a9", "ITER2=2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2190-000002a9", "0?begin2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] Set("PJSIP/2190-000002a9", "THISDIAL=PJSIP/992197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2190-000002a9", "0?docheck") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/2190-000002a9", "Debug: Found PJSIP Destination PJSIP/992197") in new
stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] GotoIf("PJSIP/2190-000002a9", "0?doset") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:12] NoOp("PJSIP/2190-000002a9", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] Set("PJSIP/2190-000002a9", "THISDIAL=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2190-000002a9", "1?Set(DIALSTATUS=CHANUNAVAIL)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:15] GotoIf("PJSIP/2190-000002a9", "1?skipset") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,dstring,17)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:17] Set("PJSIP/2190-000002a9", "ITER=2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/2190-000002a9", "1?begin") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,dstring,7)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] Set("PJSIP/2190-000002a9", "THISDIAL=PJSIP/2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] GosubIf("PJSIP/2190-000002a9", "1?zap2dahdi,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] ExecIf("PJSIP/2190-000002a9", "0?Return()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Set("PJSIP/2190-000002a9", "NEWDIAL=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] Set("PJSIP/2190-000002a9", "LOOPCNT2=1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] Set("PJSIP/2190-000002a9", "ITER2=1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] Set("PJSIP/2190-000002a9", "THISPART2=PJSIP/2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] ExecIf("PJSIP/2190-000002a9", "0?Set(THISPART2=DAHDIIP/2197)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:7] Set("PJSIP/2190-000002a9", "NEWDIAL=PJSIP/2197&") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:8] Set("PJSIP/2190-000002a9", "ITER2=2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2190-000002a9", "0?begin2") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] Set("PJSIP/2190-000002a9", "THISDIAL=PJSIP/2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] GotoIf("PJSIP/2190-000002a9", "0?docheck") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] NoOp("PJSIP/2190-000002a9", "Debug: Found PJSIP Destination PJSIP/2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:11] GotoIf("PJSIP/2190-000002a9", "0?doset") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:12] NoOp("PJSIP/2190-000002a9", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:13] Set("PJSIP/2190-000002a9", "THISDIAL=PJSIP/2197/sip:[email protected]:5060;transport=TLS") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:14] ExecIf("PJSIP/2190-000002a9", "0?Set(DIALSTATUS=CHANUNAVAIL)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:15] GotoIf("PJSIP/2190-000002a9", "0?skipset") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [dst[email protected]:16] Set("PJSIP/2190-000002a9", "DSTRING=PJSIP/2197/sip:[email protected]:5060;transport=TLS&") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:17] Set("PJSIP/2190-000002a9", "ITER=3") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:18] GotoIf("PJSIP/2190-000002a9", "0?begin") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:19] ExecIf("PJSIP/2190-000002a9", "0?Return()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:20] Set("PJSIP/2190-000002a9", "DSTRING=PJSIP/2197/sip:[email protected]:5060;transport=TLS") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:21] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:29] GotoIf("PJSIP/2190-000002a9", "0?nodial") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:30] GotoIf("PJSIP/2190-000002a9", "0?skiptrace") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:31] GosubIf("PJSIP/2190-000002a9", "1?ctset,1():ctclear,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Set("PJSIP/2190-000002a9", "DB(CALLTRACE/2197)=2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:32] Set("PJSIP/2190-000002a9", "D_OPTIONS=HhTtr") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:33] GosubIf("PJSIP/2190-000002a9", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:34] NoOp("PJSIP/2190-000002a9", "Blind Transfer: , Attended Transfer: , User: 2190, Alert Info: ") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:35] ExecIf("PJSIP/2190-000002a9", "1?Set(ALERT_INFO=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:36] ExecIf("PJSIP/2190-000002a9", "0?Set(ALERT_INFO=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:37] ExecIf("PJSIP/2190-000002a9", "0?Set(ALERT_INFO=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:38] ExecIf("PJSIP/2190-000002a9", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:39] ExecIf("PJSIP/2190-000002a9", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:40] GosubIf("PJSIP/2190-000002a9", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:41] ExecIf("PJSIP/2190-000002a9", "0?Set(CHANNEL(musicclass)=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:42] GosubIf("PJSIP/2190-000002a9", "0?qwait,1()") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:43] Set("PJSIP/2190-000002a9", "__CWIGNORE=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:44] Set("PJSIP/2190-000002a9", "__KEEPCID=TRUE") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:45] GotoIf("PJSIP/2190-000002a9", "0?usegoto,1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:46] GotoIf("PJSIP/2190-000002a9", "0?godial") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]ro-dial-one:47] Gosub("PJSIP/2190-000002a9", "sub-presencestate-display,s,1(2197)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Goto("PJSIP/2190-000002a9", "state-not_set,1") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (sub-presencestate-display,state-not_set,1)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Set("PJSIP/2190-000002a9", "PRESENCESTATE_DISPLAY=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] Return("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:48] Set("PJSIP/2190-000002a9", "CONNECTEDLINE(name,i)=Steve Allen") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:49] Set("PJSIP/2190-000002a9", "CONNECTEDLINE(num)=2197") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:50] Set("PJSIP/2190-000002a9", "D_OPTIONS=HhTtrI") in new stack
[2018-07-23 08:57:54] WARNING[14724][C-00000141] taskprocessor.c: The 'subp:PJSIP/2190-00000054' task processor queue reached 500 scheduled tasks.
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:51] Macro("PJSIP/2190-000002a9", "dialout-one-predial-hook,") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] MacroExit("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:52] ExecIf("PJSIP/2190-000002a9", "0?Set(D_OPTIONS=HhtrII)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:53] GotoIf("PJSIP/2190-000002a9", "1?zulunourl") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,s,55)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:55] ExecIf("PJSIP/2190-000002a9", "0?Set(ZULU_TYPE=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:56] GotoIf("PJSIP/2190-000002a9", "1?skippopup") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-dial-one,s,59)
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:59] UserEvent("PJSIP/2190-000002a9", "zulu-call,eventtype:calling,extension:2197,type:,url:,cnam:Simon Wood,cnum:2190,lid:1532332674.1767,from:2190,to:2197,user:") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:60] NoOp("PJSIP/2190-000002a9", "Zulu Finished") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:61] Set("PJSIP/2190-000002a9", "_zuludialopts=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:62] AGI("PJSIP/2190-000002a9", "zulureplace-one.agi,DSTRING,90") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/zulureplace-one.agi
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] res_agi.c: zulureplace-one.agi,DSTRING,90: DIALSTRING: PJSIP/2197/sip:[email protected]:5060;transport=TLS
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] res_agi.c: zulureplace-one.agi,DSTRING,90: DIALOPTS: HhTtrI
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] res_agi.c: zulureplace-one.agi,DSTRING,90: TIMEOUT: 15
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] res_agi.c: zulureplace-one.agi,DSTRING,90: NEWDIALSTRING: PJSIP/2197/sip:[email protected]:5060;transport=TLS
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] res_agi.c: <PJSIP/2190-000002a9>AGI Script zulureplace-one.agi completed, returning 0
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:63] NoOp("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:64] ExecIf("PJSIP/2190-000002a9", "0?Set(D_OPTIONS=HhTtrIg)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:65] Dial("PJSIP/2190-000002a9", "PJSIP/2197/sip:[email protected]:5060;transport=TLS,15,HhTtrIb(func-apply-sipheaders^s^1)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] app_stack.c: PJSIP/2197-000002aa Internal Gosub(func-apply-sipheaders,s,1) start
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] UserEvent("PJSIP/2197-000002aa", "zulu-call-b,type:func-apply-sipheaders,to:2197,from:2190") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:2] NoOp("PJSIP/2197-000002aa", "Applying SIP Headers to channel") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] Set("PJSIP/2197-000002aa", "SIPHEADERKEYS=") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] ExecIf("PJSIP/2197-000002aa", "0?Set(Rheader=1)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] While("PJSIP/2197-000002aa", "0") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] app_while.c: Jumping to priority 8
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:9] ExecIf("PJSIP/2197-000002aa", "0?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:10] Return("PJSIP/2197-000002aa", "") in new stack
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] app_stack.c: Spawn extension (from-internal, 2197, 1) exited non-zero on 'PJSIP/2197-000002aa'
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] app_stack.c: PJSIP/2197-000002aa Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] app_dial.c: Called PJSIP/2197/sip:[email protected]:5060;transport=TLS
[2018-07-23 08:57:54] VERBOSE[29423] netsock2.c: Using SIP RTP Audio TOS bits 184
[2018-07-23 08:57:54] VERBOSE[29423] netsock2.c: Using SIP RTP Audio CoS mark 5
[2018-07-23 08:57:54] VERBOSE[14724][C-00000141] app_dial.c: Connected line update to PJSIP/2190-000002a9 prevented.
[2018-07-23 08:57:55] VERBOSE[14724][C-00000141] app_dial.c: PJSIP/2197-000002aa is ringing
[2018-07-23 08:57:56] VERBOSE[14724][C-00000141] app_dial.c: PJSIP/2197-000002aa answered PJSIP/2190-000002a9
[2018-07-23 08:57:56] VERBOSE[14745][C-00000141] bridge_channel.c: Channel PJSIP/2197-000002aa joined 'simple_bridge' basic-bridge <a0dfba1f-05ff-4650-b3dd-3f5fd199d7b8>
[2018-07-23 08:57:56] VERBOSE[14724][C-00000141] bridge_channel.c: Channel PJSIP/2190-000002a9 joined 'simple_bridge' basic-bridge <a0dfba1f-05ff-4650-b3dd-3f5fd199d7b8>
[2018-07-23 08:57:56] VERBOSE[14724][C-00000141] res_srtp.c: SRTP unprotect failed because of authentication failure 10
[2018-07-23 08:57:59] VERBOSE[14724][C-00000141] res_srtp.c: SRTP unprotect failed because of authentication failure 160
[2018-07-23 08:58:01] VERBOSE[14745][C-00000141] bridge_channel.c: Channel PJSIP/2197-000002aa left 'simple_bridge' basic-bridge <a0dfba1f-05ff-4650-b3dd-3f5fd199d7b8>
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] bridge_channel.c: Channel PJSIP/2190-000002a9 left 'simple_bridge' basic-bridge <a0dfba1f-05ff-4650-b3dd-3f5fd199d7b8>
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] app_macro.c: Spawn extension (macro-dial-one, s, 65) exited non-zero on 'PJSIP/2190-000002a9' in macro 'dial-one'
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] app_macro.c: Spawn extension (macro-exten-vm, s, 26) exited non-zero on 'PJSIP/2190-000002a9' in macro 'exten-vm'
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Spawn extension (ext-local, 2197, 2) exited non-zero on 'PJSIP/2190-000002a9'
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] Macro("PJSIP/2190-000002a9", "hangupcall,") in new stack
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:1] GotoIf("PJSIP/2190-000002a9", "1?theend") in new stack
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:3] ExecIf("PJSIP/2190-000002a9", "0?Set(CDR(recordingfile)=)") in new stack
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:4] NoOp("PJSIP/2190-000002a9", "PJSIP/2197-000002aa monior file= ") in new stack
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:5] AGI("PJSIP/2190-000002a9", "attendedtransfer-rec-restart.php,PJSIP/2197-000002aa,") in
new stack
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] res_agi.c: <PJSIP/2190-000002a9>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Executing [[email protected]:6] Hangup("PJSIP/2190-000002a9", "") in new stack
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'PJSIP/2190-000002a9' in macro 'hangupcall'
[2018-07-23 08:58:01] VERBOSE[14724][C-00000141] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/2190-000002a9'

hi, i use sip-tls/srtp also and i get this message on every ongoing call. it annoys me but I do not see any negative impact. It is unrelated to your “one-way” voice issue.

I have had one-way voice problems on srtp before and it always seems to do with one extension not encrypted when the other is (when both phones are configured to use srtp)…do you have opportunistic encryption enabled on the extension? if so, this can lead to some phones using srtp while others not. if you have srtp working properly, you should be able to disable opportunistic encryption on the extension and things will still work. if they break, you have a srtp issue.

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