freeswitch@freeswitch>
recv 1030 bytes from tcp/[192.168.1.33]:48236 at 16:05:14.785916:
------------------------------------------------------------------------
PUBLISH sip:9110327518@192.168.1.118;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-3efec5cd215b6465-1---d8754z-
Max-Forwards: 70
Contact: <sip:9110327518@117.247.91.162:58810;transport=TCP>
To: <sip:9110327518@192.168.1.118;transport=TCP>
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=98ff5d68
Call-ID: MmU2ZGFlMWUyZDBiMDQyMTExOWFkNjRhNmEyODgxZjY.
CSeq: 14 PUBLISH
Expires: 600
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Content-Type: application/pidf+xml
SIP-If-Match: 98ZLJPmk
Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri
User-Agent: Z 3.3.25608 r25552
Event: presence
Allow-Events: presence, kpml
Content-Length: 279
<?xml version="1.0" encoding="UTF-8"?>
<presence xmlns="urn:ietf:params:xml:ns:pidf"
entity="sip:9110327518@192.168.1.118;transport=TCP">
<tuple id="9110327518" >
<status><basic>open</basic></status>
<note>On the phone</note>
</tuple>
</presence>
------------------------------------------------------------------------
recv 1000 bytes from tcp/[192.168.1.33]:48236 at 16:05:14.825631:
------------------------------------------------------------------------
PUBLISH sip:97265@192.168.1.118;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-b8b48820f0bb4937-1---d8754z-
Max-Forwards: 70
Contact: <sip:97265@117.247.91.162:58810;transport=TCP>
To: <sip:97265@192.168.1.118;transport=TCP>
From: <sip:97265@192.168.1.118;transport=TCP>;tag=1368e36f
Call-ID: ZDI1YTJhZGM3ODQyY2Q3NzEyOTQyYzRkZjg0M2U3OWM.
CSeq: 10 PUBLISH
Expires: 600
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Content-Type: application/pidf+xml
SIP-If-Match: M1gl83MI
Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri
User-Agent: Z 3.3.25608 r25552
Event: presence
Allow-Events: presence, kpml
Content-Length: 269
<?xml version="1.0" encoding="UTF-8"?>
<presence xmlns="urn:ietf:params:xml:ns:pidf"
entity="sip:97265@192.168.1.118;transport=TCP">
<tuple id="97265" >
<status><basic>open</basic></status>
<note>On the phone</note>
</tuple>
</presence>
------------------------------------------------------------------------
recv 921 bytes from tcp/[192.168.1.33]:48236 at 16:05:14.986351:
------------------------------------------------------------------------
INVITE sip:97264@192.168.1.118;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-67ee28e05cbeb2f4-1---d8754z-
Max-Forwards: 70
Contact: <sip:9110327518@117.247.91.162:58810;transport=TCP>
To: <sip:97264@192.168.1.118;transport=TCP>
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=c325a037
Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Content-Type: application/sdp
Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri
User-Agent: Z 3.3.25608 r25552
Allow-Events: presence, kpml
Content-Length: 243
v=0
o=Z 0 0 IN IP4 117.247.91.162
s=Z
c=IN IP4 117.247.91.162
t=0 0
m=audio 8000 RTP/AVP 3 110 8 0 98 101
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
------------------------------------------------------------------------
send 341 bytes to tcp/[192.168.1.33]:48236 at 16:05:14.986665:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-67ee28e05cbeb2f4-1---d8754z-;rport=48236
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=c325a037
To: <sip:97264@192.168.1.118;transport=TCP>
Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
CSeq: 1 INVITE
User-Agent: Local
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:14.981576 [NOTICE] switch_channel.c:1104 New Channel sofia/default/9110327518@192.168.1.118 [d486e76a-fc5b-414d-81a2-0c62494e2a0e]
2017-11-06 16:05:14.981576 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9110327518@192.168.1.118) Running State Change CS_NEW (Cur 1 Tot 274)
2017-11-06 16:05:14.981576 [DEBUG] sofia.c:9837 sofia/default/9110327518@192.168.1.118 receiving invite from 192.168.1.33:48236 version: 1.6.18 64bit
2017-11-06 16:05:14.981576 [DEBUG] sofia.c:9953 IP 192.168.1.33 Approved by acl "default[]". Access Granted.
send 734 bytes to tcp/[192.168.1.33]:48236 at 16:05:15.095728:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-3efec5cd215b6465-1---d8754z-;rport=48236
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=98ff5d68
To: <sip:9110327518@192.168.1.118;transport=TCP>;tag=QD0carUKS6X8a
Call-ID: MmU2ZGFlMWUyZDBiMDQyMTExOWFkNjRhNmEyODgxZjY.
CSeq: 14 PUBLISH
Contact: <sip:192.168.1.118>
Expires: 600
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
SIP-ETag: q5Hu6egp
Content-Length: 0
------------------------------------------------------------------------
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:15.106664:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bKytFU7Xg3Qr7ge
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=t8BQF9Dyg100D
To: <sip:1.1.1.1>
Call-ID: 045637c8-3d81-1236-c4b6-000c29f46286
CSeq: 114465670 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
send 724 bytes to tcp/[192.168.1.33]:48236 at 16:05:15.345909:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-b8b48820f0bb4937-1---d8754z-;rport=48236
From: <sip:97265@192.168.1.118;transport=TCP>;tag=1368e36f
To: <sip:97265@192.168.1.118;transport=TCP>;tag=rpS5BKcQpFmUp
Call-ID: ZDI1YTJhZGM3ODQyY2Q3NzEyOTQyYzRkZjg0M2U3OWM.
CSeq: 10 PUBLISH
Contact: <sip:192.168.1.118>
Expires: 600
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
SIP-ETag: aLzKWQqp
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:15.421582 [DEBUG] sofia.c:11132 Setting NAT mode based on via port
2017-11-06 16:05:15.421582 [DEBUG] sofia.c:7048 Channel sofia/default/9110327518@192.168.1.118 entering state [received][100]
2017-11-06 16:05:15.421582 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=Z 0 0 IN IP4 117.247.91.162
s=Z
c=IN IP4 117.247.91.162
t=0 0
m=audio 8000 RTP/AVP 3 110 8 0 98 101
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2017-11-06 16:05:15.421582 [DEBUG] sofia.c:7450 (sofia/default/9110327518@192.168.1.118) State Change CS_NEW -> CS_INIT
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:603 (sofia/default/9110327518@192.168.1.118) State NEW
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9110327518@192.168.1.118) Running State Change CS_INIT (Cur 1 Tot 274)
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:627 (sofia/default/9110327518@192.168.1.118) State INIT
2017-11-06 16:05:15.421582 [DEBUG] mod_sofia.c:90 sofia/default/9110327518@192.168.1.118 SOFIA INIT
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:40 sofia/default/9110327518@192.168.1.118 Standard INIT
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:48 (sofia/default/9110327518@192.168.1.118) State Change CS_INIT -> CS_ROUTING
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:627 (sofia/default/9110327518@192.168.1.118) State INIT going to sleep
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9110327518@192.168.1.118) Running State Change CS_ROUTING (Cur 1 Tot 274)
2017-11-06 16:05:15.421582 [DEBUG] switch_channel.c:2249 (sofia/default/9110327518@192.168.1.118) Callstate Change DOWN -> RINGING
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9110327518@192.168.1.118) State ROUTING
2017-11-06 16:05:15.421582 [DEBUG] mod_sofia.c:143 sofia/default/9110327518@192.168.1.118 SOFIA ROUTING
2017-11-06 16:05:15.421582 [DEBUG] switch_core_state_machine.c:236 sofia/default/9110327518@192.168.1.118 Standard ROUTING
2017-11-06 16:05:15.421582 [INFO] mod_dialplan_xml.c:637 Processing 9110327518 <9110327518>->97264 in context default
2017-11-06 16:05:15.441577 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa6f415e830 Connected.
2017-11-06 16:05:15.441577 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2017-11-06 16:05:15.441577 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [xml_handler] Params:
'Event-Name: REQUEST_PARAMS
Core-UUID: b8b0770f-83a5-4654-b268-e2c6ae265441
FreeSWITCH-Hostname: astpptest1
FreeSWITCH-Switchname: freeswitch
FreeSWITCH-IPv4: 192.168.1.118
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2017-11-06%2016%3A05%3A15
Event-Date-GMT: Mon,%2006%20Nov%202017%2010%3A35%3A15%20GMT
Event-Date-Timestamp: 1509964515421582
Event-Calling-File: mod_dialplan_xml.c
Event-Calling-Function: dialplan_xml_locate
Event-Calling-Line-Number: 608
Event-Sequence: 74948
Channel-State: CS_ROUTING
Channel-Call-State: RINGING
Channel-State-Number: 2
Channel-Name: sofia/default/9110327518%40192.168.1.118
Unique-ID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Call-Direction: inbound
Presence-Call-Direction: inbound
Channel-HIT-Dialplan: true
Channel-Presence-ID: 9110327518%40192.168.1.118
Channel-Call-UUID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Answer-State: ringing
Caller-Direction: inbound
Caller-Logical-Direction: inbound
Caller-Username: 9110327518
Caller-Dialplan: XML
Caller-Caller-ID-Name: 9110327518
Caller-Caller-ID-Number: 9110327518
Caller-Orig-Caller-ID-Name: 9110327518
Caller-Orig-Caller-ID-Number: 9110327518
Caller-Network-Addr: 192.168.1.33
Caller-ANI: 9110327518
Caller-Destination-Number: 97264
Caller-Unique-ID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Caller-Source: mod_sofia
Caller-Context: default
Caller-Channel-Name: sofia/default/9110327518%40192.168.1.118
Caller-Profile-Index: 1
Caller-Profile-Created-Time: 1509964514981576
Caller-Channel-Created-Time: 1509964514981576
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: d486e76a-fc5b-414d-81a2-0c62494e2a0e
variable_session_id: 274
variable_sip_from_params: transport%3DTCP
variable_sip_from_user: 9110327518
variable_sip_from_uri: 9110327518%40192.168.1.118
variable_sip_from_host: 192.168.1.118
variable_video_media_flow: sendrecv
variable_audio_media_flow: sendrecv
variable_channel_name: sofia/default/9110327518%40192.168.1.118
variable_sip_call_id: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
variable_ep_codec_string: CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b
variable_sip_local_network_addr: 192.168.1.118
variable_sip_network_ip: 192.168.1.33
variable_sip_network_port: 48236
variable_sip_invite_stamp: 1509964514981576
variable_sip_received_ip: 192.168.1.33
variable_sip_received_port: 48236
variable_sip_via_protocol: tcp
variable_sip_authorized: true
variable_sip_acl_authed_by: default
variable_sip_from_user_stripped: 9110327518
variable_sip_from_tag: c325a037
variable_sofia_profile_name: default
variable_recovery_profile_name: default
variable_sip_full_via: SIP/2.0/TCP%20192.168.1.33%3A58810%3Bbranch%3Dz9hG4bK-d8754z-67ee28e05cbeb2f4-1---d8754z-%3Brport%3D48236
variable_sip_recover_via: SIP/2.0/TCP%20192.168.1.33%3A58810%3Bbranch%3Dz9hG4bK-d8754z-67ee28e05cbeb2f4-1---d8754z-%3Brport%3D48236
variable_sip_full_from: %3Csip%3A9110327518%40192.168.1.118%3Btransport%3DTCP%3E%3Btag%3Dc325a037
variable_sip_full_to: %3Csip%3A97264%40192.168.1.118%3Btransport%3DTCP%3E
variable_sip_allow: INVITE,%20ACK,%20CANCEL,%20BYE,%20NOTIFY,%20REFER,%20MESSAGE,%20OPTIONS,%20INFO,%20SUBSCRIBE
variable_sip_req_params: transport%3DTCP
variable_sip_req_user: 97264
variable_sip_req_uri: 97264%40192.168.1.118
variable_sip_req_host: 192.168.1.118
variable_sip_to_params: transport%3DTCP
variable_sip_to_user: 97264
variable_sip_to_uri: 97264%40192.168.1.118
variable_sip_to_host: 192.168.1.118
variable_sip_contact_params: transport%3DTCP
variable_sip_contact_user: 9110327518
variable_sip_contact_port: 58810
variable_sip_contact_uri: 9110327518%40117.247.91.162%3A58810
variable_sip_contact_host: 117.247.91.162
variable_rtp_use_codec_string: PCMA,PCMU
variable_sip_user_agent: Z%203.3.25608%20r25552
variable_sip_via_host: 192.168.1.33
variable_sip_via_port: 58810
variable_sip_via_rport: 48236
variable_max_forwards: 70
variable_presence_id: 9110327518%40192.168.1.118
variable_sip_nat_detected: true
variable_switch_r_sdp: v%3D0%0D%0Ao%3DZ%200%200%20IN%20IP4%20117.247.91.162%0D%0As%3DZ%0D%0Ac%3DIN%20IP4%20117.247.91.162%0D%0At%3D0%200%0D%0Am%3Daudio%208000%20RTP/AVP%203%20110%208%200%2098%20101%0D%0Aa%3Drtpmap%3A110%20speex/8000%0D%0Aa%3Drtpmap%3A98%20iLBC/8000%0D%0Aa%3Dfmtp%3A98%20mode%3D20%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-15%0D%0A
variable_endpoint_disposition: DELAYED%20NEGOTIATION
variable_call_uuid: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Hunt-Direction: inbound
Hunt-Logical-Direction: inbound
Hunt-Username: 9110327518
Hunt-Dialplan: XML
Hunt-Caller-ID-Name: 9110327518
Hunt-Caller-ID-Number: 9110327518
Hunt-Orig-Caller-ID-Name: 9110327518
Hunt-Orig-Caller-ID-Number: 9110327518
Hunt-Network-Addr: 192.168.1.33
Hunt-ANI: 9110327518
Hunt-Destination-Number: 97264
Hunt-Unique-ID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Hunt-Source: mod_sofia
Hunt-Context: default
Hunt-Channel-Name: sofia/default/9110327518%40192.168.1.118
Hunt-Profile-Index: 1
Hunt-Profile-Created-Time: 1509964514981576
Hunt-Channel-Created-Time: 1509964514981576
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
'
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] section: dialplan
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_value:
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_name:
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] tag_name:
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 97264
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number : 9110327518 / 9110327518
2017-11-06 16:05:15.441577 [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.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 ="97264" LIMIT 1
2017-11-06 16:05:15.441577 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.username as username,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 username="97264" limit 1
2017-11-06 16:05:15.441577 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : local
2017-11-06 16:05:15.441577 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [IPAUTHENTICATION] Query :SELECT ip_map.*, (SELECT number FROM accounts where id=accountid AND status=0 AND deleted=0) AS account_code FROM ip_map WHERE ((INET_ATON("192.168.1.33") & (0xFFFFFFFF & (-1 << 32 - SUBSTRING_INDEX(ip, '/',-1)))) = ((0xFFFFFFFF & (-1 << 32 - SUBSTRING_INDEX(ip, '/',-1))) & INET_ATON(SUBSTRING_INDEX(ip,'/',1)))) AND ((SUBSTRING( ip, 1, CHAR_LENGTH( ip ) -3 ) = "192.168.1.33" AND prefix IN (NULL,'')) OR (SUBSTRING( ip, 1, CHAR_LENGTH( ip ) -3 ) = "192.168.1.33" AND "97264" RLIKE prefix)) ORDER BY LENGTH(prefix) DESC LIMIT 1
2017-11-06 16:05:15.441577 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 6833949103]
2017-11-06 16:05:15.441577 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "6833949103" OR id="6833949103") AND status=0 AND deleted=0 AND (expiry >= '2017-11-06 10:35:15' OR expiry = '0000-00-00 00:00:00') limit 1
2017-11-06 16:05:15.461566 [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 ='^97264.*' OR patterns ='^9726.*' OR patterns ='^972.*' OR patterns ='^97.*' OR patterns ='^9.*' OR patterns ='--') AND status = 0 AND pricelist_id = 2 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 4
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 6833949103
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 100
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 2
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
2017-11-06 16:05:15.461566 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 2 AND status = 0
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100
2017-11-06 16:05:15.461566 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
2017-11-06 16:05:15.461566 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.username as username,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 username="97264" limit 1
2017-11-06 16:05:15.461566 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Starts
2017-11-06 16:05:15.461566 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Ends
2017-11-06 16:05:15.461566 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="att_xfer">
<condition field="destination_number" expression="^att_xfer$">
<action application="read" data="1 10 'tone_stream://%(10000,0,350,440)' digits 20000 #"/>
<action application="transfer" data="-bleg ${digits}"/>
</condition>
</extension>
<extension name="97264">
<condition field="destination_number" expression="97264">
<action application="set" data="effective_destination_number=97264"/>
<action application="sched_hangup" data="+6000 normal_clearing"/>
<action application="set" data="callstart=2017-11-06 10:35:15"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="set" data="continue_on_fail=true"/>
<action application="set" data="account_id=4"/>
<action application="set" data="parent_id=0"/>
<action application="set" data="entity_id=0"/>
<action application="set" data="call_processed=internal"/>
<action application="set" data="call_direction=local"/>
<action application="set" data="accountname=ketank"/>
<action application="set" data="origination_rates=ID:0|CODE:97264|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4"/>
<action application="set" data="original_caller_id_name=9110327518"/>
<action application="set" data="original_caller_id_number=9110327518"/>
<action application="set" data="effective_caller_id_name=9110327518"/>
<action application="set" data="effective_caller_id_number=9110327518"/>
<action application="set" data="calltype=LOCAL"/>
<action application="set" data="receiver_accid=2"/>
<action application="bind_meta_app" data="2 ab ab execute_extension::att_xfer XML default"/>
<action application="bridge" data="[leg_timeout=30]user/97264@${domain_name}"/>
<condition field="${cond(${user_data 97264@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
<action application="export" data="voicemail_alternate_greet_id=97264"/>
<action application="answer"/>
<action application="voicemail" data="default $${domain_name} 97264"/>
<anti-action application="hangup" data="${originate_disposition}"/>
</condition>
</condition>
</extension>
</context>
</section>
</document>
2017-11-06 16:05:15.461566 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa6f415e830 released.
Dialplan: sofia/default/9110327518@192.168.1.118 parsing [default->att_xfer] continue=false
Dialplan: sofia/default/9110327518@192.168.1.118 Regex (FAIL) [att_xfer] destination_number(97264) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/default/9110327518@192.168.1.118 parsing [default->97264] continue=false
Dialplan: sofia/default/9110327518@192.168.1.118 Regex (PASS) [97264] destination_number(97264) =~ /97264/ break=on-false
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(effective_destination_number=97264)
Dialplan: sofia/default/9110327518@192.168.1.118 Action sched_hangup(+6000 normal_clearing)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(callstart=2017-11-06 10:35:15)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(hangup_after_bridge=true)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(continue_on_fail=true)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(account_id=4)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(parent_id=0)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(entity_id=0)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(call_processed=internal)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(call_direction=local)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(accountname=ketank)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(origination_rates=ID:0|CODE:97264|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(original_caller_id_name=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(original_caller_id_number=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(effective_caller_id_name=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(effective_caller_id_number=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(calltype=LOCAL)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(receiver_accid=2)
Dialplan: sofia/default/9110327518@192.168.1.118 Action bind_meta_app(2 ab ab execute_extension::att_xfer XML default)
Dialplan: sofia/default/9110327518@192.168.1.118 Action bridge([leg_timeout=30]user/97264@${domain_name})
|--- Dialplan: Processing recursive conditions level:1 [97264_recur_1] require-nested=TRUE
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Regex (PASS) [97264_recur_1] ${cond(${user_data 97264@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Action export(voicemail_alternate_greet_id=97264)
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Action answer()
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Action voicemail(default $${domain_name} 97264)
2017-11-06 16:05:15.481576 [DEBUG] switch_core_state_machine.c:286 (sofia/default/9110327518@192.168.1.118) State Change CS_ROUTING -> CS_EXECUTE
2017-11-06 16:05:15.481576 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9110327518@192.168.1.118) State ROUTING going to sleep
2017-11-06 16:05:15.481576 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9110327518@192.168.1.118) Running State Change CS_EXECUTE (Cur 1 Tot 274)
2017-11-06 16:05:15.481576 [DEBUG] switch_core_state_machine.c:650 (sofia/default/9110327518@192.168.1.118) State EXECUTE
2017-11-06 16:05:15.481576 [DEBUG] mod_sofia.c:198 sofia/default/9110327518@192.168.1.118 SOFIA EXECUTE
2017-11-06 16:05:15.481576 [DEBUG] switch_core_state_machine.c:328 sofia/default/9110327518@192.168.1.118 Standard EXECUTE
EXECUTE sofia/default/9110327518@192.168.1.118 set(effective_destination_number=97264)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [effective_destination_number]=[97264]
EXECUTE sofia/default/9110327518@192.168.1.118 sched_hangup(+6000 normal_clearing)
2017-11-06 16:05:15.481576 [DEBUG] switch_scheduler.c:249 Added task 142 switch_ivr_schedule_hangup (d486e76a-fc5b-414d-81a2-0c62494e2a0e) to run at 1509970515
EXECUTE sofia/default/9110327518@192.168.1.118 set(callstart=2017-11-06 10:35:15)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [callstart]=[2017-11-06 10:35:15]
EXECUTE sofia/default/9110327518@192.168.1.118 set(hangup_after_bridge=true)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [hangup_after_bridge]=[true]
EXECUTE sofia/default/9110327518@192.168.1.118 set(continue_on_fail=true)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [continue_on_fail]=[true]
EXECUTE sofia/default/9110327518@192.168.1.118 set(account_id=4)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [account_id]=[4]
EXECUTE sofia/default/9110327518@192.168.1.118 set(parent_id=0)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [parent_id]=[0]
EXECUTE sofia/default/9110327518@192.168.1.118 set(entity_id=0)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [entity_id]=[0]
EXECUTE sofia/default/9110327518@192.168.1.118 set(call_processed=internal)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [call_processed]=[internal]
EXECUTE sofia/default/9110327518@192.168.1.118 set(call_direction=local)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [call_direction]=[local]
EXECUTE sofia/default/9110327518@192.168.1.118 set(accountname=ketank)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [accountname]=[ketank]
EXECUTE sofia/default/9110327518@192.168.1.118 set(origination_rates=ID:0|CODE:97264|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [origination_rates]=[ID:0|CODE:97264|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4]
EXECUTE sofia/default/9110327518@192.168.1.118 set(original_caller_id_name=9110327518)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [original_caller_id_name]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(original_caller_id_number=9110327518)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [original_caller_id_number]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(effective_caller_id_name=9110327518)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [effective_caller_id_name]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(effective_caller_id_number=9110327518)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [effective_caller_id_number]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(calltype=LOCAL)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [calltype]=[LOCAL]
EXECUTE sofia/default/9110327518@192.168.1.118 set(receiver_accid=2)
2017-11-06 16:05:15.481576 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [receiver_accid]=[2]
EXECUTE sofia/default/9110327518@192.168.1.118 bind_meta_app(2 ab ab execute_extension::att_xfer XML default)
2017-11-06 16:05:15.481576 [ERR] mod_dptools.c:747 Cannot bind execute to multiple legs
2017-11-06 16:05:15.481576 [INFO] switch_ivr_async.c:4165 Bound A-Leg: *2 execute_extension::att_xfer XML default
2017-11-06 16:05:15.481576 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *2 execute_extension::att_xfer XML default
EXECUTE sofia/default/9110327518@192.168.1.118 bridge([leg_timeout=30]user/97264@192.168.1.118)
2017-11-06 16:05:15.481576 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-11-06 16:05:15.481576 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
2017-11-06 16:05:15.501572 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-11-06 16:05:15.501572 [NOTICE] switch_channel.c:1104 New Channel sofia/default/97264@192.168.1.161:5060 [a36afe8f-cd01-462f-a412-7eb301532ad6]
2017-11-06 16:05:15.501572 [DEBUG] mod_sofia.c:4819 (sofia/default/97264@192.168.1.161:5060) State Change CS_NEW -> CS_INIT
2017-11-06 16:05:15.501572 [DEBUG] switch_ivr_originate.c:2963 sofia/default/97264@192.168.1.161:5060 Setting leg timeout to 30
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_INIT (Cur 2 Tot 275)
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:627 (sofia/default/97264@192.168.1.161:5060) State INIT
2017-11-06 16:05:15.501572 [DEBUG] mod_sofia.c:90 sofia/default/97264@192.168.1.161:5060 SOFIA INIT
2017-11-06 16:05:15.501572 [DEBUG] sofia_glue.c:1295 sofia/default/97264@192.168.1.161:5060 sending invite version: 1.6.18 64bit
Local SDP:
v=0
o=FreeSWITCH 1509940855 1509940856 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 23660 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
send 1106 bytes to udp/[192.168.1.161]:5060 at 16:05:15.508554:
------------------------------------------------------------------------
INVITE sip:97264@192.168.1.161:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bKZ38K9r16m1X3S
Max-Forwards: 69
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646193 INVITE
Contact: <sip:mod_sofia@192.168.1.118:5060>
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 246
Remote-Party-ID: "9110327518" <sip:9110327518@192.168.1.118>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1509940855 1509940856 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 23660 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:40 sofia/default/97264@192.168.1.161:5060 Standard INIT
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:48 (sofia/default/97264@192.168.1.161:5060) State Change CS_INIT -> CS_ROUTING
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:627 (sofia/default/97264@192.168.1.161:5060) State INIT going to sleep
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_ROUTING (Cur 2 Tot 275)
2017-11-06 16:05:15.501572 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [calling][0]
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:643 (sofia/default/97264@192.168.1.161:5060) State ROUTING
2017-11-06 16:05:15.501572 [DEBUG] mod_sofia.c:143 sofia/default/97264@192.168.1.161:5060 SOFIA ROUTING
2017-11-06 16:05:15.501572 [DEBUG] switch_ivr_originate.c:67 (sofia/default/97264@192.168.1.161:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:643 (sofia/default/97264@192.168.1.161:5060) State ROUTING going to sleep
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 275)
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:662 (sofia/default/97264@192.168.1.161:5060) State CONSUME_MEDIA
2017-11-06 16:05:15.501572 [DEBUG] switch_core_state_machine.c:662 (sofia/default/97264@192.168.1.161:5060) State CONSUME_MEDIA going to sleep
recv 455 bytes from udp/[192.168.1.161]:5060 at 16:05:15.524651:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.118;rport=5060;branch=z9hG4bKZ38K9r16m1X3S
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646193 INVITE
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
recv 538 bytes from udp/[192.168.1.161]:5060 at 16:05:15.530792:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.118;rport=5060;branch=z9hG4bKZ38K9r16m1X3S
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646193 INVITE
Contact: <sip:97264@192.168.1.161:5060>
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow-Events: talk, hold
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:15.701619 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [proceeding][180]
2017-11-06 16:05:15.701619 [NOTICE] sofia.c:7156 Ring-Ready sofia/default/97264@192.168.1.161:5060!
2017-11-06 16:05:15.701619 [DEBUG] switch_channel.c:3346 (sofia/default/97264@192.168.1.161:5060) Callstate Change DOWN -> RINGING
send 748 bytes to tcp/[192.168.1.33]:48236 at 16:05:15.730865:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-67ee28e05cbeb2f4-1---d8754z-;rport=48236
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=c325a037
To: <sip:97264@192.168.1.118;transport=TCP>;tag=SZjyDeXtKraej
Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
CSeq: 1 INVITE
Contact: <sip:97264@192.168.1.118:5060;transport=tcp>
User-Agent: Local
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:15.721622 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/9110327518@192.168.1.118!
2017-11-06 16:05:15.721622 [DEBUG] sofia.c:7048 Channel sofia/default/9110327518@192.168.1.118 entering state [early][180]
2017-11-06 16:05:15.721622 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/9110327518@192.168.1.118!
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:16.107439:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bKytFU7Xg3Qr7ge
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=t8BQF9Dyg100D
To: <sip:1.1.1.1>
Call-ID: 045637c8-3d81-1236-c4b6-000c29f46286
CSeq: 114465670 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:16.301622 [WARNING] sofia.c:6098 Ping failed KK with code 503 - count 1/0/1, state DOWN
recv 336 bytes from udp/[192.168.1.119]:6060 at 16:05:18.074261:
------------------------------------------------------------------------
OPTIONS sip:192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bKf048.fc4e53e2.0
To: sip:192.168.1.118:5060
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-9838
CSeq: 14 OPTIONS
Call-ID: 19f406c45d424ea9-10323@192.168.1.119
Max-Forwards: 70
Content-Length: 0
User-Agent: SBC
------------------------------------------------------------------------
send 702 bytes to udp/[192.168.1.119]:6060 at 16:05:18.074740:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bKf048.fc4e53e2.0;received=192.168.1.119
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-9838
To: <sip:192.168.1.118:5060>;tag=X3Q1mt087U3rg
Call-ID: 19f406c45d424ea9-10323@192.168.1.119
CSeq: 14 OPTIONS
Contact: <sip:192.168.1.118>
User-Agent: Local
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
recv 780 bytes from udp/[192.168.1.161]:5060 at 16:05:24.395817:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.118;rport=5060;branch=z9hG4bKZ38K9r16m1X3S
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646193 INVITE
Contact: <sip:97264@192.168.1.161:5060>
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Content-Length: 238
v=0
o=97264 8000 8000 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 192.168.1.161
t=0 0
m=audio 5004 RTP/AVP 8 0 101
a=sendrecv
a=rtpmap:8 PCMA/8000
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
------------------------------------------------------------------------
2017-11-06 16:05:24.421622 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [completing][200]
2017-11-06 16:05:24.421622 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=97264 8000 8000 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 192.168.1.161
t=0 0
m=audio 5004 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
send 380 bytes to udp/[192.168.1.161]:5060 at 16:05:24.430877:
------------------------------------------------------------------------
ACK sip:97264@192.168.1.161:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK0c2cBmjajampN
Max-Forwards: 70
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646193 ACK
Contact: <sip:mod_sofia@192.168.1.118:5060>
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:24.421622 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [ready][200]
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:3057 Set Codec sofia/default/97264@192.168.1.161:5060 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-06 16:05:24.421622 [DEBUG] switch_core_codec.c:111 sofia/default/97264@192.168.1.161:5060 Original read codec set to PCMA:8
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:4763 sofia/default/97264@192.168.1.161:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/default/97264@192.168.1.161:5060] 192.168.1.118 port 23660 -> 192.168.1.161 port 5004 codec: 8 ms: 20
2017-11-06 16:05:24.421622 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:7175 sofia/default/97264@192.168.1.161:5060 Set 2833 dtmf send payload to 101
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:7182 sofia/default/97264@192.168.1.161:5060 Set 2833 dtmf receive payload to 101
2017-11-06 16:05:24.421622 [DEBUG] switch_core_media.c:7205 sofia/default/97264@192.168.1.161:5060 Set rtp dtmf delay to 40
2017-11-06 16:05:24.421622 [NOTICE] sofia.c:8182 Channel [sofia/default/97264@192.168.1.161:5060] has been answered
2017-11-06 16:05:24.421622 [DEBUG] switch_channel.c:3773 (sofia/default/97264@192.168.1.161:5060) Callstate Change RINGING -> ACTIVE
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:3057 Set Codec sofia/default/9110327518@192.168.1.118 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-06 16:05:24.461569 [DEBUG] switch_core_codec.c:111 sofia/default/9110327518@192.168.1.118 Original read codec set to PCMA:8
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:4763 sofia/default/9110327518@192.168.1.118 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/default/9110327518@192.168.1.118] 192.168.1.118 port 31498 -> 117.247.91.162 port 8000 codec: 8 ms: 20
2017-11-06 16:05:24.461569 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:7175 sofia/default/9110327518@192.168.1.118 Set 2833 dtmf send payload to 101
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:7182 sofia/default/9110327518@192.168.1.118 Set 2833 dtmf receive payload to 101
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:7205 sofia/default/9110327518@192.168.1.118 Set rtp dtmf delay to 40
2017-11-06 16:05:24.461569 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/9110327518@192.168.1.118!
2017-11-06 16:05:24.461569 [DEBUG] switch_channel.c:3474 (sofia/default/9110327518@192.168.1.118) Callstate Change RINGING -> EARLY
2017-11-06 16:05:24.461569 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/default/9110327518@192.168.1.118.
2017-11-06 16:05:24.461569 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/9110327518@192.168.1.118:
v=0
o=FreeSWITCH 1509933026 1509933027 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 31498 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
send 1003 bytes to tcp/[192.168.1.33]:48236 at 16:05:24.476627:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-67ee28e05cbeb2f4-1---d8754z-;rport=48236
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=c325a037
To: <sip:97264@192.168.1.118;transport=TCP>;tag=SZjyDeXtKraej
Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
CSeq: 1 INVITE
Contact: <sip:97264@192.168.1.118:5060;transport=tcp>
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 222
v=0
o=FreeSWITCH 1509933026 1509933027 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 31498 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2017-11-06 16:05:24.461569 [DEBUG] sofia.c:7048 Channel sofia/default/9110327518@192.168.1.118 entering state [completed][200]
2017-11-06 16:05:24.461569 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/default/9110327518@192.168.1.118] has been answered
2017-11-06 16:05:24.461569 [DEBUG] switch_channel.c:3773 (sofia/default/9110327518@192.168.1.118) Callstate Change EARLY -> ACTIVE
2017-11-06 16:05:24.461569 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/97264@192.168.1.161:5060]
2017-11-06 16:05:24.461569 [DEBUG] switch_ivr_originate.c:2963 sofia/default/97264@192.168.1.161:5060 Setting leg timeout to 30
2017-11-06 16:05:24.461569 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/97264@192.168.1.161:5060]
recv 473 bytes from tcp/[192.168.1.33]:48236 at 16:05:24.480742:
------------------------------------------------------------------------
ACK sip:97264@192.168.1.118:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 192.168.1.33:58810;branch=z9hG4bK-d8754z-e1b7840bc29c2aeb-1---d8754z-
Max-Forwards: 70
Contact: <sip:9110327518@117.247.91.162:58810;transport=TCP>
To: <sip:97264@192.168.1.118;transport=TCP>;tag=SZjyDeXtKraej
From: <sip:9110327518@192.168.1.118;transport=TCP>;tag=c325a037
Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
CSeq: 1 ACK
User-Agent: Z 3.3.25608 r25552
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:24.481563 [DEBUG] sofia.c:7048 Channel sofia/default/9110327518@192.168.1.118 entering state [ready][200]
2017-11-06 16:05:24.521620 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/97264@192.168.1.161:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2017-11-06 16:05:24.521620 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 275)
2017-11-06 16:05:24.521620 [DEBUG] switch_core_state_machine.c:653 (sofia/default/97264@192.168.1.161:5060) State EXCHANGE_MEDIA
2017-11-06 16:05:24.521620 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
send 917 bytes to udp/[192.168.1.161]:5060 at 16:05:24.534322:
------------------------------------------------------------------------
UPDATE sip:97264@192.168.1.161:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK1NU5cF3DFKa9g
Max-Forwards: 70
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646194 UPDATE
Contact: <sip:mod_sofia@192.168.1.118:5060>
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 246
P-Asserted-Identity: "9110327518" <sip:9110327518@192.168.1.118>
v=0
o=FreeSWITCH 1509940855 1509940856 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 23660 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2017-11-06 16:05:24.521620 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [calling][0]
2017-11-06 16:05:24.601651 [DEBUG] switch_rtp.c:7254 Correct audio ip/port confirmed.
2017-11-06 16:05:24.721576 [INFO] switch_rtp.c:7214 Auto Changing audio port from 117.247.91.162:8000 to 192.168.1.33:8000
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
recv 780 bytes from udp/[192.168.1.161]:5060 at 16:05:25.394068:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.118;rport=5060;branch=z9hG4bK1NU5cF3DFKa9g
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646194 UPDATE
Contact: <sip:97264@192.168.1.161:5060>
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Content-Length: 238
v=0
o=97264 8000 8001 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 192.168.1.161
t=0 0
m=audio 5004 RTP/AVP 8 0 101
a=sendrecv
a=rtpmap:8 PCMA/8000
a=ptime:20
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
------------------------------------------------------------------------
2017-11-06 16:05:25.381620 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [ready][200]
2017-11-06 16:05:25.381620 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=97264 8000 8001 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 192.168.1.161
t=0 0
m=audio 5004 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:4763 sofia/default/97264@192.168.1.161:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-06 16:05:25.381620 [DEBUG] sofia.c:8025 Processing updated SDP
2017-11-06 16:05:25.381620 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/default/97264@192.168.1.161:5060.
freeswitch@freeswitch>
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:26.138487:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK2ymyeamHcv0Uc
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=ZNaKrg2F2DgyQ
To: <sip:1.1.1.1>
Call-ID: 0ae98937-3d81-1236-c4b6-000c29f46286
CSeq: 114465671 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:27.138748:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK2ymyeamHcv0Uc
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=ZNaKrg2F2DgyQ
To: <sip:1.1.1.1>
Call-ID: 0ae98937-3d81-1236-c4b6-000c29f46286
CSeq: 114465671 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:27.181571 [WARNING] sofia.c:6098 Ping failed KK with code 503 - count 1/0/1, state DOWN
recv 336 bytes from udp/[192.168.1.119]:6060 at 16:05:27.983777:
------------------------------------------------------------------------
OPTIONS sip:192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bKe348.0a4b0bf7.0
To: sip:192.168.1.118:5060
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-6dde
CSeq: 14 OPTIONS
Call-ID: 19f406c45d424eaa-10323@192.168.1.119
Max-Forwards: 70
Content-Length: 0
User-Agent: SBC
------------------------------------------------------------------------
send 702 bytes to udp/[192.168.1.119]:6060 at 16:05:27.984246:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bKe348.0a4b0bf7.0;received=192.168.1.119
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-6dde
To: <sip:192.168.1.118:5060>;tag=17v4U63pvZv3e
Call-ID: 19f406c45d424eaa-10323@192.168.1.119
CSeq: 14 OPTIONS
Contact: <sip:192.168.1.118>
User-Agent: Local
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 871 bytes from udp/[192.168.1.161]:5060 at 16:05:28.915748:
------------------------------------------------------------------------
INVITE sip:mod_sofia@192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK1547255204;rport
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646194 INVITE
Contact: <sip:97264@192.168.1.161:5060>
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Type: application/sdp
Accept: application/sdp, application/dtmf-relay
Content-Length: 232
v=0
o=97264 8000 8002 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 0.0.0.0
t=0 0
m=audio 5004 RTP/AVP 0 8 101
a=sendonly
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
------------------------------------------------------------------------
send 324 bytes to udp/[192.168.1.161]:5060 at 16:05:28.916040:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK1547255204;rport=5060
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646194 INVITE
User-Agent: Local
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:28.921568 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [received][100]
2017-11-06 16:05:28.921568 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=97264 8000 8002 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 0.0.0.0
t=0 0
m=audio 5004 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendonly
a=ptime:20
2017-11-06 16:05:28.921568 [WARNING] switch_core_media.c:3947 RFC2543 from March 1999 called; They want their 0.0.0.0 hold method back.....
2017-11-06 16:05:28.921568 [DEBUG] switch_channel.c:1844 (sofia/default/97264@192.168.1.161:5060) Callstate Change ACTIVE -> HELD
2017-11-06 16:05:29.081567 [DEBUG] switch_ivr.c:623 sofia/default/9110327518@192.168.1.118 Command Execute playback(local_stream://moh)
EXECUTE sofia/default/9110327518@192.168.1.118 playback(local_stream://moh)
2017-11-06 16:05:29.081567 [DEBUG] mod_local_stream.c:871 Opening Stream [moh/8000] 8000hz
2017-11-06 16:05:29.081567 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:4763 sofia/default/97264@192.168.1.161:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:6863 Audio params changed for sofia/default/97264@192.168.1.161:5060 from 192.168.1.161:5004 to 0.0.0.0:5004
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/default/97264@192.168.1.161:5060] 192.168.1.118 port 23660 -> 0.0.0.0 port 5004 codec: 8 ms: 20
2017-11-06 16:05:29.181619 [DEBUG] switch_core_media.c:6903 AUDIO RTP CHANGING DEST TO: [0.0.0.0:5004]
2017-11-06 16:05:29.181619 [DEBUG] sofia.c:7963 Processing updated SDP
send 824 bytes to udp/[192.168.1.161]:5060 at 16:05:29.187408:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK1547255204;rport=5060
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646194 INVITE
Contact: <sip:mod_sofia@192.168.1.118:5060>
User-Agent: Local
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 234
v=0
o=FreeSWITCH 1509940855 1509940857 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 23660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=recvonly
a=ptime:20
------------------------------------------------------------------------
2017-11-06 16:05:29.181619 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [completed][200]
recv 548 bytes from udp/[192.168.1.161]:5060 at 16:05:29.201926:
------------------------------------------------------------------------
ACK sip:mod_sofia@192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK102781381;rport
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646194 ACK
Contact: <sip:97264@192.168.1.161:5060>
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:29.201572 [DEBUG] sofia.c:7048 Channel sofia/default/97264@192.168.1.161:5060 entering state [ready][200]
recv 629 bytes from udp/[192.168.1.161]:5060 at 16:05:33.438325:
------------------------------------------------------------------------
REFER sip:mod_sofia@192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK203492676;rport
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646195 REFER
Contact: <sip:97264@192.168.1.161:5060>
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Refer-To: <sip:97265@192.168.1.118>
Referred-By: <sip:97264@192.168.1.118>
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
send 690 bytes to udp/[192.168.1.161]:5060 at 16:05:33.445796:
------------------------------------------------------------------------
SIP/2.0 202 Accepted
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK203492676;rport=5060
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646195 REFER
Contact: <sip:mod_sofia@192.168.1.118:5060>
Expires: 60
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.441570 [DEBUG] sofia.c:8508 Process REFER to [97265@192.168.1.118]
send 850 bytes to udp/[192.168.1.161]:5060 at 16:05:33.446138:
------------------------------------------------------------------------
NOTIFY sip:97264@192.168.1.161:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK37DQg54m94per
Max-Forwards: 70
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646195 NOTIFY
Contact: <sip:mod_sofia@192.168.1.118:5060>
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Event: refer;id=114646195
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Subscription-State: terminated;reason=noresource
Content-Type: message/sipfrag;version=2.0
Content-Length: 16
SIP/2.0 200 OK
------------------------------------------------------------------------
2017-11-06 16:05:33.441570 [DEBUG] switch_ivr.c:2165 (sofia/default/9110327518@192.168.1.118) State Change CS_EXECUTE -> CS_ROUTING
2017-11-06 16:05:33.441570 [NOTICE] switch_ivr.c:2172 Transfer sofia/default/9110327518@192.168.1.118 to XML[97265@default]
2017-11-06 16:05:33.441570 [DEBUG] switch_ivr_play_say.c:1942 done playing file local_stream://moh
2017-11-06 16:05:33.461580 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/97264@192.168.1.161:5060]
2017-11-06 16:05:33.461580 [DEBUG] switch_channel.c:2029 (sofia/default/97264@192.168.1.161:5060) Callstate Change HELD -> UNHELD
2017-11-06 16:05:33.461580 [NOTICE] switch_ivr_bridge.c:904 Hangup sofia/default/97264@192.168.1.161:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:653 (sofia/default/97264@192.168.1.161:5060) State EXCHANGE_MEDIA going to sleep
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_HANGUP (Cur 2 Tot 275)
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:850 (sofia/default/97264@192.168.1.161:5060) Callstate Change UNHELD -> HANGUP
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:852 (sofia/default/97264@192.168.1.161:5060) State HANGUP
2017-11-06 16:05:33.461580 [DEBUG] mod_sofia.c:438 Channel sofia/default/97264@192.168.1.161:5060 hanging up, cause: NORMAL_CLEARING
2017-11-06 16:05:33.461580 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/9110327518@192.168.1.118]
2017-11-06 16:05:33.461580 [DEBUG] switch_ivr_bridge.c:1712 sofia/default/97264@192.168.1.161:5060 skip receive message [UNBRIDGE] (channel is hungup already)
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:650 (sofia/default/9110327518@192.168.1.118) State EXECUTE going to sleep
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9110327518@192.168.1.118) Running State Change CS_ROUTING (Cur 2 Tot 275)
2017-11-06 16:05:33.461580 [DEBUG] switch_channel.c:2249 (sofia/default/9110327518@192.168.1.118) Callstate Change ACTIVE -> RINGING
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9110327518@192.168.1.118) State ROUTING
2017-11-06 16:05:33.461580 [DEBUG] mod_sofia.c:143 sofia/default/9110327518@192.168.1.118 SOFIA ROUTING
2017-11-06 16:05:33.461580 [DEBUG] switch_core_state_machine.c:236 sofia/default/9110327518@192.168.1.118 Standard ROUTING
2017-11-06 16:05:33.461580 [INFO] mod_dialplan_xml.c:637 Processing 9110327518 <9110327518>->97265 in context default
2017-11-06 16:05:33.461580 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa6d801e830 Connected.
2017-11-06 16:05:33.461580 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2017-11-06 16:05:33.481581 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [xml_handler] Params:
'Event-Name: REQUEST_PARAMS
Core-UUID: b8b0770f-83a5-4654-b268-e2c6ae265441
FreeSWITCH-Hostname: astpptest1
FreeSWITCH-Switchname: freeswitch
FreeSWITCH-IPv4: 192.168.1.118
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2017-11-06%2016%3A05%3A33
Event-Date-GMT: Mon,%2006%20Nov%202017%2010%3A35%3A33%20GMT
Event-Date-Timestamp: 1509964533461580
Event-Calling-File: mod_dialplan_xml.c
Event-Calling-Function: dialplan_xml_locate
Event-Calling-Line-Number: 608
Event-Sequence: 75044
Channel-State: CS_ROUTING
Channel-Call-State: RINGING
Channel-State-Number: 2
Channel-Name: sofia/default/9110327518%40192.168.1.118
Unique-ID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Call-Direction: inbound
Presence-Call-Direction: inbound
Channel-HIT-Dialplan: true
Channel-Presence-ID: 9110327518%40192.168.1.118
Channel-Call-UUID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Answer-State: answered
Channel-Read-Codec-Name: PCMA
Channel-Read-Codec-Rate: 8000
Channel-Read-Codec-Bit-Rate: 64000
Channel-Write-Codec-Name: PCMA
Channel-Write-Codec-Rate: 8000
Channel-Write-Codec-Bit-Rate: 64000
Caller-Direction: inbound
Caller-Logical-Direction: inbound
Caller-Username: 9110327518
Caller-Dialplan: XML
Caller-Caller-ID-Name: 9110327518
Caller-Caller-ID-Number: 9110327518
Caller-Orig-Caller-ID-Name: 9110327518
Caller-Orig-Caller-ID-Number: 9110327518
Caller-Callee-ID-Name: Outbound%20Call
Caller-Callee-ID-Number: 97264
Caller-Network-Addr: 192.168.1.33
Caller-ANI: 9110327518
Caller-Destination-Number: 97265
Caller-Unique-ID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Caller-Source: mod_sofia
Caller-Transfer-Source: 1509964533%3A196e5e30-f8ea-4f36-8b0e-1330c770d8f8%3Abl_xfer%3A97265/default/XML
Caller-Context: default
Caller-RDNIS: 97264
Caller-Channel-Name: sofia/default/9110327518%40192.168.1.118
Caller-Profile-Index: 2
Caller-Profile-Created-Time: 1509964533441570
Caller-Channel-Created-Time: 1509964514981576
Caller-Channel-Answered-Time: 1509964524461569
Caller-Channel-Progress-Time: 1509964515701619
Caller-Channel-Progress-Media-Time: 1509964524461569
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: d486e76a-fc5b-414d-81a2-0c62494e2a0e
variable_session_id: 274
variable_sip_from_params: transport%3DTCP
variable_sip_from_user: 9110327518
variable_sip_from_uri: 9110327518%40192.168.1.118
variable_sip_from_host: 192.168.1.118
variable_video_media_flow: sendrecv
variable_channel_name: sofia/default/9110327518%40192.168.1.118
variable_ep_codec_string: CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b
variable_sip_local_network_addr: 192.168.1.118
variable_sip_network_ip: 192.168.1.33
variable_sip_network_port: 48236
variable_sip_invite_stamp: 1509964514981576
variable_sip_received_ip: 192.168.1.33
variable_sip_received_port: 48236
variable_sip_via_protocol: tcp
variable_sip_authorized: true
variable_sip_acl_authed_by: default
variable_sip_from_user_stripped: 9110327518
variable_sofia_profile_name: default
variable_recovery_profile_name: default
variable_sip_allow: INVITE,%20ACK,%20CANCEL,%20BYE,%20NOTIFY,%20REFER,%20MESSAGE,%20OPTIONS,%20INFO,%20SUBSCRIBE
variable_sip_req_params: transport%3DTCP
variable_sip_req_user: 97264
variable_sip_req_uri: 97264%40192.168.1.118
variable_sip_req_host: 192.168.1.118
variable_sip_to_params: transport%3DTCP
variable_sip_to_user: 97264
variable_sip_to_uri: 97264%40192.168.1.118
variable_sip_to_host: 192.168.1.118
variable_sip_contact_params: transport%3DTCP
variable_sip_contact_user: 9110327518
variable_sip_contact_port: 58810
variable_sip_contact_uri: 9110327518%40117.247.91.162%3A58810
variable_sip_contact_host: 117.247.91.162
variable_sip_user_agent: Z%203.3.25608%20r25552
variable_sip_via_host: 192.168.1.33
variable_sip_via_port: 58810
variable_sip_via_rport: 48236
variable_presence_id: 9110327518%40192.168.1.118
variable_switch_r_sdp: v%3D0%0D%0Ao%3DZ%200%200%20IN%20IP4%20117.247.91.162%0D%0As%3DZ%0D%0Ac%3DIN%20IP4%20117.247.91.162%0D%0At%3D0%200%0D%0Am%3Daudio%208000%20RTP/AVP%203%20110%208%200%2098%20101%0D%0Aa%3Drtpmap%3A110%20speex/8000%0D%0Aa%3Drtpmap%3A98%20iLBC/8000%0D%0Aa%3Dfmtp%3A98%20mode%3D20%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-15%0D%0A
variable_effective_destination_number: 97264
variable_callstart: 2017-11-06%2010%3A35%3A15
variable_hangup_after_bridge: true
variable_continue_on_fail: true
variable_account_id: 4
variable_parent_id: 0
variable_entity_id: 0
variable_call_processed: internal
variable_call_direction: local
variable_accountname: ketank
variable_origination_rates: ID%3A0%7CCODE%3A97264%7CDESTINATION%3ALocal%7CCONNECTIONCOST%3A0%7CINCLUDEDSECONDS%3A0%7CCOST%3A0%7CINC%3A60%7CINITIALBLOCK%3A0%7CRATEGROUP%3A2%7CMARKUP%3A0%7CACCID%3A4
variable_original_caller_id_name: 9110327518
variable_original_caller_id_number: 9110327518
variable_effective_caller_id_name: 9110327518
variable_effective_caller_id_number: 9110327518
variable_calltype: LOCAL
variable_receiver_accid: 2
variable_dialed_user: 97264
variable_dialed_domain: 192.168.1.118
variable_originated_legs: ARRAY%3A%3Aa36afe8f-cd01-462f-a412-7eb301532ad6%3BOutbound%20Call%3B97264%7C%3Aa36afe8f-cd01-462f-a412-7eb301532ad6%3BOutbound%20Call%3B97264
variable_rtp_use_codec_string: PCMA,PCMU
variable_audio_media_flow: sendrecv
variable_rtp_audio_recv_pt: 8
variable_rtp_use_codec_name: PCMA
variable_rtp_use_codec_rate: 8000
variable_rtp_use_codec_ptime: 20
variable_rtp_use_codec_channels: 1
variable_rtp_last_audio_codec_string: PCMA%408000h%4020i%401c
variable_read_codec: PCMA
variable_original_read_codec: PCMA
variable_read_rate: 8000
variable_original_read_rate: 8000
variable_write_codec: PCMA
variable_write_rate: 8000
variable_dtmf_type: rfc2833
variable_local_media_ip: 192.168.1.118
variable_local_media_port: 31498
variable_advertised_media_ip: 192.168.1.118
variable_rtp_use_timer_name: soft
variable_rtp_use_pt: 8
variable_rtp_use_ssrc: 1174983138
variable_rtp_2833_send_payload: 101
variable_rtp_2833_recv_payload: 101
variable_remote_media_ip: 117.247.91.162
variable_remote_media_port: 8000
variable_rtp_local_sdp_str: v%3D0%0D%0Ao%3DFreeSWITCH%201509933026%201509933027%20IN%20IP4%20192.168.1.118%0D%0As%3DFreeSWITCH%0D%0Ac%3DIN%20IP4%20192.168.1.118%0D%0At%3D0%200%0D%0Am%3Daudio%2031498%20RTP/AVP%208%20101%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-16%0D%0Aa%3Dptime%3A20%0D%0Aa%3Dsendrecv%0D%0A
variable_sip_nat_detected: true
variable_endpoint_disposition: ANSWER
variable_originate_causes: ARRAY%3A%3Aa36afe8f-cd01-462f-a412-7eb301532ad6%3BNONE%7C%3Aa36afe8f-cd01-462f-a412-7eb301532ad6%3BNONE
variable_originate_disposition: SUCCESS
variable_DIALSTATUS: SUCCESS
variable_sip_to_tag: SZjyDeXtKraej
variable_sip_from_tag: c325a037
variable_sip_cseq: 1
variable_sip_call_id: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM.
variable_sip_full_via: SIP/2.0/TCP%20192.168.1.33%3A58810%3Bbranch%3Dz9hG4bK-d8754z-e1b7840bc29c2aeb-1---d8754z-%3Brport%3D48236
variable_sip_recover_via: SIP/2.0/TCP%20192.168.1.33%3A58810%3Bbranch%3Dz9hG4bK-d8754z-e1b7840bc29c2aeb-1---d8754z-%3Brport%3D48236
variable_sip_full_from: %3Csip%3A9110327518%40192.168.1.118%3Btransport%3DTCP%3E%3Btag%3Dc325a037
variable_sip_full_to: %3Csip%3A97264%40192.168.1.118%3Btransport%3DTCP%3E%3Btag%3DSZjyDeXtKraej
variable_last_bridge_to: a36afe8f-cd01-462f-a412-7eb301532ad6
variable_bridge_channel: sofia/default/97264%40192.168.1.161%3A5060
variable_bridge_uuid: a36afe8f-cd01-462f-a412-7eb301532ad6
variable_last_sent_callee_id_name: Outbound%20Call
variable_last_sent_callee_id_number: 97264
variable_remote_audio_ip_reported: 117.247.91.162
variable_remote_audio_ip: 192.168.1.33
variable_remote_audio_port_reported: 8000
variable_remote_audio_port: 8000
variable_rtp_auto_adjust_audio: true
variable_switch_m_sdp: v%3D0%0D%0Ao%3D97264%208000%208002%20IN%20IP4%20192.168.1.161%0D%0As%3DSIP%20Call%0D%0Ac%3DIN%20IP4%200.0.0.0%0D%0At%3D0%200%0D%0Am%3Daudio%205004%20RTP/AVP%200%208%20101%0D%0Aa%3Drtpmap%3A0%20PCMU/8000%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-15%0D%0Aa%3Dsendonly%0D%0Aa%3Dptime%3A20%0D%0A
variable_current_application_data: local_stream%3A//moh
variable_current_application: playback
variable_sip_h_Referred-By: %3Csip%3A97264%40192.168.1.118%3E
variable_sip_refer_to: %3Csip%3A97265%40192.168.1.118%3E
variable_max_forwards: 69
variable_transfer_history: 1509964533%3A196e5e30-f8ea-4f36-8b0e-1330c770d8f8%3Abl_xfer%3A97265/default/XML
variable_transfer_source: 1509964533%3A196e5e30-f8ea-4f36-8b0e-1330c770d8f8%3Abl_xfer%3A97265/default/XML
variable_playback_last_offset_pos: 34880
variable_playback_seconds: 4
variable_playback_ms: 4570
variable_playback_samples: 36560
variable_current_application_response: PLAYBACK%20ERROR
variable_bridge_hangup_cause: NORMAL_CLEARING
variable_call_uuid: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Hunt-Direction: inbound
Hunt-Logical-Direction: inbound
Hunt-Username: 9110327518
Hunt-Dialplan: XML
Hunt-Caller-ID-Name: 9110327518
Hunt-Caller-ID-Number: 9110327518
Hunt-Orig-Caller-ID-Name: 9110327518
Hunt-Orig-Caller-ID-Number: 9110327518
Hunt-Callee-ID-Name: Outbound%20Call
Hunt-Callee-ID-Number: 97264
Hunt-Network-Addr: 192.168.1.33
Hunt-ANI: 9110327518
Hunt-Destination-Number: 97265
Hunt-Unique-ID: d486e76a-fc5b-414d-81a2-0c62494e2a0e
Hunt-Source: mod_sofia
Hunt-Transfer-Source: 1509964533%3A196e5e30-f8ea-4f36-8b0e-1330c770d8f8%3Abl_xfer%3A97265/default/XML
Hunt-Context: default
Hunt-RDNIS: 97264
Hunt-Channel-Name: sofia/default/9110327518%40192.168.1.118
Hunt-Profile-Index: 2
Hunt-Profile-Created-Time: 1509964533441570
Hunt-Channel-Created-Time: 1509964514981576
Hunt-Channel-Answered-Time: 1509964524461569
Hunt-Channel-Progress-Time: 1509964515701619
Hunt-Channel-Progress-Media-Time: 1509964524461569
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
'
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_name:
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_value:
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] section: dialplan
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] tag_name:
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 97265
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number : 9110327518 / 9110327518
2017-11-06 16:05:33.481581 [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.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 ="97265" LIMIT 1
2017-11-06 16:05:33.481581 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.username as username,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 username="97265" limit 1
2017-11-06 16:05:33.481581 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : local
2017-11-06 16:05:33.481581 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [IPAUTHENTICATION] Query :SELECT ip_map.*, (SELECT number FROM accounts where id=accountid AND status=0 AND deleted=0) AS account_code FROM ip_map WHERE ((INET_ATON("192.168.1.33") & (0xFFFFFFFF & (-1 << 32 - SUBSTRING_INDEX(ip, '/',-1)))) = ((0xFFFFFFFF & (-1 << 32 - SUBSTRING_INDEX(ip, '/',-1))) & INET_ATON(SUBSTRING_INDEX(ip,'/',1)))) AND ((SUBSTRING( ip, 1, CHAR_LENGTH( ip ) -3 ) = "192.168.1.33" AND prefix IN (NULL,'')) OR (SUBSTRING( ip, 1, CHAR_LENGTH( ip ) -3 ) = "192.168.1.33" AND "97265" RLIKE prefix)) ORDER BY LENGTH(prefix) DESC LIMIT 1
2017-11-06 16:05:33.481581 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 6833949103]
2017-11-06 16:05:33.481581 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "6833949103" OR id="6833949103") AND status=0 AND deleted=0 AND (expiry >= '2017-11-06 10:35:33' OR expiry = '0000-00-00 00:00:00') limit 1
recv 507 bytes from udp/[192.168.1.161]:5060 at 16:05:33.491003:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.118;rport=5060;branch=z9hG4bK37DQg54m94per
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646195 NOTIFY
Contact: <sip:97264@192.168.1.161:5060>
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.501565 [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 ='^97265.*' OR patterns ='^9726.*' OR patterns ='^972.*' OR patterns ='^97.*' OR patterns ='^9.*' OR patterns ='--') AND status = 0 AND pricelist_id = 2 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1
recv 549 bytes from udp/[192.168.1.161]:5060 at 16:05:33.506922:
------------------------------------------------------------------------
BYE sip:mod_sofia@192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK1887183128;rport
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646196 BYE
Contact: <sip:97264@192.168.1.161:5060>
Max-Forwards: 70
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 4
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 6833949103
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 100
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 2
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
2017-11-06 16:05:33.501565 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 2 AND status = 0
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100
2017-11-06 16:05:33.501565 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
2017-11-06 16:05:33.501565 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.username as username,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 username="97265" limit 1
2017-11-06 16:05:33.501565 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/default/97264@192.168.1.161:5060
send 538 bytes to udp/[192.168.1.161]:5060 at 16:05:33.514880:
------------------------------------------------------------------------
BYE sip:97264@192.168.1.161:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK4g7Fj0Nr6DD1K
Max-Forwards: 70
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646196 BYE
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:60 sofia/default/97264@192.168.1.161:5060 Standard HANGUP, cause: NORMAL_CLEARING
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:852 (sofia/default/97264@192.168.1.161:5060) State HANGUP going to sleep
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:619 (sofia/default/97264@192.168.1.161:5060) State Change CS_HANGUP -> CS_REPORTING
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_REPORTING (Cur 2 Tot 275)
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:938 (sofia/default/97264@192.168.1.161:5060) State REPORTING
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:174 sofia/default/97264@192.168.1.161:5060 Standard REPORTING, cause: NORMAL_CLEARING
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:938 (sofia/default/97264@192.168.1.161:5060) State REPORTING going to sleep
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:610 (sofia/default/97264@192.168.1.161:5060) State Change CS_REPORTING -> CS_DESTROY
2017-11-06 16:05:33.501565 [DEBUG] switch_core_session.c:1664 Session 275 (sofia/default/97264@192.168.1.161:5060) Locked, Waiting on external entities
2017-11-06 16:05:33.501565 [NOTICE] switch_core_session.c:1682 Session 275 (sofia/default/97264@192.168.1.161:5060) Ended
2017-11-06 16:05:33.501565 [NOTICE] switch_core_session.c:1686 Close Channel sofia/default/97264@192.168.1.161:5060 [CS_DESTROY]
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:741 (sofia/default/97264@192.168.1.161:5060) Running State Change CS_DESTROY (Cur 1 Tot 275)
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:751 (sofia/default/97264@192.168.1.161:5060) State DESTROY
2017-11-06 16:05:33.501565 [DEBUG] mod_sofia.c:343 sofia/default/97264@192.168.1.161:5060 SOFIA DESTROY
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:181 sofia/default/97264@192.168.1.161:5060 Standard DESTROY
2017-11-06 16:05:33.501565 [DEBUG] switch_core_state_machine.c:751 (sofia/default/97264@192.168.1.161:5060) State DESTROY going to sleep
2017-11-06 16:05:33.501565 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Starts
2017-11-06 16:05:33.501565 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Ends
2017-11-06 16:05:33.501565 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="att_xfer">
<condition field="destination_number" expression="^att_xfer$">
<action application="read" data="1 10 'tone_stream://%(10000,0,350,440)' digits 20000 #"/>
<action application="transfer" data="-bleg ${digits}"/>
</condition>
</extension>
<extension name="97265">
<condition field="destination_number" expression="97265">
<action application="set" data="effective_destination_number=97265"/>
<action application="sched_hangup" data="+6000 normal_clearing"/>
<action application="set" data="callstart=2017-11-06 10:35:33"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="set" data="continue_on_fail=true"/>
<action application="set" data="account_id=4"/>
<action application="set" data="parent_id=0"/>
<action application="set" data="entity_id=0"/>
<action application="set" data="call_processed=internal"/>
<action application="set" data="call_direction=local"/>
<action application="set" data="accountname=ketank"/>
<action application="set" data="origination_rates=ID:0|CODE:97265|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4"/>
<action application="set" data="original_caller_id_name=9110327518"/>
<action application="set" data="original_caller_id_number=9110327518"/>
<action application="set" data="effective_caller_id_name=9110327518"/>
<action application="set" data="effective_caller_id_number=9110327518"/>
<action application="set" data="calltype=LOCAL"/>
<action application="set" data="receiver_accid=2"/>
<action application="bind_meta_app" data="2 ab ab execute_extension::att_xfer XML default"/>
<action application="bridge" data="[leg_timeout=30]user/97265@${domain_name}"/>
<condition field="${cond(${user_data 97265@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
<action application="export" data="voicemail_alternate_greet_id=97265"/>
<action application="answer"/>
<action application="voicemail" data="default $${domain_name} 97265"/>
<anti-action application="hangup" data="${originate_disposition}"/>
</condition>
</condition>
</extension>
</context>
</section>
</document>
2017-11-06 16:05:33.501565 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa6d801e830 released.
Dialplan: sofia/default/9110327518@192.168.1.118 parsing [default->att_xfer] continue=false
Dialplan: sofia/default/9110327518@192.168.1.118 Regex (FAIL) [att_xfer] destination_number(97265) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/default/9110327518@192.168.1.118 parsing [default->97265] continue=false
Dialplan: sofia/default/9110327518@192.168.1.118 Regex (PASS) [97265] destination_number(97265) =~ /97265/ break=on-false
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(effective_destination_number=97265)
Dialplan: sofia/default/9110327518@192.168.1.118 Action sched_hangup(+6000 normal_clearing)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(callstart=2017-11-06 10:35:33)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(hangup_after_bridge=true)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(continue_on_fail=true)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(account_id=4)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(parent_id=0)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(entity_id=0)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(call_processed=internal)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(call_direction=local)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(accountname=ketank)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(origination_rates=ID:0|CODE:97265|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(original_caller_id_name=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(original_caller_id_number=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(effective_caller_id_name=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(effective_caller_id_number=9110327518)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(calltype=LOCAL)
Dialplan: sofia/default/9110327518@192.168.1.118 Action set(receiver_accid=2)
Dialplan: sofia/default/9110327518@192.168.1.118 Action bind_meta_app(2 ab ab execute_extension::att_xfer XML default)
Dialplan: sofia/default/9110327518@192.168.1.118 Action bridge([leg_timeout=30]user/97265@${domain_name})
|--- Dialplan: Processing recursive conditions level:1 [97265_recur_1] require-nested=TRUE
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Regex (PASS) [97265_recur_1] ${cond(${user_data 97265@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Action export(voicemail_alternate_greet_id=97265)
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Action answer()
|--- Dialplan: sofia/default/9110327518@192.168.1.118 Action voicemail(default $${domain_name} 97265)
2017-11-06 16:05:33.521567 [DEBUG] switch_core_state_machine.c:286 (sofia/default/9110327518@192.168.1.118) State Change CS_ROUTING -> CS_EXECUTE
2017-11-06 16:05:33.521567 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9110327518@192.168.1.118) State ROUTING going to sleep
2017-11-06 16:05:33.521567 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9110327518@192.168.1.118) Running State Change CS_EXECUTE (Cur 1 Tot 275)
2017-11-06 16:05:33.521567 [DEBUG] switch_channel.c:2251 (sofia/default/9110327518@192.168.1.118) Callstate Change RINGING -> ACTIVE
2017-11-06 16:05:33.521567 [DEBUG] switch_core_state_machine.c:650 (sofia/default/9110327518@192.168.1.118) State EXECUTE
2017-11-06 16:05:33.521567 [DEBUG] mod_sofia.c:198 sofia/default/9110327518@192.168.1.118 SOFIA EXECUTE
2017-11-06 16:05:33.521567 [DEBUG] switch_core_state_machine.c:328 sofia/default/9110327518@192.168.1.118 Standard EXECUTE
EXECUTE sofia/default/9110327518@192.168.1.118 set(effective_destination_number=97265)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [effective_destination_number]=[97265]
EXECUTE sofia/default/9110327518@192.168.1.118 sched_hangup(+6000 normal_clearing)
2017-11-06 16:05:33.521567 [DEBUG] switch_scheduler.c:249 Added task 143 switch_ivr_schedule_hangup (d486e76a-fc5b-414d-81a2-0c62494e2a0e) to run at 1509970533
EXECUTE sofia/default/9110327518@192.168.1.118 set(callstart=2017-11-06 10:35:33)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [callstart]=[2017-11-06 10:35:33]
EXECUTE sofia/default/9110327518@192.168.1.118 set(hangup_after_bridge=true)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [hangup_after_bridge]=[true]
EXECUTE sofia/default/9110327518@192.168.1.118 set(continue_on_fail=true)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [continue_on_fail]=[true]
EXECUTE sofia/default/9110327518@192.168.1.118 set(account_id=4)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [account_id]=[4]
EXECUTE sofia/default/9110327518@192.168.1.118 set(parent_id=0)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [parent_id]=[0]
EXECUTE sofia/default/9110327518@192.168.1.118 set(entity_id=0)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [entity_id]=[0]
EXECUTE sofia/default/9110327518@192.168.1.118 set(call_processed=internal)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [call_processed]=[internal]
EXECUTE sofia/default/9110327518@192.168.1.118 set(call_direction=local)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [call_direction]=[local]
EXECUTE sofia/default/9110327518@192.168.1.118 set(accountname=ketank)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [accountname]=[ketank]
EXECUTE sofia/default/9110327518@192.168.1.118 set(origination_rates=ID:0|CODE:97265|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [origination_rates]=[ID:0|CODE:97265|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:2|MARKUP:0|ACCID:4]
EXECUTE sofia/default/9110327518@192.168.1.118 set(original_caller_id_name=9110327518)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [original_caller_id_name]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(original_caller_id_number=9110327518)
recv 537 bytes from udp/[192.168.1.161]:5060 at 16:05:33.535326:
------------------------------------------------------------------------
SIP/2.0 481 Call Leg/Transaction Does Not Exist
Via: SIP/2.0/UDP 192.168.1.118;rport=5060;branch=z9hG4bK4g7Fj0Nr6DD1K
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
To: <sip:97264@192.168.1.161:5060>;tag=1987421158
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646196 BYE
Contact: <sip:97264@192.168.1.161:5060>
Supported: replaces, path, timer
User-Agent: Grandstream GXP1620 1.0.0.38
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [original_caller_id_number]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(effective_caller_id_name=9110327518)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [effective_caller_id_name]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(effective_caller_id_number=9110327518)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [effective_caller_id_number]=[9110327518]
EXECUTE sofia/default/9110327518@192.168.1.118 set(calltype=LOCAL)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [calltype]=[LOCAL]
EXECUTE sofia/default/9110327518@192.168.1.118 set(receiver_accid=2)
2017-11-06 16:05:33.521567 [DEBUG] mod_dptools.c:1530 SET sofia/default/9110327518@192.168.1.118 [receiver_accid]=[2]
EXECUTE sofia/default/9110327518@192.168.1.118 bind_meta_app(2 ab ab execute_extension::att_xfer XML default)
2017-11-06 16:05:33.521567 [ERR] mod_dptools.c:747 Cannot bind execute to multiple legs
2017-11-06 16:05:33.521567 [INFO] switch_ivr_async.c:4165 Bound A-Leg: *2 execute_extension::att_xfer XML default
2017-11-06 16:05:33.521567 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *2 execute_extension::att_xfer XML default
EXECUTE sofia/default/9110327518@192.168.1.118 bridge([leg_timeout=30]user/97265@192.168.1.118)
2017-11-06 16:05:33.521567 [DEBUG] switch_channel.c:1823 (sofia/default/9110327518@192.168.1.118) Callstate Change ACTIVE -> RING_WAIT
2017-11-06 16:05:33.521567 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-11-06 16:05:33.521567 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
send 298 bytes to udp/[192.168.1.161]:5060 at 16:05:33.540192:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.161:5060;branch=z9hG4bK1887183128;rport=5060
From: <sip:97264@192.168.1.161:5060>;tag=1987421158
To: "9110327518" <sip:9110327518@192.168.1.118>;tag=UH5FH4y1DaQKS
Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286
CSeq: 114646196 BYE
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.541565 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-11-06 16:05:33.541565 [NOTICE] switch_channel.c:1104 New Channel sofia/default/97265@192.168.1.156:5062 [16619ecf-c164-4b6c-96a3-e57619545cd2]
2017-11-06 16:05:33.541565 [DEBUG] mod_sofia.c:4819 (sofia/default/97265@192.168.1.156:5062) State Change CS_NEW -> CS_INIT
2017-11-06 16:05:33.541565 [DEBUG] switch_ivr_originate.c:2963 sofia/default/97265@192.168.1.156:5062 Setting leg timeout to 30
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97265@192.168.1.156:5062) Running State Change CS_INIT (Cur 2 Tot 276)
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:627 (sofia/default/97265@192.168.1.156:5062) State INIT
2017-11-06 16:05:33.541565 [DEBUG] mod_sofia.c:90 sofia/default/97265@192.168.1.156:5062 SOFIA INIT
2017-11-06 16:05:33.541565 [DEBUG] sofia_glue.c:1295 sofia/default/97265@192.168.1.156:5062 sending invite version: 1.6.18 64bit
Local SDP:
v=0
o=FreeSWITCH 1509937239 1509937240 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 27294 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
send 1122 bytes to udp/[192.168.1.156]:5062 at 16:05:33.548929:
------------------------------------------------------------------------
INVITE sip:97265@192.168.1.156:5062 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK5S08KU6U3p3KF
Max-Forwards: 68
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646202 INVITE
Contact: <sip:mod_sofia@192.168.1.118:5060>
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Referred-By: <sip:97264@192.168.1.118>
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 222
Remote-Party-ID: "9110327518" <sip:9110327518@192.168.1.118>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1509937239 1509937240 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 27294 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:40 sofia/default/97265@192.168.1.156:5062 Standard INIT
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:48 (sofia/default/97265@192.168.1.156:5062) State Change CS_INIT -> CS_ROUTING
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:627 (sofia/default/97265@192.168.1.156:5062) State INIT going to sleep
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97265@192.168.1.156:5062) Running State Change CS_ROUTING (Cur 2 Tot 276)
2017-11-06 16:05:33.541565 [DEBUG] sofia.c:7048 Channel sofia/default/97265@192.168.1.156:5062 entering state [calling][0]
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:643 (sofia/default/97265@192.168.1.156:5062) State ROUTING
2017-11-06 16:05:33.541565 [DEBUG] mod_sofia.c:143 sofia/default/97265@192.168.1.156:5062 SOFIA ROUTING
2017-11-06 16:05:33.541565 [DEBUG] switch_ivr_originate.c:67 (sofia/default/97265@192.168.1.156:5062) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:643 (sofia/default/97265@192.168.1.156:5062) State ROUTING going to sleep
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97265@192.168.1.156:5062) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 276)
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:662 (sofia/default/97265@192.168.1.156:5062) State CONSUME_MEDIA
2017-11-06 16:05:33.541565 [DEBUG] switch_core_state_machine.c:662 (sofia/default/97265@192.168.1.156:5062) State CONSUME_MEDIA going to sleep
recv 324 bytes from udp/[192.168.1.156]:5062 at 16:05:33.628351:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK5S08KU6U3p3KF
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646202 INVITE
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 0
------------------------------------------------------------------------
recv 551 bytes from udp/[192.168.1.156]:5062 at 16:05:33.769923:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK5S08KU6U3p3KF
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>;tag=1787539068
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646202 INVITE
Contact: <sip:97265@192.168.1.156:5062>
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
User-Agent: Yealink SIP-T21P 34.72.0.75
Allow-Events: talk,hold,conference,refer,check-sync
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:33.821576 [DEBUG] sofia.c:7048 Channel sofia/default/97265@192.168.1.156:5062 entering state [proceeding][180]
2017-11-06 16:05:33.821576 [NOTICE] sofia.c:7156 Ring-Ready sofia/default/97265@192.168.1.156:5062!
2017-11-06 16:05:33.821576 [DEBUG] switch_channel.c:3346 (sofia/default/97265@192.168.1.156:5062) Callstate Change DOWN -> RINGING
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:37.166959:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK62S1NpQZ0ZS6a
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=3SFpZv5XpH98N
To: <sip:1.1.1.1>
Call-ID: 117c5946-3d81-1236-c4b6-000c29f46286
CSeq: 114465672 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 739 bytes from udp/[192.168.1.156]:5062 at 16:05:37.915935:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK5S08KU6U3p3KF
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>;tag=1787539068
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646202 INVITE
Contact: <sip:97265@192.168.1.156:5062>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 213
v=0
o=- 20007 20007 IN IP4 192.168.1.156
s=SDP data
c=IN IP4 192.168.1.156
t=0 0
m=audio 11794 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=sendrecv
a=ptime:20
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
------------------------------------------------------------------------
2017-11-06 16:05:37.961621 [DEBUG] sofia.c:7048 Channel sofia/default/97265@192.168.1.156:5062 entering state [completing][200]
2017-11-06 16:05:37.961621 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=- 20007 20007 IN IP4 192.168.1.156
s=SDP data
c=IN IP4 192.168.1.156
t=0 0
m=audio 11794 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
send 380 bytes to udp/[192.168.1.156]:5062 at 16:05:37.973960:
------------------------------------------------------------------------
ACK sip:97265@192.168.1.156:5062 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK7BKtQH82X8FSp
Max-Forwards: 70
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>;tag=1787539068
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646202 ACK
Contact: <sip:mod_sofia@192.168.1.118:5060>
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:37.961621 [DEBUG] sofia.c:7048 Channel sofia/default/97265@192.168.1.156:5062 entering state [ready][200]
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:3057 Set Codec sofia/default/97265@192.168.1.156:5062 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-06 16:05:37.961621 [DEBUG] switch_core_codec.c:111 sofia/default/97265@192.168.1.156:5062 Original read codec set to PCMA:8
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:4763 sofia/default/97265@192.168.1.156:5062 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/default/97265@192.168.1.156:5062] 192.168.1.118 port 27294 -> 192.168.1.156 port 11794 codec: 8 ms: 20
2017-11-06 16:05:37.961621 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:7175 sofia/default/97265@192.168.1.156:5062 Set 2833 dtmf send payload to 101
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:7182 sofia/default/97265@192.168.1.156:5062 Set 2833 dtmf receive payload to 101
2017-11-06 16:05:37.961621 [DEBUG] switch_core_media.c:7205 sofia/default/97265@192.168.1.156:5062 Set rtp dtmf delay to 40
2017-11-06 16:05:37.961621 [NOTICE] sofia.c:8182 Channel [sofia/default/97265@192.168.1.156:5062] has been answered
2017-11-06 16:05:37.961621 [DEBUG] switch_channel.c:3773 (sofia/default/97265@192.168.1.156:5062) Callstate Change RINGING -> ACTIVE
2017-11-06 16:05:37.981565 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/97265@192.168.1.156:5062]
2017-11-06 16:05:37.981565 [DEBUG] switch_channel.c:2047 (sofia/default/9110327518@192.168.1.118) Callstate Change RING_WAIT -> ACTIVE
2017-11-06 16:05:37.981565 [DEBUG] switch_ivr_originate.c:2963 sofia/default/97265@192.168.1.156:5062 Setting leg timeout to 30
2017-11-06 16:05:37.981565 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/97265@192.168.1.156:5062]
2017-11-06 16:05:37.981565 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/97265@192.168.1.156:5062) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2017-11-06 16:05:37.981565 [DEBUG] switch_core_state_machine.c:584 (sofia/default/97265@192.168.1.156:5062) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 276)
2017-11-06 16:05:37.981565 [DEBUG] switch_core_state_machine.c:653 (sofia/default/97265@192.168.1.156:5062) State EXCHANGE_MEDIA
2017-11-06 16:05:37.981565 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
send 893 bytes to udp/[192.168.1.156]:5062 at 16:05:38.019360:
------------------------------------------------------------------------
UPDATE sip:97265@192.168.1.156:5062 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK8mcKScS6tH6Bj
Max-Forwards: 70
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>;tag=1787539068
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646203 UPDATE
Contact: <sip:mod_sofia@192.168.1.118:5060>
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 222
P-Asserted-Identity: "9110327518" <sip:9110327518@192.168.1.118>
v=0
o=FreeSWITCH 1509937239 1509937240 IN IP4 192.168.1.118
s=FreeSWITCH
c=IN IP4 192.168.1.118
t=0 0
m=audio 27294 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2017-11-06 16:05:38.001569 [DEBUG] sofia.c:7048 Channel sofia/default/97265@192.168.1.156:5062 entering state [calling][0]
2017-11-06 16:05:38.041570 [DEBUG] switch_rtp.c:7254 Correct audio ip/port confirmed.
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:38.167128:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK62S1NpQZ0ZS6a
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=3SFpZv5XpH98N
To: <sip:1.1.1.1>
Call-ID: 117c5946-3d81-1236-c4b6-000c29f46286
CSeq: 114465672 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
recv 739 bytes from udp/[192.168.1.156]:5062 at 16:05:38.460661:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK8mcKScS6tH6Bj
From: "9110327518" <sip:9110327518@192.168.1.118>;tag=2gpXX1mtS8jpa
To: <sip:97265@192.168.1.156:5062>;tag=1787539068
Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286
CSeq: 114646203 UPDATE
Contact: <sip:97265@192.168.1.156:5062>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
User-Agent: Yealink SIP-T21P 34.72.0.75
Content-Length: 213
v=0
o=- 20007 20008 IN IP4 192.168.1.156
s=SDP data
c=IN IP4 192.168.1.156
t=0 0
m=audio 11794 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=sendrecv
a=ptime:20
a=fmtp:101 0-15
a=rtpmap:101 telephone-event/8000
------------------------------------------------------------------------
2017-11-06 16:05:38.461571 [DEBUG] sofia.c:7048 Channel sofia/default/97265@192.168.1.156:5062 entering state [ready][200]
2017-11-06 16:05:38.461571 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=- 20007 20008 IN IP4 192.168.1.156
s=SDP data
c=IN IP4 192.168.1.156
t=0 0
m=audio 11794 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2017-11-06 16:05:38.481571 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-06 16:05:38.481571 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-06 16:05:38.481571 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
2017-11-06 16:05:38.481571 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
2017-11-06 16:05:38.481571 [DEBUG] switch_core_media.c:4763 sofia/default/97265@192.168.1.156:5062 Set 2833 dtmf send payload to 101 recv payload to 101
2017-11-06 16:05:38.481571 [DEBUG] sofia.c:8025 Processing updated SDP
2017-11-06 16:05:38.481571 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/default/97265@192.168.1.156:5062.
recv 336 bytes from udp/[192.168.1.119]:6060 at 16:05:38.826819:
------------------------------------------------------------------------
OPTIONS sip:192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bK1867.ead25d91.0
To: sip:192.168.1.118:5060
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-95be
CSeq: 14 OPTIONS
Call-ID: 19f406c45d424e8e-10320@192.168.1.119
Max-Forwards: 70
Content-Length: 0
User-Agent: SBC
------------------------------------------------------------------------
send 702 bytes to udp/[192.168.1.119]:6060 at 16:05:38.827299:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bK1867.ead25d91.0;received=192.168.1.119
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-95be
To: <sip:192.168.1.118:5060>;tag=428e1Qp1KtZUH
Call-ID: 19f406c45d424e8e-10320@192.168.1.119
CSeq: 14 OPTIONS
Contact: <sip:192.168.1.118>
User-Agent: Local
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:39.381622 [WARNING] sofia.c:6098 Ping failed KK with code 503 - count 1/0/1, state DOWN
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
freeswitch@freeswitch>
recv 336 bytes from udp/[192.168.1.119]:6060 at 16:05:48.736548:
------------------------------------------------------------------------
OPTIONS sip:192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bKf348.5e597242.0
To: sip:192.168.1.118:5060
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-264b
CSeq: 14 OPTIONS
Call-ID: 19f406c45d424eab-10323@192.168.1.119
Max-Forwards: 70
Content-Length: 0
User-Agent: SBC
------------------------------------------------------------------------
send 702 bytes to udp/[192.168.1.119]:6060 at 16:05:48.737245:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 117.247.91.162:6060;branch=z9hG4bKf348.5e597242.0;received=192.168.1.119
From: <sip:ping@192.168.1.119:5060>;tag=709be372f8df6ad02e74147e04c36617-264b
To: <sip:192.168.1.118:5060>;tag=6mU04Dr8Dcc1r
Call-ID: 19f406c45d424eab-10323@192.168.1.119
CSeq: 14 OPTIONS
Contact: <sip:192.168.1.118>
User-Agent: Local
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
send 605 bytes to udp/[1.1.1.1]:5060 at 16:05:49.195922:
------------------------------------------------------------------------
OPTIONS sip:1.1.1.1;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.1.118;rport;branch=z9hG4bK9X5BU799QtvyD
Max-Forwards: 70
From: <sip:1.1.1.1>;tag=7XmS688BBN2Km
To: <sip:1.1.1.1>
Call-ID: 18a7d274-3d81-1236-c4b6-000c29f46286
CSeq: 114465673 OPTIONS
User-Agent: Local
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
------------------------------------------------------------------------
2017-11-06 16:05:50.001567 [WARNING] sofia.c:6098 Ping failed KK with code 503 - count 1/0/1, state DOWN
freeswitch@freeswitch> /exit
root@astpptest1:/home/inextrix#