2018-07-27 17:23:39.433640 [NOTICE] switch_channel.c:1104 New Channel sofia/default/7120041412@phone.c2a.com.au [f5ec8f6c-1155-481b-8cfe-1d29dc6631ee] 2018-07-27 17:23:39.433640 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7120041412@phone.c2a.com.au) Running State Change CS_NEW (Cur 9 Tot 970429) 2018-07-27 17:23:39.433640 [DEBUG] sofia.c:9873 sofia/default/7120041412@phone.c2a.com.au receiving invite from 103.239.77.180:1491 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit 2018-07-27 17:23:39.433640 [DEBUG] sofia.c:10044 IP 103.239.77.180 Rejected by acl "default". Falling back to Digest auth. 2018-07-27 17:23:39.433640 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [1300368909@phone.c2a.com.au] from ip 103.239.77.180 2018-07-27 17:23:39.433640 [DEBUG] switch_core_state_machine.c:603 (sofia/default/7120041412@phone.c2a.com.au) State NEW 2018-07-27 17:23:39.433640 [DEBUG] sofia.c:2334 detaching session f5ec8f6c-1155-481b-8cfe-1d29dc6631ee 2018-07-27 17:23:39.453618 [DEBUG] sofia.c:2442 Re-attaching to session f5ec8f6c-1155-481b-8cfe-1d29dc6631ee 2018-07-27 17:23:39.473617 [DEBUG] sofia.c:9873 sofia/default/7120041412@phone.c2a.com.au receiving invite from 103.239.77.180:1491 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit 2018-07-27 17:23:39.473617 [DEBUG] sofia.c:10044 IP 103.239.77.180 Rejected by acl "default". Falling back to Digest auth. 2018-07-27 17:23:39.473617 [DEBUG] sofia.c:11168 Setting NAT mode based on via received 2018-07-27 17:23:39.473617 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [received][100] 2018-07-27 17:23:39.473617 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=7120041412 8000 8000 IN IP4 192.168.10.192 s=SIP Call c=IN IP4 192.168.10.192 t=0 0 m=audio 5004 RTP/AVP 0 8 4 18 2 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 2018-07-27 17:23:39.473617 [DEBUG] sofia.c:7480 (sofia/default/7120041412@phone.c2a.com.au) State Change CS_NEW -> CS_INIT 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7120041412@phone.c2a.com.au) Running State Change CS_INIT (Cur 9 Tot 970429) 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7120041412@phone.c2a.com.au) State INIT 2018-07-27 17:23:39.473617 [DEBUG] mod_sofia.c:90 sofia/default/7120041412@phone.c2a.com.au SOFIA INIT 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:40 sofia/default/7120041412@phone.c2a.com.au Standard INIT 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:48 (sofia/default/7120041412@phone.c2a.com.au) State Change CS_INIT -> CS_ROUTING 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7120041412@phone.c2a.com.au) State INIT going to sleep 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7120041412@phone.c2a.com.au) Running State Change CS_ROUTING (Cur 9 Tot 970429) 2018-07-27 17:23:39.473617 [DEBUG] switch_channel.c:2249 (sofia/default/7120041412@phone.c2a.com.au) Callstate Change DOWN -> RINGING 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7120041412@phone.c2a.com.au) State ROUTING 2018-07-27 17:23:39.473617 [DEBUG] mod_sofia.c:143 sofia/default/7120041412@phone.c2a.com.au SOFIA ROUTING 2018-07-27 17:23:39.473617 [DEBUG] switch_core_state_machine.c:236 sofia/default/7120041412@phone.c2a.com.au Standard ROUTING 2018-07-27 17:23:39.473617 [INFO] mod_dialplan_xml.c:637 Processing 7120041412 <7120041412>->1300368909 in context default 2018-07-27 17:23:39.493630 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fae38b91ff0 Connected. 2018-07-27 17:23:39.493630 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard') 2018-07-27 17:23:39.493630 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [xml_handler] Params: 'Event-Name: REQUEST_PARAMS Core-UUID: 2715576f-0c4c-4efc-8e55-f1fc5da2dfd8 FreeSWITCH-Hostname: primary FreeSWITCH-Switchname: primary FreeSWITCH-IPv4: 103.226.53.20 FreeSWITCH-IPv6: %3A%3A1 Event-Date-Local: 2018-07-27%2017%3A23%3A39 Event-Date-GMT: Fri,%2027%20Jul%202018%2007%3A23%3A39%20GMT Event-Date-Timestamp: 1532676219473617 Event-Calling-File: mod_dialplan_xml.c Event-Calling-Function: dialplan_xml_locate Event-Calling-Line-Number: 608 Event-Sequence: 59862398 Channel-State: CS_ROUTING Channel-Call-State: RINGING Channel-State-Number: 2 Channel-Name: sofia/default/7120041412%40phone.c2a.com.au Unique-ID: f5ec8f6c-1155-481b-8cfe-1d29dc6631ee Call-Direction: inbound Presence-Call-Direction: inbound Channel-HIT-Dialplan: true Channel-Presence-ID: 7120041412%40phone.c2a.com.au Channel-Call-UUID: f5ec8f6c-1155-481b-8cfe-1d29dc6631ee Answer-State: ringing Caller-Direction: inbound Caller-Logical-Direction: inbound Caller-Username: 7120041412 Caller-Dialplan: XML Caller-Caller-ID-Name: 7120041412 Caller-Caller-ID-Number: 7120041412 Caller-Orig-Caller-ID-Name: 7120041412 Caller-Orig-Caller-ID-Number: 7120041412 Caller-Network-Addr: 103.239.77.180 Caller-ANI: 7120041412 Caller-Destination-Number: 1300368909 Caller-Unique-ID: f5ec8f6c-1155-481b-8cfe-1d29dc6631ee Caller-Source: mod_sofia Caller-Context: default Caller-Channel-Name: sofia/default/7120041412%40phone.c2a.com.au Caller-Profile-Index: 1 Caller-Profile-Created-Time: 1532676219473617 Caller-Channel-Created-Time: 1532676219473617 Caller-Channel-Answered-Time: 0 Caller-Channel-Progress-Time: 0 Caller-Channel-Progress-Media-Time: 0 Caller-Channel-Hangup-Time: 0 Caller-Channel-Transfer-Time: 0 Caller-Channel-Resurrect-Time: 0 Caller-Channel-Bridged-Time: 0 Caller-Channel-Last-Hold: 0 Caller-Channel-Hold-Accum: 0 Caller-Screen-Bit: true Caller-Privacy-Hide-Name: false Caller-Privacy-Hide-Number: false variable_direction: inbound variable_uuid: f5ec8f6c-1155-481b-8cfe-1d29dc6631ee variable_session_id: 970429 variable_sip_from_user: 7120041412 variable_sip_from_uri: 7120041412%40phone.c2a.com.au variable_sip_from_host: phone.c2a.com.au variable_video_media_flow: sendrecv variable_audio_media_flow: sendrecv variable_channel_name: sofia/default/7120041412%40phone.c2a.com.au variable_sip_call_id: 1288767206-5060-6%40BJC.BGI.BA.BJC variable_ep_codec_string: CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b,mod_g729.G729%408000h%4020i%408000b variable_sip_local_network_addr: 103.226.53.19 variable_sip_network_ip: 103.239.77.180 variable_sip_network_port: 1491 variable_sip_invite_stamp: 1532676219473617 variable_sip_received_ip: 103.239.77.180 variable_sip_received_port: 1491 variable_sip_via_protocol: udp variable_sip_authorized: true variable_Event-Name: REQUEST_PARAMS variable_Core-UUID: 2715576f-0c4c-4efc-8e55-f1fc5da2dfd8 variable_FreeSWITCH-Hostname: primary variable_FreeSWITCH-Switchname: primary variable_FreeSWITCH-IPv4: 103.226.53.20 variable_FreeSWITCH-IPv6: %3A%3A1 variable_Event-Date-Local: 2018-07-27%2017%3A23%3A39 variable_Event-Date-GMT: Fri,%2027%20Jul%202018%2007%3A23%3A39%20GMT variable_Event-Date-Timestamp: 1532676219473617 variable_Event-Calling-File: sofia.c variable_Event-Calling-Function: sofia_handle_sip_i_invite variable_Event-Calling-Line-Number: 10096 variable_Event-Sequence: 59862391 variable_sip_number_alias: 7120041412 variable_sip_auth_username: 7120041412 variable_sip_auth_realm: phone.c2a.com.au variable_number_alias: 7120041412 variable_requested_user_name: 7120041412 variable_requested_domain_name: 103.226.53.20 variable_effective_caller_id_name: 0265162229 variable_effective_caller_id_number: 0265162229 variable_sipcall: true variable_accountcode: 98055562 variable_user_name: 7120041412 variable_domain_name: 103.226.53.20 variable_sip_from_user_stripped: 7120041412 variable_sip_from_tag: 760539825 variable_sofia_profile_name: default variable_recovery_profile_name: default variable_sip_P-Preferred-Identity: %3Csip%3A7120041412%40phone.c2a.com.au%3E variable_sip_cid_type: pid variable_sip_full_route: %3Csip%3Aphone.c2a.com.au%3A5060%3Blr%3E variable_sip_full_via: SIP/2.0/UDP%20192.168.10.192%3A5060%3Bbranch%3Dz9hG4bK673446469%3Brport%3D1491%3Breceived%3D103.239.77.180 variable_sip_full_from: %3Csip%3A7120041412%40phone.c2a.com.au%3E%3Btag%3D760539825 variable_sip_full_to: %3Csip%3A1300368909%40phone.c2a.com.au%3E variable_sip_allow: INVITE,%20ACK,%20OPTIONS,%20CANCEL,%20BYE,%20SUBSCRIBE,%20NOTIFY,%20INFO,%20REFER,%20UPDATE variable_sip_req_user: 1300368909 variable_sip_req_uri: 1300368909%40phone.c2a.com.au variable_sip_req_host: phone.c2a.com.au variable_sip_to_user: 1300368909 variable_sip_to_uri: 1300368909%40phone.c2a.com.au variable_sip_to_host: phone.c2a.com.au variable_sip_contact_user: 7120041412 variable_sip_contact_port: 5060 variable_sip_contact_uri: 7120041412%40192.168.10.192%3A5060 variable_sip_contact_host: 192.168.10.192 variable_rtp_use_codec_string: PCMA,PCMU,G729,G722 variable_sip_user_agent: Grandstream%20HT701%201.0.10.3 variable_sip_via_host: 192.168.10.192 variable_sip_via_port: 5060 variable_sip_via_rport: 1491 variable_max_forwards: 70 variable_presence_id: 7120041412%40phone.c2a.com.au variable_sip_Privacy: none variable_sip_nat_detected: true variable_switch_r_sdp: v%3D0%0D%0Ao%3D7120041412%208000%208000%20IN%20IP4%20192.168.10.192%0D%0As%3DSIP%20Call%0D%0Ac%3DIN%20IP4%20192.168.10.192%0D%0At%3D0%200%0D%0Am%3Daudio%205004%20RTP/AVP%200%208%204%2018%202%2097%20101%0D%0Aa%3Drtpmap%3A0%20PCMU/8000%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A4%20G723/8000%0D%0Aa%3Drtpmap%3A18%20G729/8000%0D%0Aa%3Dfmtp%3A18%20annexb%3Dno%0D%0Aa%3Drtpmap%3A2%20G726-32/8000%0D%0Aa%3Drtpmap%3A97%20iLBC/8000%0D%0Aa%3Dfmtp%3A97%20mode%3D20%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-16,32-36,54%0D%0Aa%3Dptime%3A20%0D%0A variable_endpoint_disposition: PROXY%20MEDIA variable_call_uuid: f5ec8f6c-1155-481b-8cfe-1d29dc6631ee Hunt-Direction: inbound Hunt-Logical-Direction: inbound Hunt-Username: 7120041412 Hunt-Dialplan: XML Hunt-Caller-ID-Name: 7120041412 Hunt-Caller-ID-Number: 7120041412 Hunt-Orig-Caller-ID-Name: 7120041412 Hunt-Orig-Caller-ID-Number: 7120041412 Hunt-Network-Addr: 103.239.77.180 Hunt-ANI: 7120041412 Hunt-Destination-Number: 1300368909 Hunt-Unique-ID: f5ec8f6c-1155-481b-8cfe-1d29dc6631ee Hunt-Source: mod_sofia Hunt-Context: default Hunt-Channel-Name: sofia/default/7120041412%40phone.c2a.com.au Hunt-Profile-Index: 1 Hunt-Profile-Created-Time: 1532676219473617 Hunt-Channel-Created-Time: 1532676219473617 Hunt-Channel-Answered-Time: 0 Hunt-Channel-Progress-Time: 0 Hunt-Channel-Progress-Media-Time: 0 Hunt-Channel-Hangup-Time: 0 Hunt-Channel-Transfer-Time: 0 Hunt-Channel-Resurrect-Time: 0 Hunt-Channel-Bridged-Time: 0 Hunt-Channel-Last-Hold: 0 Hunt-Channel-Hold-Accum: 0 Hunt-Screen-Bit: true Hunt-Privacy-Hide-Name: false Hunt-Privacy-Hide-Number: false ' 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_value: 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_name: 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] tag_name: 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] section: dialplan 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 1300368909 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number : / 2018-07-27 17:23:39.493630 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.always,A.always_destination,A.always_vm_flag,A.user_busy_vm_flag,A.user_not_registered_vm_flag,A.no_answer_vm_flag,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="1300368909" LIMIT 1 2018-07-27 17:23:39.493630 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="1300368909" limit 1 2018-07-27 17:23:39.493630 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : outbound 2018-07-27 17:23:39.493630 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 98055562] 2018-07-27 17:23:39.493630 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "98055562" OR id="98055562") AND status=0 AND deleted=0 AND (expiry >= '2018-07-27 07:23:39' OR expiry = '0000-00-00 00:00:00') limit 1 2018-07-27 17:23:39.513610 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns ='^1300368909.*' OR blocked_patterns ='^130036890.*' OR blocked_patterns ='^13003689.*' OR blocked_patterns ='^1300368.*' OR blocked_patterns ='^130036.*' OR blocked_patterns ='^13003.*' OR blocked_patterns ='^1300.*' OR blocked_patterns ='^130.*' OR blocked_patterns ='^13.*' OR blocked_patterns ='^1.*' OR blocked_patterns ='--') AND accountid = 28 limit 1 2018-07-27 17:23:39.513610 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns ='^1300368909.*' OR patterns ='^130036890.*' OR patterns ='^13003689.*' OR patterns ='^1300368.*' OR patterns ='^130036.*' OR patterns ='^13003.*' OR patterns ='^1300.*' OR patterns ='^130.*' OR patterns ='^13.*' OR patterns ='^1.*' OR patterns ='--') AND status = 0 AND pricelist_id = 3 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information =================== 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 28 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 98055562 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 99868.8506 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 1 [0:prepaid,1:postpaid] 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 3 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] ======================================================== 2018-07-27 17:23:39.513610 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 3 AND status = 0 2018-07-27 17:23:39.513610 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern ='^1300368909.*' OR pattern ='^130036890.*' OR pattern ='^13003689.*' OR pattern ='^1300368.*' OR pattern ='^130036.*' OR pattern ='^13003.*' OR pattern ='^1300.*' OR pattern ='^130.*' OR pattern ='^13.*' OR pattern ='^1.*' OR pattern ='--') AND status = 0 AND pricelist_id = 3 ORDER BY LENGTH(pattern) DESC,cost DESC LIMIT 1 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information =================== 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 2362 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.35000 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.00000 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] comment : 13 numbers 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 28 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================ 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100 2018-07-27 17:23:39.513610 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes 2018-07-27 17:23:39.513610 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CARRIER_RATES_TRUNKS] Query :SELECT GROUP_CONCAT(trunk_id) as ids FROM routing WHERE pricelist_id=3 2018-07-27 17:23:39.513610 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TK.cid_translation,TR.init_inc,TK.status,TK.dialed_modify,TK.maxchannels,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern ='^1300368909.*' OR pattern ='^130036890.*' OR pattern ='^13003689.*' OR pattern ='^1300368.*' OR pattern ='^130036.*' OR pattern ='^13003.*' OR pattern ='^1300.*' OR pattern ='^130.*' OR pattern ='^13.*' OR pattern ='^1.*' OR pattern ='--') AND TR.status = 0 AND TR.trunk_id IN (2,3) ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Termination Rates Information =================== 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 2362 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Code : ^13.* 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Destination : 13 numbers 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Free Seconds : 0 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Prefix : ^13.* 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Strip : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Prepend : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Carrier id : 3 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] carrier_name : IBOSS 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] dialplan_variable : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Failover gateway : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Vendor id : 155 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Number Translation : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Max channels : 0 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================END OF TERMINATION RATES======================= 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Termination Rates Information =================== 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 6 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Code : ^13.* 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Destination : Australia 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.35000 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Free Seconds : 0 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Prefix : ^13.* 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Strip : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Prepend : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Carrier id : 2 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] carrier_name : ivox 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] dialplan_variable : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Failover gateway : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Vendor id : 154 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Number Translation : 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] Max channels : 0 2018-07-27 17:23:39.533614 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================END OF TERMINATION RATES======================= 2018-07-27 17:23:39.533614 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 28 AND status=0 LIMIT 1 2018-07-27 17:23:39.533614 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLOUTBOUND] Caller ID Translation Starts 2018-07-27 17:23:39.533614 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLOUTBOUND] Caller ID Translation Ends 2018-07-27 17:23:39.533614 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLOUTBOUND] Caller ID Translation Starts 2018-07-27 17:23:39.533614 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLOUTBOUND] Caller ID Translation Ends 2018-07-27 17:23:39.533614 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:
2018-07-27 17:23:39.533614 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fae38b91ff0 released. Dialplan: sofia/default/7120041412@phone.c2a.com.au parsing [default->1300368909] continue=false Dialplan: sofia/default/7120041412@phone.c2a.com.au Regex (PASS) [1300368909] destination_number(1300368909) =~ /1300368909/ break=on-false Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(effective_destination_number=1300368909) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action sched_hangup(+6000 normal_clearing) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(callstart=2018-07-27 07:23:39) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(hangup_after_bridge=true) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(continue_on_fail=true) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(account_id=28) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(parent_id=0) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(entity_id=0) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(call_processed=internal) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(call_direction=outbound) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(accountname=default) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action export(t38_passthru=true) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(fax_enable_t38=true) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(fax_enable_t38_request=true) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(origination_rates=ID:2362|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:3|MARKUP:0|ACCID:28) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(calltype=STANDARD) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(termination_rates=ID:2362|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|TRUNK:3|PROVIDER:155) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(trunk_id=3) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(provider_id=155) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action bridge([leg_timeout=0]sofia/gateway/IBOSS/1300368909) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(calltype=STANDARD) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(termination_rates=ID:6|CODE:^13.*|DESTINATION:Australia|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|TRUNK:2|PROVIDER:154) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(trunk_id=2) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action set(provider_id=154) Dialplan: sofia/default/7120041412@phone.c2a.com.au Action bridge([leg_timeout=0]sofia/gateway/ivox/1300368909) 2018-07-27 17:23:39.533614 [DEBUG] switch_core_state_machine.c:286 (sofia/default/7120041412@phone.c2a.com.au) State Change CS_ROUTING -> CS_EXECUTE 2018-07-27 17:23:39.533614 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7120041412@phone.c2a.com.au) State ROUTING going to sleep 2018-07-27 17:23:39.533614 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7120041412@phone.c2a.com.au) Running State Change CS_EXECUTE (Cur 9 Tot 970429) 2018-07-27 17:23:39.533614 [DEBUG] switch_core_state_machine.c:650 (sofia/default/7120041412@phone.c2a.com.au) State EXECUTE 2018-07-27 17:23:39.533614 [DEBUG] mod_sofia.c:198 sofia/default/7120041412@phone.c2a.com.au SOFIA EXECUTE 2018-07-27 17:23:39.533614 [DEBUG] switch_core_state_machine.c:328 sofia/default/7120041412@phone.c2a.com.au Standard EXECUTE EXECUTE sofia/default/7120041412@phone.c2a.com.au set(effective_destination_number=1300368909) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [effective_destination_number]=[1300368909] EXECUTE sofia/default/7120041412@phone.c2a.com.au sched_hangup(+6000 normal_clearing) 2018-07-27 17:23:39.533614 [DEBUG] switch_scheduler.c:249 Added task 394839 switch_ivr_schedule_hangup (f5ec8f6c-1155-481b-8cfe-1d29dc6631ee) to run at 1532682219 EXECUTE sofia/default/7120041412@phone.c2a.com.au set(callstart=2018-07-27 07:23:39) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [callstart]=[2018-07-27 07:23:39] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(hangup_after_bridge=true) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [hangup_after_bridge]=[true] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(continue_on_fail=true) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [continue_on_fail]=[true] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(account_id=28) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [account_id]=[28] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(parent_id=0) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [parent_id]=[0] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(entity_id=0) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [entity_id]=[0] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(call_processed=internal) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [call_processed]=[internal] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(call_direction=outbound) 2018-07-27 17:23:39.533614 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [call_direction]=[outbound] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(accountname=default) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [accountname]=[default] EXECUTE sofia/default/7120041412@phone.c2a.com.au export(t38_passthru=true) 2018-07-27 17:23:39.553605 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [t38_passthru]=[true] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(fax_enable_t38=true) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [fax_enable_t38]=[true] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(fax_enable_t38_request=true) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [fax_enable_t38_request]=[true] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(origination_rates=ID:2362|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:3|MARKUP:0|ACCID:28) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [origination_rates]=[ID:2362|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.35000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:3|MARKUP:0|ACCID:28] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(calltype=STANDARD) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [calltype]=[STANDARD] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(termination_rates=ID:2362|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|TRUNK:3|PROVIDER:155) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [termination_rates]=[ID:2362|CODE:^13.*|DESTINATION:13 numbers|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|TRUNK:3|PROVIDER:155] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(trunk_id=3) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [trunk_id]=[3] EXECUTE sofia/default/7120041412@phone.c2a.com.au set(provider_id=155) 2018-07-27 17:23:39.553605 [DEBUG] mod_dptools.c:1548 SET sofia/default/7120041412@phone.c2a.com.au [provider_id]=[155] EXECUTE sofia/default/7120041412@phone.c2a.com.au bridge([leg_timeout=0]sofia/gateway/IBOSS/1300368909) 2018-07-27 17:23:39.553605 [DEBUG] switch_channel.c:1250 sofia/default/7120041412@phone.c2a.com.au EXPORTING[export_vars] [t38_passthru]=[true] to event 2018-07-27 17:23:39.553605 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-07-27 17:23:39.553605 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables 2018-07-27 17:23:39.553605 [NOTICE] switch_channel.c:1104 New Channel sofia/default/1300368909 [ee7e546f-879b-43f0-8f34-291657ecc7ce] 2018-07-27 17:23:39.553605 [DEBUG] mod_sofia.c:4819 (sofia/default/1300368909) State Change CS_NEW -> CS_INIT 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:584 (sofia/default/1300368909) Running State Change CS_INIT (Cur 10 Tot 970430) 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:627 (sofia/default/1300368909) State INIT 2018-07-27 17:23:39.553605 [DEBUG] mod_sofia.c:90 sofia/default/1300368909 SOFIA INIT 2018-07-27 17:23:39.553605 [DEBUG] switch_core_media.c:9710 sofia/default/1300368909 Patched SDP --- v=0 o=7120041412 8000 8000 IN IP4 192.168.10.192 s=SIP Call c=IN IP4 192.168.10.192 t=0 0 m=audio 5004 RTP/AVP 0 8 4 18 2 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 +++ v=0 o=FreeSWITCH 1936332568 1936332569 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 28450 RTP/AVP 0 8 4 18 2 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 2018-07-27 17:23:39.553605 [DEBUG] sofia_glue.c:1295 sofia/default/1300368909 sending invite version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit Local SDP: v=0 o=FreeSWITCH 1936332568 1936332569 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 28450 RTP/AVP 0 8 4 18 2 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:40 sofia/default/1300368909 Standard INIT 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:48 (sofia/default/1300368909) State Change CS_INIT -> CS_ROUTING 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:627 (sofia/default/1300368909) State INIT going to sleep 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:584 (sofia/default/1300368909) Running State Change CS_ROUTING (Cur 10 Tot 970430) 2018-07-27 17:23:39.553605 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [calling][0] 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:643 (sofia/default/1300368909) State ROUTING 2018-07-27 17:23:39.553605 [DEBUG] mod_sofia.c:143 sofia/default/1300368909 SOFIA ROUTING 2018-07-27 17:23:39.553605 [DEBUG] switch_ivr_originate.c:67 (sofia/default/1300368909) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:643 (sofia/default/1300368909) State ROUTING going to sleep 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:584 (sofia/default/1300368909) Running State Change CS_CONSUME_MEDIA (Cur 10 Tot 970430) 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:662 (sofia/default/1300368909) State CONSUME_MEDIA 2018-07-27 17:23:39.553605 [DEBUG] switch_core_state_machine.c:662 (sofia/default/1300368909) State CONSUME_MEDIA going to sleep 2018-07-27 17:23:40.433613 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [98056383@phone.c2a.com.au] from ip 103.239.76.212 2018-07-27 17:23:41.413608 [DEBUG] sofia.c:6170 Ping to sip user '6217448486@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.413608 [DEBUG] sofia.c:6170 Ping to sip user '8567825548@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.413608 [DEBUG] sofia.c:6170 Ping to sip user '6786926165@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.413608 [DEBUG] sofia.c:6170 Ping to sip user '5990414253@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '7120041412@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '4686909652@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '8080062168@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '2372167153@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '5837699930@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '5573548337@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.433608 [DEBUG] sofia.c:6170 Ping to sip user '4176375620@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.453632 [DEBUG] sofia.c:6170 Ping to sip user '2649153346@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:41.453632 [DEBUG] sofia.c:6170 Ping to sip user '3580807566@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:42.273642 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [proceeding][183] 2018-07-27 17:23:42.273642 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 340844292 340844292 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=audio 24082 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - 2018-07-27 17:23:42.273642 [DEBUG] switch_core_media.c:9710 sofia/default/1300368909 Patched SDP --- v=0 o=FreeSWITCH 1936332568 1936332569 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 28450 RTP/AVP 0 8 4 18 2 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 +++ v=0 o=FreeSWITCH 1936332568 1936332570 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 28450 RTP/AVP 0 8 4 18 2 97 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 2018-07-27 17:23:42.273642 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/1300368909 PROXY/0 0 ms 160 samples 0 bits 1 channels 2018-07-27 17:23:42.273642 [DEBUG] switch_core_codec.c:111 sofia/default/1300368909 Original read codec set to PROXY:0 2018-07-27 17:23:42.273642 [DEBUG] switch_core_media.c:6944 PROXY AUDIO RTP [sofia/default/1300368909] 125.213.162.116:24082->125.213.162.116:24082 codec: 0 ms: 20 2018-07-27 17:23:42.273642 [DEBUG] switch_rtp.c:4133 Not using a timer 2018-07-27 17:23:42.273642 [DEBUG] switch_core_media.c:7179 sofia/default/1300368909 Set 2833 dtmf send payload to 101 2018-07-27 17:23:42.273642 [DEBUG] switch_core_media.c:7186 sofia/default/1300368909 Set 2833 dtmf receive payload to 101 2018-07-27 17:23:42.273642 [DEBUG] switch_core_media.c:7209 sofia/default/1300368909 Set rtp dtmf delay to 40 2018-07-27 17:23:42.273642 [NOTICE] sofia.c:7266 Pre-Answer sofia/default/1300368909! 2018-07-27 17:23:42.273642 [DEBUG] switch_channel.c:3474 (sofia/default/1300368909) Callstate Change DOWN -> EARLY 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:9710 sofia/default/7120041412@phone.c2a.com.au Patched SDP --- v=0 o=- 340844292 340844292 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=audio 24082 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - +++ v=0 o=FreeSWITCH 1936428031 1936428032 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 20570 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/7120041412@phone.c2a.com.au PROXY/0 0 ms 160 samples 0 bits 1 channels 2018-07-27 17:23:42.293618 [DEBUG] switch_core_codec.c:111 sofia/default/7120041412@phone.c2a.com.au Original read codec set to PROXY:0 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:6944 PROXY AUDIO RTP [sofia/default/7120041412@phone.c2a.com.au] 192.168.10.192:5004->192.168.10.192:5004 codec: 0 ms: 20 2018-07-27 17:23:42.293618 [DEBUG] switch_rtp.c:4133 Not using a timer 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:7179 sofia/default/7120041412@phone.c2a.com.au Set 2833 dtmf send payload to 101 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:7186 sofia/default/7120041412@phone.c2a.com.au Set 2833 dtmf receive payload to 101 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:7209 sofia/default/7120041412@phone.c2a.com.au Set rtp dtmf delay to 40 2018-07-27 17:23:42.293618 [INFO] switch_ivr_originate.c:3654 Sending early media 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:9710 sofia/default/7120041412@phone.c2a.com.au Patched SDP --- v=0 o=- 340844292 340844292 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=audio 24082 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - +++ v=0 o=FreeSWITCH 1936428031 1936428033 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 20570 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - 2018-07-27 17:23:42.293618 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/7120041412@phone.c2a.com.au. 2018-07-27 17:23:42.293618 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/default/7120041412@phone.c2a.com.au! 2018-07-27 17:23:42.293618 [DEBUG] switch_channel.c:3474 (sofia/default/7120041412@phone.c2a.com.au) Callstate Change RINGING -> EARLY 2018-07-27 17:23:42.293618 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/1300368909] 2018-07-27 17:23:42.293618 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [early][183] 2018-07-27 17:23:42.293618 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/1300368909) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2018-07-27 17:23:42.293618 [DEBUG] switch_core_state_machine.c:584 (sofia/default/1300368909) Running State Change CS_EXCHANGE_MEDIA (Cur 10 Tot 970430) 2018-07-27 17:23:42.293618 [DEBUG] switch_core_state_machine.c:653 (sofia/default/1300368909) State EXCHANGE_MEDIA 2018-07-27 17:23:42.293618 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA 2018-07-27 17:23:42.293618 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. 2018-07-27 17:23:42.573788 [INFO] switch_rtp.c:7231 Auto Changing audio port from 192.168.10.192:5004 to 103.239.77.180:5004 2018-07-27 17:23:43.433629 [DEBUG] sofia.c:6170 Ping to sip user '1803015463@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:43.433629 [DEBUG] sofia.c:6170 Ping to sip user '7993449808@103.226.53.20' succeeded with code 200 - count 3, state Reachable 2018-07-27 17:23:43.593620 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [completing][200] 2018-07-27 17:23:43.593620 [DEBUG] sofia.c:7091 Duplicate SDP v=0 o=- 340844292 340844292 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=audio 24082 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - 2018-07-27 17:23:43.593620 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [ready][200] 2018-07-27 17:23:43.593620 [NOTICE] sofia.c:8180 Channel [sofia/default/1300368909] has been answered 2018-07-27 17:23:43.593620 [DEBUG] switch_channel.c:3773 (sofia/default/1300368909) Callstate Change EARLY -> ACTIVE 2018-07-27 17:23:43.593620 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/1300368909. 2018-07-27 17:23:43.593620 [DEBUG] switch_core_media.c:9710 sofia/default/7120041412@phone.c2a.com.au Patched SDP --- v=0 o=- 340844292 340844292 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=audio 24082 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - +++ v=0 o=FreeSWITCH 1936428031 1936428034 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=audio 20570 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=silenceSupp:off - - - - 2018-07-27 17:23:43.593620 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/7120041412@phone.c2a.com.au. 2018-07-27 17:23:43.593620 [NOTICE] switch_ivr.c:779 Channel [sofia/default/7120041412@phone.c2a.com.au] has been answered 2018-07-27 17:23:43.593620 [DEBUG] switch_channel.c:3773 (sofia/default/7120041412@phone.c2a.com.au) Callstate Change EARLY -> ACTIVE 2018-07-27 17:23:43.593620 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [completed][200] 2018-07-27 17:23:43.613622 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. 2018-07-27 17:23:43.613622 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. 2018-07-27 17:23:43.713672 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [ready][200] 2018-07-27 17:23:43.713672 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/7120041412@phone.c2a.com.au. 2018-07-27 17:23:44.453618 [DEBUG] sofia.c:6170 Ping to sip user '98084069@103.226.53.20' succeeded with code 200 - count 3, state Reachable 2018-07-27 17:23:45.433611 [DEBUG] sofia.c:6170 Ping to sip user '2114812383@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.433611 [DEBUG] sofia.c:6170 Ping to sip user '6330123028@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '4936172231@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '8463161113@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '6072475659@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '3116364723@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '5750271407@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '7623336111@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.453597 [DEBUG] sofia.c:6170 Ping to sip user '6615257118@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '9024007661@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '5069530460@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '3159861784@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '1419067075@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '5378582960@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '4118115760@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.473592 [DEBUG] sofia.c:6170 Ping to sip user '6663049871@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:45.773612 [DEBUG] sofia.c:7084 Channel sofia/default/8779617009@phone.c2a.com.au entering state [terminated][487] 2018-07-27 17:23:45.773612 [NOTICE] sofia.c:8273 Hangup sofia/default/8779617009@phone.c2a.com.au [CS_EXECUTE] [ORIGINATOR_CANCEL] 2018-07-27 17:23:45.773612 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/8779617009@phone.c2a.com.au] 2018-07-27 17:23:45.793611 [DEBUG] switch_ivr_bridge.c:706 sofia/default/8779617009@phone.c2a.com.au ending bridge by request from write function 2018-07-27 17:23:45.793611 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/0280211244] 2018-07-27 17:23:45.793611 [NOTICE] switch_ivr_bridge.c:900 Hangup sofia/default/0280211244 [CS_EXCHANGE_MEDIA] [ORIGINATOR_CANCEL] 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:653 (sofia/default/0280211244) State EXCHANGE_MEDIA going to sleep 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0280211244) Running State Change CS_HANGUP (Cur 10 Tot 970430) 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:850 (sofia/default/0280211244) Callstate Change EARLY -> HANGUP 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0280211244) State HANGUP 2018-07-27 17:23:45.793611 [DEBUG] mod_sofia.c:432 sofia/default/0280211244 Overriding SIP cause 487 with 487 from the other leg 2018-07-27 17:23:45.793611 [DEBUG] mod_sofia.c:438 Channel sofia/default/0280211244 hanging up, cause: ORIGINATOR_CANCEL 2018-07-27 17:23:45.793611 [DEBUG] switch_ivr_bridge.c:1712 sofia/default/0280211244 skip receive message [UNBRIDGE] (channel is hungup already) 2018-07-27 17:23:45.793611 [DEBUG] switch_ivr_bridge.c:1715 sofia/default/8779617009@phone.c2a.com.au skip receive message [UNBRIDGE] (channel is hungup already) 2018-07-27 17:23:45.793611 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/default/0280211244 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:60 sofia/default/0280211244 Standard HANGUP, cause: ORIGINATOR_CANCEL 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0280211244) State HANGUP going to sleep 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:619 (sofia/default/0280211244) State Change CS_HANGUP -> CS_REPORTING 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0280211244) Running State Change CS_REPORTING (Cur 10 Tot 970430) 2018-07-27 17:23:45.793611 [DEBUG] switch_core_session.c:2815 sofia/default/8779617009@phone.c2a.com.au skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:650 (sofia/default/8779617009@phone.c2a.com.au) State EXECUTE going to sleep 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8779617009@phone.c2a.com.au) Running State Change CS_HANGUP (Cur 10 Tot 970430) 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0280211244) State REPORTING 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:850 (sofia/default/8779617009@phone.c2a.com.au) Callstate Change EARLY -> HANGUP 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8779617009@phone.c2a.com.au) State HANGUP 2018-07-27 17:23:45.793611 [DEBUG] mod_sofia.c:438 Channel sofia/default/8779617009@phone.c2a.com.au hanging up, cause: ORIGINATOR_CANCEL 2018-07-27 17:23:45.793611 [INFO] mod_json_cdr.c:271 Process [da4ed662-3e17-47d0-a09e-3d9cbac891af.cdr.json] 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:60 sofia/default/8779617009@phone.c2a.com.au Standard HANGUP, cause: ORIGINATOR_CANCEL 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:852 (sofia/default/8779617009@phone.c2a.com.au) State HANGUP going to sleep 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:619 (sofia/default/8779617009@phone.c2a.com.au) State Change CS_HANGUP -> CS_REPORTING 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:584 (sofia/default/8779617009@phone.c2a.com.au) Running State Change CS_REPORTING (Cur 10 Tot 970430) 2018-07-27 17:23:45.793611 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8779617009@phone.c2a.com.au) State REPORTING 2018-07-27 17:23:45.793611 [INFO] mod_json_cdr.c:271 Process [370d44cc-105a-4323-a31e-0efe1fc2d40f.cdr.json] 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:174 sofia/default/0280211244 Standard REPORTING, cause: ORIGINATOR_CANCEL 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0280211244) State REPORTING going to sleep 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:610 (sofia/default/0280211244) State Change CS_REPORTING -> CS_DESTROY 2018-07-27 17:23:45.853624 [DEBUG] switch_core_session.c:1665 Session 970428 (sofia/default/0280211244) Locked, Waiting on external entities 2018-07-27 17:23:45.853624 [NOTICE] switch_core_session.c:1683 Session 970428 (sofia/default/0280211244) Ended 2018-07-27 17:23:45.853624 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/0280211244 [CS_DESTROY] 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:741 (sofia/default/0280211244) Running State Change CS_DESTROY (Cur 9 Tot 970430) 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:751 (sofia/default/0280211244) State DESTROY 2018-07-27 17:23:45.853624 [DEBUG] mod_sofia.c:343 sofia/default/0280211244 SOFIA DESTROY 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:181 sofia/default/0280211244 Standard DESTROY 2018-07-27 17:23:45.853624 [DEBUG] switch_core_state_machine.c:751 (sofia/default/0280211244) State DESTROY going to sleep 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:174 sofia/default/8779617009@phone.c2a.com.au Standard REPORTING, cause: ORIGINATOR_CANCEL 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:938 (sofia/default/8779617009@phone.c2a.com.au) State REPORTING going to sleep 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:610 (sofia/default/8779617009@phone.c2a.com.au) State Change CS_REPORTING -> CS_DESTROY 2018-07-27 17:23:45.933620 [DEBUG] switch_core_session.c:1665 Session 970427 (sofia/default/8779617009@phone.c2a.com.au) Locked, Waiting on external entities 2018-07-27 17:23:45.933620 [NOTICE] switch_core_session.c:1683 Session 970427 (sofia/default/8779617009@phone.c2a.com.au) Ended 2018-07-27 17:23:45.933620 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/8779617009@phone.c2a.com.au [CS_DESTROY] 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:741 (sofia/default/8779617009@phone.c2a.com.au) Running State Change CS_DESTROY (Cur 8 Tot 970430) 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8779617009@phone.c2a.com.au) State DESTROY 2018-07-27 17:23:45.933620 [DEBUG] mod_sofia.c:343 sofia/default/8779617009@phone.c2a.com.au SOFIA DESTROY 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:181 sofia/default/8779617009@phone.c2a.com.au Standard DESTROY 2018-07-27 17:23:45.933620 [DEBUG] switch_core_state_machine.c:751 (sofia/default/8779617009@phone.c2a.com.au) State DESTROY going to sleep 2018-07-27 17:23:46.033639 [DEBUG] switch_scheduler.c:144 Deleting task 394838 switch_ivr_schedule_hangup (370d44cc-105a-4323-a31e-0efe1fc2d40f) 2018-07-27 17:23:47.433685 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [7993449808@phone.c2a.com.au] from ip 103.226.53.102 2018-07-27 17:23:48.033625 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [8852604137@phone.c2a.com.au] from ip 103.226.53.161 freeswitch@primary> freeswitch@primary> 2018-07-27 17:23:48.933633 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [9631869658@phone.c2a.com.au] from ip 207.136.3.80 freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> 2018-07-27 17:23:49.153640 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [8703498704@phone.c2a.com.au] from ip 103.239.77.250 freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> freeswitch@primary> 2018-07-27 17:23:50.433629 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [received][100] 2018-07-27 17:23:50.433629 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 340844292 340844293 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=image 24462 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 2018-07-27 17:23:50.433629 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/1300368909. 2018-07-27 17:23:50.433629 [DEBUG] switch_core_media.c:6291 AUDIO RTP CHANGING DEST TO: [125.213.162.116:24462] 2018-07-27 17:23:50.433629 [DEBUG] sofia.c:7830 Passing SDP to other leg. v=0 o=- 340844292 340844293 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=image 24462 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 2018-07-27 17:23:50.453649 [DEBUG] mod_sofia.c:1487 sofia/default/7120041412@phone.c2a.com.au Sending media re-direct: v=0 o=- 340844292 340844293 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=image 24462 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 2018-07-27 17:23:50.453649 [DEBUG] switch_core_media.c:6269 Remote address:port [192.168.10.192:5004] has not changed. 2018-07-27 17:23:50.453649 [DEBUG] switch_core_media.c:9710 sofia/default/7120041412@phone.c2a.com.au Patched SDP --- v=0 o=- 340844292 340844293 IN IP4 125.213.162.112 s=ENSResip c=IN IP4 125.213.162.116 t=0 0 m=image 24462 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 +++ v=0 o=FreeSWITCH 1936428031 1936428035 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=image 20570 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 2018-07-27 17:23:50.453649 [DEBUG] sofia_glue.c:1295 sofia/default/7120041412@phone.c2a.com.au sending invite version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit Local SDP: v=0 o=FreeSWITCH 1936428031 1936428035 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=image 20570 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxRateManagement:transferredTCF a=T38FaxUdpEC:t38UDPRedundancy a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 2018-07-27 17:23:50.453649 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [calling][0] 2018-07-27 17:23:50.513609 [DEBUG] switch_core_media.c:6269 Remote address:port [192.168.10.192:5004] has not changed. 2018-07-27 17:23:50.513609 [DEBUG] sofia.c:6654 Passing 200 OK to other leg v=0 o=7120041412 8000 8001 IN IP4 192.168.10.192 s=SIP Call c=IN IP4 192.168.10.192 t=0 0 m=image 5004 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy 2018-07-27 17:23:50.513609 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [completing][200] 2018-07-27 17:23:50.513609 [DEBUG] sofia.c:7091 Duplicate SDP v=0 o=7120041412 8000 8001 IN IP4 192.168.10.192 s=SIP Call c=IN IP4 192.168.10.192 t=0 0 m=image 5004 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy 2018-07-27 17:23:50.513609 [DEBUG] mod_sofia.c:2132 Responding with 200 [OK] 2018-07-27 17:23:50.513609 [DEBUG] switch_core_media.c:9710 sofia/default/1300368909 Patched SDP --- v=0 o=7120041412 8000 8001 IN IP4 192.168.10.192 s=SIP Call c=IN IP4 192.168.10.192 t=0 0 m=image 5004 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy +++ v=0 o=FreeSWITCH 1936332568 1936332571 IN IP4 103.226.53.19 s=FreeSWITCH c=IN IP4 103.226.53.19 t=0 0 m=image 28450 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy 2018-07-27 17:23:50.513609 [DEBUG] switch_core_media.c:6269 Remote address:port [125.213.162.116:24462] has not changed. 2018-07-27 17:23:50.513609 [DEBUG] sofia.c:7084 Channel sofia/default/7120041412@phone.c2a.com.au entering state [ready][200] 2018-07-27 17:23:50.513609 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [completed][200] 2018-07-27 17:23:50.513609 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/7120041412@phone.c2a.com.au. 2018-07-27 17:23:50.593610 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. 2018-07-27 17:23:50.613612 [DEBUG] sofia.c:7084 Channel sofia/default/1300368909 entering state [ready][200] 2018-07-27 17:23:51.713635 [WARNING] sofia_reg.c:2906 Can't find user [1878568962@103.226.53.20] from 103.239.77.38 You must define a domain called '103.226.53.20' in your directory and add a user with the id="1878568962" attribute and you must configure your device to use the proper domain in it's authentication credentials. 2018-07-27 17:23:51.713635 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [1878568962@phone.c2a.com.au] from ip 103.239.77.38 2018-07-27 17:23:53.453622 [DEBUG] sofia.c:6170 Ping to sip user '2124127137@103.226.53.20' succeeded with code 200 - count 3, state Reachable 2018-07-27 17:23:53.473659 [DEBUG] sofia.c:6170 Ping to sip user '98064628@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:53.473659 [DEBUG] sofia.c:6170 Ping to sip user '3742291443@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:23:53.473659 [DEBUG] sofia.c:6170 Ping to sip user '7849275805@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:23:53.473659 [DEBUG] sofia.c:6170 Ping to sip user '4401164399@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:23:53.473659 [DEBUG] sofia.c:6170 Ping to sip user '8062035925@103.226.53.20' succeeded with code 200 - count 3, state Reachable 2018-07-27 17:23:53.493626 [DEBUG] sofia.c:6170 Ping to sip user '6841655420@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:23:53.513657 [DEBUG] sofia.c:6170 Ping to sip user '98062003@103.226.53.20' succeeded with code 200 - count 3, state Reachable 2018-07-27 17:23:56.533605 [DEBUG] sofia.c:6170 Ping to sip user '98062117@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:23:57.493621 [DEBUG] sofia.c:6170 Ping to sip user '8779491582@103.226.53.20' succeeded with code 200 - count 1, state Reachable freeswitch@primary> freeswitch@primary> freeswitch@primary> 2018-07-27 17:23:58.493637 [DEBUG] sofia.c:6170 Ping to sip user '2188581467@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:02.493639 [DEBUG] sofia.c:6170 Ping to sip user '4381068958@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:02.493639 [DEBUG] sofia.c:6170 Ping to sip user '98060082@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:02.493639 [DEBUG] sofia.c:6170 Ping to sip user '4250559859@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:02.833616 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [5748841388@phone.c2a.com.au] from ip 103.239.76.201 2018-07-27 17:24:02.873624 [WARNING] sofia_reg.c:2906 Can't find user [5748841388@103.226.53.20] from 103.239.76.201 You must define a domain called '103.226.53.20' in your directory and add a user with the id="5748841388" attribute and you must configure your device to use the proper domain in it's authentication credentials. 2018-07-27 17:24:02.873624 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [5748841388@phone.c2a.com.au] from ip 103.239.76.201 2018-07-27 17:24:06.493619 [DEBUG] sofia.c:6170 Ping to sip user '1803015463@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:24:06.513658 [DEBUG] sofia.c:6170 Ping to sip user '8841961777@103.226.53.20' succeeded with code 200 - count 2, state Reachable 2018-07-27 17:24:06.513658 [DEBUG] sofia.c:6170 Ping to sip user '1552424269@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:06.533618 [DEBUG] sofia.c:6170 Ping to sip user '8703498704@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:06.553618 [DEBUG] sofia.c:6170 Ping to sip user '9631869658@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:07.493633 [DEBUG] sofia.c:6170 Ping to sip user '7568975362@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:08.533623 [WARNING] sofia.c:6146 Sip user '4222645691@103.226.53.20' is now Unreachable 2018-07-27 17:24:08.533623 [WARNING] sofia.c:6157 Expire sip user '4222645691@103.226.53.20' due to options failure 2018-07-27 17:24:08.573618 [WARNING] sofia.c:6146 Sip user '2220907642@103.226.53.20' is now Unreachable 2018-07-27 17:24:08.573618 [WARNING] sofia.c:6157 Expire sip user '2220907642@103.226.53.20' due to options failure 2018-07-27 17:24:09.533630 [DEBUG] sofia.c:6170 Ping to sip user '9157676046@103.226.53.20' succeeded with code 200 - count 1, state Reachable 2018-07-27 17:24:09.973618 [NOTICE] sofia.c:1012 Hangup sofia/default/anonymous@phone.c2a.com.au [CS_EXECUTE] [NORMAL_CLEARING] 2018-07-27 17:24:09.973618 [DEBUG] switch_ivr_bridge.c:706 sofia/default/anonymous@phone.c2a.com.au ending bridge by request from write function 2018-07-27 17:24:09.973618 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/0448484662] 2018-07-27 17:24:09.973618 [NOTICE] switch_ivr_bridge.c:904 Hangup sofia/default/0448484662 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:653 (sofia/default/0448484662) State EXCHANGE_MEDIA going to sleep 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0448484662) Running State Change CS_HANGUP (Cur 8 Tot 970430) 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:850 (sofia/default/0448484662) Callstate Change ACTIVE -> HANGUP 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0448484662) State HANGUP 2018-07-27 17:24:09.973618 [DEBUG] mod_sofia.c:432 sofia/default/0448484662 Overriding SIP cause 480 with 200 from the other leg 2018-07-27 17:24:09.973618 [DEBUG] mod_sofia.c:438 Channel sofia/default/0448484662 hanging up, cause: NORMAL_CLEARING 2018-07-27 17:24:09.973618 [DEBUG] switch_ivr_bridge.c:706 sofia/default/0448484662 ending bridge by request from write function 2018-07-27 17:24:09.973618 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/default/0448484662 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:60 sofia/default/0448484662 Standard HANGUP, cause: NORMAL_CLEARING 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:852 (sofia/default/0448484662) State HANGUP going to sleep 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:619 (sofia/default/0448484662) State Change CS_HANGUP -> CS_REPORTING 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:584 (sofia/default/0448484662) Running State Change CS_REPORTING (Cur 8 Tot 970430) 2018-07-27 17:24:09.973618 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/anonymous@phone.c2a.com.au] 2018-07-27 17:24:09.973618 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0448484662) State REPORTING 2018-07-27 17:24:09.973618 [DEBUG] switch_ivr_bridge.c:1712 sofia/default/0448484662 skip receive message [UNBRIDGE] (channel is hungup already) 2018-07-27 17:24:09.973618 [DEBUG] switch_ivr_bridge.c:1715 sofia/default/anonymous@phone.c2a.com.au skip receive message [UNBRIDGE] (channel is hungup already) 2018-07-27 17:24:09.993604 [DEBUG] switch_core_session.c:2815 sofia/default/anonymous@phone.c2a.com.au skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:650 (sofia/default/anonymous@phone.c2a.com.au) State EXECUTE going to sleep 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:584 (sofia/default/anonymous@phone.c2a.com.au) Running State Change CS_HANGUP (Cur 8 Tot 970430) 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:850 (sofia/default/anonymous@phone.c2a.com.au) Callstate Change ACTIVE -> HANGUP 2018-07-27 17:24:09.993604 [INFO] mod_json_cdr.c:271 Process [4bc60738-066e-4b3c-bca8-21b459cd350a.cdr.json] 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:852 (sofia/default/anonymous@phone.c2a.com.au) State HANGUP 2018-07-27 17:24:09.993604 [DEBUG] mod_sofia.c:438 Channel sofia/default/anonymous@phone.c2a.com.au hanging up, cause: NORMAL_CLEARING 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:60 sofia/default/anonymous@phone.c2a.com.au Standard HANGUP, cause: NORMAL_CLEARING 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:852 (sofia/default/anonymous@phone.c2a.com.au) State HANGUP going to sleep 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:619 (sofia/default/anonymous@phone.c2a.com.au) State Change CS_HANGUP -> CS_REPORTING 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:584 (sofia/default/anonymous@phone.c2a.com.au) Running State Change CS_REPORTING (Cur 8 Tot 970430) 2018-07-27 17:24:09.993604 [DEBUG] switch_core_state_machine.c:938 (sofia/default/anonymous@phone.c2a.com.au) State REPORTING 2018-07-27 17:24:09.993604 [INFO] mod_json_cdr.c:271 Process [8d622834-bca6-4e7f-bebd-bfb238df269f.cdr.json] 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:174 sofia/default/0448484662 Standard REPORTING, cause: NORMAL_CLEARING 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:938 (sofia/default/0448484662) State REPORTING going to sleep 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:610 (sofia/default/0448484662) State Change CS_REPORTING -> CS_DESTROY 2018-07-27 17:24:10.053636 [DEBUG] switch_core_session.c:1665 Session 970424 (sofia/default/0448484662) Locked, Waiting on external entities 2018-07-27 17:24:10.053636 [NOTICE] switch_core_session.c:1683 Session 970424 (sofia/default/0448484662) Ended 2018-07-27 17:24:10.053636 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/0448484662 [CS_DESTROY] 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:741 (sofia/default/0448484662) Running State Change CS_DESTROY (Cur 7 Tot 970430) 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:751 (sofia/default/0448484662) State DESTROY 2018-07-27 17:24:10.053636 [DEBUG] mod_sofia.c:343 sofia/default/0448484662 SOFIA DESTROY 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:181 sofia/default/0448484662 Standard DESTROY 2018-07-27 17:24:10.053636 [DEBUG] switch_core_state_machine.c:751 (sofia/default/0448484662) State DESTROY going to sleep 2018-07-27 17:24:10.093621 [DEBUG] switch_core_state_machine.c:174 sofia/default/anonymous@phone.c2a.com.au Standard REPORTING, cause: NORMAL_CLEARING 2018-07-27 17:24:10.093621 [DEBUG] switch_core_state_machine.c:938 (sofia/default/anonymous@phone.c2a.com.au) State REPORTING going to sleep 2018-07-27 17:24:10.113620 [DEBUG] switch_core_state_machine.c:610 (sofia/default/anonymous@phone.c2a.com.au) State Change CS_REPORTING -> CS_DESTROY