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: To: From: ;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 open On the phone ------------------------------------------------------------------------ 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: To: From: ;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 open On the phone ------------------------------------------------------------------------ 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: To: From: ;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: ;tag=c325a037 To: 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: ;tag=98ff5d68 To: ;tag=QD0carUKS6X8a Call-ID: MmU2ZGFlMWUyZDBiMDQyMTExOWFkNjRhNmEyODgxZjY. CSeq: 14 PUBLISH Contact: 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: ;tag=t8BQF9Dyg100D To: 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: ;tag=1368e36f To: ;tag=rpS5BKcQpFmUp Call-ID: ZDI1YTJhZGM3ODQyY2Q3NzEyOTQyYzRkZjg0M2U3OWM. CSeq: 10 PUBLISH Contact: 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:
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" ;tag=UH5FH4y1DaQKS To: Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646193 INVITE Contact: 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" ;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" ;tag=UH5FH4y1DaQKS To: 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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646193 INVITE Contact: 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: ;tag=c325a037 To: ;tag=SZjyDeXtKraej Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM. CSeq: 1 INVITE Contact: 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: ;tag=t8BQF9Dyg100D To: 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: ;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: ;tag=709be372f8df6ad02e74147e04c36617-9838 To: ;tag=X3Q1mt087U3rg Call-ID: 19f406c45d424ea9-10323@192.168.1.119 CSeq: 14 OPTIONS Contact: 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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646193 INVITE Contact: 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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646193 ACK Contact: 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: ;tag=c325a037 To: ;tag=SZjyDeXtKraej Call-ID: ZmJhZTBkOGRhZTFhYzQyZWRlNjIzMmRmZThmMTAwYzM. CSeq: 1 INVITE Contact: 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: To: ;tag=SZjyDeXtKraej From: ;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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646194 UPDATE Contact: 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" 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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646194 UPDATE Contact: 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: ;tag=ZNaKrg2F2DgyQ To: 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: ;tag=ZNaKrg2F2DgyQ To: 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: ;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: ;tag=709be372f8df6ad02e74147e04c36617-6dde To: ;tag=17v4U63pvZv3e Call-ID: 19f406c45d424eaa-10323@192.168.1.119 CSeq: 14 OPTIONS Contact: 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: ;tag=1987421158 To: "9110327518" ;tag=UH5FH4y1DaQKS Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646194 INVITE Contact: 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: ;tag=1987421158 To: "9110327518" ;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: ;tag=1987421158 To: "9110327518" ;tag=UH5FH4y1DaQKS Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646194 INVITE Contact: 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: ;tag=1987421158 To: "9110327518" ;tag=UH5FH4y1DaQKS Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646194 ACK Contact: 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: ;tag=1987421158 To: "9110327518" ;tag=UH5FH4y1DaQKS Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646195 REFER Contact: Max-Forwards: 70 Supported: replaces, path, timer User-Agent: Grandstream GXP1620 1.0.0.38 Refer-To: Referred-By: 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: ;tag=1987421158 To: "9110327518" ;tag=UH5FH4y1DaQKS Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646195 REFER Contact: 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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646195 NOTIFY Contact: 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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646195 NOTIFY Contact: 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: ;tag=1987421158 To: "9110327518" ;tag=UH5FH4y1DaQKS Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646196 BYE Contact: 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" ;tag=UH5FH4y1DaQKS To: ;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:
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" ;tag=UH5FH4y1DaQKS To: ;tag=1987421158 Call-ID: 0493884d-3d81-1236-c4b6-000c29f46286 CSeq: 114646196 BYE Contact: 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: ;tag=1987421158 To: "9110327518" ;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" ;tag=2gpXX1mtS8jpa To: Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286 CSeq: 114646202 INVITE Contact: 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: Content-Type: application/sdp Content-Disposition: session Content-Length: 222 Remote-Party-ID: "9110327518" ;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" ;tag=2gpXX1mtS8jpa To: 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" ;tag=2gpXX1mtS8jpa To: ;tag=1787539068 Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286 CSeq: 114646202 INVITE Contact: 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: ;tag=3SFpZv5XpH98N To: 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" ;tag=2gpXX1mtS8jpa To: ;tag=1787539068 Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286 CSeq: 114646202 INVITE Contact: 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" ;tag=2gpXX1mtS8jpa To: ;tag=1787539068 Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286 CSeq: 114646202 ACK Contact: 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" ;tag=2gpXX1mtS8jpa To: ;tag=1787539068 Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286 CSeq: 114646203 UPDATE Contact: 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" 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: ;tag=3SFpZv5XpH98N To: 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" ;tag=2gpXX1mtS8jpa To: ;tag=1787539068 Call-ID: 0f544714-3d81-1236-c4b6-000c29f46286 CSeq: 114646203 UPDATE Contact: 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: ;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: ;tag=709be372f8df6ad02e74147e04c36617-95be To: ;tag=428e1Qp1KtZUH Call-ID: 19f406c45d424e8e-10320@192.168.1.119 CSeq: 14 OPTIONS Contact: 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: ;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: ;tag=709be372f8df6ad02e74147e04c36617-264b To: ;tag=6mU04Dr8Dcc1r Call-ID: 19f406c45d424eab-10323@192.168.1.119 CSeq: 14 OPTIONS Contact: 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: ;tag=7XmS688BBN2Km To: 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#