tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f24040448f0 from (udp/193.85.174.217:5060) has 1638 bytes, veclen = 1 recv 1638 bytes from udp/[88.208.76.34]:63327 at 12:47:32.489405: ------------------------------------------------------------------------ INVITE sip:9462793697@test.pricall.eu SIP/2.0 Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.-q8Rv6V5~;rport From: ;tag=SOFkWxJ6u To: "9462793697" CSeq: 20 INVITE Call-ID: 7cKhvS-Suo Max-Forwards: 70 Supported: replaces, outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 984 Contact: ;+sip.instance="" User-Agent: PriCall2_iPhone.SE_iOS10.2.1/3.16-33-g620383d (belle-sip/1.5.0) v=0 o=9468349698 3161 1449 IN IP4 192.168.1.116 s=Talk c=IN IP4 192.168.1.116 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7284 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 88.208.76.34 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f24040448f0 (1638 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:9462793697@test.pricall.eu SIP/2.0 (CSeq 20) nta.c:3174 agent_check_request_via() nta: Via check: received=88.208.76.34 nta.c:3085 agent_recv_request() nta: INVITE (20) going to a default leg nta.c:1348 set_timeout() nta: timer shortened to 200 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f2404001930, 0x7f2404001130, 0x7f2404042b90) called soa.c:403 soa_set_params() soa_set_params(static::0x7f240403c140, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f2404043b30) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f240403c140) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f240403c140, (nil), 0x7f240404516e, 984) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f2404042b90): adding session usage tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 310 bytes of 310 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 310 send 310 bytes to udp/[88.208.76.34]:63327 at 12:47:32.489740: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.-q8Rv6V5~;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" Call-ID: 7cKhvS-Suo CSeq: 20 INVITE User-Agent: test.pricall.eu Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (20) nua_stack.c:271 nua_stack_event() nua(0x7f2404042b90): event i_invite 100 Trying nua_session.c:4139 signal_call_state_change() nua(0x7f2404042b90): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f240403c140, [0x7f241b78f590], [0x7f241b78f598], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f2404042b90): event i_state 100 Trying nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2017-03-16 12:47:32.476442 [NOTICE] switch_channel.c:1104 New Channel sofia/default/9468349698@test.pricall.eu [b8f14cf2-0a46-11e7-ba6b-ab12ffd70ef0] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2017-03-16 12:47:32.476442 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_NEW (Cur 1 Tot 5) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:32.476442 [DEBUG] sofia.c:9819 sofia/default/9468349698@test.pricall.eu receiving invite from 88.208.76.34:63327 version: 1.6.15 64bit 2017-03-16 12:47:32.476442 [DEBUG] switch_core_media.c:453 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a 2017-03-16 12:47:32.476442 [DEBUG] sofia.c:9990 IP 88.208.76.34 Rejected by acl "default". Falling back to Digest auth. nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f2404042b90): sent signal r_respond 2017-03-16 12:47:32.476442 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [9462793697@test.pricall.eu] from ip 88.208.76.34 nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_stack.c:573 nua_stack_signal() nua(0x7f2404042b90): recv signal r_respond 407 Proxy Authentication Required nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f240403c140, ...) called 2017-03-16 12:47:32.476442 [DEBUG] switch_core_state_machine.c:603 (sofia/default/9468349698@test.pricall.eu) State NEW nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f240403c140) called tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 809 bytes of 809 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 809 send 809 bytes to udp/[88.208.76.34]:63327 at 12:47:32.490696: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.-q8Rv6V5~;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=rD5UK4aD9Zp5c Call-ID: 7cKhvS-Suo CSeq: 20 INVITE User-Agent: test.pricall.eu Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 Proxy-Authenticate: Digest realm="test.pricall.eu", nonce="b8f15a94-0a46-11e7-ba6c-ab12ffd70ef0", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (20) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f2404042b90): removing session usage nua_session.c:4139 signal_call_state_change() nua(0x7f2404042b90): call state changed: received -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f2404042b90): event i_state 407 Proxy Authentication Required nua_stack.c:271 nua_stack_event() nua(0x7f2404042b90): event i_terminated 407 Proxy Authentication Required soa.c:356 soa_destroy() soa_destroy(static::0x7f240403c140) called nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f2404043b30) nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2017-03-16 12:47:32.476442 [DEBUG] sofia.c:2334 detaching session b8f14cf2-0a46-11e7-ba6b-ab12ffd70ef0 nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f2404042b90): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f2404042b90): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f24040394d0 from (udp/193.85.174.217:5060) has 415 bytes, veclen = 1 recv 415 bytes from udp/[88.208.76.34]:63327 at 12:47:32.530890: ------------------------------------------------------------------------ ACK sip:9462793697@test.pricall.eu SIP/2.0 Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.-q8Rv6V5~;rport Call-ID: 7cKhvS-Suo From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=rD5UK4aD9Zp5c Contact: ;+sip.instance="" Max-Forwards: 70 CSeq: 20 ACK ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f24040394d0 (415 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:9462793697@test.pricall.eu SIP/2.0 (CSeq 20) nta.c:3174 agent_check_request_via() nta: Via check: received=88.208.76.34 nta.c:3019 agent_recv_request() nta: ACK (20) is going to INVITE (20) tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f24040394d0 from (udp/193.85.174.217:5060) has 1910 bytes, veclen = 1 recv 1910 bytes from udp/[88.208.76.34]:63327 at 12:47:32.532091: ------------------------------------------------------------------------ INVITE sip:9462793697@test.pricall.eu SIP/2.0 Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.WgTdcdJ44;rport From: ;tag=SOFkWxJ6u To: "9462793697" CSeq: 21 INVITE Call-ID: 7cKhvS-Suo Max-Forwards: 70 Supported: replaces, outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 984 Contact: ;+sip.instance="" User-Agent: PriCall2_iPhone.SE_iOS10.2.1/3.16-33-g620383d (belle-sip/1.5.0) Proxy-Authorization: Digest realm="test.pricall.eu", nonce="b8f15a94-0a46-11e7-ba6c-ab12ffd70ef0", algorithm=MD5, username="9468349698", uri="sip:9462793697@test.pricall.eu", response="4413a29f5d4528f98561335a35d3ddbf", cnonce="ulAVZ9~~6zeXtraf", nc=00000001, qop=auth v=0 o=9468349698 3161 1449 IN IP4 192.168.1.116 s=Talk c=IN IP4 192.168.1.116 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7284 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 88.208.76.34 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f24040394d0 (1910 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:9462793697@test.pricall.eu SIP/2.0 (CSeq 21) nta.c:3174 agent_check_request_via() nta: Via check: received=88.208.76.34 nta.c:3085 agent_recv_request() nta: INVITE (21) going to a default leg nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f2404001930, 0x7f2404001130, 0x7f240403a430) called soa.c:403 soa_set_params() soa_set_params(static::0x7f2404043db0, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f240403af70) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f2404043db0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f2404043db0, (nil), 0x7f240403c4ae, 984) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f240403a430): adding session usage tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 310 bytes of 310 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 310 send 310 bytes to udp/[88.208.76.34]:63327 at 12:47:32.532381: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.WgTdcdJ44;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" Call-ID: 7cKhvS-Suo CSeq: 21 INVITE User-Agent: test.pricall.eu Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (21) nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_invite 100 Trying nua_session.c:4139 signal_call_state_change() nua(0x7f240403a430): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f2404043db0, [0x7f241b78f590], [0x7f241b78f598], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 100 Trying nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2017-03-16 12:47:32.516434 [DEBUG] sofia.c:2442 Re-attaching to session b8f14cf2-0a46-11e7-ba6b-ab12ffd70ef0 nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:32.536436 [DEBUG] sofia.c:9819 sofia/default/9468349698@test.pricall.eu receiving invite from 88.208.76.34:63327 version: 1.6.15 64bit 2017-03-16 12:47:32.536436 [DEBUG] switch_core_media.c:453 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a 2017-03-16 12:47:32.536436 [DEBUG] sofia.c:9990 IP 88.208.76.34 Rejected by acl "default". Falling back to Digest auth. nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil) 2017-03-16 12:47:32.636429 [DEBUG] sofia.c:11131 Setting NAT mode based on via received nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:32.636429 [DEBUG] sofia.c:7042 Channel sofia/default/9468349698@test.pricall.eu entering state [received][100] 2017-03-16 12:47:32.636429 [DEBUG] sofia.c:7052 Remote SDP: v=0 o=9468349698 3161 1449 IN IP4 192.168.1.116 s=Talk c=IN IP4 192.168.1.116 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7284 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 88.208.76.34 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 2017-03-16 12:47:32.636429 [DEBUG] sofia.c:7438 (sofia/default/9468349698@test.pricall.eu) State Change CS_NEW -> CS_INIT nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_INIT (Cur 1 Tot 5) 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:627 (sofia/default/9468349698@test.pricall.eu) State INIT 2017-03-16 12:47:32.636429 [DEBUG] mod_sofia.c:90 sofia/default/9468349698@test.pricall.eu SOFIA INIT 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:40 sofia/default/9468349698@test.pricall.eu Standard INIT 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:48 (sofia/default/9468349698@test.pricall.eu) State Change CS_INIT -> CS_ROUTING 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:627 (sofia/default/9468349698@test.pricall.eu) State INIT going to sleep 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_ROUTING (Cur 1 Tot 5) 2017-03-16 12:47:32.636429 [DEBUG] switch_channel.c:2249 (sofia/default/9468349698@test.pricall.eu) Callstate Change DOWN -> RINGING 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9468349698@test.pricall.eu) State ROUTING 2017-03-16 12:47:32.636429 [DEBUG] mod_sofia.c:143 sofia/default/9468349698@test.pricall.eu SOFIA ROUTING 2017-03-16 12:47:32.636429 [DEBUG] switch_core_state_machine.c:236 sofia/default/9468349698@test.pricall.eu Standard ROUTING 2017-03-16 12:47:32.636429 [INFO] mod_dialplan_xml.c:637 Processing 9468349698 <9468349698>->9462793697 in context default nta.c:1296 agent_timer() nta: timer set next to 1621 ms Dialplan: sofia/default/9468349698@test.pricall.eu parsing [default->] continue=false Dialplan: sofia/default/9468349698@test.pricall.eu Regex (PASS) [] destination_number(9462793697) =~ // break=on-false Dialplan: sofia/default/9468349698@test.pricall.eu Action set(callstart=2017-03-16 12:47:32) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(call_processed=internal) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(originated_destination_number=9462793697) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(hangup_after_bridge=true) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(accountid=101) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(account_type=0) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(resellerid=0) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(accountcode=9468349698) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(call_direction=inbound) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(calltype=DID) Dialplan: sofia/default/9468349698@test.pricall.eu Action sched_hangup(+6000 allotted_timeout) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(effective_destination_number=9462793697) Dialplan: sofia/default/9468349698@test.pricall.eu Action system(/usr/local/astpp/push.sh google APA91bF87SOAAGQmXJCJ1jvLax6V6jkMuTLMYGALWJgdbaOeitkpqmCyY8v76g_bhOgbSvJrYMr8680VgC09SGQhf-6QTfJhDwNkmuy-IqCwz-fMH58xozQ 9468349698 9462793697 voice nothing) Dialplan: sofia/default/9468349698@test.pricall.eu Action sleep(3000) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(zrtp_secure_media=true) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(zrtp_passthru=true) Dialplan: sofia/default/9468349698@test.pricall.eu Action limit(db 9462793697 db_9462793697 1) Dialplan: sofia/default/9468349698@test.pricall.eu Action set(origination_rates=ID:16|CODE:^.9462793697.*|DESTINATION:9462793697|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:1|MARKUP:0|ACCID:101) Dialplan: sofia/default/9468349698@test.pricall.eu Action bridge({sip_invite_to_uri=}user/9462793697@phone.pricall.eu) 2017-03-16 12:47:32.736431 [DEBUG] switch_core_state_machine.c:286 (sofia/default/9468349698@test.pricall.eu) State Change CS_ROUTING -> CS_EXECUTE 2017-03-16 12:47:32.736431 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9468349698@test.pricall.eu) State ROUTING going to sleep 2017-03-16 12:47:32.736431 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_EXECUTE (Cur 1 Tot 5) 2017-03-16 12:47:32.736431 [DEBUG] switch_core_state_machine.c:650 (sofia/default/9468349698@test.pricall.eu) State EXECUTE 2017-03-16 12:47:32.736431 [DEBUG] mod_sofia.c:198 sofia/default/9468349698@test.pricall.eu SOFIA EXECUTE 2017-03-16 12:47:32.736431 [DEBUG] switch_core_state_machine.c:328 sofia/default/9468349698@test.pricall.eu Standard EXECUTE EXECUTE sofia/default/9468349698@test.pricall.eu set(callstart=2017-03-16 12:47:32) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [callstart]=[2017-03-16 12:47:32] EXECUTE sofia/default/9468349698@test.pricall.eu set(call_processed=internal) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [call_processed]=[internal] EXECUTE sofia/default/9468349698@test.pricall.eu set(originated_destination_number=9462793697) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [originated_destination_number]=[9462793697] EXECUTE sofia/default/9468349698@test.pricall.eu set(hangup_after_bridge=true) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [hangup_after_bridge]=[true] EXECUTE sofia/default/9468349698@test.pricall.eu set(accountid=101) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [accountid]=[101] EXECUTE sofia/default/9468349698@test.pricall.eu set(account_type=0) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [account_type]=[0] EXECUTE sofia/default/9468349698@test.pricall.eu set(resellerid=0) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [resellerid]=[0] EXECUTE sofia/default/9468349698@test.pricall.eu set(accountcode=9468349698) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [accountcode]=[9468349698] EXECUTE sofia/default/9468349698@test.pricall.eu set(call_direction=inbound) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [call_direction]=[inbound] EXECUTE sofia/default/9468349698@test.pricall.eu set(calltype=DID) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [calltype]=[DID] EXECUTE sofia/default/9468349698@test.pricall.eu sched_hangup(+6000 allotted_timeout) 2017-03-16 12:47:32.736431 [DEBUG] switch_scheduler.c:249 Added task 6 switch_ivr_schedule_hangup (b8f14cf2-0a46-11e7-ba6b-ab12ffd70ef0) to run at 1489674452 EXECUTE sofia/default/9468349698@test.pricall.eu set(effective_destination_number=9462793697) 2017-03-16 12:47:32.736431 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [effective_destination_number]=[9462793697] EXECUTE sofia/default/9468349698@test.pricall.eu system(/usr/local/astpp/push.sh google APA91bF87SOAAGQmXJCJ1jvLax6V6jkMuTLMYGALWJgdbaOeitkpqmCyY8v76g_bhOgbSvJrYMr8680VgC09SGQhf-6QTfJhDwNkmuy-IqCwz-fMH58xozQ 9468349698 9462793697 voice nothing) 2017-03-16 12:47:32.736431 [NOTICE] mod_dptools.c:2099 Executing command: /usr/local/astpp/push.sh google APA91bF87SOAAGQmXJCJ1jvLax6V6jkMuTLMYGALWJgdbaOeitkpqmCyY8v76g_bhOgbSvJrYMr8680VgC09SGQhf-6QTfJhDwNkmuy-IqCwz-fMH58xozQ 9468349698 9462793697 voice nothing EXECUTE sofia/default/9468349698@test.pricall.eu sleep(3000) nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:657 nua_options() nua: nua_options: entering nua_stack.c:529 nua_signal() nua(0x7f23f401c8d0): sent signal r_options nua_stack.c:569 nua_stack_signal() nua(0x7f23f401c8d0): recv signal r_options nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f2404001930, 0x7f2404001130, 0x7f23f401c8d0) called soa.c:403 soa_set_params() soa_set_params(static::0x7f240403a860, ...) called soa.c:403 soa_set_params() soa_set_params(static::0x7f240403a860, ...) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = udp/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name udp/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 1439 bytes of 1439 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 1439 send 1439 bytes to udp/[88.208.76.34]:63327 at 12:47:34.217739: ------------------------------------------------------------------------ OPTIONS sip:9468349698@88.208.76.34:63327;app-id=eu.pricall.phone.pricall.voip.prod;pn-type=apple;pn-tok=15F002B315BCA34F3B02FD20204EBA00448CD8DF65FD0FBE0372BBA34D975EE6;msg-tok=15F002B315BCA34F3B02FD20204EBA00448CD8DF65FD0FBE0372BBA34D975EE6;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;transport=udp SIP/2.0 Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK77cNtmy0y1rvr Route: ;app-id=eu.pricall.phone.pricall.voip.prod;pn-type=apple;pn-tok=15F002B315BCA34F3B02FD20204EBA00448CD8DF65FD0FBE0372BBA34D975EE6;msg-tok=15F002B315BCA34F3B02FD20204EBA00448CD8DF65FD0FBE0372BBA34D975EE6;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;transport=udp Max-Forwards: 70 From: ;tag=tZQDQtcm3H3am To: Call-ID: b9f8e51a-0a46-11e7-ba7e-ab12ffd70ef0_pnN6LeHiVr CSeq: 104497532 OPTIONS Contact: User-Agent: test.pricall.eu Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 ------------------------------------------------------------------------ nta.c:8304 outgoing_send() nta: sent OPTIONS (104497532) to udp/88.208.76.34:63327 tport.c:4160 tport_pend() tport_pend(0x7f2404004560): pending 0x7f2404040930 for udp/193.85.174.217:5060 (already 0) nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (104497531) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f241b78fc90) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/1 resent, 0/1 tout, 1/1 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 907 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f2404042690 from (udp/193.85.174.217:5060) has 278 bytes, veclen = 1 recv 278 bytes from udp/[88.208.76.34]:63327 at 12:47:34.768757: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK77cNtmy0y1rvr From: ;tag=tZQDQtcm3H3am To: ;tag=j1NQ- Call-ID: b9f8e51a-0a46-11e7-ba7e-ab12ffd70ef0_pnN6LeHiVr CSeq: 104497532 OPTIONS ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f2404042690 (278 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 200 Ok for OPTIONS (104497532) nta.c:3366 agent_recv_response() nta: 200 Ok is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 551.178 ms tport.c:4222 tport_release() tport_release(0x7f2404004560): 0x7f2404040930 by 0x7f2404041ea0 with 0x7f2404042690 nua_stack.c:271 nua_stack_event() nua(0x7f23f401c8d0): event r_options 200 Ok nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:34.756447 [DEBUG] sofia.c:6164 Ping to sip user '9468349698@phone.pricall.eu' succeeded with code 200 - count 3, state Reachable nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f23f401c8d0): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f23f401c8d0): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) soa.c:356 soa_destroy() soa_destroy(static::0x7f240403a860) called nta.c:1296 agent_timer() nta: timer set next to 2313 ms EXECUTE sofia/default/9468349698@test.pricall.eu set(zrtp_secure_media=true) 2017-03-16 12:47:35.796429 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [zrtp_secure_media]=[true] EXECUTE sofia/default/9468349698@test.pricall.eu set(zrtp_passthru=true) 2017-03-16 12:47:35.796429 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [zrtp_passthru]=[true] EXECUTE sofia/default/9468349698@test.pricall.eu limit(db 9462793697 db_9462793697 1) 2017-03-16 12:47:35.796429 [DEBUG] switch_limit.c:126 incr called: 9462793697_db_9462793697 max:1, interval:0 2017-03-16 12:47:35.796429 [DEBUG] mod_db.c:194 Usage for 9462793697_db_9462793697 is now 1/1 EXECUTE sofia/default/9468349698@test.pricall.eu set(origination_rates=ID:16|CODE:^.9462793697.*|DESTINATION:9462793697|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:1|MARKUP:0|ACCID:101) 2017-03-16 12:47:35.796429 [DEBUG] mod_dptools.c:1527 SET sofia/default/9468349698@test.pricall.eu [origination_rates]=[ID:16|CODE:^.9462793697.*|DESTINATION:9462793697|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|RATEGROUP:1|MARKUP:0|ACCID:101] EXECUTE sofia/default/9468349698@test.pricall.eu bridge({sip_invite_to_uri=}user/9462793697@phone.pricall.eu) 2017-03-16 12:47:35.796429 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables 2017-03-16 12:47:35.896429 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables 2017-03-16 12:47:35.896429 [NOTICE] switch_channel.c:1104 New Channel sofia/default/9462793697@88.208.76.34:45519 [baf9c704-0a46-11e7-ba8b-ab12ffd70ef0] 2017-03-16 12:47:35.896429 [DEBUG] mod_sofia.c:4809 (sofia/default/9462793697@88.208.76.34:45519) State Change CS_NEW -> CS_INIT 2017-03-16 12:47:35.896429 [DEBUG] switch_core_media.c:332 Passing a-leg remote zrtp-hash (audio) to b-leg 2017-03-16 12:47:35.896429 [DEBUG] mod_sofia.c:4879 [zrtp_passthru] Setting a-leg inherit_codec=true 2017-03-16 12:47:35.896429 [DEBUG] mod_sofia.c:4882 [zrtp_passthru] Setting b-leg absolute_codec_string='mod_opus.opus@48000h@20i@2c,mod_silk.SILK@16000h@20i,CORE_SPEEX_MODULE.speex@16000h@20i,CORE_SPEEX_MODULE.speex@8000h@20i,CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b' 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_INIT (Cur 2 Tot 6) 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:627 (sofia/default/9462793697@88.208.76.34:45519) State INIT 2017-03-16 12:47:35.896429 [DEBUG] mod_sofia.c:90 sofia/default/9462793697@88.208.76.34:45519 SOFIA INIT nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2017-03-16 12:47:35.896429 [DEBUG] switch_core_media.c:9574 sofia/default/9462793697@88.208.76.34:45519 Patched SDP --- v=0 o=9468349698 3161 1449 IN IP4 192.168.1.116 s=Talk c=IN IP4 192.168.1.116 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7284 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 88.208.76.34 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 +++ v=0 o=FreeSWITCH 3480841748 3480841749 IN IP4 193.85.174.217 s=FreeSWITCH c=IN IP4 193.85.174.217 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 32576 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 193.85.174.217 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 2017-03-16 12:47:35.896429 [DEBUG] sofia_glue.c:1264 sip:9462793697@88.208.76.34:45519;transport=udp Setting proxy route to sofia/default/9462793697@88.208.76.34:45519 2017-03-16 12:47:35.896429 [DEBUG] sofia_glue.c:1293 sofia/default/9462793697@88.208.76.34:45519 sending invite version: 1.6.15 64bit Local SDP: v=0 o=FreeSWITCH 3480841748 3480841749 IN IP4 193.85.174.217 s=FreeSWITCH c=IN IP4 193.85.174.217 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 32576 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 193.85.174.217 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:529 nua_signal() nua(0x7f2398000b00): sent signal r_invite 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:40 sofia/default/9462793697@88.208.76.34:45519 Standard INIT 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:48 (sofia/default/9462793697@88.208.76.34:45519) State Change CS_INIT -> CS_ROUTING 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:627 (sofia/default/9462793697@88.208.76.34:45519) State INIT going to sleep nua_stack.c:569 nua_stack_signal() nua(0x7f2398000b00): recv signal r_invite nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f2404001930, 0x7f2404001130, 0x7f2398000b00) called soa.c:403 soa_set_params() soa_set_params(static::0x7f240403a860, ...) called soa.c:403 soa_set_params() soa_set_params(static::0x7f240403a860, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f240403a860, (nil), 0x7f239800898d, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f240403a860, (nil), 0x7f239800898d, -1) called 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_ROUTING (Cur 2 Tot 6) nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f2398000b00): adding session usage nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f2404043080) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f240403a860) called soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f240403a860, 0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f240403a860, soa_generate_offer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f240403a860, soa_generate_offer): generating local description soa_static.c:1217 offer_answer_step() soa_static(0x7f240403a860, soa_generate_offer): upgrade with local description 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9462793697@88.208.76.34:45519) State ROUTING 2017-03-16 12:47:35.896429 [DEBUG] mod_sofia.c:143 sofia/default/9462793697@88.208.76.34:45519 SOFIA ROUTING soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f241b78d950, (nil), ""): called 2017-03-16 12:47:35.896429 [DEBUG] switch_ivr_originate.c:67 (sofia/default/9462793697@88.208.76.34:45519) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:643 (sofia/default/9462793697@88.208.76.34:45519) State ROUTING going to sleep soa_static.c:1446 offer_answer_step() soa_static(0x7f240403a860, soa_generate_offer): storing local description soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f240403a860, [(nil)], [0x7f241b78fac0], [0x7f241b78fabc]) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 6) tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = udp/88.208.76.34:45519 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:45519 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name udp/88.208.76.34:45519 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:662 (sofia/default/9462793697@88.208.76.34:45519) State CONSUME_MEDIA 2017-03-16 12:47:35.896429 [DEBUG] switch_core_state_machine.c:662 (sofia/default/9462793697@88.208.76.34:45519) State CONSUME_MEDIA going to sleep tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 2056 bytes of 2056 to udp/88.208.76.34:45519 tport.c:3492 tport_send_msg() tport_vsend returned 2056 send 2056 bytes to udp/[88.208.76.34]:45519 at 12:47:35.902200: ------------------------------------------------------------------------ INVITE sip:9462793697@88.208.76.34:45519;transport=udp SIP/2.0 Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK8g6DvFF4UaFFm Route: ;transport=udp Max-Forwards: 69 From: "9468349698" ;tag=U8g6rNXQ0tSXF To: Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498163 INVITE Contact: User-Agent: test.pricall.eu Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 Session-Expires: 1800;refresher=uac Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 1007 X-FS-Support: update_display,send_info Remote-Party-ID: "9468349698" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 3480841748 3480841749 IN IP4 193.85.174.217 s=FreeSWITCH c=IN IP4 193.85.174.217 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 32576 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 193.85.174.217 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=candidate:1 1 UDP 2130706431 192.168.1.116 7284 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 7285 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 7284 typ srflx raddr 192.168.1.116 rport 7284 a=candidate:2 2 UDP 1694498814 88.208.76.34 7285 typ srflx raddr 192.168.1.116 rport 7285 a=rtcp-fb:* trr-int 5000 ------------------------------------------------------------------------ nta.c:8304 outgoing_send() nta: sent INVITE (104498163) to udp/88.208.76.34:45519 tport.c:4160 tport_pend() tport_pend(0x7f2404004560): pending 0x7f2404030520 for udp/193.85.174.217:5060 (already 0) nta.c:1348 set_timeout() nta: timer shortened to 1000 ms nua_session.c:4139 signal_call_state_change() nua(0x7f2398000b00): call state changed: init -> calling, sent offer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f240403a860, [0x7f241b78fab0], [0x7f241b78fab8], [(nil)]) called nua_stack.c:269 nua_stack_event() nua(0x7f2398000b00): event i_state INVITE sent nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:35.896429 [DEBUG] sofia.c:7042 Channel sofia/default/9462793697@88.208.76.34:45519 entering state [calling][0] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f2404038130 from (udp/193.85.174.217:5060) has 269 bytes, veclen = 1 recv 269 bytes from udp/[88.208.76.34]:45519 at 12:47:36.035491: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK8g6DvFF4UaFFm From: "9468349698" ;tag=U8g6rNXQ0tSXF To: sip:9462793697@phone.pricall.eu Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498163 INVITE ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f2404038130 (269 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (104498163) nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 133.372 ms tport.c:4222 tport_release() tport_release(0x7f2404004560): 0x7f2404030520 by 0x7f24040308d0 with 0x7f2404038130 (preliminary) nta.c:1296 agent_timer() nta: timer set next to 628 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f2404038130 from (udp/193.85.174.217:5060) has 368 bytes, veclen = 1 recv 368 bytes from udp/[88.208.76.34]:45519 at 12:47:37.409749: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK8g6DvFF4UaFFm From: "9468349698" ;tag=U8g6rNXQ0tSXF To: ;tag=80qoS6t Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498163 INVITE User-Agent: LinphoneAndroid/1.0.0 (belle-sip/1.6.0) Supported: replaces, outbound ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f2404038130 (368 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 180 Ringing for INVITE (104498163) nta.c:3366 agent_recv_response() nta: 180 Ringing is going to a transaction tport.c:4222 tport_release() tport_release(0x7f2404004560): 0x7f2404030520 by 0x7f24040308d0 with 0x7f2404038130 (preliminary) nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event r_invite 180 Ringing nua_session.c:4139 signal_call_state_change() nua(0x7f2398000b00): call state changed: calling -> proceeding nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event i_state 180 Ringing nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:37.396428 [DEBUG] sofia.c:7042 Channel sofia/default/9462793697@88.208.76.34:45519 entering state [proceeding][180] 2017-03-16 12:47:37.396428 [NOTICE] sofia.c:7150 Ring-Ready sofia/default/9462793697@88.208.76.34:45519! 2017-03-16 12:47:37.396428 [DEBUG] switch_channel.c:3345 (sofia/default/9462793697@88.208.76.34:45519) Callstate Change DOWN -> RINGING nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f240403a430): sent signal r_respond 2017-03-16 12:47:37.416432 [NOTICE] mod_sofia.c:2263 Ring-Ready sofia/default/9468349698@test.pricall.eu! nua_stack.c:573 nua_stack_signal() nua(0x7f240403a430): recv signal r_respond 180 Ringing nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f2404043db0, ...) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 826 bytes of 826 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 826 send 826 bytes to udp/[88.208.76.34]:63327 at 12:47:37.427702: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.WgTdcdJ44;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr Call-ID: 7cKhvS-Suo CSeq: 21 INVITE Contact: User-Agent: test.pricall.eu Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 180 Ringing for INVITE (21) nua_session.c:4139 signal_call_state_change() nua(0x7f240403a430): call state changed: received -> early nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 180 Ringing nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:37.416432 [DEBUG] sofia.c:7042 Channel sofia/default/9468349698@test.pricall.eu entering state [early][180] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:37.416432 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/9468349698@test.pricall.eu! nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 407 response nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f241b78fb60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 2238 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f240403b980 from (udp/193.85.174.217:5060) has 1305 bytes, veclen = 1 recv 1305 bytes from udp/[88.208.76.34]:45519 at 12:47:38.532337: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK8g6DvFF4UaFFm From: "9468349698" ;tag=U8g6rNXQ0tSXF To: ;tag=80qoS6t Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498163 INVITE User-Agent: LinphoneAndroid/1.0.0 (belle-sip/1.6.0) Supported: replaces, outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Contact: ;+sip.instance="" Content-Type: application/sdp Content-Length: 675 v=0 o=9462793697 1600 3483 IN IP4 192.168.1.114 s=Talk c=IN IP4 192.168.1.114 b=AS:1152 t=0 0 a=ice-pwd:8a6558f1c7217c3272777de9 a=ice-ufrag:382e25b1 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/AVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 6132d44eaaa44702d9a5178f7adb52b4d95815d26998b2d3929df57428320a51 a=ice-mismatch a=rtcp-fb:* trr-int 5000 ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f240403b980 (1305 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 200 Ok for INVITE (104498163) nta.c:3366 agent_recv_response() nta: 200 Ok is going to a transaction tport.c:4222 tport_release() tport_release(0x7f2404004560): 0x7f2404030520 by 0x7f24040308d0 with 0x7f240403b980 nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh session after 904 seconds (in [895..905]) soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f240403a860, (nil), 0x7f2404044b66, 675) called soa.c:1595 soa_process_answer() soa_process_answer(static::0x7f240403a860) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f240403a860, soa_process_answer): called soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f24040354a0, 0x7f2404044ee0, ""): called soa_static.c:1304 offer_answer_step() soa_static(0x7f240403a860, soa_process_answer): upgrade codecs with remote description soa.c:1730 soa_activate() soa_activate(static::0x7f240403a860, (nil)) called nua_session.c:988 nua_session_client_response() nua(0x7f2398000b00): INVITE: processed SDP answer in 200 Ok nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event r_invite 200 Ok nua_session.c:4139 signal_call_state_change() nua(0x7f2398000b00): call state changed: proceeding -> completing, received answer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f240403a860, [0x7f241b78f310], [0x7f241b78f318], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f240403a860, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event i_state 200 Ok nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:453 Found audio zrtp-hash; setting r_sdp_audio_zrtp_hash=1.10 6132d44eaaa44702d9a5178f7adb52b4d95815d26998b2d3929df57428320a51 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:332 Passing a-leg remote zrtp-hash (audio) to b-leg 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:338 Passing b-leg remote zrtp-hash (audio) to a-leg nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.516433 [DEBUG] sofia.c:7042 Channel sofia/default/9462793697@88.208.76.34:45519 entering state [completing][200] 2017-03-16 12:47:38.516433 [DEBUG] sofia.c:7052 Remote SDP: v=0 o=9462793697 1600 3483 IN IP4 192.168.1.114 s=Talk c=IN IP4 192.168.1.114 b=AS:1152 t=0 0 a=ice-pwd:8a6558f1c7217c3272777de9 a=ice-ufrag:382e25b1 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/AVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 6132d44eaaa44702d9a5178f7adb52b4d95815d26998b2d3929df57428320a51 a=ice-mismatch a=rtcp-fb:* trr-int 5000 nua.c:639 nua_ack() nua: nua_ack: entering nua_stack.c:529 nua_signal() nua(0x7f2398000b00): sent signal r_ack nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_stack.c:569 nua_stack_signal() nua(0x7f2398000b00): recv signal r_ack nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f240403a860, ...) called soa.c:1730 soa_activate() soa_activate(static::0x7f240403a860, (nil)) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = udp/88.208.76.34:45519 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:45519 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name udp/88.208.76.34:45519 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 404 bytes of 404 to udp/88.208.76.34:45519 tport.c:3492 tport_send_msg() tport_vsend returned 404 send 404 bytes to udp/[88.208.76.34]:45519 at 12:47:38.533711: ------------------------------------------------------------------------ ACK sip:9462793697@88.208.76.34:45519;transport=udp SIP/2.0 Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bK9SZ6Xa07rK51F Max-Forwards: 70 From: "9468349698" ;tag=U8g6rNXQ0tSXF To: ;tag=80qoS6t Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498163 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ nta.c:8304 outgoing_send() nta: sent ACK (104498163) to udp/88.208.76.34:45519 nua_session.c:4139 signal_call_state_change() nua(0x7f2398000b00): call state changed: completing -> ready nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event i_state 200 ACK sent nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event i_active 200 Call active nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.516433 [DEBUG] sofia.c:7042 Channel sofia/default/9462793697@88.208.76.34:45519 entering state [ready][200] 2017-03-16 12:47:38.516433 [INFO] switch_channel.c:3373 sofia/default/9462793697@88.208.76.34:45519 Activating ZRTP passthru mode. 2017-03-16 12:47:38.516433 [NOTICE] sofia.c:8123 Channel [sofia/default/9462793697@88.208.76.34:45519] has been answered 2017-03-16 12:47:38.516433 [DEBUG] switch_channel.c:3772 (sofia/default/9462793697@88.208.76.34:45519) Callstate Change RINGING -> ACTIVE 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:3047 Set Codec sofia/default/9462793697@88.208.76.34:45519 PROXY/0 0 ms 160 samples 0 bits 1 channels 2017-03-16 12:47:38.516433 [DEBUG] switch_core_codec.c:111 sofia/default/9462793697@88.208.76.34:45519 Original read codec set to PROXY:0 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:6798 PROXY AUDIO RTP [sofia/default/9462793697@88.208.76.34:45519] 192.168.1.114:7076->192.168.1.114:7076 codec: 0 ms: 20 2017-03-16 12:47:38.516433 [DEBUG] switch_rtp.c:3896 Not using a timer 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:7038 sofia/default/9462793697@88.208.76.34:45519 Set 2833 dtmf send payload to 101 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:7045 sofia/default/9462793697@88.208.76.34:45519 Set 2833 dtmf receive payload to 101 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:7068 sofia/default/9462793697@88.208.76.34:45519 Set rtp dtmf delay to 40 2017-03-16 12:47:38.516433 [INFO] switch_core_media.c:7086 Activating ZRTP PROXY MODE 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:7087 Disable NOTIMER_DURING_BRIDGE 2017-03-16 12:47:38.516433 [DEBUG] switch_core_media.c:7089 Activating audio UDPTL mode nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.536431 [DEBUG] switch_ivr_originate.c:413 Codec string PROXY@8000h@20i not supported on sofia/default/9468349698@test.pricall.eu, skipping inheritance 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:9574 sofia/default/9468349698@test.pricall.eu Patched SDP --- v=0 o=9462793697 1600 3483 IN IP4 192.168.1.114 s=Talk c=IN IP4 192.168.1.114 b=AS:1152 t=0 0 a=ice-pwd:8a6558f1c7217c3272777de9 a=ice-ufrag:382e25b1 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/AVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 6132d44eaaa44702d9a5178f7adb52b4d95815d26998b2d3929df57428320a51 a=ice-mismatch a=rtcp-fb:* trr-int 5000 +++ v=0 o=FreeSWITCH 3480937211 3480937212 IN IP4 193.85.174.217 s=FreeSWITCH c=IN IP4 193.85.174.217 b=AS:1152 t=0 0 a=ice-pwd:8a6558f1c7217c3272777de9 a=ice-ufrag:382e25b1 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 22772 RTP/AVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 6132d44eaaa44702d9a5178f7adb52b4d95815d26998b2d3929df57428320a51 a=ice-mismatch a=rtcp-fb:* trr-int 5000 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:3047 Set Codec sofia/default/9468349698@test.pricall.eu PROXY/0 0 ms 160 samples 0 bits 1 channels 2017-03-16 12:47:38.536431 [DEBUG] switch_core_codec.c:111 sofia/default/9468349698@test.pricall.eu Original read codec set to PROXY:0 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:6798 PROXY AUDIO RTP [sofia/default/9468349698@test.pricall.eu] 192.168.1.116:7284->192.168.1.116:7284 codec: 0 ms: 20 2017-03-16 12:47:38.536431 [DEBUG] switch_rtp.c:3896 Not using a timer 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:7038 sofia/default/9468349698@test.pricall.eu Set 2833 dtmf send payload to 101 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:7045 sofia/default/9468349698@test.pricall.eu Set 2833 dtmf receive payload to 101 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:7068 sofia/default/9468349698@test.pricall.eu Set rtp dtmf delay to 40 2017-03-16 12:47:38.536431 [INFO] switch_core_media.c:7086 Activating ZRTP PROXY MODE 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:7087 Disable NOTIMER_DURING_BRIDGE 2017-03-16 12:47:38.536431 [DEBUG] switch_core_media.c:7089 Activating audio UDPTL mode nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f240403a430): sent signal r_respond nua_stack.c:573 nua_stack_signal() nua(0x7f240403a430): recv signal r_respond 200 OK nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f2404043db0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f2404043db0, (nil), 0x7f23a006236f, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f2404043db0, (nil), 0x7f23a006236f, -1) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f2404043db0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f2404043db0, soa_generate_answer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f2404043db0, soa_generate_answer): generating local description 2017-03-16 12:47:38.536431 [NOTICE] switch_ivr_originate.c:3628 Channel [sofia/default/9468349698@test.pricall.eu] has been answered soa_static.c:1230 offer_answer_step() soa_static(0x7f2404043db0, soa_generate_answer): upgrade with remote description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f241b78d9a0, 0x7f2404040e80, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f2404043db0, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f2404043db0, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f2404043db0, [(nil)], [0x7f241b78fb10], [0x7f241b78fb0c]) called tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 1591 bytes of 1591 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 1591 send 1591 bytes to udp/[88.208.76.34]:63327 at 12:47:38.554242: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.WgTdcdJ44;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr Call-ID: 7cKhvS-Suo CSeq: 21 INVITE Contact: User-Agent: test.pricall.eu Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, 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 Session-Expires: 120;refresher=uas Content-Type: application/sdp Content-Disposition: session Content-Length: 696 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 3480937211 3480937212 IN IP4 193.85.174.217 s=FreeSWITCH c=IN IP4 193.85.174.217 b=AS:1152 t=0 0 a=ice-pwd:8a6558f1c7217c3272777de9 a=ice-ufrag:382e25b1 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 22772 RTP/AVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 6132d44eaaa44702d9a5178f7adb52b4d95815d26998b2d3929df57428320a51 a=ice-mismatch a=rtcp-fb:* trr-int 5000 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (21) nta.c:1348 set_timeout() nta: timer shortened to 500 ms nua_session.c:4139 signal_call_state_change() nua(0x7f240403a430): call state changed: early -> completed, sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f2404043db0, [0x7f241b78fc20], [0x7f241b78fc28], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f2404043db0, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2017-03-16 12:47:38.536431 [DEBUG] switch_channel.c:3772 (sofia/default/9468349698@test.pricall.eu) Callstate Change RINGING -> ACTIVE nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.536431 [DEBUG] sofia.c:7042 Channel sofia/default/9468349698@test.pricall.eu entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.536431 [DEBUG] switch_ivr_originate.c:3686 Originate Resulted in Success: [sofia/default/9462793697@88.208.76.34:45519] 2017-03-16 12:47:38.536431 [DEBUG] switch_ivr_originate.c:3686 Originate Resulted in Success: [sofia/default/9462793697@88.208.76.34:45519] 2017-03-16 12:47:38.556432 [DEBUG] switch_ivr_bridge.c:1566 (sofia/default/9462793697@88.208.76.34:45519) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2017-03-16 12:47:38.556432 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 6) 2017-03-16 12:47:38.556432 [DEBUG] switch_core_state_machine.c:653 (sofia/default/9462793697@88.208.76.34:45519) State EXCHANGE_MEDIA 2017-03-16 12:47:38.556432 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f2404045e20 from (udp/193.85.174.217:5060) has 658 bytes, veclen = 1 recv 658 bytes from udp/[88.208.76.34]:63327 at 12:47:38.649631: ------------------------------------------------------------------------ ACK sip:9462793697@193.85.174.217:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.1.116:63327;rport;branch=z9hG4bK.HFVVQPnZh From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr CSeq: 21 ACK Call-ID: 7cKhvS-Suo Max-Forwards: 70 Proxy-Authorization: Digest realm="test.pricall.eu", nonce="b8f15a94-0a46-11e7-ba6c-ab12ffd70ef0", algorithm=MD5, username="9468349698", uri="sip:9462793697@test.pricall.eu", response="4413a29f5d4528f98561335a35d3ddbf", cnonce="ulAVZ9~~6zeXtraf", nc=00000001, qop=auth User-Agent: PriCall2_iPhone.SE_iOS10.2.1/3.16-33-g620383d (belle-sip/1.5.0) ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f2404045e20 (658 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:9462793697@193.85.174.217:5060;transport=udp SIP/2.0 (CSeq 21) nta.c:3174 agent_check_request_via() nta: Via check: received=88.208.76.34 nta.c:3019 agent_recv_request() nta: ACK (21) is going to INVITE (21) nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f2404043db0) called nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_ack 200 OK nua_session.c:4139 signal_call_state_change() nua(0x7f240403a430): call state changed: completed -> ready nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 200 OK nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_active 200 Call active nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh session after 60 seconds (in [55..65]) nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.636433 [DEBUG] sofia.c:7042 Channel sofia/default/9468349698@test.pricall.eu entering state [ready][200] 2017-03-16 12:47:38.636433 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for sofia/default/9468349698@test.pricall.eu. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:38.836432 [INFO] switch_rtp.c:6954 Auto Changing audio port from 192.168.1.116:7284 to 88.208.76.34:7284 nta.c:1296 agent_timer() nta: timer set next to 714 ms 2017-03-16 12:47:39.476431 [INFO] switch_rtp.c:6954 Auto Changing audio port from 192.168.1.114:7076 to 88.208.76.34:7076 nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate OPTIONS (104497532) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f241b78fc90) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/2 term, 1/3 free nta.c:1296 agent_timer() nta: timer set next to 3881 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f2404045e20 from (udp/193.85.174.217:5060) has 2670 bytes, veclen = 1 recv 2670 bytes from udp/[88.208.76.34]:63327 at 12:47:42.151926: ------------------------------------------------------------------------ INVITE sip:9462793697@193.85.174.217:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.SRh1NBSmw;rport From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr CSeq: 22 INVITE Call-ID: 7cKhvS-Suo Max-Forwards: 70 Subject: Media change Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 1362 Contact: ;expires=3600;+sip.instance="" User-Agent: PriCall2_iPhone.SE_iOS10.2.1/3.16-33-g620383d (belle-sip/1.5.0) Proxy-Authorization: Digest realm="test.pricall.eu", nonce="b8f15a94-0a46-11e7-ba6c-ab12ffd70ef0", algorithm=MD5, username="9468349698", uri="sip:9462793697@193.85.174.217:5060;transport=udp", response="39073c09203d4b58f71c35fff6c724f6", cnonce="8eZckkDOgHcgFK4R", nc=00000002, qop=auth v=0 o=9468349698 3161 1450 IN IP4 192.168.1.116 s=Talk c=IN IP4 192.168.1.116 b=AS:1152 t=0 0 a=ice-pwd:b4c481a69fe3a4ae3c0b8a7b a=ice-ufrag:8aa0ef70 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7284 RTP/AVP 96 97 98 99 0 8 101 100 102 c=IN IP4 88.208.76.34 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=zrtp-hash:1.10 0c1f231eefe2b7f3f74da0278618b79aec507b940f66f276822a87bf3ea14b0a a=rtcp-fb:* trr-int 5000 m=video 9204 RTP/AVP 96 97 c=IN IP4 88.208.76.34 a=rtpmap:96 VP8/90000 a=rtpmap:97 H264/90000 a=fmtp:97 profile-level-id=42801F a=zrtp-hash:1.10 dcaecdd510316dfebbec26f512c765d6cb34caf21d67ab4133c954a29f7d0edd a=candidate:1 1 UDP 2130706431 192.168.1.116 9204 typ host a=candidate:1 2 UDP 2130706430 192.168.1.116 9205 typ host a=candidate:2 1 UDP 1694498815 88.208.76.34 9204 typ srflx raddr 192.168.1.116 rport 9204 a=candidate:2 2 UDP 1694498814 88.208.76.34 9205 typ srflx raddr 192.168.1.116 rport 9205 a=rtcp-fb:* trr-int 5000 a=rtcp-fb:96 nack pli a=rtcp-fb:96 nack sli a=rtcp-fb:96 ack rpsi a=rtcp-fb:96 ccm fir a=rtcp-fb:97 nack pli a=rtcp-fb:97 ccm fir ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f2404045e20 (2670 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:9462793697@193.85.174.217:5060;transport=udp SIP/2.0 (CSeq 22) nta.c:3174 agent_check_request_via() nta: Via check: received=88.208.76.34 nta.c:3248 agent_aliases() nta: canonizing sip:9462793697@193.85.174.217:5060 with contact nta.c:3060 agent_recv_request() nta: INVITE (22) going to existing leg nta.c:1348 set_timeout() nta: timer shortened to 200 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f2404043db0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f2404043db0, (nil), 0x7f2404032c0c, 1362) called tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 328 bytes of 328 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 328 send 328 bytes to udp/[88.208.76.34]:63327 at 12:47:42.152264: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.SRh1NBSmw;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr Call-ID: 7cKhvS-Suo CSeq: 22 INVITE User-Agent: test.pricall.eu Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (22) nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_invite 100 Trying nua_session.c:4145 signal_call_state_change() nua(0x7f240403a430): ready call updated: received received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f2404043db0, [0x7f241b78f590], [0x7f241b78f598], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 100 Trying nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f240403a430): sent signal r_respond 2017-03-16 12:47:42.136435 [NOTICE] sofia.c:9717 Hangup sofia/default/9468349698@test.pricall.eu [CS_EXECUTE] [INCOMPATIBLE_DESTINATION] nua_stack.c:573 nua_stack_signal() nua(0x7f240403a430): recv signal r_respond 488 Not Acceptable Here nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f2404043db0, ...) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f2404043db0) called tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = UDP/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name UDP/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 503 bytes of 503 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 503 send 503 bytes to udp/[88.208.76.34]:63327 at 12:47:42.152609: ------------------------------------------------------------------------ SIP/2.0 488 Not Acceptable Here Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.SRh1NBSmw;rport=63327;received=88.208.76.34 From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr Call-ID: 7cKhvS-Suo CSeq: 22 INVITE User-Agent: test.pricall.eu Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 488 Not Acceptable Here for INVITE (22) nua_session.c:4145 signal_call_state_change() nua(0x7f240403a430): ready call updated: init nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 488 Not Acceptable Here nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_active 488 Call active soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f2404043db0) called nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:42.136435 [DEBUG] sofia.c:1453 Channel is already hungup. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-03-16 12:47:42.136435 [DEBUG] switch_ivr_bridge.c:752 BRIDGE THREAD DONE [sofia/default/9468349698@test.pricall.eu] 2017-03-16 12:47:42.136435 [DEBUG] switch_ivr_bridge.c:752 BRIDGE THREAD DONE [sofia/default/9462793697@88.208.76.34:45519] 2017-03-16 12:47:42.136435 [NOTICE] switch_ivr_bridge.c:856 Hangup sofia/default/9462793697@88.208.76.34:45519 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:653 (sofia/default/9462793697@88.208.76.34:45519) State EXCHANGE_MEDIA going to sleep 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_HANGUP (Cur 2 Tot 6) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:850 (sofia/default/9462793697@88.208.76.34:45519) Callstate Change ACTIVE -> HANGUP 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:852 (sofia/default/9462793697@88.208.76.34:45519) State HANGUP 2017-03-16 12:47:42.136435 [DEBUG] mod_sofia.c:438 Channel sofia/default/9462793697@88.208.76.34:45519 hanging up, cause: NORMAL_CLEARING 2017-03-16 12:47:42.136435 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/default/9462793697@88.208.76.34:45519 nua.c:645 nua_bye() nua: nua_bye: entering nua_stack.c:529 nua_signal() nua(0x7f2398000b00): sent signal r_bye 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:60 sofia/default/9462793697@88.208.76.34:45519 Standard HANGUP, cause: NORMAL_CLEARING nua_stack.c:569 nua_stack_signal() nua(0x7f2398000b00): recv signal r_bye 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:852 (sofia/default/9462793697@88.208.76.34:45519) State HANGUP going to sleep nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f240403a860, ...) called soa.c:1784 soa_terminate() soa_terminate(static::0x7f240403a860) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f240403a860) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:619 (sofia/default/9462793697@88.208.76.34:45519) State Change CS_HANGUP -> CS_REPORTING tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = udp/88.208.76.34:45519 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:45519 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name udp/88.208.76.34:45519 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 571 bytes of 571 to udp/88.208.76.34:45519 tport.c:3492 tport_send_msg() tport_vsend returned 571 send 571 bytes to udp/[88.208.76.34]:45519 at 12:47:42.154717: ------------------------------------------------------------------------ 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_REPORTING (Cur 2 Tot 6) BYE sip:9462793697@88.208.76.34:45519;transport=udp SIP/2.0 Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bKa3rZZ5gBpvUmB Max-Forwards: 70 From: "9468349698" ;tag=U8g6rNXQ0tSXF To: ;tag=80qoS6t Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498164 BYE User-Agent: test.pricall.eu Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ nta.c:8304 outgoing_send() nta: sent BYE (104498164) to udp/88.208.76.34:45519 tport.c:4160 tport_pend() tport_pend(0x7f2404004560): pending 0x7f2404040910 for udp/193.85.174.217:5060 (already 0) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:938 (sofia/default/9462793697@88.208.76.34:45519) State REPORTING 2017-03-16 12:47:42.136435 [DEBUG] switch_ivr_bridge.c:1664 sofia/default/9462793697@88.208.76.34:45519 skip receive message [UNBRIDGE] (channel is hungup already) 2017-03-16 12:47:42.136435 [DEBUG] switch_ivr_bridge.c:1667 sofia/default/9468349698@test.pricall.eu skip receive message [UNBRIDGE] (channel is hungup already) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_session.c:2814 sofia/default/9468349698@test.pricall.eu skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:650 (sofia/default/9468349698@test.pricall.eu) State EXECUTE going to sleep 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_HANGUP (Cur 2 Tot 6) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:850 (sofia/default/9468349698@test.pricall.eu) Callstate Change ACTIVE -> HANGUP 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:852 (sofia/default/9468349698@test.pricall.eu) State HANGUP 2017-03-16 12:47:42.136435 [DEBUG] mod_sofia.c:438 Channel sofia/default/9468349698@test.pricall.eu hanging up, cause: INCOMPATIBLE_DESTINATION 2017-03-16 12:47:42.136435 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/default/9468349698@test.pricall.eu nua.c:645 nua_bye() nua: nua_bye: entering nua_stack.c:529 nua_signal() nua(0x7f240403a430): sent signal r_bye 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:60 sofia/default/9468349698@test.pricall.eu Standard HANGUP, cause: INCOMPATIBLE_DESTINATION nua_stack.c:569 nua_stack_signal() nua(0x7f240403a430): recv signal r_bye nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f2404043db0, ...) called 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:852 (sofia/default/9468349698@test.pricall.eu) State HANGUP going to sleep soa.c:1784 soa_terminate() soa_terminate(static::0x7f2404043db0) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f2404043db0) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3257 tport_tsend() tport_tsend(0x7f2404004560) tpn = udp/88.208.76.34:63327 tport.c:4046 tport_resolve() tport_resolve addrinfo = 88.208.76.34:63327 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:619 (sofia/default/9468349698@test.pricall.eu) State Change CS_HANGUP -> CS_REPORTING tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f2404004560): not found by name udp/88.208.76.34:63327 tport.c:3594 tport_vsend() tport_vsend(0x7f2404004560): 876 bytes of 876 to udp/88.208.76.34:63327 tport.c:3492 tport_send_msg() tport_vsend returned 876 send 876 bytes to udp/[88.208.76.34]:63327 at 12:47:42.155800: ------------------------------------------------------------------------ BYE sip:9468349698@88.208.76.34:63327;app-id=eu.pricall.phone.pricall.voip.prod;pn-type=apple;pn-tok=15F002B315BCA34F3B02FD20204EBA00448CD8DF65FD0FBE0372BBA34D975EE6;msg-tok=15F002B315BCA34F3B02FD20204EBA00448CD8DF65FD0FBE0372BBA34D975EE6;pn-msg-str=IM_MSG;pn-call-str=IC_MSG;pn-call-snd=notes_of_the_optimistic.caf;pn-msg-snd=msg.caf;pn-timeout=0;pn-silent=1;transport=udp SIP/2.0 Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bKBcjr101eK5H7p Max-Forwards: 70 From: "9462793697" ;tag=SpymNZUg68crr To: ;tag=SOFkWxJ6u Call-ID: 7cKhvS-Suo CSeq: 104498167 BYE User-Agent: test.pricall.eu Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Reason: Q.850;cause=88;text="INCOMPATIBLE_DESTINATION" Content-Length: 0 ------------------------------------------------------------------------ nta.c:8304 outgoing_send() nta: sent BYE (104498167) to udp/88.208.76.34:63327 tport.c:4160 tport_pend() tport_pend(0x7f2404004560): pending 0x7f2404042130 for udp/193.85.174.217:5060 (already 1) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:584 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_REPORTING (Cur 2 Tot 6) 2017-03-16 12:47:42.136435 [DEBUG] switch_core_state_machine.c:938 (sofia/default/9468349698@test.pricall.eu) State REPORTING tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f2404049fc0 from (udp/193.85.174.217:5060) has 360 bytes, veclen = 1 recv 360 bytes from udp/[88.208.76.34]:45519 at 12:47:42.192151: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bKa3rZZ5gBpvUmB From: "9468349698" ;tag=U8g6rNXQ0tSXF To: ;tag=80qoS6t Call-ID: 92583039-84e9-1235-94b7-000c29d00b35 CSeq: 104498164 BYE User-Agent: LinphoneAndroid/1.0.0 (belle-sip/1.6.0) Supported: replaces, outbound ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f2404049fc0 (360 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 200 Ok for BYE (104498164) nta.c:3366 agent_recv_response() nta: 200 Ok is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 37.542 ms tport.c:4222 tport_release() tport_release(0x7f2404004560): 0x7f2404040910 by 0x7f2404048290 with 0x7f2404049fc0 nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event r_bye 200 Ok nua_session.c:4139 signal_call_state_change() nua(0x7f2398000b00): call state changed: terminating -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event i_state 200 to BYE nua_stack.c:271 nua_stack_event() nua(0x7f2398000b00): event i_terminated 200 to BYE nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f2398000b00): removing session usage soa.c:356 soa_destroy() soa_destroy(static::0x7f240403a860) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f2404043080) nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f2398000b00 nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f2398000b00): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f2398000b00): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f240403df80 from (udp/193.85.174.217:5060) has 768 bytes, veclen = 1 recv 768 bytes from udp/[88.208.76.34]:63327 at 12:47:42.195553: ------------------------------------------------------------------------ ACK sip:9462793697@193.85.174.217:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.1.116:63327;branch=z9hG4bK.SRh1NBSmw;rport Call-ID: 7cKhvS-Suo From: ;tag=SOFkWxJ6u To: "9462793697" ;tag=SpymNZUg68crr Contact: ;expires=3600;+sip.instance="" Max-Forwards: 70 CSeq: 22 ACK ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f240403df80 (768 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:9462793697@193.85.174.217:5060;transport=udp SIP/2.0 (CSeq 22) nta.c:3174 agent_check_request_via() nta: Via check: received=88.208.76.34 nta.c:3019 agent_recv_request() nta: ACK (22) is going to INVITE (22) nta.c:1296 agent_timer() nta: timer set next to 804 ms 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:174 sofia/default/9462793697@88.208.76.34:45519 Standard REPORTING, cause: NORMAL_CLEARING 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:938 (sofia/default/9462793697@88.208.76.34:45519) State REPORTING going to sleep 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:610 (sofia/default/9462793697@88.208.76.34:45519) State Change CS_REPORTING -> CS_DESTROY 2017-03-16 12:47:42.376431 [DEBUG] switch_core_session.c:1664 Session 6 (sofia/default/9462793697@88.208.76.34:45519) Locked, Waiting on external entities 2017-03-16 12:47:42.376431 [NOTICE] switch_core_session.c:1682 Session 6 (sofia/default/9462793697@88.208.76.34:45519) Ended 2017-03-16 12:47:42.376431 [NOTICE] switch_core_session.c:1686 Close Channel sofia/default/9462793697@88.208.76.34:45519 [CS_DESTROY] 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:741 (sofia/default/9462793697@88.208.76.34:45519) Running State Change CS_DESTROY (Cur 1 Tot 6) 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:751 (sofia/default/9462793697@88.208.76.34:45519) State DESTROY 2017-03-16 12:47:42.376431 [DEBUG] mod_sofia.c:343 sofia/default/9462793697@88.208.76.34:45519 SOFIA DESTROY 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:181 sofia/default/9462793697@88.208.76.34:45519 Standard DESTROY 2017-03-16 12:47:42.376431 [DEBUG] switch_core_state_machine.c:751 (sofia/default/9462793697@88.208.76.34:45519) State DESTROY going to sleep 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:174 sofia/default/9468349698@test.pricall.eu Standard REPORTING, cause: INCOMPATIBLE_DESTINATION 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:938 (sofia/default/9468349698@test.pricall.eu) State REPORTING going to sleep 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:610 (sofia/default/9468349698@test.pricall.eu) State Change CS_REPORTING -> CS_DESTROY 2017-03-16 12:47:42.396430 [DEBUG] switch_core_session.c:1664 Session 5 (sofia/default/9468349698@test.pricall.eu) Locked, Waiting on external entities 2017-03-16 12:47:42.396430 [NOTICE] switch_core_session.c:1682 Session 5 (sofia/default/9468349698@test.pricall.eu) Ended 2017-03-16 12:47:42.396430 [NOTICE] switch_core_session.c:1686 Close Channel sofia/default/9468349698@test.pricall.eu [CS_DESTROY] 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:741 (sofia/default/9468349698@test.pricall.eu) Running State Change CS_DESTROY (Cur 0 Tot 6) 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:751 (sofia/default/9468349698@test.pricall.eu) State DESTROY 2017-03-16 12:47:42.396430 [DEBUG] mod_sofia.c:343 sofia/default/9468349698@test.pricall.eu SOFIA DESTROY 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:181 sofia/default/9468349698@test.pricall.eu Standard DESTROY 2017-03-16 12:47:42.396430 [DEBUG] switch_core_state_machine.c:751 (sofia/default/9468349698@test.pricall.eu) State DESTROY going to sleep tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f240403df80 from (udp/193.85.174.217:5060) has 358 bytes, veclen = 1 recv 358 bytes from udp/[88.208.76.34]:63327 at 12:47:42.624058: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/UDP 193.85.174.217;rport;branch=z9hG4bKBcjr101eK5H7p From: "9462793697" ;tag=SpymNZUg68crr To: ;tag=SOFkWxJ6u Call-ID: 7cKhvS-Suo CSeq: 104498167 BYE User-Agent: PriCall2_iPhone.SE_iOS10.2.1/3.16-33-g620383d (belle-sip/1.5.0) Supported: replaces, outbound ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): msg 0x7f240403df80 (358 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 200 Ok for BYE (104498167) nta.c:3366 agent_recv_response() nta: 200 Ok is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 468.355 ms tport.c:4222 tport_release() tport_release(0x7f2404004560): 0x7f2404042130 by 0x7f2404037b40 with 0x7f240403df80 nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event r_bye 200 Ok nua_session.c:4139 signal_call_state_change() nua(0x7f240403a430): call state changed: terminating -> terminated nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_state 200 to BYE nua_stack.c:271 nua_stack_event() nua(0x7f240403a430): event i_terminated 200 to BYE nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f240403a430): removing session usage soa.c:356 soa_destroy() soa_destroy(static::0x7f2404043db0) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f240403af70) nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f240403a430 nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f240403a430): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f240403a430): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) 2017-03-16 12:47:42.736429 [DEBUG] switch_scheduler.c:144 Deleting task 6 switch_ivr_schedule_hangup (b8f14cf2-0a46-11e7-ba6b-ab12ffd70ef0) nta.c:1296 agent_timer() nta: timer set next to 494 ms nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 200 response nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f241b78fb60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 3541 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f2404004560): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f2404004560) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f2404004560) msg 0x7f24040394d0 from (udp/193.85.174.217:5060) has 4 bytes, veclen = 1 tport.c:3023 tport_deliver() tport_deliver(0x7f2404004560): bad msg 0x7f24040394d0 (4 bytes) from udp/88.208.76.34:5060/sip next=(nil) nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate BYE (104498164) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f241b78fc90) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/3 term, 1/4 free nta.c:1296 agent_timer() nta: timer set next to 4 ms nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 488 response nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f241b78fb60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free nta.c:1296 agent_timer() nta: timer set next to 428 ms nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate BYE (104498167) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f241b78fc90) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/2 term, 1/3 free nta.c:1296 agent_timer() nta: timer set next to 22908 ms