Hi, Sudden call termination about 30 s after the connection has been estableshed. There is no record in the SIPTRACE about sending BYE to/from the UA. tcpdump also does not see any SIP-related packets at the moment of call termination. FS hungup the channel but the UA continues to send rtp. tport.c:2782 tport_wakeup() tport_wakeup(0x7f30800a2f80): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f30800a2f80) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f30800a2f80): tls_read() returned 1372 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f30800a2f80) msg 0x7f30800e2e50 from (tls/33.2.151.64:2210) has 1372 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f30800a2f80): msg 0x7f30800e2e50 (1372 bytes) from tls/33.2.151.64:2210/sips next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:009197@6.27.9.120:5061 SIP/2.0 (CSeq 50) nta.c:3174 agent_check_request_via() nta: Via check: received=33.2.151.64 nta.c:3085 agent_recv_request() nta: INVITE (50) going to a default leg nta.c:1348 set_timeout() nta: timer shortened to 2000 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:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f3080044490, 0x7f3080043c90, 0x7f3080063290) called soa.c:403 soa_set_params() soa_set_params(static::0x7f30800d65b0, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f30800f2c50) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f30800d65b0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f30800d65b0, (nil), 0x7f30800eb52f, 637) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f3080063290): adding session usage nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_invite 100 Trying nua_session.c:4143 signal_call_state_change() nua(0x7f3080063290): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f30800d65b0, [0x7f30a14f97b8], [0x7f30a14f97c0], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_state 100 Trying tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2020-02-22 08:56:56.867070 [NOTICE] switch_channel.c:1118 New Channel sofia/external/1000@6.27.9.120:5061 [223734d0-5538-11ea-bbfb-e979e915e05b] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:585 (sofia/external/1000@6.27.9.120:5061) Running State Change CS_NEW (Cur 1 Tot 9) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:56.867070 [DEBUG] sofia.c:10255 sofia/external/1000@6.27.9.120:5061 receiving invite from 33.2.151.64:2210 version: 1.10.2-release git f7bdd38 2019-12-31 14:01:19Z 64bit nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering nua_stack.c:569 nua_stack_signal() nua(0x7f3080063290): recv signal r_set_params nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f30800d65b0, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event r_set_params 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:529 nua_signal() nua(0x7f3080063290): sent signal r_set_params nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:56.867070 [DEBUG] sofia.c:7301 Channel sofia/external/1000@6.27.9.120:5061 entering state [received][100] 2020-02-22 08:56:56.867070 [DEBUG] sofia.c:7311 Remote SDP: v=0 o=1000 8002 8000 IN IP4 192.168.2.5 s=SIP Call c=IN IP4 192.168.2.5 t=0 0 m=audio 5012 RTP/SAVP 8 0 4 18 97 102 2 103 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:102 G729E/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:103 AAL2-G726-40/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,32-36,54 a=ptime:20 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:djoxnaC5dQ7mre6tjhfK13Ca1sBgQKEIBjQab653|2^32 a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:SCSxesFRMzZfGeNNxnFkkUjUKx6Ui182k2VqrtUY|2^32 2020-02-22 08:56:56.867070 [DEBUG] sofia.c:7714 (sofia/external/1000@6.27.9.120:5061) State Change CS_NEW -> CS_INIT 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 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:604 (sofia/external/1000@6.27.9.120:5061) State NEW 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:585 (sofia/external/1000@6.27.9.120:5061) Running State Change CS_INIT (Cur 1 Tot 9) 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:628 (sofia/external/1000@6.27.9.120:5061) State INIT 2020-02-22 08:56:56.867070 [DEBUG] mod_sofia.c:93 sofia/external/1000@6.27.9.120:5061 SOFIA INIT 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:40 sofia/external/1000@6.27.9.120:5061 Standard INIT 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1000@6.27.9.120:5061) State Change CS_INIT -> CS_ROUTING 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:628 (sofia/external/1000@6.27.9.120:5061) State INIT going to sleep 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:585 (sofia/external/1000@6.27.9.120:5061) Running State Change CS_ROUTING (Cur 1 Tot 9) 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:2332 (sofia/external/1000@6.27.9.120:5061) Callstate Change DOWN -> RINGING 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:644 (sofia/external/1000@6.27.9.120:5061) State ROUTING nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:573 nua_stack_signal() nua(0x7f3080063290): recv signal r_respond 100 Trying nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f30800d65b0, ...) called tport.c:3273 tport_tsend() tport_tsend(0x7f30800a2f80) tpn = TLS/33.2.151.64:2210 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f30800a3420 0x7f30800ebe20 379 (379) tport.c:3610 tport_vsend() tport_vsend(0x7f30800a2f80): 379 bytes of 379 to tls/33.2.151.64:2210 tport.c:3508 tport_send_msg() tport_vsend returned 379 tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:6797 incoming_reply() nta: sent 100 Trying for INVITE (50) nua_stack.c:529 nua_signal() nua(0x7f3080063290): sent signal r_respond 2020-02-22 08:56:56.867070 [DEBUG] mod_sofia.c:154 sofia/external/1000@6.27.9.120:5061 SOFIA ROUTING 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:236 sofia/external/1000@6.27.9.120:5061 Standard ROUTING 2020-02-22 08:56:56.867070 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->009197 in context public Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->unloop] continue=false Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->outside_call] continue=true Dialplan: sofia/external/1000@6.27.9.120:5061 Absolute Condition [outside_call] Dialplan: sofia/external/1000@6.27.9.120:5061 Action set(outside_call=true) Dialplan: sofia/external/1000@6.27.9.120:5061 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->call_debug] continue=true Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->public_extensions] continue=false Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (FAIL) [public_extensions] destination_number(009197) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->public_conference_extensions] continue=false Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (FAIL) [public_conference_extensions] destination_number(009197) =~ /^(3[5-8][01][0-9])$/ break=on-false Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->public_did] continue=false Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (FAIL) [public_did] destination_number(009197) =~ /^(5551212)$/ break=on-false Dialplan: sofia/external/1000@6.27.9.120:5061 parsing [public->us1_ipv6] continue=false Dialplan: sofia/external/1000@6.27.9.120:5061 Regex (PASS) [us1_ipv6] destination_number(009197) =~ /^00(\d{3,})$/ break=on-false Dialplan: sofia/external/1000@6.27.9.120:5061 Action export(inbound_late_negotiation=true) Dialplan: sofia/external/1000@6.27.9.120:5061 Action export(inbound_zrtp_passthru=false) Dialplan: sofia/external/1000@6.27.9.120:5061 Action set(rtp_secure_media=mandatory:AES_CM_128_HMAC_SHA1_80) Dialplan: sofia/external/1000@6.27.9.120:5061 Action export(absolute_codec_string=PCMA) Dialplan: sofia/external/1000@6.27.9.120:5061 Action set(ringback=%(2000,4000,440,480)) Dialplan: sofia/external/1000@6.27.9.120:5061 Action bridge([rtp_secure_media=mandatory:AEAD_AES_256_GCM_8]sofia/gateway/us1_ipv6/9197) 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:287 (sofia/external/1000@6.27.9.120:5061) State Change CS_ROUTING -> CS_EXECUTE 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:644 (sofia/external/1000@6.27.9.120:5061) State ROUTING going to sleep 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:585 (sofia/external/1000@6.27.9.120:5061) Running State Change CS_EXECUTE (Cur 1 Tot 9) 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:651 (sofia/external/1000@6.27.9.120:5061) State EXECUTE 2020-02-22 08:56:56.867070 [DEBUG] mod_sofia.c:209 sofia/external/1000@6.27.9.120:5061 SOFIA EXECUTE 2020-02-22 08:56:56.867070 [DEBUG] switch_core_state_machine.c:329 sofia/external/1000@6.27.9.120:5061 Standard EXECUTE EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 set(outside_call=true) 2020-02-22 08:56:56.867070 [DEBUG] mod_dptools.c:1672 SET sofia/external/1000@6.27.9.120:5061 [outside_call]=[true] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 export(RFC2822_DATE=Sat, 22 Feb 2020 08:56:56 +0300) 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [RFC2822_DATE]=[Sat, 22 Feb 2020 08:56:56 +0300] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 export(inbound_late_negotiation=true) 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [inbound_late_negotiation]=[true] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 export(inbound_zrtp_passthru=false) 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [inbound_zrtp_passthru]=[false] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 set(rtp_secure_media=mandatory:AES_CM_128_HMAC_SHA1_80) 2020-02-22 08:56:56.867070 [DEBUG] mod_dptools.c:1672 SET sofia/external/1000@6.27.9.120:5061 [rtp_secure_media]=[mandatory:AES_CM_128_HMAC_SHA1_80] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 export(absolute_codec_string=PCMA) 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [absolute_codec_string]=[PCMA] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 set(ringback=%(2000,4000,440,480)) 2020-02-22 08:56:56.867070 [DEBUG] mod_dptools.c:1672 SET sofia/external/1000@6.27.9.120:5061 [ringback]=[%(2000,4000,440,480)] EXECUTE [depth=0] sofia/external/1000@6.27.9.120:5061 bridge([rtp_secure_media=mandatory:AEAD_AES_256_GCM_8]sofia/gateway/us1_ipv6/9197) 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1264 sofia/external/1000@6.27.9.120:5061 EXPORTING[export_vars] [RFC2822_DATE]=[Sat, 22 Feb 2020 08:56:56 +0300] to event 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1264 sofia/external/1000@6.27.9.120:5061 EXPORTING[export_vars] [inbound_late_negotiation]=[true] to event 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1264 sofia/external/1000@6.27.9.120:5061 EXPORTING[export_vars] [inbound_zrtp_passthru]=[false] to event 2020-02-22 08:56:56.867070 [DEBUG] switch_channel.c:1264 sofia/external/1000@6.27.9.120:5061 EXPORTING[export_vars] [absolute_codec_string]=[PCMA] to event 2020-02-22 08:56:56.867070 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables 2020-02-22 08:56:56.867070 [DEBUG] switch_ivr_originate.c:2760 Parsing session specific variables 2020-02-22 08:56:56.887055 [NOTICE] switch_channel.c:1118 New Channel sofia/external-ipv6/9197 [22386314-5538-11ea-bc07-e979e915e05b] 2020-02-22 08:56:56.887055 [DEBUG] mod_sofia.c:5089 (sofia/external-ipv6/9197) State Change CS_NEW -> CS_INIT 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:585 (sofia/external-ipv6/9197) Running State Change CS_INIT (Cur 2 Tot 10) 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:628 (sofia/external-ipv6/9197) State INIT 2020-02-22 08:56:56.887055 [DEBUG] mod_sofia.c:93 sofia/external-ipv6/9197 SOFIA INIT 2020-02-22 08:56:56.887055 [DEBUG] switch_core_media.c:1215 Set Local audio crypto Key [1 AEAD_AES_256_GCM_8 inline:l7g+SjnmyEXkdODYNoM4vjNljooxPJvFuumXJZM8OpgX52o5hnFWJ54qvhU=] 2020-02-22 08:56:56.887055 [DEBUG] switch_core_media.c:1215 Set Local video crypto Key [1 AEAD_AES_256_GCM_8 inline:UCkQ762LUOckln/vOdFBmuNp6gow4IM4WLQxgp1vMJ4XJMY3YLrmmt2KRlg=] 2020-02-22 08:56:56.887055 [DEBUG] switch_core_media.c:1215 Set Local text crypto Key [1 AEAD_AES_256_GCM_8 inline:b8+841hCfTOwh3wNzMustM9VWGHaCdw2kCm4rwH4LF9TLrpTUuLF8BhgnjI=] nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2020-02-22 08:56:56.887055 [DEBUG] sofia_glue.c:1618 sofia/external-ipv6/9197 sending invite version: 1.10.2-release git f7bdd38 2019-12-31 14:01:19Z 64bit Local SDP: v=0 o=FreeSWITCH 1582333804 1582333805 IN IP6 2a2a:810b:a2ba::65 s=FreeSWITCH c=IN IP6 2a2a:810b:a2ba::65 t=0 0 m=audio 17212 RTP/SAVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=crypto:1 AEAD_AES_256_GCM_8 inline:l7g+SjnmyEXkdODYNoM4vjNljooxPJvFuumXJZM8OpgX52o5hnFWJ54qvhU= a=ptime:20 a=sendrecv nua.c:633 nua_invite() nua: nua_invite: entering nua_stack.c:569 nua_stack_signal() nua(0x18ca7e0): recv signal r_invite nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f307c0448f0, 0x7f307c0440f0, 0x18ca7e0) called soa.c:403 soa_set_params() soa_set_params(static::0x7f307c0b7770, ...) called soa.c:403 soa_set_params() soa_set_params(static::0x7f307c0b7770, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f307c0b7770, (nil), 0x17cec61, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f307c0b7770, (nil), 0x17cec61, -1) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x18ca7e0): adding session usage nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f307c0bfdd0) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f307c0b7770) called soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f307c0b7770, 0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f307c0b7770, soa_generate_offer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f307c0b7770, soa_generate_offer): generating local description soa_static.c:1217 offer_answer_step() soa_static(0x7f307c0b7770, soa_generate_offer): upgrade with local description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f308b4e49f0, (nil), ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f307c0b7770, soa_generate_offer): storing local description soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f307c0b7770, [(nil)], [0x7f308b4e6b28], [0x7f308b4e6b24]) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4604 tport_by_name() tport(0x7f307c048c20): found 0x7f307c064180 by name tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:3273 tport_tsend() tport_tsend(0x7f307c064180) tpn = tls/[2a01:7b30:a00f:62ba::3]:9999 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f307c061870 0x7f307c0f0750 911 (911) tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f307c061870 0x7f307c05d000 332 (332) tport.c:3610 tport_vsend() tport_vsend(0x7f307c064180): 1243 bytes of 1243 to tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:3508 tport_send_msg() tport_vsend returned 1243 tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer nta.c:8310 outgoing_send() nta: sent INVITE (16621716) to tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:4176 tport_pend() tport_pend(0x7f307c064180): pending 0x7f307c0ec980 for tls/[2a01:7b30:a00f:62ba::3]:9999 (already 1) nua_session.c:4143 signal_call_state_change() nua(0x18ca7e0): call state changed: init -> calling, sent offer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f307c0b7770, [0x7f308b4e6b08], [0x7f308b4e6b10], [(nil)]) called nua_stack.c:269 nua_stack_event() nua(0x18ca7e0): event i_state INVITE sent nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:529 nua_signal() nua(0x18ca7e0): sent signal r_invite 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:40 sofia/external-ipv6/9197 Standard INIT 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:48 (sofia/external-ipv6/9197) State Change CS_INIT -> CS_ROUTING 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:628 (sofia/external-ipv6/9197) State INIT going to sleep 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:585 (sofia/external-ipv6/9197) Running State Change CS_ROUTING (Cur 2 Tot 10) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:56.887055 [DEBUG] sofia.c:7301 Channel sofia/external-ipv6/9197 entering state [calling][0] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:644 (sofia/external-ipv6/9197) State ROUTING 2020-02-22 08:56:56.887055 [DEBUG] mod_sofia.c:154 sofia/external-ipv6/9197 SOFIA ROUTING 2020-02-22 08:56:56.887055 [DEBUG] switch_ivr_originate.c:67 (sofia/external-ipv6/9197) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:644 (sofia/external-ipv6/9197) State ROUTING going to sleep 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:585 (sofia/external-ipv6/9197) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 10) 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:663 (sofia/external-ipv6/9197) State CONSUME_MEDIA 2020-02-22 08:56:56.887055 [DEBUG] switch_core_state_machine.c:663 (sofia/external-ipv6/9197) State CONSUME_MEDIA going to sleep tport.c:2782 tport_wakeup() tport_wakeup(0x7f307c064180): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f307c064180) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f307c064180): tls_read() returned 401 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f307c064180) msg 0x7f307c0acc80 from (tls/[2a01:7b30:a00f:62ba::3]:9999) has 401 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f307c064180): msg 0x7f307c0acc80 (401 bytes) from tls/[2a01:7b30:a00f:62ba::3]:9999/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (16621716) nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 23.315 ms tport.c:4238 tport_release() tport_release(0x7f307c064180): 0x7f307c0ec980 by 0x7f307c0b1410 with 0x7f307c0acc80 (preliminary) tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer tport.c:2782 tport_wakeup() tport_wakeup(0x7f307c064180): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f307c064180) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f307c064180): tls_read() returned 955 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f307c064180) msg 0x7f307c0acc80 from (tls/[2a01:7b30:a00f:62ba::3]:9999) has 955 bytes, veclen = 1 tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer tport.c:2782 tport_wakeup() tport_wakeup(0x7f307c064180): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f307c064180) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f307c064180): tls_read() returned 340 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f307c064180) msg 0x7f307c0acc80 from (tls/[2a01:7b30:a00f:62ba::3]:9999) has 340 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f307c064180): msg 0x7f307c0acc80 (1295 bytes) from tls/[2a01:7b30:a00f:62ba::3]:9999/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 200 OK for INVITE (16621716) nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction tport.c:4238 tport_release() tport_release(0x7f307c064180): 0x7f307c0ec980 by 0x7f307c0b1410 with 0x7f307c0acc80 soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f307c0b7770, (nil), 0x7f307c0ed3b0, 340) called soa.c:1595 soa_process_answer() soa_process_answer(static::0x7f307c0b7770) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f307c0b7770, soa_process_answer): called soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f309804da10, 0x7f308c016280, ""): called soa_static.c:1304 offer_answer_step() soa_static(0x7f307c0b7770, soa_process_answer): upgrade codecs with remote description soa.c:1730 soa_activate() soa_activate(static::0x7f307c0b7770, (nil)) called nua_session.c:992 nua_session_client_response() nua(0x18ca7e0): INVITE: processed SDP answer in 200 OK (200) nua_stack.c:271 nua_stack_event() nua(0x18ca7e0): event r_invite 200 OK nua_session.c:4143 signal_call_state_change() nua(0x18ca7e0): call state changed: calling -> completing, received answer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f307c0b7770, [0x7f308b4e6558], [0x7f308b4e6560], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f307c0b7770, ...) called nua_stack.c:271 nua_stack_event() nua(0x18ca7e0): event i_state 200 OK tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer 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 2020-02-22 08:56:57.927086 [INFO] sofia.c:1369 sofia/external-ipv6/9197 Update Callee ID to "9197" <sip:9197@[2a01:7b30:a00f:62ba::3]> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:57.927086 [DEBUG] sofia.c:7301 Channel sofia/external-ipv6/9197 entering state [completing][200] 2020-02-22 08:56:57.927086 [DEBUG] sofia.c:7311 Remote SDP: v=0 o=FreeSWITCH 1582325031 1582325032 IN IP6 2a01:7b30:a00f:62ba::3 s=FreeSWITCH c=IN IP6 2a01:7b30:a00f:62ba::3 t=0 0 m=audio 25986 RTP/SAVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=crypto:1 AEAD_AES_256_GCM_8 inline:YtCNFeeP7Nfe5QM64JWmcNBBdpwXAYEG3ZJ2e0aKTFJBhhiR4CCieyro68E= nua.c:639 nua_ack() nua: nua_ack: entering nua_stack.c:569 nua_stack_signal() nua(0x18ca7e0): recv signal r_ack nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f307c0b7770, ...) called soa.c:1730 soa_activate() soa_activate(static::0x7f307c0b7770, (nil)) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4604 tport_by_name() tport(0x7f307c048c20): found 0x7f307c064180 by name tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:3273 tport_tsend() tport_tsend(0x7f307c064180) tpn = tls/[2a01:7b30:a00f:62ba::3]:9999 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f307c061870 0x7f307c0b4a50 461 (461) tport.c:3610 tport_vsend() tport_vsend(0x7f307c064180): 461 bytes of 461 to tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:3508 tport_send_msg() tport_vsend returned 461 tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer nta.c:8310 outgoing_send() nta: sent ACK (16621716) to tls/[2a01:7b30:a00f:62ba::3]:9999 nua_session.c:4143 signal_call_state_change() nua(0x18ca7e0): call state changed: completing -> ready nua_stack.c:271 nua_stack_event() nua(0x18ca7e0): event i_state 200 ACK sent nua_stack.c:271 nua_stack_event() nua(0x18ca7e0): 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_stack.c:529 nua_signal() nua(0x18ca7e0): sent signal r_ack nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:57.927086 [DEBUG] sofia.c:7301 Channel sofia/external-ipv6/9197 entering state [ready][200] 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:1813 looking for crypto suite [AEAD_AES_256_GCM_8]alias=[] in [1 AEAD_AES_256_GCM_8 inline:YtCNFeeP7Nfe5QM64JWmcNBBdpwXAYEG3ZJ2e0aKTFJBhhiR4CCieyro68E=] 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:1822 Found suite AEAD_AES_256_GCM_8 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:1892 Set Remote Key [1 AEAD_AES_256_GCM_8 inline:YtCNFeeP7Nfe5QM64JWmcNBBdpwXAYEG3ZJ2e0aKTFJBhhiR4CCieyro68E=] 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:3837 Set Codec sofia/external-ipv6/9197 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2020-02-22 08:56:57.927086 [DEBUG] switch_core_codec.c:111 sofia/external-ipv6/9197 Original read codec set to PCMA:8 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:5909 sofia/external-ipv6/9197 Set 2833 dtmf send payload to 101 recv payload to 101 2020-02-22 08:56:57.927086 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/external-ipv6/9197] 2a2a:810b:a2ba::65 port 17212 -> 2a01:7b30:a00f:62ba::3 port 25986 codec: 8 ms: 20 2020-02-22 08:56:57.927086 [DEBUG] switch_rtp.c:4430 Not using a timer 2020-02-22 08:56:57.947037 [DEBUG] switch_core_media.c:8973 sofia/external-ipv6/9197 Set 2833 dtmf send payload to 101 2020-02-22 08:56:57.947037 [DEBUG] switch_core_media.c:8980 sofia/external-ipv6/9197 Set 2833 dtmf receive payload to 101 2020-02-22 08:56:57.947037 [DEBUG] switch_core_media.c:9003 sofia/external-ipv6/9197 Set rtp dtmf delay to 40 2020-02-22 08:56:57.947037 [INFO] switch_rtp.c:4212 Activating audio Secure RTP SEND 2020-02-22 08:56:57.947037 [DEBUG] switch_core_sqldb.c:2827 Secure Type: srtp:sdes:AEAD_AES_256_GCM_8 2020-02-22 08:56:57.947037 [INFO] switch_rtp.c:4190 Activating audio Secure RTP RECV 2020-02-22 08:56:57.947037 [DEBUG] switch_core_sqldb.c:2827 Secure Type: srtp:sdes:AEAD_AES_256_GCM_8 2020-02-22 08:56:57.947037 [NOTICE] sofia.c:8479 Channel [sofia/external-ipv6/9197] has been answered 2020-02-22 08:56:57.947037 [DEBUG] switch_channel.c:3865 (sofia/external-ipv6/9197) Callstate Change DOWN -> ACTIVE 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 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:1813 looking for crypto suite [AES_CM_128_HMAC_SHA1_80]alias=[] in [1 AES_CM_128_HMAC_SHA1_80 inline:djoxnaC5dQ7mre6tjhfK13Ca1sBgQKEIBjQab653|2^32] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:1822 Found suite AES_CM_128_HMAC_SHA1_80 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:1892 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:djoxnaC5dQ7mre6tjhfK13Ca1sBgQKEIBjQab653|2^32] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:1215 Set Local audio crypto Key [1 AES_CM_128_HMAC_SHA1_80 inline:1FV79mvFW9EJ0Kzoz54tK71JzkmM8BYeOYcUd+uP] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [iLBC:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729E:102:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [AAL2-G726-40:103:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:3837 Set Codec sofia/external/1000@6.27.9.120:5061 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2020-02-22 08:56:57.967059 [DEBUG] switch_core_codec.c:111 sofia/external/1000@6.27.9.120:5061 Original read codec set to PCMA:8 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:5909 sofia/external/1000@6.27.9.120:5061 Set 2833 dtmf send payload to 101 recv payload to 101 2020-02-22 08:56:57.967059 [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/external/1000@6.27.9.120:5061] 6.27.9.120 port 27568 -> 192.168.2.5 port 5012 codec: 8 ms: 20 2020-02-22 08:56:57.967059 [DEBUG] switch_rtp.c:4408 Starting timer [timerfd] 160 bytes per 20ms nta.c:1289 agent_timer() nta: timer not set 2020-02-22 08:56:59.027038 [DEBUG] switch_core_media.c:8973 sofia/external/1000@6.27.9.120:5061 Set 2833 dtmf send payload to 101 2020-02-22 08:56:59.027038 [DEBUG] switch_core_media.c:8980 sofia/external/1000@6.27.9.120:5061 Set 2833 dtmf receive payload to 101 2020-02-22 08:56:59.027038 [DEBUG] switch_core_media.c:9003 sofia/external/1000@6.27.9.120:5061 Set rtp dtmf delay to 40 2020-02-22 08:56:59.027038 [DEBUG] switch_core_media.c:1501 LIFETIME found in |2^32, base 2 exp 32 2020-02-22 08:56:59.027038 [NOTICE] switch_core_media.c:1524 Skipping MKI due to empty index 2020-02-22 08:56:59.027038 [INFO] switch_rtp.c:4212 Activating audio Secure RTP SEND 2020-02-22 08:56:59.027038 [DEBUG] switch_core_sqldb.c:2827 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2020-02-22 08:56:59.027038 [INFO] switch_rtp.c:4190 Activating audio Secure RTP RECV 2020-02-22 08:56:59.027038 [DEBUG] switch_core_sqldb.c:2827 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2020-02-22 08:56:59.027038 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/1000@6.27.9.120:5061! 2020-02-22 08:56:59.027038 [DEBUG] switch_channel.c:3565 (sofia/external/1000@6.27.9.120:5061) Callstate Change RINGING -> EARLY 2020-02-22 08:56:59.027038 [DEBUG] switch_core_media.c:8641 Audio params are unchanged for sofia/external/1000@6.27.9.120:5061. 2020-02-22 08:56:59.027038 [DEBUG] mod_sofia.c:898 Local SDP sofia/external/1000@6.27.9.120:5061: v=0 o=FreeSWITCH 1582323451 1582323452 IN IP4 6.27.9.120 s=FreeSWITCH c=IN IP4 6.27.9.120 t=0 0 m=audio 27568 RTP/SAVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:1FV79mvFW9EJ0Kzoz54tK71JzkmM8BYeOYcUd+uP nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:573 nua_stack_signal() nua(0x7f3080063290): recv signal r_respond 200 OK nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f30800d65b0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f30800d65b0, (nil), 0x7f309c050042, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f30800d65b0, (nil), 0x7f309c050042, -1) called nua_session.c:2324 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f30800d65b0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f30800d65b0, soa_generate_answer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f30800d65b0, soa_generate_answer): generating local description soa_static.c:1230 offer_answer_step() soa_static(0x7f30800d65b0, soa_generate_answer): upgrade with remote description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f30a14f7a20, 0x7f30800e2250, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f30800d65b0, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f30800d65b0, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f30800d65b0, [(nil)], [0x7f30a14f9b58], [0x7f30a14f9b54]) called tport.c:3273 tport_tsend() tport_tsend(0x7f30800a2f80) tpn = TLS/33.2.151.64:2210 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f30800a3420 0x7f3080068f70 758 (758) tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f30800a3420 0x7f30800a0e50 305 (305) tport.c:3610 tport_vsend() tport_vsend(0x7f30800a2f80): 1063 bytes of 1063 to tls/33.2.151.64:2210 tport.c:3508 tport_send_msg() tport_vsend returned 1063 tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:6797 incoming_reply() nta: sent 200 OK for INVITE (50) nta.c:1350 set_timeout() nta: timer set to 500 ms nua_session.c:4143 signal_call_state_change() nua(0x7f3080063290): call state changed: received -> completed, sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f30800d65b0, [0x7f30a14f9c08], [0x7f30a14f9c10], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f30800d65b0, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_state 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:529 nua_signal() nua(0x7f3080063290): sent signal r_respond nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:59.027038 [DEBUG] sofia.c:7301 Channel sofia/external/1000@6.27.9.120:5061 entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:59.027038 [NOTICE] switch_ivr_originate.c:3751 Channel [sofia/external/1000@6.27.9.120:5061] has been answered 2020-02-22 08:56:59.027038 [DEBUG] switch_channel.c:3865 (sofia/external/1000@6.27.9.120:5061) Callstate Change EARLY -> ACTIVE 2020-02-22 08:56:59.027038 [DEBUG] switch_ivr_originate.c:3809 Originate Resulted in Success: [sofia/external-ipv6/9197] 2020-02-22 08:56:59.027038 [DEBUG] switch_ivr_bridge.c:1796 (sofia/external-ipv6/9197) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2020-02-22 08:56:59.027038 [DEBUG] switch_core_state_machine.c:585 (sofia/external-ipv6/9197) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 10) 2020-02-22 08:56:59.027038 [DEBUG] switch_core_state_machine.c:654 (sofia/external-ipv6/9197) State EXCHANGE_MEDIA 2020-02-22 08:56:59.027038 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA 2020-02-22 08:56:59.027038 [DEBUG] switch_rtp.c:7720 Correct audio ip/port confirmed. tport.c:2782 tport_wakeup() tport_wakeup(0x7f30800a2f80): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f30800a2f80) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f30800a2f80): tls_read() returned 568 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f30800a2f80) msg 0x7f30800f0fc0 from (tls/33.2.151.64:2210) has 568 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f30800a2f80): msg 0x7f30800f0fc0 (568 bytes) from tls/33.2.151.64:2210/sips next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:009197@6.27.9.120:6666;transport=tls SIP/2.0 (CSeq 50) nta.c:3174 agent_check_request_via() nta: Via check: received=33.2.151.64 nta.c:3019 agent_recv_request() nta: ACK (50) is going to INVITE (50) nua_session.c:2573 process_ack_or_cancel() nua: process_ack_or_cancel: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f30800d65b0) called nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_ack 200 OK nua_session.c:4143 signal_call_state_change() nua(0x7f3080063290): call state changed: completed -> ready nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_state 200 OK nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_active 200 Call active nta.c:5744 incoming_free() nta: incoming_free(0x7f30800cc750) tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer 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_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 2020-02-22 08:56:59.127093 [DEBUG] sofia.c:7301 Channel sofia/external/1000@6.27.9.120:5061 entering state [ready][200] 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:798 nua_info() nua: nua_info: entering nua_stack.c:569 nua_stack_signal() nua(0x18ca7e0): recv signal r_info nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f307c0b7770, ...) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4604 tport_by_name() tport(0x7f307c048c20): found 0x7f307c064180 by name tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:3273 tport_tsend() tport_tsend(0x7f307c064180) tpn = tls/[2a01:7b30:a00f:62ba::3]:9999 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f307c061870 0x7f307c0f9130 764 (764) tport.c:3610 tport_vsend() tport_vsend(0x7f307c064180): 764 bytes of 764 to tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:3508 tport_send_msg() tport_vsend returned 764 tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer nta.c:8310 outgoing_send() nta: sent INFO (16621717) to tls/[2a01:7b30:a00f:62ba::3]:9999 tport.c:4176 tport_pend() tport_pend(0x7f307c064180): pending 0x7f307c0f0ed0 for tls/[2a01:7b30:a00f:62ba::3]:9999 (already 1) nua_stack.c:529 nua_signal() nua(0x18ca7e0): sent signal r_info nua.c:810 nua_update() nua: nua_update: entering nua_stack.c:569 nua_stack_signal() nua(0x7f3080063290): recv signal r_update nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f30800d65b0, ...) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f30800d65b0) called soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f30800d65b0, 0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f30800d65b0, soa_generate_offer): called soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f30800d99f0, (nil), ""): called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f30800d65b0, [(nil)], [0x7f30a14f9b78], [0x7f30a14f9b74]) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3273 tport_tsend() tport_tsend(0x7f3080049a00) tpn = tls/192.168.2.5:5099 tport.c:4062 tport_resolve() tport_resolve addrinfo = 192.168.2.5:5099 tport.c:4696 tport_by_addrinfo() tport_by_addrinfo(0x7f3080049a00): not found by name tls/192.168.2.5:5099 tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f3080049a00): new secondary tport 0x7f30800e5000 tport_type_tcp.c:203 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f30800e5000): Setting TCP_KEEPIDLE to 30 tport_type_tcp.c:209 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f30800e5000): Setting TCP_KEEPINTVL to 30 tport_type_tls.c:686 tport_tls_connect() tport_tls_connect(0x7f30800e5000): connecting to tls/192.168.2.5:5099/sips tport.c:2302 tport_set_secondary_timer() tport(0x7f30800e5000): reset timer tport.c:3798 tport_queue() tport_queue(0x7f30800e5000): queueing 0x7f30800e2e50 for tls/192.168.2.5:5099 nta.c:8310 outgoing_send() nta: sent UPDATE (16621717) to tls/192.168.2.5:5099 tport.c:4176 tport_pend() tport_pend(0x7f30800e5000): pending 0x7f30800e2e50 for tls/192.168.2.5:5099 (already 0) nua_session.c:4149 signal_call_state_change() nua(0x7f3080063290): ready call updated: calling sent offer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f30800d65b0, [0x7f30a14f9b58], [0x7f30a14f9b60], [(nil)]) called nua_stack.c:269 nua_stack_event() nua(0x7f3080063290): event i_state UPDATE sent nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:529 nua_signal() nua(0x7f3080063290): sent signal r_update nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2020-02-22 08:56:59.147097 [DEBUG] sofia.c:7301 Channel sofia/external/1000@6.27.9.120:5061 entering state [calling][0] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering tport.c:2782 tport_wakeup() tport_wakeup(0x7f307c064180): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f307c064180) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f307c064180): tls_read() returned 537 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f307c064180) msg 0x7f307c0f7420 from (tls/[2a01:7b30:a00f:62ba::3]:9999) has 537 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f307c064180): msg 0x7f307c0f7420 (537 bytes) from tls/[2a01:7b30:a00f:62ba::3]:9999/sips next=(nil) nta.c:3299 agent_recv_response() nta: received 200 OK for INFO (16621717) nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 20.353 ms tport.c:4238 tport_release() tport_release(0x7f307c064180): 0x7f307c0f0ed0 by 0x7f307c0ac960 with 0x7f307c0f7420 nua_stack.c:271 nua_stack_event() nua(0x18ca7e0): event r_info 200 OK nta.c:8728 outgoing_free() nta: outgoing_free(0x7f307c0ac960) tport.c:2302 tport_set_secondary_timer() tport(0x7f307c064180): reset timer 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 2020-02-22 08:56:59.327055 [INFO] switch_rtp.c:7680 Auto Changing audio port from 192.168.2.5:5012 to 33.2.151.64:5012 nta.c:1296 agent_timer() nta: timer set next to 31631 ms tport.c:2782 tport_wakeup() tport_wakeup(0x7f30800a2f80): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f30800a2f80) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f30800a2f80): tls_read() returned 788 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f30800a2f80) msg 0x7f30800688b0 from (tls/33.2.151.64:2210) has 788 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f30800a2f80): msg 0x7f30800688b0 (788 bytes) from tls/33.2.151.64:2210/sips next=(nil) nta.c:2880 agent_recv_request() nta: received REGISTER sip:6.27.9.120:5061 SIP/2.0 (CSeq 2247) nta.c:3174 agent_check_request_via() nta: Via check: received=33.2.151.64 nta.c:3085 agent_recv_request() nta: REGISTER (2247) 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:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f3080044490, 0x7f3080043c90, 0x7f30800aa610) called soa.c:403 soa_set_params() soa_set_params(static::0x7f30800eab50, ...) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f30800aa610): adding registrar usage tport.c:4176 tport_pend() tport_pend(0x7f30800a2f80): pending (nil) for tls/33.2.151.64:2210 (already 0) nua_stack.c:271 nua_stack_event() nua(0x7f30800aa610): event i_register 100 Trying tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer 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:573 nua_stack_signal() nua(0x7f30800aa610): recv signal r_respond 200 OK nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f30800eab50, ...) called tport.c:3273 tport_tsend() tport_tsend(0x7f30800a2f80) tpn = TLS/33.2.151.64:2210 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f30800a3420 0x7f30800e66e0 621 (621) tport.c:3610 tport_vsend() tport_vsend(0x7f30800a2f80): 621 bytes of 621 to tls/33.2.151.64:2210 tport.c:3508 tport_send_msg() tport_vsend returned 621 tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (2247) nta.c:5744 incoming_free() nta: incoming_free(0x7f30800cc750) nua_stack.c:529 nua_signal() nua(0x7f30800aa610): sent signal r_respond nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:569 nua_stack_signal() nua(0x7f30800aa610): recv signal r_destroy nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f30800aa610): removing registrar usage tport.c:4238 tport_release() tport_release(0x7f30800a2f80): (nil) by 0x7f30800aa610 with (nil) tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) soa.c:356 soa_destroy() soa_destroy(static::0x7f30800eab50) called nua_stack.c:529 nua_signal() nua(0x7f30800aa610): sent signal r_destroy nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nta.c:1296 agent_timer() nta: timer set next to 1052 ms nta.c:9107 outgoing_timer_dk() nta: timer D fired, terminate INVITE (16621703) nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f308b4e6c60) nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/2 tout, 1/2 term, 1/4 free nta.c:1296 agent_timer() nta: timer set next to 3 ms nta.c:8988 outgoing_timer_bf() nta: timer F fired, terminating ACK (16621703) nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f308b4e6c60) nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 1/2 tout, 0/1 term, 1/3 free nta.c:1296 agent_timer() nta: timer set next to 26697 ms tport.c:2782 tport_wakeup() tport_wakeup(0x7f30800a2f80): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f30800a2f80) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f30800a2f80): tls_read() returned 4 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f30800a2f80) msg 0x7f30800688b0 from (tls/33.2.151.64:2210) has 4 bytes, veclen = 1 tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer tport.c:2782 tport_wakeup() tport_wakeup(0x7f30800a2f80): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f30800a2f80) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f30800a2f80): tls_read() returned 788 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f30800a2f80) msg 0x7f30800688b0 from (tls/33.2.151.64:2210) has 788 bytes, veclen = 1 tport.c:3039 tport_deliver() tport_deliver(0x7f30800a2f80): msg 0x7f30800688b0 (792 bytes) from tls/33.2.151.64:2210/sips next=(nil) nta.c:2880 agent_recv_request() nta: received REGISTER sip:6.27.9.120:5061 SIP/2.0 (CSeq 2248) nta.c:3174 agent_check_request_via() nta: Via check: received=33.2.151.64 nta.c:3085 agent_recv_request() nta: REGISTER (2248) 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:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f3080044490, 0x7f3080043c90, 0x7f30800ead90) called soa.c:403 soa_set_params() soa_set_params(static::0x7f30800eb600, ...) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f30800ead90): adding registrar usage tport.c:4176 tport_pend() tport_pend(0x7f30800a2f80): pending (nil) for tls/33.2.151.64:2210 (already 0) nua_stack.c:271 nua_stack_event() nua(0x7f30800ead90): event i_register 100 Trying tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer 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:573 nua_stack_signal() nua(0x7f30800ead90): recv signal r_respond 200 OK nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f30800eb600, ...) called tport.c:3273 tport_tsend() tport_tsend(0x7f30800a2f80) tpn = TLS/33.2.151.64:2210 tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f30800a3420 0x7f3080069a90 621 (621) tport.c:3610 tport_vsend() tport_vsend(0x7f30800a2f80): 621 bytes of 621 to tls/33.2.151.64:2210 tport.c:3508 tport_send_msg() tport_vsend returned 621 tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:6797 incoming_reply() nta: sent 200 OK for REGISTER (2248) nta.c:5744 incoming_free() nta: incoming_free(0x7f30800b2d00) nua_stack.c:529 nua_signal() nua(0x7f30800ead90): sent signal r_respond nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:569 nua_stack_signal() nua(0x7f30800ead90): recv signal r_destroy nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f30800ead90): removing registrar usage tport.c:4238 tport_release() tport_release(0x7f30800a2f80): (nil) by 0x7f30800ead90 with (nil) tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) soa.c:356 soa_destroy() soa_destroy(static::0x7f30800eb600) called nua_stack.c:529 nua_signal() nua(0x7f30800ead90): sent signal r_destroy nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering tport.c:2782 tport_wakeup() tport_wakeup(0x7f30800a2f80): events IN tport.c:2880 tport_recv_event() tport_recv_event(0x7f30800a2f80) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f30800a2f80): tls_read() returned 4 tport.c:3221 tport_recv_iovec() tport_recv_iovec(0x7f30800a2f80) msg 0x7f30800eb490 from (tls/33.2.151.64:2210) has 4 bytes, veclen = 1 tport.c:2302 tport_set_secondary_timer() tport(0x7f30800a2f80): reset timer nta.c:9107 outgoing_timer_dk() nta: timer D fired, terminate INVITE (16621716) nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f308b4e6c60) nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1 tout, 1/1 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 2 ms nta.c:8988 outgoing_timer_bf() nta: timer F fired, terminating ACK (16621716) nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f308b4e6c60) nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 1/1 tout, 0/0 term, 1/1 free nta.c:1289 agent_timer() nta: timer not set nta.c:8988 outgoing_timer_bf() nta: timer F fired, timeout UPDATE (16621717) tport.c:4238 tport_release() tport_release(0x7f30800e5000): 0x7f30800e2e50 by 0x7f30800f19f0 with (nil) nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event r_update 408 Request Timeout nta.c:8728 outgoing_free() nta: outgoing_free(0x7f30800f19f0) tport.c:2302 tport_set_secondary_timer() tport(0x7f30800e5000): reset timer nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:1784 soa_terminate() soa_terminate(static::0x7f30800d65b0) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f30800d65b0) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:4604 tport_by_name() tport(0x7f3080049a00): found 0x7f30800e5000 by name tls/192.168.2.5:5099 tport.c:3273 tport_tsend() tport_tsend(0x7f30800e5000) tpn = tls/192.168.2.5:5099 tport.c:3798 tport_queue() tport_queue(0x7f30800e5000): queueing 0x7f30800e2250 for tls/192.168.2.5:5099 nta.c:8310 outgoing_send() nta: sent BYE (16621718) to tls/192.168.2.5:5099 tport.c:4176 tport_pend() tport_pend(0x7f30800e5000): pending 0x7f30800e2250 for tls/192.168.2.5:5099 (already 0) nua_session.c:4143 signal_call_state_change() nua(0x7f3080063290): call state changed: ready -> terminating nua_stack.c:271 nua_stack_event() nua(0x7f3080063290): event i_state 487 BYE sent nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 1/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 32001 ms 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 2020-02-22 08:57:31.167054 [DEBUG] sofia.c:7301 Channel sofia/external/1000@6.27.9.120:5061 entering state [terminating][487] 2020-02-22 08:57:31.167054 [NOTICE] sofia.c:8534 Hangup sofia/external/1000@6.27.9.120:5061 [CS_EXECUTE] [ORIGINATOR_CANCEL] 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:569 nua_stack_signal() nua(0x7f3080063290): recv signal r_destroy nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f3080063290): removing session usage nua_session.c:4143 signal_call_state_change() nua(0x7f3080063290): call state changed: terminating -> terminated nua_stack.c:269 nua_stack_event() nua(0x7f3080063290): event i_state Terminated nua_stack.c:269 nua_stack_event() nua(0x7f3080063290): event i_terminated Terminated soa.c:356 soa_destroy() soa_destroy(static::0x7f30800d65b0) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f30800f2c50) nua_stack.c:529 nua_signal() nua(0x7f3080063290): sent signal r_destroy nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering 2020-02-22 08:57:31.167054 [DEBUG] switch_ivr_bridge.c:829 sofia/external/1000@6.27.9.120:5061 ending bridge by request from read function 2020-02-22 08:57:31.167054 [DEBUG] switch_ivr_bridge.c:915 BRIDGE THREAD DONE [sofia/external/1000@6.27.9.120:5061] 2020-02-22 08:57:31.187101 [DEBUG] switch_ivr_bridge.c:823 sofia/external/1000@6.27.9.120:5061 ending bridge by request from write function 2020-02-22 08:57:31.187101 [DEBUG] switch_ivr_bridge.c:915 BRIDGE THREAD DONE [sofia/external-ipv6/9197] 2020-02-22 08:57:31.187101 [NOTICE] switch_ivr_bridge.c:1032 Hangup sofia/external-ipv6/9197 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] -- Regards, V.Bogatyryev