Thanks for that Michael The specific point referred to wouldn’t help in my scenario as I have no xml directory to refer to. However reading that doc further I realised that in my use with users authenticated via Radius and not xml directory I needed to use <action application="bridge" data="sofia/internal/$1%"/> So I now have calls routing to registered endpoints!
On 21 Sep 2017, at 18:51, Michael Jerris <mike@jerris.com> wrote:
https://freeswitch.org/confluence/display/FREESWITCH/XML+User+Directory#XMLU... <https://freeswitch.org/confluence/display/FREESWITCH/XML+User+Directory#XMLUserDirectory-DialString>
On Sep 20, 2017, at 6:36 PM, Joseph Waite <joelists@tm.net.uk <mailto:joelists@tm.net.uk>> wrote:
Hi Guys
Knocking my head against this. I am trying to route calls to registered endpoints. But it is not working.
The log of the whole call is as follows
2017-09-20 23:31:49.230782 [NOTICE] switch_channel.c:1104 New Channel sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [a923b79f-e080-416c-934c-af13b570f813] 2017-09-20 23:31:49.230782 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_NEW (Cur 1 Tot 16430) 2017-09-20 23:31:49.230782 [DEBUG] sofia.c:9873 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> receiving invite from 185.8.92.3:5062 version: 1.6.19 git febfb38 2017-09-14 23:14:02Z 64bit 2017-09-20 23:31:49.270606 [DEBUG] sofia.c:7084 Channel sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> entering state [received][100] 2017-09-20 23:31:49.270606 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=FreeSWITCH 1505928870 1505928871 IN IP4 185.8.92.3 s=FreeSWITCH c=IN IP4 185.8.92.3 t=0 0 m=audio 17854 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20
2017-09-20 23:31:49.270606 [DEBUG] sofia.c:7486 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_NEW -> CS_INIT 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:603 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State NEW 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_INIT (Cur 1 Tot 16430) 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:627 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State INIT 2017-09-20 23:31:49.270606 [DEBUG] mod_sofia.c:90 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA INIT 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:40 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard INIT 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:48 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_INIT -> CS_ROUTING 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:627 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State INIT going to sleep 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_ROUTING (Cur 1 Tot 16430) 2017-09-20 23:31:49.270606 [DEBUG] switch_channel.c:2249 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Callstate Change DOWN -> RINGING 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:643 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State ROUTING 2017-09-20 23:31:49.270606 [DEBUG] mod_sofia.c:143 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA ROUTING 2017-09-20 23:31:49.270606 [ERR] mod_xml_radius.c:933 Result of true match: 185.35.229.6 == ^185\.35\.229\.30 2017-09-20 23:31:49.270606 [ERR] mod_xml_radius.c:930 Didn't match: inbound == ^outbound 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:236 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard ROUTING 2017-09-20 23:31:49.270606 [INFO] mod_dialplan_xml.c:637 Processing 07966677711 <07966677711>->443307881011 in context public Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [public->unloop] continue=false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [public->outside_call] continue=true Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Absolute Condition [outside_call] Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(outside_call=true) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [public->call_debug] continue=true Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [public->rejections] continue=false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [rejections] ${radius_auth_result}() =~ /2/ break=on-false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [public->timedouts] continue=false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [timedouts] ${radius_auth_result}() =~ /1/ break=on-false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [public->JeraSoft VCS Routing] continue=false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (PASS) [JeraSoft VCS Routing] destination_number(443307881011) =~ /^(.+)$/ break=on-false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action export(nolocal:h323-call-origin=originate) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(sip_h_X-accountcode=${accountcode}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(call_direction=outbound) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(hangup_after_bridge=true) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(continue_on_fail=true) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(inherit_codec=true) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(call_timeout=20) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(fail_on_single_reject=USER_BUSY) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(origination_caller_id_name=${sip_req_user}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(origination_caller_id_number=${sip_from_user}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(SRCGWIP=src-gw-ip=${network_addr}) INLINE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(SRCGWIP=src-gw-ip=185.8.92.3) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [SRCGWIP]=[src-gw-ip=185.8.92.3] Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(CALLID=h323-conf-id=${uuid}) INLINE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(CALLID=h323-conf-id=a923b79f-e080-416c-934c-af13b570f813) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [CALLID]=[h323-conf-id=a923b79f-e080-416c-934c-af13b570f813] Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(CALLINGNUMBER=${caller_id_number}) INLINE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(CALLINGNUMBER=07966677711) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [CALLINGNUMBER]=[07966677711] Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(CALLEDNUMBER=${destination_number}) INLINE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(CALLEDNUMBER=443307881011) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [CALLEDNUMBER]=[443307881011] Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action auth_function(in ${DIALED_NUMBER}, in ${USERNAME}, in ${PASSWD}, out AUTH_RESULT) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action export(credit_time=${credit_time}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action export(cisco_service_info=${cisco_service_info) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action export(sip_redirect_context=redirect) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action transfer(443307881011 XML ipauth) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action hangup(${bridge_hangup_cause}) 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:286 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_ROUTING -> CS_EXECUTE 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:643 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State ROUTING going to sleep 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_EXECUTE (Cur 1 Tot 16430) 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State EXECUTE 2017-09-20 23:31:49.270606 [DEBUG] mod_sofia.c:198 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA EXECUTE 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:328 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard EXECUTE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(outside_call=true) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [outside_call]=[true] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> export(RFC2822_DATE=Wed, 20 Sep 2017 23:31:49 +0100) 2017-09-20 23:31:49.270606 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 20 Sep 2017 23:31:49 +0100] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> export(nolocal:h323-call-origin=originate) 2017-09-20 23:31:49.270606 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [h323-call-origin]=[originate] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(sip_h_X-accountcode=) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [sip_h_X-accountcode]=[UNDEF] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(call_direction=outbound) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [call_direction]=[outbound] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(hangup_after_bridge=true) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [hangup_after_bridge]=[true] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(continue_on_fail=true) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [continue_on_fail]=[true] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(inherit_codec=true) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [inherit_codec]=[true] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(call_timeout=20) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [call_timeout]=[20] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(fail_on_single_reject=USER_BUSY) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [fail_on_single_reject]=[USER_BUSY] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(origination_caller_id_name=443307881011) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [origination_caller_id_name]=[443307881011] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(origination_caller_id_number=07966677711) 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [origination_caller_id_number]=[07966677711] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> auth_function(in , in 07966677711, in , out AUTH_RESULT) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:301 allocate initial structure. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:313 initialzed configuration. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set authserver := 185.35.229.30:1812:h4nn4h. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set dictionary := /usr/local/freeswitch/conf/dictionaries/dictionary. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set seqfile := /var/run/radius.seq. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set mapfile := /usr/local/etc/radiusclient/port-id-map. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set default_realm := . 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set radius_timeout := 3. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set radius_retries := 2. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set radius_deadtime := 0. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:318 set bindaddr := 185.35.229.6. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:371 ... radius: User-Name: 07966677711 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:380 ... radius: User-Password: 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:391 ... radius: Called-station-Id is empty, ignoring... 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:413 Handle attribute: h323-conf-id 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:439 ... dictionary data: id:24, vendor id:9, attr type:0, attr name:h323-conf-id (589848) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:444 ... radius: key:h323-conf-id, value:CALLID (h323-conf-id=a923b79f-e080-416c-934c-af13b570f813) as string 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:413 Handle attribute: Cisco-AVPair 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:439 ... dictionary data: id:1, vendor id:9, attr type:0, attr name:Cisco-AVPair (589825) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:444 ... radius: key:Cisco-AVPair, value:SRCGWIP (src-gw-ip=185.8.92.3) as string 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:413 Handle attribute: Cisco-AVPair 2017-09-20 23:31:49.270606 [ERR] mod_rad_auth.c:178 Undefined channel variable: SRCGWNAME. 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:439 ... dictionary data: id:1, vendor id:9, attr type:0, attr name:Cisco-AVPair (589825) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:444 ... radius: key:Cisco-AVPair, value:SRCGWNAME () as string 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:413 Handle attribute: Cisco-AVPair 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:439 ... dictionary data: id:1, vendor id:9, attr type:0, attr name:Cisco-AVPair (589825) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:444 ... radius: key:Cisco-AVPair, value:request-type=number (request-type=number) as string 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:413 Handle attribute: Calling-Station-Id 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:439 ... dictionary data: id:31, vendor id:0, attr type:0, attr name:Calling-Station-Id (31) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:444 ... radius: key:Calling-Station-Id, value:CALLINGNUMBER (07966677711) as string 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:413 Handle attribute: Called-Station-Id 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:439 ... dictionary data: id:30, vendor id:0, attr type:0, attr name:Called-Station-Id (30) 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:444 ... radius: key:Called-Station-Id, value:CALLEDNUMBER (443307881011) as string 2017-09-20 23:31:49.270606 [DEBUG] mod_rad_auth.c:491 sending radius packet ... 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:497 RADIUS Authentication OK 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:519 Handle attribute: CREDIT_TIME 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:522 attribute (CREDIT_TIME) found in radius packet 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:523 set variable credit_time := 7199 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:519 Handle attribute: CISCO_SERVICE_INFO 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:522 attribute (CISCO_SERVICE_INFO) found in radius packet 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:523 set variable cisco_service_info := 200 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:519 Handle attribute: RADIUS_RETURN_CODE 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:522 attribute (RADIUS_RETURN_CODE) found in radius packet 2017-09-20 23:31:49.290658 [DEBUG] mod_rad_auth.c:523 set variable return_code := 16 EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> export(credit_time=7199) 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [credit_time]=[7199] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> export(cisco_service_info=200) 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [cisco_service_info]=[200] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> export(sip_redirect_context=redirect) 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_redirect_context]=[redirect] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> transfer(443307881011 XML ipauth) 2017-09-20 23:31:49.290658 [DEBUG] switch_ivr.c:2165 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_EXECUTE -> CS_ROUTING 2017-09-20 23:31:49.290658 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> to XML[443307881011@ipauth] 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State EXECUTE going to sleep 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_ROUTING (Cur 1 Tot 16430) 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:643 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State ROUTING 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:143 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA ROUTING 2017-09-20 23:31:49.290658 [ERR] mod_xml_radius.c:933 Result of true match: 185.35.229.6 == ^185\.35\.229\.30 2017-09-20 23:31:49.290658 [ERR] mod_xml_radius.c:930 Didn't match: inbound == ^outbound 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:236 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard ROUTING 2017-09-20 23:31:49.290658 [INFO] mod_dialplan_xml.c:637 Processing 07966677711 <07966677711>->443307881011 in context ipauth Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [ipauth->Auth Calls] continue=false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (PASS) [Auth Calls] ${cisco_service_info}(200) =~ /^200$/ break=never Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(execute_on_answer=sched_hangup +${credit_time} alloted_timeout) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action bridge({sip_invite_from_uri=sip:${sip_from_user}@${sip_network_ip}}sofia/external/${destination_number}@185.35.229.30:5060 <sip:${sip_from_user}@${sip_network_ip}}sofia/external/${destination_number}@185.35.229.30:5060>) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action hangup(${bridge_hangup_cause}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [Auth Calls] ${cisco_service_info}(200) =~ /^101$/ break=on-true Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [Auth Calls] ${cisco_service_info}(200) =~ /^221$/ break=on-true Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (FAIL) [Auth Calls] ${cisco_service_info}(200) =~ /^201$/ break=on-true Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Absolute Condition [Auth Calls] Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action log(INFO Were in the IPauth Context!!) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action log(INFO credit_time=${credit_time}) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action log(INFO cisco_service_info=${cisco_service_info}) 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:286 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_ROUTING -> CS_EXECUTE 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:643 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State ROUTING going to sleep 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_EXECUTE (Cur 1 Tot 16430) 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State EXECUTE 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:198 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA EXECUTE 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:328 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard EXECUTE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(execute_on_answer=sched_hangup +7199 alloted_timeout) 2017-09-20 23:31:49.290658 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [execute_on_answer]=[sched_hangup +7199 alloted_timeout] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> bridge({sip_invite_from_uri=sip:07966677711@185.8.92.3 <mailto:07966677711@185.8.92.3>}sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 20 Sep 2017 23:31:49 +0100] to event 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [h323-call-origin]=[originate] to event 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [credit_time]=[7199] to event 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [cisco_service_info]=[200] to event 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [sip_redirect_context]=[redirect] to event 2017-09-20 23:31:49.290658 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-09-20 23:31:49.290658 [NOTICE] switch_channel.c:1104 New Channel sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 [848843db-cad9-48a8-a4bd-2ac6b6b77dff] 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:4819 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State Change CS_NEW -> CS_INIT 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:584 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Running State Change CS_INIT (Cur 2 Tot 16431) 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:627 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State INIT 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:90 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 SOFIA INIT 2017-09-20 23:31:49.290658 [DEBUG] sofia_glue.c:1295 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 sending invite version: 1.6.19 git febfb38 2017-09-14 23:14:02Z 64bit Local SDP: v=0 o=FreeSWITCH 1505929783 1505929784 IN IP4 185.35.229.6 s=FreeSWITCH c=IN IP4 185.35.229.6 t=0 0 m=audio 16926 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv
2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:40 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 Standard INIT 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:48 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State Change CS_INIT -> CS_ROUTING 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:627 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State INIT going to sleep 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:584 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Running State Change CS_ROUTING (Cur 2 Tot 16431) 2017-09-20 23:31:49.290658 [DEBUG] sofia.c:7084 Channel sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 entering state [calling][0] 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:643 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State ROUTING 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:143 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 SOFIA ROUTING 2017-09-20 23:31:49.290658 [DEBUG] switch_ivr_originate.c:67 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2017-09-20 23:31:49.290658 [ERR] mod_xml_radius.c:930 Didn't match: 185.35.229.30:5060 == ^185\.35\.229\.30 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:643 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State ROUTING going to sleep 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:584 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 16431) 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:662 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State CONSUME_MEDIA 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:662 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State CONSUME_MEDIA going to sleep 2017-09-20 23:31:49.350696 [DEBUG] sofia.c:6540 Redirect: Transfering to joehouse XML redirect 2017-09-20 23:31:49.350696 [DEBUG] switch_ivr.c:2165 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_EXECUTE -> CS_ROUTING 2017-09-20 23:31:49.350696 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> to XML[joehouse@redirect] 2017-09-20 23:31:49.350696 [NOTICE] sofia.c:6549 Hangup sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 [CS_CONSUME_MEDIA] [REDIRECTION_TO_NEW_DESTINATION] 2017-09-20 23:31:49.350696 [DEBUG] sofia.c:1453 Channel is already hungup. 2017-09-20 23:31:49.350696 [DEBUG] sofia.c:1453 Channel is already hungup. 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:584 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Running State Change CS_HANGUP (Cur 2 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:850 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Callstate Change DOWN -> HANGUP 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:852 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State HANGUP 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:438 Channel sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 hanging up, cause: REDIRECTION_TO_NEW_DESTINATION 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:60 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 Standard HANGUP, cause: REDIRECTION_TO_NEW_DESTINATION 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:852 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State HANGUP going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:619 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State Change CS_HANGUP -> CS_REPORTING 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:584 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Running State Change CS_REPORTING (Cur 2 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:938 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State REPORTING 2017-09-20 23:31:49.350696 [ERR] mod_xml_radius.c:930 Didn't match: 185.35.229.30:5060 == ^185\.35\.229\.30 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:174 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 Standard REPORTING, cause: REDIRECTION_TO_NEW_DESTINATION 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:938 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State REPORTING going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:610 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State Change CS_REPORTING -> CS_DESTROY 2017-09-20 23:31:49.350696 [DEBUG] switch_core_session.c:1665 Session 16431 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Locked, Waiting on external entities 2017-09-20 23:31:49.350696 [DEBUG] switch_ivr_originate.c:3837 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2017-09-20 23:31:49.350696 [NOTICE] switch_core_session.c:1683 Session 16431 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Ended 2017-09-20 23:31:49.350696 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 [CS_DESTROY] 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:741 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) Running State Change CS_DESTROY (Cur 1 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:751 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State DESTROY 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:343 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 SOFIA DESTROY 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:181 sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060 Standard DESTROY 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:751 (sofia/external/443307881011@185.35.229.30 <mailto:sofia/external/443307881011@185.35.229.30>:5060) State DESTROY going to sleep 2017-09-20 23:31:49.350696 [INFO] mod_dptools.c:3436 Originate Failed. Cause: ORIGINATOR_CANCEL 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State EXECUTE going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_ROUTING (Cur 1 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:643 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State ROUTING 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:143 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA ROUTING 2017-09-20 23:31:49.350696 [ERR] mod_xml_radius.c:933 Result of true match: 185.35.229.6 == ^185\.35\.229\.30 2017-09-20 23:31:49.350696 [ERR] mod_xml_radius.c:930 Didn't match: inbound == ^outbound 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:236 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard ROUTING 2017-09-20 23:31:49.350696 [INFO] mod_dialplan_xml.c:637 Processing 07966677711 <07966677711>->joehouse in context redirect Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> parsing [redirect->Redirect Calls] continue=false Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Regex (PASS) [Redirect Calls] ${sip_redirect_contact_0}(<sip:joehouse@185.35.229.6 <sip:joehouse@185.35.229.6>>;src_number=07966677711;q=1.00) =~ /^<sip:(.+)\@185.35.229.6(.+)$/ break=on-true Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(process_cdr=true) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action log(ALERT Local User) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action set(accountcode=jerasoftoutbound) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action log(ALERT joehouse) Dialplan: sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Action bridge(user/joehouse@sip.biznetuk.com <mailto:user/joehouse@sip.biznetuk.com>) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:286 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_ROUTING -> CS_EXECUTE 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:643 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State ROUTING going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_EXECUTE (Cur 1 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State EXECUTE 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:198 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA EXECUTE 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:328 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard EXECUTE EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(process_cdr=true) 2017-09-20 23:31:49.350696 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [process_cdr]=[true] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> log(ALERT Local User) 2017-09-20 23:31:49.350696 [ALERT] mod_dptools.c:1742 Local User EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> set(accountcode=jerasoftoutbound) 2017-09-20 23:31:49.350696 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [accountcode]=[jerasoftoutbound] EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> log(ALERT joehouse) 2017-09-20 23:31:49.350696 [ALERT] mod_dptools.c:1742 joehouse EXECUTE sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> bridge(user/joehouse@sip.biznetuk.com <mailto:user/joehouse@sip.biznetuk.com>) 2017-09-20 23:31:49.350696 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 20 Sep 2017 23:31:49 +0100] to event 2017-09-20 23:31:49.350696 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [h323-call-origin]=[originate] to event 2017-09-20 23:31:49.350696 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [credit_time]=[7199] to event 2017-09-20 23:31:49.350696 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [cisco_service_info]=[200] to event 2017-09-20 23:31:49.350696 [DEBUG] switch_channel.c:1250 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> EXPORTING[export_vars] [sip_redirect_context]=[redirect] to event 2017-09-20 23:31:49.350696 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-09-20 23:31:49.350696 [WARNING] mod_dptools.c:4184 Can't find user [joehouse@sip.biznetuk.com <mailto:joehouse@sip.biznetuk.com>] 2017-09-20 23:31:49.350696 [NOTICE] switch_ivr_originate.c:2851 Cannot create outgoing channel of type [user] cause: [SUBSCRIBER_ABSENT] 2017-09-20 23:31:49.350696 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 20 [SUBSCRIBER_ABSENT] 2017-09-20 23:31:49.350696 [INFO] mod_dptools.c:3436 Originate Failed. Cause: SUBSCRIBER_ABSENT 2017-09-20 23:31:49.350696 [NOTICE] switch_core_state_machine.c:385 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> has executed the last dialplan instruction, hanging up. 2017-09-20 23:31:49.350696 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [CS_EXECUTE] [NORMAL_CLEARING] 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State EXECUTE going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_HANGUP (Cur 1 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:850 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Callstate Change RINGING -> HANGUP 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:852 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State HANGUP 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:438 Channel sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> hanging up, cause: NORMAL_CLEARING 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:60 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard HANGUP, cause: NORMAL_CLEARING 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:852 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State HANGUP going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:619 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_HANGUP -> CS_REPORTING 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_REPORTING (Cur 1 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:938 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State REPORTING 2017-09-20 23:31:49.350696 [ERR] mod_xml_radius.c:933 Result of true match: 185.35.229.6 == ^185\.35\.229\.30 2017-09-20 23:31:49.350696 [ERR] mod_xml_radius.c:930 Didn't match: inbound == ^outbound 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:174 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard REPORTING, cause: NORMAL_CLEARING 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:938 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State REPORTING going to sleep 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:610 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State Change CS_REPORTING -> CS_DESTROY 2017-09-20 23:31:49.350696 [DEBUG] switch_core_session.c:1665 Session 16430 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Locked, Waiting on external entities 2017-09-20 23:31:49.350696 [NOTICE] switch_core_session.c:1683 Session 16430 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Ended 2017-09-20 23:31:49.350696 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> [CS_DESTROY] 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:741 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) Running State Change CS_DESTROY (Cur 0 Tot 16431) 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:751 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State DESTROY 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:343 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> SOFIA DESTROY 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:181 sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3> Standard DESTROY 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:751 (sofia/external/07966677711@185.8.92.3 <mailto:sofia/external/07966677711@185.8.92.3>) State DESTROY going to sleep
its saying there is no endpoint registered yet the output of show registrations shows there is
freeswitch@BiznetukSBC1> show registrations reg_user,realm,token,url,expires,network_ip,network_port,network_proto,hostname,metadata,registration_uuid joehouse,sip.biznetuk.com <http://sip.biznetuk.com/>,1030250472@192_168_1_101,sofia/internal/sip:joehouse@185.35.230.2:5382,1505947110,185.35.230.2,5382,udp,BiznetukSBC1,,60484000-aa2d-4b21-9d58-11e7d4155f1e <sip:joehouse@185.35.230.2:5382,1505947110,185.35.230.2,5382,udp,BiznetukSBC1,,60484000-aa2d-4b21-9d58-11e7d4155f1e>
1 total.
Any ideas? _________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org <mailto:consulting@freeswitch.org> http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org