[Freeswitch-users] Routing calls to registered user.
Michael Jerris
mike at jerris.com
Thu Sep 21 17:51:32 UTC 2017
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> 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)
> 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
>
> 1 total.
>
>
> Any ideas?
> _________________________________________________________________________
> 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/a8eca8d6/attachment-0001.html>
More information about the FreeSWITCH-users
mailing list