search

signalwire / freeswitch

FreeSWITCH is a Software Defined Telecom Stack enabling the digital transformation from proprietary telecom switches to a versatile software implementation that runs on any commodity hardware. From a Raspberry PI to a multi-core server, FreeSWITCH can unlock the telecommunications potential of any device.
https://freeswitch.com/#getting-started
Other
3.65k stars 1.44k forks source link

Enabling `100rel`(PRACK SIP Message) is not sending CHANNEL_HANGUP while device declining the call #2365

Open premkumarramasamy opened 10 months ago

premkumarramasamy commented 10 months ago

Describe the bug I am facing one issue with option enable-100rel option(we have enabled this in external profile). When this option is enabled FS is not generating CHANNAL_HANGUP event. Scenario is like this: Call is established from FreeSWITCH and it is declined by the device, we are getting 486 response from the device, upon this FS is not generating CHANNEL_HANGUP event. Is there any open issue with this behaviour or am I missing some config? Without this option FS is generating the events.

To Reproduce Steps to reproduce the behavior:

  1. Register a Event Socket Library using any of the available tools/library
  2. Please a valid dial command in fs_cli to reach a device registered to FS/SBC, which will generate events and they are published to event socket
  3. Decline the call from the device, Device should send 486 to FS, ideally this should generate a CHANNEL_HANGUP event, which is missing when enable-100rel flag enabled in the dialplan.

Expected behavior CHANNEL_HANGUP event should be sent to event socket client registered

Package version or git hash

Trace logs Provide freeswitch logs w/ DEBUG and UUID logging enabled Seeing the below message in the debug logs.

tport.c:2769 tport_wakeup_pri() tport_wakeup_pri(0x7f96b0004ec0): events IN
tport.c:2900 tport_recv_event() tport_recv_event(0x7f96b0004ec0)
tport.c:3237 tport_recv_iovec() tport_recv_iovec(0x7f96b0004ec0) msg 0x7f96b002d230 from (udp/10.192.133.207:5080) has 502 bytes, veclen = 1
tport.c:3055 tport_deliver() tport_deliver(0x7f96b0004ec0): msg 0x7f96b002d230 (502 bytes) from udp/10.192.133.145:5080/sip next=(nil)
nta.c:3378 agent_recv_response() nta: received 200 OK for PRACK (78270254)
nta.c:3445 agent_recv_response() nta: 200 OK is going to a transaction
nta.c:9697 outgoing_estimate_delay() nta_outgoing: RTT is 11.053 ms
tport.c:4253 tport_release() tport_release(0x7f96b0004ec0): 0x7f96b002c100 by 0x7f96b0028290 with 0x7f96b002d230
nua_stack.c:301 nua_stack_event() nua(0x7f96c8002370): event r_prack 200 OK
nua_stack.c:389 nua_application_event() nua: nua_application_event: entering
nua.c:1170 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96c8002370): entering
nua_stack.c:558 nua_signal() nua(0x7f96c8002370): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:558 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua(0x7f96c8002370): 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:365 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:1170 nua_handle_unref_user() nua nua_handle_unref_user(0x7f96c8002370): entering
nua_stack.c:599 nua_stack_signal() nua(0x7f96c8002370): recv signal r_handle_unref
nua_stack.c:558 nua_signal() nua(0x7f96c8002370): sent signal r_handle_unref
nua.c:1157 nua_unref_user() nua: nua_unref_user: entering
nua_stack.c:558 nua_signal() nua((nil)): sent signal r_unref
nua_stack.c:599 nua_stack_signal() nua((nil)): recv signal r_unref
nta.c:1317 agent_timer() nta: timer set next to 4010 ms
tport.c:2769 tport_wakeup_pri() tport_wakeup_pri(0x7f96b0004ec0): events IN
tport.c:2900 tport_recv_event() tport_recv_event(0x7f96b0004ec0)
tport.c:3237 tport_recv_iovec() tport_recv_iovec(0x7f96b0004ec0) msg 0x7f96b002db20 from (udp/10.192.133.207:5080) has 419 bytes, veclen = 1
tport.c:3055 tport_deliver() tport_deliver(0x7f96b0004ec0): msg 0x7f96b002db20 (419 bytes) from udp/10.192.133.145:5080/sip next=(nil)
nta.c:3378 agent_recv_response() nta: received 486 Busy here for INVITE (78270253)
nta.c:3445 agent_recv_response() nta: 486 Busy here is going to a transaction
tport.c:4253 tport_release() tport_release(0x7f96b0004ec0): 0x7f96b001e910 by 0x7f96b0015f60 with 0x7f96b002db20
tport.c:3290 tport_tsend() tport_tsend(0x7f96b0004ec0) tpn = udp/10.192.133.145:5060
tport.c:4076 tport_resolve() tport_resolve addrinfo = 10.192.133.145:5060
tport.c:4713 tport_by_addrinfo() tport_by_addrinfo(0x7f96b0004ec0): not found by name udp/10.192.133.145:5060
tport.c:3625 tport_vsend() tport_vsend(0x7f96b0004ec0): 408 bytes of 408 to udp/10.192.133.145:5060
tport.c:3526 tport_send_msg() tport_vsend returned 408
nta.c:8400 outgoing_send() nta: sent ACK (78270253) to udp/10.192.133.145:5060
nta.c:8829 outgoing_free() nta: outgoing_free(0x7f96b0026b90)
nta.c:9233 outgoing_timer_dk() nta: timer K fired, terminate PRACK (78270254)
nta.c:8905 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f96dd2fbb30)
nta.c:9045 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/3 free
nta.c:1317 agent_timer() nta: timer set next to 7415 ms
nta.c:7248 _nta_incoming_timer() nta: timer J fired, terminate 200 response
nta.c:5904 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f96dd2fbb30)
nta.c:7270 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free

backtrace from core file If applicable, provide the full backtrace from the core file.

(gdb) set pagination off
(gdb) set logging file /tmp/backtrace.log
(gdb) set logging on
Copying output to /tmp/backtrace.log.
(gdb) bt
(gdb) bt full
(gdb) info threads
(gdb) thread apply all bt
(gdb) thread apply all bt full
(gdb) set logging off
Done logging to /tmp/backtrace.log.
(gdb) quit
denyspozniak commented 5 months ago

Hello!

I think that our case is also related to this issue; when we enable 100rel on the external profile (port 5080), the 486 Busy Here status is not forwarded to the internal profile. When we turn off 100rel, everything works as it should. In the trace screenshot, the internal FS leg is on port 5060, and the external leg is on port 5080.

image