[Freeswitch-users] Routing calls to registered user.

Joseph Waite joelists at tm.net.uk
Thu Sep 21 19:18:18 UTC 2017


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 at jerris.com> wrote:
> 
> https://freeswitch.org/confluence/display/FREESWITCH/XML+User+Directory#XMLUserDirectory-DialString <https://freeswitch.org/confluence/display/FREESWITCH/XML+User+Directory#XMLUserDirectory-DialString>
> 
>> On Sep 20, 2017, at 6:36 PM, Joseph Waite <joelists at tm.net.uk <mailto:joelists at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State NEW
>> 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:584 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State INIT
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_sofia.c:90 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> SOFIA INIT
>> 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:40 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Standard INIT
>> 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:48 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State ROUTING
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_sofia.c:143 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [public->unloop] continue=false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [public->outside_call] continue=true
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Absolute Condition [outside_call]
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(outside_call=true) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [public->call_debug] continue=true
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [public->rejections] continue=false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [rejections] ${radius_auth_result}() =~ /2/ break=on-false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [public->timedouts] continue=false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [timedouts] ${radius_auth_result}() =~ /1/ break=on-false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [public->JeraSoft VCS Routing] continue=false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (PASS) [JeraSoft VCS Routing] destination_number(443307881011) =~ /^(.+)$/ break=on-false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action export(nolocal:h323-call-origin=originate) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(sip_h_X-accountcode=${accountcode}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(call_direction=outbound) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(hangup_after_bridge=true) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(continue_on_fail=true) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(inherit_codec=true) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(call_timeout=20) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(fail_on_single_reject=USER_BUSY) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(origination_caller_id_name=${sip_req_user}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(origination_caller_id_number=${sip_from_user}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(SRCGWIP=src-gw-ip=${network_addr}) INLINE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [SRCGWIP]=[src-gw-ip=185.8.92.3]
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(CALLID=h323-conf-id=${uuid}) INLINE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [CALLID]=[h323-conf-id=a923b79f-e080-416c-934c-af13b570f813]
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(CALLINGNUMBER=${caller_id_number}) INLINE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(CALLINGNUMBER=07966677711)
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [CALLINGNUMBER]=[07966677711]
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(CALLEDNUMBER=${destination_number}) INLINE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(CALLEDNUMBER=443307881011)
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [CALLEDNUMBER]=[443307881011]
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action auth_function(in ${DIALED_NUMBER}, in ${USERNAME}, in ${PASSWD}, out AUTH_RESULT) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action export(credit_time=${credit_time}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action export(cisco_service_info=${cisco_service_info) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action export(sip_redirect_context=redirect) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action transfer(443307881011 XML ipauth) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State EXECUTE
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_sofia.c:198 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> SOFIA EXECUTE
>> 2017-09-20 23:31:49.270606 [DEBUG] switch_core_state_machine.c:328 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Standard EXECUTE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(outside_call=true)
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [outside_call]=[true]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [sip_h_X-accountcode]=[UNDEF]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(call_direction=outbound)
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [call_direction]=[outbound]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [hangup_after_bridge]=[true]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [continue_on_fail]=[true]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(inherit_codec=true)
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [inherit_codec]=[true]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(call_timeout=20)
>> 2017-09-20 23:31:49.270606 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [call_timeout]=[20]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [fail_on_single_reject]=[USER_BUSY]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [origination_caller_id_name]=[443307881011]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [origination_caller_id_number]=[07966677711]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> transfer(443307881011 XML ipauth)
>> 2017-09-20 23:31:49.290658 [DEBUG] switch_ivr.c:2165 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> to XML[443307881011 at ipauth]
>> 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:650 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State ROUTING
>> 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:143 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [ipauth->Auth Calls] continue=false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (PASS) [Auth Calls] ${cisco_service_info}(200) =~ /^200$/ break=never
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(execute_on_answer=sched_hangup +${credit_time} alloted_timeout) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action hangup(${bridge_hangup_cause}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [Auth Calls] ${cisco_service_info}(200) =~ /^101$/ break=on-true
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [Auth Calls] ${cisco_service_info}(200) =~ /^221$/ break=on-true
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (FAIL) [Auth Calls] ${cisco_service_info}(200) =~ /^201$/ break=on-true
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Absolute Condition [Auth Calls]
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action log(INFO  Were in the IPauth Context!!) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action log(INFO  credit_time=${credit_time}) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State EXECUTE
>> 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:198 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> SOFIA EXECUTE
>> 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:328 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Standard EXECUTE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [execute_on_answer]=[sched_hangup +7199 alloted_timeout]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> bridge({sip_invite_from_uri=sip:07966677711 at 185.8.92.3 <mailto:07966677711 at 185.8.92.3>}sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060)
>> 2017-09-20 23:31:49.290658 [DEBUG] switch_channel.c:1250 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060) State INIT
>> 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:90 sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060 SOFIA INIT
>> 2017-09-20 23:31:49.290658 [DEBUG] sofia_glue.c:1295 sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060 Standard INIT
>> 2017-09-20 23:31:49.290658 [DEBUG] switch_core_state_machine.c:48 (sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060) State ROUTING
>> 2017-09-20 23:31:49.290658 [DEBUG] mod_sofia.c:143 sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060 SOFIA ROUTING
>> 2017-09-20 23:31:49.290658 [DEBUG] switch_ivr_originate.c:67 (sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> to XML[joehouse at redirect]
>> 2017-09-20 23:31:49.350696 [NOTICE] sofia.c:6549 Hangup sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060) State HANGUP
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:438 Channel sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:60 sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060) Ended
>> 2017-09-20 23:31:49.350696 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060 [CS_DESTROY]
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:741 (sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060) State DESTROY
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:343 sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060 SOFIA DESTROY
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:181 sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 185.35.229.30>:5060 Standard DESTROY
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:751 (sofia/external/443307881011 at 185.35.229.30 <mailto:sofia/external/443307881011 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State ROUTING
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:143 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> parsing [redirect->Redirect Calls] continue=false
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Regex (PASS) [Redirect Calls] ${sip_redirect_contact_0}(<sip:joehouse at 185.35.229.6 <sip:joehouse at 185.35.229.6>>;src_number=07966677711;q=1.00) =~ /^<sip:(.+)\@185.35.229.6(.+)$/ break=on-true
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(process_cdr=true) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action log(ALERT Local User) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action set(accountcode=jerasoftoutbound) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action log(ALERT joehouse) 
>> Dialplan: sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Action bridge(user/joehouse at sip.biznetuk.com <mailto:user/joehouse at sip.biznetuk.com>) 
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:286 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State EXECUTE
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:198 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> SOFIA EXECUTE
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:328 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Standard EXECUTE
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(process_cdr=true)
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [process_cdr]=[true]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> set(accountcode=jerasoftoutbound)
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_dptools.c:1548 SET sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [accountcode]=[jerasoftoutbound]
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> log(ALERT joehouse)
>> 2017-09-20 23:31:49.350696 [ALERT] mod_dptools.c:1742 joehouse
>> EXECUTE sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> bridge(user/joehouse at sip.biznetuk.com <mailto:user/joehouse at sip.biznetuk.com>)
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_channel.c:1250 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at sip.biznetuk.com <mailto:joehouse at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State HANGUP
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:438 Channel sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) Ended
>> 2017-09-20 23:31:49.350696 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> [CS_DESTROY]
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:741 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3>) State DESTROY
>> 2017-09-20 23:31:49.350696 [DEBUG] mod_sofia.c:343 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> SOFIA DESTROY
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:181 sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 185.8.92.3> Standard DESTROY
>> 2017-09-20 23:31:49.350696 [DEBUG] switch_core_state_machine.c:751 (sofia/external/07966677711 at 185.8.92.3 <mailto:sofia/external/07966677711 at 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 at 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 at 192_168_1_101,sofia/internal/sip:joehouse at 185.35.230.2:5382,1505947110,185.35.230.2,5382,udp,BiznetukSBC1,,60484000-aa2d-4b21-9d58-11e7d4155f1e <sip:joehouse at 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 at freeswitch.org <mailto:consulting at 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 at 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 at 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 at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20170921/23797223/attachment-0001.html>


More information about the FreeSWITCH-users mailing list