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