Hi,
We have a big problem where our PBX receives a 486 busy message from our SBC, but then forwards this on as 503 Service unavailable. Because the PBX sends 503 service unavailable our provider repeatedly tries to setup the call. Can someone help identify wht the 486 is fowarded to our provider as 503?
Endpoints sends 486 Busy message
PBX sends provider 503 even though it is 486 that was received from the endpoint
Thanks in advance
Are you using PJSIP or chan_sip for these connections?
PJSIP - the SIP trunk is between the SIP provider --> PBX --> SBC are all PJSIP.
The SBC sends the PBX the 486 busy message, which then the PBX sends our SIP provider 503 Service Unavailable messages.
Becayse our provider retries on Service Unavailable after a set time, it is causing a huge influx of calls…
As above. No idea why but in my experience the PBX should just send through the 486 Busy message
I have done more tests. When I set the DDI destination to an extension, dial it and stay in the call and then place another call, the device sends 486 to the pbx which sends the 486 message to our provider, so the mobile that placed the call receives User Busy.
Its only when our SBC sends the 486 message on busy, that the PBX sends 503 unavailable here.
Verbose logs from the timeframe of a call may help, as well as a full SIP trace (not just the ladder diagram).
First Call:
[2021-02-09 21:41:01] VERBOSE[85008] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘192.168.222.3’
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_sipprovider_primary-00001685”, “__DIRECTION=INBOUND”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] Gosub(“PJSIP/to_sipprovider_primary-00001685”, “sub-record-check,s,1(in,+499119380003,dontcare)”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “0?initialized”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_sipprovider_primary-00001685”, “__REC_STATUS=INITIALIZED”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_sipprovider_primary-00001685”, “NOW=1612903261”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:4] Set(“PJSIP/to_sipprovider_primary-00001685”, “__DAY=09”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:5] Set(“PJSIP/to_sipprovider_primary-00001685”, “__MONTH=02”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_sipprovider_primary-00001685”, “__YEAR=2021”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:7] Set(“PJSIP/to_sipprovider_primary-00001685”, “__TIMESTR=20210209-214101”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:8] Set(“PJSIP/to_sipprovider_primary-00001685”, “__FROMEXTEN=unknown”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:9] Set(“PJSIP/to_sipprovider_primary-00001685”, “__MON_FMT=wav”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:10] NoOp(“PJSIP/to_sipprovider_primary-00001685”, “Recordings initialized”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:11] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “0?Set(ARG3=dontcare)”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:12] Set(“PJSIP/to_sipprovider_primary-00001685”, “REC_POLICY_MODE_SAVE=”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:13] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “0?Set(REC_STATUS=NO)”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:14] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “2?checkaction”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:17] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “1?sub-record-check,in,1”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (sub-record-check,in,1)
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_sipprovider_primary-00001685”, “Inbound Recording Check to +499119380003”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_sipprovider_primary-00001685”, “FROMEXTEN=unknown”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “14?Set(FROMEXTEN=00447834987586)”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:4] Gosub(“PJSIP/to_sipprovider_primary-00001685”, “recordcheck,1(dontcare,in,+499119380003)”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_sipprovider_primary-00001685”, “Starting recording check against dontcare”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] Goto(“PJSIP/to_sipprovider_primary-00001685”, “dontcare”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:3] Return(“PJSIP/to_sipprovider_primary-00001685”, “”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:5] Return(“PJSIP/to_sipprovider_primary-00001685”, “”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_sipprovider_primary-00001685”, “CHANNEL(tonezone)=us”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:4] Set(“PJSIP/to_sipprovider_primary-00001685”, “__FROM_DID=+499119380003”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:5] Set(“PJSIP/to_sipprovider_primary-00001685”, “returnhere=1”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:6] Gosub(“PJSIP/to_sipprovider_primary-00001685”, “app-blacklist-check,s,1()”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “0?blacklisted”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_sipprovider_primary-00001685”, “CALLED_BLACKLIST=1”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:3] Return(“PJSIP/to_sipprovider_primary-00001685”, “”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:7] Set(“PJSIP/to_sipprovider_primary-00001685”, “CDR(did)=+499119380003”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:8] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “0?”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:9] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “0 ?Set(CALLERID(name)=00447834987586)”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:10] Set(“PJSIP/to_sipprovider_primary-00001685”, “__MOHCLASS=”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:11] Set(“PJSIP/to_sipprovider_primary-00001685”, “__REVERSAL_REJECT=FALSE”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:12] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “1?post-reverse-charge”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (from-pstn,+499119380003,14)
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:14] NoOp(“PJSIP/to_sipprovider_primary-00001685”, “”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:15] Set(“PJSIP/to_sipprovider_primary-00001685”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:16] Set(“PJSIP/to_sipprovider_primary-00001685”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:17] Set(“PJSIP/to_sipprovider_primary-00001685”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:18] Set(“PJSIP/to_sipprovider_primary-00001685”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:19] NoOp(“PJSIP/to_sipprovider_primary-00001685”, “CallerID Entry Point”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:20] Set(“PJSIP/to_sipprovider_primary-00001685”, “__CRM_DIRECTION=INBOUND”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:21] Set(“PJSIP/to_sipprovider_primary-00001685”, “__CRM_SOURCE=00447834987586”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:22] Set(“PJSIP/to_sipprovider_primary-00001685”, “__CRM_LINKEDID=1612903261.12056”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:23] AGI(“PJSIP/to_sipprovider_primary-00001685”, “sangomacrm.agi,true”) in new stack
[2021-02-09 21:41:01] VERBOSE[57351][C-00000b3a] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] res_agi.c: <PJSIP/to_sipprovider_primary-00001685>AGI Script sangomacrm.agi completed, returning 0
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:24] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:25] Goto(“PJSIP/to_sipprovider_primary-00001685”, “ext-trunk,2,1”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (ext-trunk,2,1)
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_sipprovider_primary-00001685”, “[email protected]”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_sipprovider_primary-00001685”, “TDIAL_STRING=PJSIP”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_sipprovider_primary-00001685”, “DIAL_TRUNK=2”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:4] Goto(“PJSIP/to_sipprovider_primary-00001685”, “ext-trunk,tdial,1”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (ext-trunk,tdial,1)
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_sipprovider_primary-00001685”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:2] GotoIf(“PJSIP/to_sipprovider_primary-00001685”, “1?nomax”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx_builtins.c: Goto (ext-trunk,tdial,4)
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:4] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “1?Set(CALLERPRES(name-pres)=allowed_not_screened)”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:5] ExecIf(“PJSIP/to_sipprovider_primary-00001685”, “1?Set(CALLERPRES(num-pres)=allowed_not_screened)”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_sipprovider_primary-00001685”, “DIAL_NUMBER=+499119380003”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:7] GosubIf(“PJSIP/to_sipprovider_primary-00001685”, “0?sub-flp-2,s,1()”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:8] Set(“PJSIP/to_sipprovider_primary-00001685”, “OUTNUM=+499119380003”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:9] Set(“PJSIP/to_sipprovider_primary-00001685”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] pbx.c: Executing [[email protected]:10] Dial(“PJSIP/to_sipprovider_primary-00001685”, “PJSIP/[email protected],300,T”) in new stack
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] app_dial.c: Called PJSIP/[email protected]
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:02] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is making progress passing it to PJSIP/to_sipprovider_primary-00001685
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is making progress passing it to PJSIP/to_sipprovider_primary-00001685
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:03] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 is ringing
[2021-02-09 21:41:06] VERBOSE[57351][C-00000b3a] app_dial.c: PJSIP/sbctrunk-00001686 answered PJSIP/to_sipprovider_primary-00001685
[2021-02-09 21:41:06] VERBOSE[57395][C-00000b3a] bridge_channel.c: Channel PJSIP/sbctrunk-00001686 joined ‘simple_bridge’ basic-bridge
[2021-02-09 21:41:06] VERBOSE[57351][C-00000b3a] bridge_channel.c: Channel PJSIP/to_sipprovider_primary-00001685 joined ‘simple_bridge’ basic-bridge
Whilst in first call (so should return busy)
[2021-02-09 21:41:47] VERBOSE[54947] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘192.168.222.3’
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_telefonica_primary-00001687”, “__DIRECTION=INBOUND”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] Gosub(“PJSIP/to_telefonica_primary-00001687”, “sub-record-check,s,1(in,+499119380003,dontcare)”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “0?initialized”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001687”, “__REC_STATUS=INITIALIZED”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_telefonica_primary-00001687”, “NOW=1612903307”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:4] Set(“PJSIP/to_telefonica_primary-00001687”, “__DAY=09”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:5] Set(“PJSIP/to_telefonica_primary-00001687”, “__MONTH=02”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_telefonica_primary-00001687”, “__YEAR=2021”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:7] Set(“PJSIP/to_telefonica_primary-00001687”, “__TIMESTR=20210209-214147”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:8] Set(“PJSIP/to_telefonica_primary-00001687”, “__FROMEXTEN=unknown”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:9] Set(“PJSIP/to_telefonica_primary-00001687”, “__MON_FMT=wav”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:10] NoOp(“PJSIP/to_telefonica_primary-00001687”, “Recordings initialized”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:11] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “0?Set(ARG3=dontcare)”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:12] Set(“PJSIP/to_telefonica_primary-00001687”, “REC_POLICY_MODE_SAVE=”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:13] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “0?Set(REC_STATUS=NO)”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:14] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “2?checkaction”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:17] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “1?sub-record-check,in,1”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (sub-record-check,in,1)
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_telefonica_primary-00001687”, “Inbound Recording Check to +499119380003”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001687”, “FROMEXTEN=unknown”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “14?Set(FROMEXTEN=00447969776426)”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:4] Gosub(“PJSIP/to_telefonica_primary-00001687”, “recordcheck,1(dontcare,in,+499119380003)”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_telefonica_primary-00001687”, “Starting recording check against dontcare”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] Goto(“PJSIP/to_telefonica_primary-00001687”, “dontcare”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] Return(“PJSIP/to_telefonica_primary-00001687”, “”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:5] Return(“PJSIP/to_telefonica_primary-00001687”, “”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_telefonica_primary-00001687”, “CHANNEL(tonezone)=us”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:4] Set(“PJSIP/to_telefonica_primary-00001687”, “__FROM_DID=+499119380003”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:5] Set(“PJSIP/to_telefonica_primary-00001687”, “returnhere=1”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:6] Gosub(“PJSIP/to_telefonica_primary-00001687”, “app-blacklist-check,s,1()”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “0?blacklisted”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001687”, “CALLED_BLACKLIST=1”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] Return(“PJSIP/to_telefonica_primary-00001687”, “”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:7] Set(“PJSIP/to_telefonica_primary-00001687”, “CDR(did)=+499119380003”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:8] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “0?”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:9] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “0 ?Set(CALLERID(name)=00447969776426)”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:10] Set(“PJSIP/to_telefonica_primary-00001687”, “__MOHCLASS=”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:11] Set(“PJSIP/to_telefonica_primary-00001687”, “__REVERSAL_REJECT=FALSE”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:12] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “1?post-reverse-charge”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (from-pstn,+499119380003,14)
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:14] NoOp(“PJSIP/to_telefonica_primary-00001687”, “”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:15] Set(“PJSIP/to_telefonica_primary-00001687”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:16] Set(“PJSIP/to_telefonica_primary-00001687”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:17] Set(“PJSIP/to_telefonica_primary-00001687”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:18] Set(“PJSIP/to_telefonica_primary-00001687”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:19] NoOp(“PJSIP/to_telefonica_primary-00001687”, “CallerID Entry Point”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:20] Set(“PJSIP/to_telefonica_primary-00001687”, “__CRM_DIRECTION=INBOUND”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:21] Set(“PJSIP/to_telefonica_primary-00001687”, “__CRM_SOURCE=00447969776426”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:22] Set(“PJSIP/to_telefonica_primary-00001687”, “__CRM_LINKEDID=1612903307.12058”) in new stack
[2021-02-09 21:41:47] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:23] AGI(“PJSIP/to_telefonica_primary-00001687”, “sangomacrm.agi,true”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] res_agi.c: <PJSIP/to_telefonica_primary-00001687>AGI Script sangomacrm.agi completed, returning 0
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:24] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:25] Goto(“PJSIP/to_telefonica_primary-00001687”, “ext-trunk,2,1”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (ext-trunk,2,1)
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_telefonica_primary-00001687”, “[email protected]”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001687”, “TDIAL_STRING=PJSIP”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_telefonica_primary-00001687”, “DIAL_TRUNK=2”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:4] Goto(“PJSIP/to_telefonica_primary-00001687”, “ext-trunk,tdial,1”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (ext-trunk,tdial,1)
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_telefonica_primary-00001687”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “1?nomax”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx_builtins.c: Goto (ext-trunk,tdial,4)
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:4] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “1?Set(CALLERPRES(name-pres)=allowed_not_screened)”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:5] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “1?Set(CALLERPRES(num-pres)=allowed_not_screened)”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_telefonica_primary-00001687”, “DIAL_NUMBER=+499119380003”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:7] GosubIf(“PJSIP/to_telefonica_primary-00001687”, “0?sub-flp-2,s,1()”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:8] Set(“PJSIP/to_telefonica_primary-00001687”, “OUTNUM=+499119380003”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:9] Set(“PJSIP/to_telefonica_primary-00001687”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:10] Dial(“PJSIP/to_telefonica_primary-00001687”, “PJSIP/[email protected],300,T”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: Called PJSIP/[email protected]
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: PJSIP/fronerisbc-00001688 is ringing
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: PJSIP/fronerisbc-00001688 is ringing
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: Everyone is busy/congested at this time (1:0/1/0)
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:11] Set(“PJSIP/to_telefonica_primary-00001687”, “CALLERID(number)=00447969776426”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:12] Set(“PJSIP/to_telefonica_primary-00001687”, “CALLERID(name)=+447969776426”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:13] Hangup(“PJSIP/to_telefonica_primary-00001687”, “”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Spawn extension (ext-trunk, tdial, 13) exited non-zero on ‘PJSIP/to_telefonica_primary-00001687’
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_stack.c: PJSIP/to_telefonica_primary-00001687 Internal Gosub(crm-hangup,s,1) start
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_telefonica_primary-00001687”, “Sending Hangup to CRM”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:2] NoOp(“PJSIP/to_telefonica_primary-00001687”, “HANGUP CAUSE: 34”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/to_telefonica_primary-00001687”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:4] NoOp(“PJSIP/to_telefonica_primary-00001687”, “MASTER CHANNEL: 1612903307.12058 = 1612903307.12058”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:5] GotoIf(“PJSIP/to_telefonica_primary-00001687”, “0?return”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_telefonica_primary-00001687”, “__CRM_HANGUP=1”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:7] AGI(“PJSIP/to_telefonica_primary-00001687”, “sangomacrm.agi”) in new stack
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2021-02-09 21:41:49] VERBOSE[57589][C-00000b3b] res_agi.c: <PJSIP/to_telefonica_primary-00001687>AGI Script sangomacrm.agi completed, returning 0
[2021-02-09 21:41:49] VERBOSE[57589][C-00000b3b] pbx.c: Executing [[email protected]:8] Return(“PJSIP/to_telefonica_primary-00001687”, “”) in new stack
[2021-02-09 21:41:49] VERBOSE[57589][C-00000b3b] app_stack.c: Spawn extension (ext-trunk, tdial, 13) exited non-zero on ‘PJSIP/to_telefonica_primary-00001687’
[2021-02-09 21:41:49] VERBOSE[57589][C-00000b3b] app_stack.c: PJSIP/to_telefonica_primary-00001687 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2021-02-09 21:41:49] VERBOSE[54947] pbx_variables.c: Setting global variable ‘SIPDOMAIN’ to ‘192.168.222.3’
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_telefonica_primary-00001689”, “__DIRECTION=INBOUND”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] Gosub(“PJSIP/to_telefonica_primary-00001689”, “sub-record-check,s,1(in,+499119380003,dontcare)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “0?initialized”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001689”, “__REC_STATUS=INITIALIZED”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_telefonica_primary-00001689”, “NOW=1612903309”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:4] Set(“PJSIP/to_telefonica_primary-00001689”, “__DAY=09”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:5] Set(“PJSIP/to_telefonica_primary-00001689”, “__MONTH=02”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_telefonica_primary-00001689”, “__YEAR=2021”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:7] Set(“PJSIP/to_telefonica_primary-00001689”, “__TIMESTR=20210209-214149”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:8] Set(“PJSIP/to_telefonica_primary-00001689”, “__FROMEXTEN=unknown”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:9] Set(“PJSIP/to_telefonica_primary-00001689”, “__MON_FMT=wav”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:10] NoOp(“PJSIP/to_telefonica_primary-00001689”, “Recordings initialized”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:11] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “0?Set(ARG3=dontcare)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:12] Set(“PJSIP/to_telefonica_primary-00001689”, “REC_POLICY_MODE_SAVE=”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:13] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “0?Set(REC_STATUS=NO)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:14] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “2?checkaction”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:17] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “1?sub-record-check,in,1”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (sub-record-check,in,1)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_telefonica_primary-00001689”, “Inbound Recording Check to +499119380003”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001689”, “FROMEXTEN=unknown”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “14?Set(FROMEXTEN=00447969776426)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:4] Gosub(“PJSIP/to_telefonica_primary-00001689”, “recordcheck,1(dontcare,in,+499119380003)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_telefonica_primary-00001689”, “Starting recording check against dontcare”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] Goto(“PJSIP/to_telefonica_primary-00001689”, “dontcare”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] Return(“PJSIP/to_telefonica_primary-00001689”, “”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:5] Return(“PJSIP/to_telefonica_primary-00001689”, “”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_telefonica_primary-00001689”, “CHANNEL(tonezone)=us”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:4] Set(“PJSIP/to_telefonica_primary-00001689”, “__FROM_DID=+499119380003”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:5] Set(“PJSIP/to_telefonica_primary-00001689”, “returnhere=1”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:6] Gosub(“PJSIP/to_telefonica_primary-00001689”, “app-blacklist-check,s,1()”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “0?blacklisted”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001689”, “CALLED_BLACKLIST=1”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] Return(“PJSIP/to_telefonica_primary-00001689”, “”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:7] Set(“PJSIP/to_telefonica_primary-00001689”, “CDR(did)=+499119380003”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:8] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “0?”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:9] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “0 ?Set(CALLERID(name)=00447969776426)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:10] Set(“PJSIP/to_telefonica_primary-00001689”, “__MOHCLASS=”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:11] Set(“PJSIP/to_telefonica_primary-00001689”, “__REVERSAL_REJECT=FALSE”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:12] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “1?post-reverse-charge”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (from-pstn,+499119380003,14)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:14] NoOp(“PJSIP/to_telefonica_primary-00001689”, “”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:15] Set(“PJSIP/to_telefonica_primary-00001689”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:16] Set(“PJSIP/to_telefonica_primary-00001689”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:17] Set(“PJSIP/to_telefonica_primary-00001689”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:18] Set(“PJSIP/to_telefonica_primary-00001689”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:19] NoOp(“PJSIP/to_telefonica_primary-00001689”, “CallerID Entry Point”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:20] Set(“PJSIP/to_telefonica_primary-00001689”, “__CRM_DIRECTION=INBOUND”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:21] Set(“PJSIP/to_telefonica_primary-00001689”, “__CRM_SOURCE=00447969776426”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:22] Set(“PJSIP/to_telefonica_primary-00001689”, “__CRM_LINKEDID=1612903309.12060”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:23] AGI(“PJSIP/to_telefonica_primary-00001689”, “sangomacrm.agi,true”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] res_agi.c: <PJSIP/to_telefonica_primary-00001689>AGI Script sangomacrm.agi completed, returning 0
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:24] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:25] Goto(“PJSIP/to_telefonica_primary-00001689”, “ext-trunk,2,1”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (ext-trunk,2,1)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_telefonica_primary-00001689”, “[email protected]”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] Set(“PJSIP/to_telefonica_primary-00001689”, “TDIAL_STRING=PJSIP”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] Set(“PJSIP/to_telefonica_primary-00001689”, “DIAL_TRUNK=2”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:4] Goto(“PJSIP/to_telefonica_primary-00001689”, “ext-trunk,tdial,1”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (ext-trunk,tdial,1)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] Set(“PJSIP/to_telefonica_primary-00001689”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “1?nomax”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx_builtins.c: Goto (ext-trunk,tdial,4)
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:4] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “1?Set(CALLERPRES(name-pres)=allowed_not_screened)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:5] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “1?Set(CALLERPRES(num-pres)=allowed_not_screened)”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_telefonica_primary-00001689”, “DIAL_NUMBER=+499119380003”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:7] GosubIf(“PJSIP/to_telefonica_primary-00001689”, “0?sub-flp-2,s,1()”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:8] Set(“PJSIP/to_telefonica_primary-00001689”, “OUTNUM=+499119380003”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:9] Set(“PJSIP/to_telefonica_primary-00001689”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:10] Dial(“PJSIP/to_telefonica_primary-00001689”, “PJSIP/[email protected],300,T”) in new stack
[2021-02-09 21:41:49] VERBOSE[57644][C-00000b3c] app_dial.c: Called PJSIP/[email protected]
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] app_dial.c: PJSIP/fronerisbc-0000168a is ringing
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] app_dial.c: PJSIP/fronerisbc-0000168a is ringing
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] app_dial.c: Everyone is busy/congested at this time (1:0/1/0)
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:11] Set(“PJSIP/to_telefonica_primary-00001689”, “CALLERID(number)=00447969776426”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:12] Set(“PJSIP/to_telefonica_primary-00001689”, “CALLERID(name)=+447969776426”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:13] Hangup(“PJSIP/to_telefonica_primary-00001689”, “”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Spawn extension (ext-trunk, tdial, 13) exited non-zero on ‘PJSIP/to_telefonica_primary-00001689’
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] app_stack.c: PJSIP/to_telefonica_primary-00001689 Internal Gosub(crm-hangup,s,1) start
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:1] NoOp(“PJSIP/to_telefonica_primary-00001689”, “Sending Hangup to CRM”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:2] NoOp(“PJSIP/to_telefonica_primary-00001689”, “HANGUP CAUSE: 34”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:3] ExecIf(“PJSIP/to_telefonica_primary-00001689”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:4] NoOp(“PJSIP/to_telefonica_primary-00001689”, “MASTER CHANNEL: 1612903309.12060 = 1612903309.12060”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:5] GotoIf(“PJSIP/to_telefonica_primary-00001689”, “0?return”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:6] Set(“PJSIP/to_telefonica_primary-00001689”, “__CRM_HANGUP=1”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:7] AGI(“PJSIP/to_telefonica_primary-00001689”, “sangomacrm.agi”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] res_agi.c: <PJSIP/to_telefonica_primary-00001689>AGI Script sangomacrm.agi completed, returning 0
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] pbx.c: Executing [[email protected]:8] Return(“PJSIP/to_telefonica_primary-00001689”, “”) in new stack
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] app_stack.c: Spawn extension (ext-trunk, tdial, 13) exited non-zero on ‘PJSIP/to_telefonica_primary-00001689’
[2021-02-09 21:41:50] VERBOSE[57644][C-00000b3c] app_stack.c: PJSIP/to_telefonica_primary-00001689 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
^C
I see the busy message in the SIP trace from the SBC and the below in the second call whilst the first call is ongoing.
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: PJSIP/sbctrunk-00001688 is ringing
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: PJSIP/sbctrunk-00001688 is ringing
[2021-02-09 21:41:48] VERBOSE[57589][C-00000b3b] app_dial.c: Everyone is busy/congested at this time (1:0/1/0)
But the PBX does not send on the 486 message to our provider, instead it sends on the 503 message. I can send a full SIP trace if required to you personally?
Please share call traces and verbose logs using pastebin.
If I understand right you have the SBC set up as a trunk. Do you happen to have the SBC trunk configured with “Continue if Busy” set to yes?
Is the 486 expected in normal call flow? IMO, annoying a customer with a busy signal is not a good idea.
If his party is on the phone, depending on your business you might send the call to a receptionist, voicemail, or a queue where the caller can choose to wait, be called back, or leave a message.
If the 486 is caused by insufficient channels, etc., fix that.
To many attempts that result in a busy signal is inviting the customer to go to a competitor.
The SBC is setup as a trunk yep correct.
The SBC “Continue if Busy” is set to no
The SIP provider is setup to continue if busy - if it gets a busy tone, it auto tries to send out of the secondary SIP trunk instead.
I just tried to set the SIP provider Continue if Busy to no and it made no difference. The 503 is sent to provider, and for some reason, they continue to send the call in even when a 503 has been sent.
Bacause the call comes in that way, it just spams with INVITES and the caller continues hearing ringing - which isnt good because they think they are connecting to the callee even when the callee is busy.
We need the 486 because we will have the users as part of a queue. If we add all SBC extensions in the queue setup, in theory it will never follow onto the next agent with any ring strategy, it will just sit and continue to call the agent.
486 busy should be sent in cases where no failover destination such as voicemail is set IMO so in theory the busy should be sent because there is no failover destination
I think it’s a bug in the dialplan logic that is followed when you set Trunk as a destination target.
Normal trunk dialing logic (when trunks are used in outbound routes) is somewhat sophisticated and looks at the reason an outbound call failed. On failure it either goes back into the dialplan to try another trunk (Continue if Busy) or it responds back to the caller according to the reason given downstream. ([macro-dialout-trunk] from /etc/asterisk/extensions_additional.conf)
When you set Trunk as a destination target it uses another part of the dialplan called [ext-trunk] which is not sophisticated… in fact it might be incomplete. It issues a Dial command for the trunk and whatever the result, follows it with a plain Hangup (no reason considered).
I am guessing that issuing a Hangup on a channel that is still ringing and hasn’t been answered results in the 503 response.
You might be able to work around this bug with a different call flow. What is the purpose of the SBC? Do you have endpoints registered to it?
Cheers. No - no endpoints configured as such. The SBC is an Opensips SBC which forwards the call to a Teams user using Direct Routing.
So normal test:
PSTN --> Extension with fm/fm to Teams user --> SBC --> Teams user
To take out the complexity and get to the bottom of the issue, I have disabled fm/fm to understand why the busy isnt working.
I have also tried setting the destination to the extension with a UCP forward, but the same thing happens everytime.
Happy to try another call flow?
Cheers…
Can you expand on that a bit? Where do you have the Teams/SBC trunk selected as a target?
As an inbound route, we have tried:
Which of those three bullet points corresponds to the logs posted earlier? The second one (straight to the SBC SIP trunk) I believe?
