freeswitch@test> 
freeswitch@test> 
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f9668011390 from (udp/192.168.1.166:5080) has 4 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): bad msg 0x7f9668011390 (4 bytes) from udp/192.168.1.166:5080/sip next=(nil)
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f96680285d0 from (udp/192.168.1.166:5080) has 766 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f96680285d0 (766 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:2951 agent_recv_request() nta: received INVITE sip:0000@192.168.1.166:5080;transport=UDP SIP/2.0 (CSeq 1) (load: 0 rps)
nta.c:3319 agent_aliases() nta: canonizing sip:0000@192.168.1.166:5080 with contact
nta.c:3156 agent_recv_request() nta: INVITE (1) going to a default leg
nta.c:1362 set_timeout() nta: timer set to 200 ms
nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
nua_stack.c:935 nh_create() nua: nh_create: entering
nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:280 soa_clone() soa_clone(static::0x7f9668001b90, 0x7f9668001390, 0x7f9668001fb0) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
nta.c:4488 nta_leg_tcreate() nta_leg_tcreate(0x7f966800eca0)
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f9668012dd0) called
soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f9668012dd0, (nil), 0x7f9668012832, 188) called
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f9668001fb0): adding session usage
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_invite 100 Trying
nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: init -> received, received offer
soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f9668012dd0, [0x7f9696768610], [0x7f9696768618], [(nil)]) called
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 100 Trying
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:341 nua_handle_bind() nua: nua_handle_bind: entering
2021-12-15 13:16:06.306094 93.63% [NOTICE] switch_channel.c:1123 New Channel sofia/external/1234@192.168.1.166:5080 [28a9abce-1577-436d-a925-168503e5c82c]
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_NEW (Cur 1 Tot 9)
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
2021-12-15 13:16:06.306094 93.63% [INFO] sofia.c:10462 sofia/external/1234@192.168.1.166:5080 receiving invite from 192.168.1.166:44068 version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit call-id: YqPqtGVJcra2S-9IwR-khw..
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [received][100]
2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=Z 1639574166265 1 IN IP4 192.168.1.166
s=Z
c=IN IP4 192.168.1.166
t=0 0
m=audio 8000 RTP/AVP 106
a=rtpmap:106 opus/48000/2
a=fmtp:106 minptime=20; useinbandfec=1

nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[opus:116:48000:20:0:1]
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [opus:106:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_opus.c:619 Opus encoder: set bitrate to local settings [72000bps]
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_opus.c:619 Opus encoder: set bitrate to local settings [72000bps]
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:3872 Set Codec sofia/external/1234@192.168.1.166:5080 opus/48000 20 ms 960 samples 0 bits 1 channels
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_codec.c:111 sofia/external/1234@192.168.1.166:5080 Original read codec set to opus:116
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_media.c:5982 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7933 (sofia/external/1234@192.168.1.166:5080) State Change CS_NEW -> CS_INIT
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:600 (sofia/external/1234@192.168.1.166:5080) State NEW
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_INIT (Cur 1 Tot 9)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/1234@192.168.1.166:5080) State INIT
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:97 sofia/external/1234@192.168.1.166:5080 SOFIA INIT
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:40 sofia/external/1234@192.168.1.166:5080 Standard INIT
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:48 (sofia/external/1234@192.168.1.166:5080) State Change CS_INIT -> CS_ROUTING
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/1234@192.168.1.166:5080) State INIT going to sleep
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_ROUTING (Cur 1 Tot 9)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_channel.c:2380 (sofia/external/1234@192.168.1.166:5080) Callstate Change DOWN -> RINGING
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/1234@192.168.1.166:5080) State ROUTING
nua.c:878 nua_respond() nua: nua_respond: entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_respond
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:158 sofia/external/1234@192.168.1.166:5080 SOFIA ROUTING
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:230 sofia/external/1234@192.168.1.166:5080 Standard ROUTING
2021-12-15 13:16:06.306094 93.63% [INFO] mod_dialplan_xml.c:639 Processing 1234 <1234>->0000 in context public
nua_stack.c:603 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_respond 100 Trying
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 367 bytes of 367 to udp/192.168.1.166:44068
tport.c:3521 tport_send_msg() tport_vsend returned 367
Dialplan: sofia/external/1234@192.168.1.166:5080 parsing [public->ex0] continue=false
nta.c:6868 incoming_reply() nta: sent 100 Trying for INVITE (1)
Dialplan: sofia/external/1234@192.168.1.166:5080 Regex (PASS) [ex0] destination_number(0000) =~ /0000/ break=on-false
Dialplan: sofia/external/1234@192.168.1.166:5080 Action info() 
Dialplan: sofia/external/1234@192.168.1.166:5080 Action set(hangup_after_bridge=true) 
Dialplan: sofia/external/1234@192.168.1.166:5080 Action export(nolocal:absolute_codec_string=PCMA) 
Dialplan: sofia/external/1234@192.168.1.166:5080 Action bridge(sofia/external/7777@192.168.1.166:5090) 
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:281 (sofia/external/1234@192.168.1.166:5080) State Change CS_ROUTING -> CS_EXECUTE
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/1234@192.168.1.166:5080) State ROUTING going to sleep
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/1234@192.168.1.166:5080) Running State Change CS_EXECUTE (Cur 1 Tot 9)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:647 (sofia/external/1234@192.168.1.166:5080) State EXECUTE
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:213 sofia/external/1234@192.168.1.166:5080 SOFIA EXECUTE
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:323 sofia/external/1234@192.168.1.166:5080 Standard EXECUTE
EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 info()
2021-12-15 13:16:06.306094 93.63% [INFO] mod_dptools.c:1898 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-Call-State: [RINGING]
Channel-State-Number: [4]
Channel-Name: [sofia/external/1234@192.168.1.166:5080]
Unique-ID: [28a9abce-1577-436d-a925-168503e5c82c]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Call-UUID: [28a9abce-1577-436d-a925-168503e5c82c]
Answer-State: [ringing]
Channel-Read-Codec-Name: [opus]
Channel-Read-Codec-Rate: [48000]
Channel-Read-Codec-Bit-Rate: [0]
Channel-Write-Codec-Name: [opus]
Channel-Write-Codec-Rate: [48000]
Channel-Write-Codec-Bit-Rate: [0]
Caller-Direction: [inbound]
Caller-Logical-Direction: [inbound]
Caller-Username: [1234]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [1234]
Caller-Caller-ID-Number: [1234]
Caller-Orig-Caller-ID-Name: [1234]
Caller-Orig-Caller-ID-Number: [1234]
Caller-Network-Addr: [192.168.1.166]
Caller-ANI: [1234]
Caller-Destination-Number: [0000]
Caller-Unique-ID: [28a9abce-1577-436d-a925-168503e5c82c]
Caller-Source: [mod_sofia]
Caller-Context: [public]
Caller-Channel-Name: [sofia/external/1234@192.168.1.166:5080]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1639574166306094]
Caller-Channel-Created-Time: [1639574166306094]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Channel-Resurrect-Time: [0]
Caller-Channel-Bridged-Time: [0]
Caller-Channel-Last-Hold: [0]
Caller-Channel-Hold-Accum: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [28a9abce-1577-436d-a925-168503e5c82c]
variable_session_id: [9]
variable_sip_from_params: [transport=UDP]
variable_sip_from_user: [1234]
variable_sip_from_port: [5080]
variable_sip_from_uri: [1234@192.168.1.166:5080]
variable_sip_from_host: [192.168.1.166]
variable_video_media_flow: [disabled]
variable_text_media_flow: [disabled]
variable_channel_name: [sofia/external/1234@192.168.1.166:5080]
variable_sip_call_id: [YqPqtGVJcra2S-9IwR-khw..]
variable_sip_local_network_addr: [192.168.1.166]
variable_sip_network_ip: [192.168.1.166]
variable_sip_network_port: [44068]
variable_sip_invite_stamp: [1639574166306094]
variable_sip_received_ip: [192.168.1.166]
variable_sip_received_port: [44068]
variable_sip_via_protocol: [udp]
variable_sip_from_user_stripped: [1234]
variable_sip_from_tag: [1cc66e3d]
variable_sofia_profile_name: [external]
variable_sofia_profile_url: [sip:mod_sofia@192.168.1.166:5080]
variable_recovery_profile_name: [external]
variable_sip_full_via: [SIP/2.0/UDP 192.168.1.166:44068;branch=z9hG4bK-524287-1---54f2af585e8554e1;rport=44068]
variable_sip_full_from: [<sip:1234@192.168.1.166:5080;transport=UDP>;tag=1cc66e3d]
variable_sip_full_to: [<sip:0000@192.168.1.166:5080>]
variable_sip_allow: [INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE]
variable_sip_req_params: [transport=UDP]
variable_sip_req_user: [0000]
variable_sip_req_port: [5080]
variable_sip_req_uri: [0000@192.168.1.166:5080]
variable_sip_req_host: [192.168.1.166]
variable_sip_to_user: [0000]
variable_sip_to_port: [5080]
variable_sip_to_uri: [0000@192.168.1.166:5080]
variable_sip_to_host: [192.168.1.166]
variable_sip_contact_params: [transport=UDP]
variable_sip_contact_user: [1234]
variable_sip_contact_port: [44068]
variable_sip_contact_uri: [1234@192.168.1.166:44068]
variable_sip_contact_host: [192.168.1.166]
variable_sip_user_agent: [Z 5.4.12 v2.10.13.2-mod]
variable_sip_via_host: [192.168.1.166]
variable_sip_via_port: [44068]
variable_sip_via_rport: [44068]
variable_max_forwards: [70]
variable_switch_r_sdp: [v=0
o=Z 1639574166265 1 IN IP4 192.168.1.166
s=Z
c=IN IP4 192.168.1.166
t=0 0
m=audio 8000 RTP/AVP 106
a=rtpmap:106 opus/48000/2
a=fmtp:106 minptime=20; useinbandfec=1
]
variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c]
variable_rtp_use_codec_string: [OPUS,PCMU,PCMA,VP8,VP9]
variable_remote_video_media_flow: [inactive]
variable_remote_text_media_flow: [inactive]
variable_remote_audio_media_flow: [sendrecv]
variable_audio_media_flow: [sendrecv]
variable_remote_media_ip: [192.168.1.166]
variable_remote_media_port: [8000]
variable_rtp_audio_recv_pt: [106]
variable_rtp_use_codec_name: [opus]
variable_rtp_use_codec_fmtp: [minptime=20; useinbandfec=1]
variable_rtp_use_codec_rate: [48000]
variable_rtp_use_codec_ptime: [20]
variable_rtp_use_codec_channels: [1]
variable_rtp_last_audio_codec_string: [opus@48000h@20i@1c]
variable_read_codec: [opus]
variable_original_read_codec: [opus]
variable_read_rate: [48000]
variable_original_read_rate: [48000]
variable_write_codec: [opus]
variable_write_rate: [48000]
variable_dtmf_type: [info]
variable_endpoint_disposition: [RECEIVED]
variable_call_uuid: [28a9abce-1577-436d-a925-168503e5c82c]
variable_current_application: [info]


EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 set(hangup_after_bridge=true)
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_dptools.c:1685 SET sofia/external/1234@192.168.1.166:5080 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 export(nolocal:absolute_codec_string=PCMA)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[PCMA]
EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 bridge(sofia/external/7777@192.168.1.166:5090)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_channel.c:1269 sofia/external/1234@192.168.1.166:5080 EXPORTING[export_vars] [absolute_codec_string]=[PCMA] to event
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2021-12-15 13:16:06.306094 93.63% [NOTICE] switch_channel.c:1123 New Channel sofia/external/7777@192.168.1.166:5090 [1f6e2bc8-89bb-4089-881d-575b56c6f0b3]
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:5121 (sofia/external/7777@192.168.1.166:5090) State Change CS_NEW -> CS_INIT
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_INIT (Cur 2 Tot 10)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/7777@192.168.1.166:5090) State INIT
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:97 sofia/external/7777@192.168.1.166:5090 SOFIA INIT
nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
nua.c:341 nua_handle_bind() nua: nua_handle_bind: entering
2021-12-15 13:16:06.306094 93.63% [INFO] sofia_glue.c:1651 sofia/external/7777@192.168.1.166:5090 sending invite call-id: (null)
2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia_glue.c:1654 sofia/external/7777@192.168.1.166:5090 sending invite version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1639544422 1639544423 IN IP4 192.168.1.166
s=FreeSWITCH
c=IN IP4 192.168.1.166
t=0 0
m=audio 29744 RTP/AVP 8 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

nua.c:632 nua_invite() nua: nua_invite: entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_invite
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:40 sofia/external/7777@192.168.1.166:5090 Standard INIT
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:48 (sofia/external/7777@192.168.1.166:5090) State Change CS_INIT -> CS_ROUTING
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:624 (sofia/external/7777@192.168.1.166:5090) State INIT going to sleep
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_invite
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:280 soa_clone() soa_clone(static::0x7f9668001b90, 0x7f9668001390, 0x7f96340037a0) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f9668024df0, (nil), 0x7f963401445c, -1) called
soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f9668024df0, (nil), 0x7f963401445c, -1) called
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f96340037a0): adding session usage
nta.c:4488 nta_leg_tcreate() nta_leg_tcreate(0x7f9668018240)
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_ROUTING (Cur 2 Tot 10)
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f9668024df0) called
soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f9668024df0, 0) called
soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f9668024df0, soa_generate_offer): called
soa_static.c:1189 offer_answer_step() soa_static(0x7f9668024df0, soa_generate_offer): generating local description
soa_static.c:1217 offer_answer_step() soa_static(0x7f9668024df0, soa_generate_offer): upgrade with local description
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f96967667e0, (nil), ""): called
soa_static.c:1446 offer_answer_step() soa_static(0x7f9668024df0, soa_generate_offer): storing local description
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668024df0, [(nil)], [0x7f9696768960], [0x7f969676895c]) called
nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/7777@192.168.1.166:5090) State ROUTING
2021-12-15 13:16:06.306094 93.63% [DEBUG] mod_sofia.c:158 sofia/external/7777@192.168.1.166:5090 SOFIA ROUTING
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_ivr_originate.c:67 (sofia/external/7777@192.168.1.166:5090) State Change CS_ROUTING -> CS_CONSUME_MEDIA
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = */192.168.1.166:5090
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:640 (sofia/external/7777@192.168.1.166:5090) State ROUTING going to sleep
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:5090
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 10)
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name */192.168.1.166:5090
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:659 (sofia/external/7777@192.168.1.166:5090) State CONSUME_MEDIA
2021-12-15 13:16:06.306094 93.63% [DEBUG] switch_core_state_machine.c:659 (sofia/external/7777@192.168.1.166:5090) State CONSUME_MEDIA going to sleep
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 1049 bytes of 1049 to udp/192.168.1.166:5090
tport.c:3521 tport_send_msg() tport_vsend returned 1049
nta.c:8390 outgoing_send() nta: sent INVITE (45233291) to */192.168.1.166:5090
tport.c:4189 tport_pend() tport_pend(0x7f96680062f0): pending 0x7f96680289e0 for udp/192.168.1.166:5080 (already 0)
nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: init -> calling, sent offer
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668024df0, [0x7f9696768940], [0x7f9696768948], [(nil)]) called
nua_stack.c:299 nua_stack_event() nua(0x7f96340037a0): event i_state INVITE sent
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:06.306094 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [calling][0]
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801e970 from (udp/192.168.1.166:5080) has 253 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801e970 (253 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:3370 agent_recv_response() nta: received 100 Trying for INVITE (45233291)
nta.c:3437 agent_recv_response() nta: 100 Trying is going to a transaction
nta.c:9684 outgoing_estimate_delay() nta_outgoing: RTT is 10.244 ms
tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f96680289e0 by 0x7f9668027ad0 with 0x7f966801e970 (preliminary)
nta.c:1301 agent_timer() nta: timer not set
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801e970 from (udp/192.168.1.166:5080) has 346 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801e970 (346 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:3370 agent_recv_response() nta: received 180 Ringing for INVITE (45233291)
nta.c:3437 agent_recv_response() nta: 180 Ringing is going to a transaction
tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f96680289e0 by 0x7f9668027ad0 with 0x7f966801e970 (preliminary)
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event r_invite 180 Ringing
nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: calling -> proceeding
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 180 Ringing
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
2021-12-15 13:16:06.566002 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [proceeding][180]
2021-12-15 13:16:06.566002 93.63% [NOTICE] sofia.c:7610 Ring-Ready sofia/external/7777@192.168.1.166:5090!
2021-12-15 13:16:06.566002 93.63% [DEBUG] switch_channel.c:3494 (sofia/external/7777@192.168.1.166:5090) Callstate Change DOWN -> RINGING
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:878 nua_respond() nua: nua_respond: entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_respond
2021-12-15 13:16:06.586006 93.63% [NOTICE] mod_sofia.c:2515 Ring-Ready sofia/external/1234@192.168.1.166:5080!
2021-12-15 13:16:06.586006 93.63% [NOTICE] switch_ivr_originate.c:565 Ring Ready sofia/external/1234@192.168.1.166:5080!
nua_stack.c:603 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_respond 180 Ringing
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
nua_session.c:2318 nua_invite_server_respond() nua: nua_invite_server_respond: entering
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 729 bytes of 729 to udp/192.168.1.166:44068
tport.c:3521 tport_send_msg() tport_vsend returned 729
nta.c:6868 incoming_reply() nta: sent 180 Ringing for INVITE (1)
nta.c:1362 set_timeout() nta: timer set to 60000 ms
nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: received -> early
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 180 Ringing
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
2021-12-15 13:16:06.606012 93.63% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [early][180]
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f9668011370 from (udp/192.168.1.166:5080) has 752 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f9668011370 (752 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:3370 agent_recv_response() nta: received 200 Ok for INVITE (45233291)
nta.c:3437 agent_recv_response() nta: 200 Ok is going to a transaction
tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f96680289e0 by 0x7f9668027ad0 with 0x7f9668011370
nta.c:1360 set_timeout() nta: timer shortened to 32000 ms
soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f9668024df0, (nil), 0x7f9634000b2f, 145) called
soa.c:1595 soa_process_answer() soa_process_answer(static::0x7f9668024df0) called
soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f9668024df0, soa_process_answer): called
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f9668010050, 0x7f966801a0b0, ""): called
soa_static.c:1304 offer_answer_step() soa_static(0x7f9668024df0, soa_process_answer): upgrade codecs with remote description
soa.c:1730 soa_activate() soa_activate(static::0x7f9668024df0, (nil)) called
nua_session.c:986 nua_session_client_response() nua(0x7f96340037a0): INVITE: processed SDP answer in 200 Ok (200)
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event r_invite 200 Ok
nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: proceeding -> completing, received answer
soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f9668024df0, [0x7f9696768320], [0x7f9696768328], [(nil)]) called
soa.c:616 soa_get_params() soa_get_params(static::0x7f9668024df0, ...) called
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 200 Ok
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:08.106041 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [completing][200]
2021-12-15 13:16:08.106041 92.23% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=9999 450 2195 IN IP4 192.168.1.166
s=Talk
c=IN IP4 192.168.1.166
t=0 0
m=audio 7078 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000

nua.c:638 nua_ack() nua: nua_ack: entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_ack
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_ack
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
soa.c:1730 soa_activate() soa_activate(static::0x7f9668024df0, (nil)) called
nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = udp/192.168.1.166:5090
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:5090
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name udp/192.168.1.166:5090
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 381 bytes of 381 to udp/192.168.1.166:5090
tport.c:3521 tport_send_msg() tport_vsend returned 381
nta.c:8390 outgoing_send() nta: sent ACK (45233291) to udp/192.168.1.166:5090
nua_session.c:4140 signal_call_state_change() nua(0x7f96340037a0): call state changed: completing -> ready
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 200 ACK sent
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_active 200 Call active
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
2021-12-15 13:16:08.106041 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [ready][200]
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5568 Set telephone-event payload to 101@8000
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:3872 Set Codec sofia/external/7777@192.168.1.166:5090 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_codec.c:111 sofia/external/7777@192.168.1.166:5090 Original read codec set to PCMA:8
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5917 Set telephone-event payload to 101@8000
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:5975 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf send payload to 101 recv payload to 101
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:8779 AUDIO RTP [sofia/external/7777@192.168.1.166:5090] 192.168.1.166 port 29744 -> 192.168.1.166 port 7078 codec: 8 ms: 20
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_rtp.c:4641 Not using a timer
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9091 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf send payload to 101
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9098 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf receive payload to 101
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9121 sofia/external/7777@192.168.1.166:5090 Set rtp dtmf delay to 40
2021-12-15 13:16:08.106041 92.23% [NOTICE] sofia.c:8683 Channel [sofia/external/7777@192.168.1.166:5090] has been answered
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_channel.c:3950 (sofia/external/7777@192.168.1.166:5090) Callstate Change RINGING -> ACTIVE
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:8779 AUDIO RTP [sofia/external/1234@192.168.1.166:5080] 192.168.1.166 port 22076 -> 192.168.1.166 port 8000 codec: 106 ms: 20
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_rtp.c:4641 Not using a timer
2021-12-15 13:16:08.106041 92.23% [DEBUG] switch_core_media.c:9121 sofia/external/1234@192.168.1.166:5080 Set rtp dtmf delay to 40
2021-12-15 13:16:08.106041 92.23% [DEBUG] mod_sofia.c:913 Local SDP sofia/external/1234@192.168.1.166:5080:
v=0
o=FreeSWITCH 1639552092 1639552093 IN IP4 192.168.1.166
s=FreeSWITCH
c=IN IP4 192.168.1.166
t=0 0
m=audio 22076 RTP/AVP 106
a=rtpmap:106 opus/48000/2
a=fmtp:106 useinbandfec=1; minptime=20
a=ptime:20
a=sendrecv

nua.c:878 nua_respond() nua: nua_respond: entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_respond
nua_stack.c:603 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_respond 200 OK
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668012dd0, ...) called
soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f9668012dd0, (nil), 0x7f963000f8db, -1) called
soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f9668012dd0, (nil), 0x7f963000f8db, -1) called
nua_session.c:2318 nua_invite_server_respond() nua: nua_invite_server_respond: entering
soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f9668012dd0) called
soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f9668012dd0, soa_generate_answer): called
soa_static.c:1189 offer_answer_step() soa_static(0x7f9668012dd0, soa_generate_answer): generating local description
soa_static.c:1230 offer_answer_step() soa_static(0x7f9668012dd0, soa_generate_answer): upgrade with remote description
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f9696766800, 0x7f966801cf80, ""): called
soa_static.c:1446 offer_answer_step() soa_static(0x7f9668012dd0, soa_generate_answer): storing local description
soa.c:1730 soa_activate() soa_activate(static::0x7f9668012dd0, (nil)) called
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668012dd0, [(nil)], [0x7f9696768980], [0x7f969676897c]) called
2021-12-15 13:16:08.106041 92.23% [NOTICE] switch_ivr_originate.c:3834 Channel [sofia/external/1234@192.168.1.166:5080] has been answered
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 975 bytes of 975 to udp/192.168.1.166:44068
tport.c:3521 tport_send_msg() tport_vsend returned 975
nta.c:6868 incoming_reply() nta: sent 200 OK for INVITE (1)
nta.c:1360 set_timeout() nta: timer shortened to 500 ms
nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: early -> completed, sent answer
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f9668012dd0, [0x7f9696768a50], [0x7f9696768a58], [(nil)]) called
soa.c:616 soa_get_params() soa_get_params(static::0x7f9668012dd0, ...) called
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 200 OK
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_channel.c:3950 (sofia/external/1234@192.168.1.166:5080) Callstate Change RINGING -> ACTIVE
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
2021-12-15 13:16:08.126068 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [completed][200]
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_ivr_originate.c:3892 Originate Resulted in Success: [sofia/external/7777@192.168.1.166:5090] Peer UUID: 1f6e2bc8-89bb-4089-881d-575b56c6f0b3
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801ddd0 from (udp/192.168.1.166:5080) has 438 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801ddd0 (438 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:2951 agent_recv_request() nta: received ACK sip:0000@192.168.1.166:5080;transport=udp SIP/2.0 (CSeq 1) (load: 0 rps)
nta.c:3090 agent_recv_request() nta: ACK (1) is going to INVITE (1)
nua_session.c:2567 process_ack_or_cancel() nua: process_ack_or_cancel: entering
soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f9668012dd0) called
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_ack 200 OK
nua_session.c:4140 signal_call_state_change() nua(0x7f9668001fb0): call state changed: completed -> ready
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 200 OK
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_active 200 Call active
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
2021-12-15 13:16:08.126068 92.23% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [ready][200]
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_ivr_bridge.c:1793 (sofia/external/7777@192.168.1.166:5090) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_core_state_machine.c:581 (sofia/external/7777@192.168.1.166:5090) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 10)
2021-12-15 13:16:08.126068 92.23% [DEBUG] switch_core_state_machine.c:650 (sofia/external/7777@192.168.1.166:5090) State EXCHANGE_MEDIA
2021-12-15 13:16:08.126068 92.23% [DEBUG] mod_sofia.c:671 SOFIA EXCHANGE_MEDIA
2021-12-15 13:16:08.165988 92.23% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
2021-12-15 13:16:08.165988 92.23% [NOTICE] switch_core_media.c:16153 Activating write resampler
2021-12-15 13:16:08.226073 92.23% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
2021-12-15 13:16:08.226073 92.23% [NOTICE] switch_core_media.c:16153 Activating write resampler
nta.c:1308 agent_timer() nta: timer set next to 4501 ms
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966801e440 from (udp/192.168.1.166:5080) has 917 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966801e440 (917 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:2951 agent_recv_request() nta: received INVITE sip:mod_sofia@192.168.1.166:5080 SIP/2.0 (CSeq 111) (load: 0 rps)
nta.c:3319 agent_aliases() nta: canonizing sip:mod_sofia@192.168.1.166:5080 with contact
nta.c:3131 agent_recv_request() nta: INVITE (111) going to existing leg
nta.c:1360 set_timeout() nta: timer shortened to 200 ms
nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f9668024df0) called
soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f9668024df0, (nil), 0x7f966802548d, 280) called
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_invite 100 Trying
nua_session.c:4146 signal_call_state_change() nua(0x7f96340037a0): ready call updated: received received offer
soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f9668024df0, [0x7f9696768610], [0x7f9696768618], [(nil)]) called
nua_stack.c:301 nua_stack_event() nua(0x7f96340037a0): event i_state 100 Trying
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:878 nua_respond() nua: nua_respond: entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_respond
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:603 nua_stack_signal() nua(0x7f96340037a0): recv signal r_respond 100 Trying
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:403 soa_set_params() soa_set_params(static::0x7f9668024df0, ...) called
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:5090
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:5090
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:5090
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 361 bytes of 361 to udp/192.168.1.166:5090
tport.c:3521 tport_send_msg() tport_vsend returned 361
nta.c:6868 incoming_reply() nta: sent 100 Trying for INVITE (111)
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:11.046069 91.53% [DEBUG] sofia.c:7499 Channel sofia/external/7777@192.168.1.166:5090 entering state [received][100]
2021-12-15 13:16:11.046069 91.53% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=9999 450 2196 IN IP4 192.168.1.166
s=Talk
c=IN IP4 192.168.1.166
t=0 0
a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
m=audio 7078 RTP/AVP 8 101
a=rtpmap:101 telephone-event/8000
a=sendonly
a=rtcp-fb:* trr-int 5000
a=rtcp-fb:* ccm tmmbr

2021-12-15 13:16:11.046069 91.53% [DEBUG] switch_channel.c:1975 (sofia/external/7777@192.168.1.166:5090) Callstate Change ACTIVE -> HELD
2021-12-15 13:16:11.166080 91.53% [DEBUG] switch_ivr.c:632 sofia/external/1234@192.168.1.166:5080 Command Execute [depth=0] playback(local_stream://moh)
EXECUTE [depth=0] sofia/external/1234@192.168.1.166:5080 playback(local_stream://moh)
2021-12-15 13:16:11.166080 91.53% [ERR] switch_core_file.c:346 Invalid file format [local_stream] for [moh]!
nta.c:1308 agent_timer() nta: timer set next to 1864 ms
2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5652 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5707 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5568 Set telephone-event payload to 101@8000
2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5917 Set telephone-event payload to 101@8000
2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:5975 sofia/external/7777@192.168.1.166:5090 Set 2833 dtmf send payload to 101 recv payload to 101
2021-12-15 13:16:11.306024 91.53% [DEBUG] switch_core_media.c:8761 Audio params are unchanged for sofia/external/7777@192.168.1.166:5090.
2021-12-15 13:16:11.306024 91.53% [DEBUG] sofia.c:8454 Processing updated SDP
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96340037a0): entering
nua_stack.c:559 nua_signal() nua(0x7f96340037a0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96340037a0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:11.326016 91.53% [INFO] sofia_glue.c:1651 sofia/external/1234@192.168.1.166:5080 sending invite call-id: (null)
2021-12-15 13:16:11.326016 91.53% [DEBUG] sofia_glue.c:1654 sofia/external/1234@192.168.1.166:5080 sending invite version: 1.10.8-dev git e428be3 2021-11-17 19:23:28Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1639552092 1639552095 IN IP4 192.168.1.166
s=FreeSWITCH
c=IN IP4 192.168.1.166
t=0 0
m=audio 22076 RTP/AVP 8
a=rtpmap:8 PCMA/8000
a=ptime:20
a=sendonly

nua.c:632 nua_invite() nua: nua_invite: entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_invite
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_invite
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:356 soa_destroy() soa_destroy(static::0x7f9668012dd0) called
nta.c:2707 nta_tpn_by_url() nta: selecting scheme sip
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 856 bytes of 856 to udp/192.168.1.166:44068
tport.c:3521 tport_send_msg() tport_vsend returned 856
nta.c:8390 outgoing_send() nta: sent INVITE (45233293) to UDP/192.168.1.166:44068
tport.c:4189 tport_pend() tport_pend(0x7f96680062f0): pending 0x7f966801f4a0 for udp/192.168.1.166:5080 (already 0)
nta.c:1360 set_timeout() nta: timer shortened to 1000 ms
nua_session.c:4146 signal_call_state_change() nua(0x7f9668001fb0): ready call updated: calling sent offer
nua_stack.c:299 nua_stack_event() nua(0x7f9668001fb0): event i_state INVITE sent
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f96680062f0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f96680062f0)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f96680062f0) msg 0x7f966802a390 from (udp/192.168.1.166:5080) has 345 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f96680062f0): msg 0x7f966802a390 (345 bytes) from udp/192.168.1.166:5080/sip next=(nil)
nta.c:3370 agent_recv_response() nta: received 415 Unsupported Media Type for INVITE (45233293)
nta.c:3437 agent_recv_response() nta: 415 Unsupported Media Type is going to a transaction
nta.c:9684 outgoing_estimate_delay() nta_outgoing: RTT is 0.385 ms
tport.c:4251 tport_release() tport_release(0x7f96680062f0): 0x7f966801f4a0 by 0x7f9668022d40 with 0x7f966802a390
tport.c:3286 tport_tsend() tport_tsend(0x7f96680062f0) tpn = UDP/192.168.1.166:44068
tport.c:4075 tport_resolve() tport_resolve addrinfo = 192.168.1.166:44068
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f96680062f0): not found by name UDP/192.168.1.166:44068
tport.c:3623 tport_vsend() tport_vsend(0x7f96680062f0): 338 bytes of 338 to udp/192.168.1.166:44068
tport.c:3521 tport_send_msg() tport_vsend returned 338
nta.c:8390 outgoing_send() nta: sent ACK (45233293) to UDP/192.168.1.166:44068
nta.c:8816 outgoing_free() nta: outgoing_free(0x7f96680256f0)
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event r_invite 415 Unsupported Media Type
nua_session.c:4146 signal_call_state_change() nua(0x7f9668001fb0): ready call updated: init
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_state 415 Unsupported Media Type
nua_stack.c:301 nua_stack_event() nua(0x7f9668001fb0): event i_active 415 Call active
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
2021-12-15 13:16:11.326016 91.53% [DEBUG] sofia.c:7499 Channel sofia/external/1234@192.168.1.166:5080 entering state [calling][0]
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
2021-12-15 13:16:11.326016 91.53% [DEBUG] sofia.c:7492 Channel sofia/external/1234@192.168.1.166:5080 skipping state [ready][415]
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nua.c:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1164 nua_handle_unref_user() nua nua_handle_unref_user(0x7f9668001fb0): entering
nua_stack.c:559 nua_signal() nua(0x7f9668001fb0): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:559 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f9668001fb0): recv signal r_handle_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nta.c:1308 agent_timer() nta: timer set next to 788 ms
nta.c:7211 _nta_incoming_timer() nta: timer I fired, terminate 200 response
nta.c:5896 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f96967689d0)
nta.c:7265 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/2 free
nta.c:1308 agent_timer() nta: timer set next to 26983 ms