[Home]

Summary:ASTERISK-28430: res_rtp_asterisk.c: FRACK!, Failed assertion errno != EBADF
Reporter:under (under)Labels:patch
Date Opened:2019-05-27 04:39:45Date Closed:2020-10-08 04:03:15
Priority:MajorRegression?
Status:Closed/CompleteComponents:Core/General
Versions:16.2.1 Frequency of
Occurrence
Constant
Related
Issues:
is duplicated byASTERISK-28543 When Asterisk cannot connect to SIP socket it starts to flood with "Bad descriptor" errors and hangs
is duplicated byASTERISK-28765 tcptls API: bad file descriptor when connection fails
is duplicated byASTERISK-28996 chan_sip: TLS - Bad file descriptor errors
Environment:FreeBSD-11.2Attachments:( 0) 5.diff
Description:Asterisk hangs up a call in the middle.
The following message is inside log:

[2019-05-27 11:12:04] ERROR[100170] asterisk-stable-16.2.1/main/tcptls.c: Unable to connect SIP socket to 192.168.0.5:5060: Host is down
[2019-05-27 11:12:04] ERROR[100170] asterisk-stable-16.2.1/channels/chan_sip.c: unable to start TCPTLS client
[2019-05-27 11:12:04] ERROR[102203][C-00000001] asterisk-stable-16.2.1/res/res_rtp_asterisk.c: FRACK!, Failed assertion errno != EBADF (0)
[2019-05-27 11:12:04] ERROR[102203][C-00000001] : Got 25 backtrace records
# 0: 0x735c7a <__ast_assert_failed+0x8a> at /usr/local/sbin/asterisk
# 1: 0x833b20ef9 <__internal_res_rtp_asterisk_self+0x5fe9> at /usr/local/lib/asterisk/res_rtp_asterisk.so
# 2: 0x68f53a <ast_rtp_instance_read+0x5a> at /usr/local/sbin/asterisk
# 3: 0x83253d025 <__internal_chan_sip_self+0xa15c5> at /usr/local/lib/asterisk/chan_sip.so
# 4: 0x832486333 <_init+0xa6a3> at /usr/local/lib/asterisk/chan_sip.so
# 5: 0x5157e1 <__ast_read+0xac1> at /usr/local/sbin/asterisk
# 6: 0x51766b <ast_read_stream+0x1b> at /usr/local/sbin/asterisk
# 7: 0x4aa26a <bridge_handle_trip+0x13a> at /usr/local/sbin/asterisk
# 8: 0x4a8872 <bridge_channel_wait+0x342> at /usr/local/sbin/asterisk
# 9: 0x4a7ec0 <bridge_channel_internal_join+0x630> at /usr/local/sbin/asterisk
#10: 0x4b3e9a <ast_bridge_join+0x3ca> at /usr/local/sbin/asterisk
#11: 0x5af39f <ast_bridge_call_with_flags+0x18f> at /usr/local/sbin/asterisk
#12: 0x5af8c7 <ast_bridge_call+0x27> at /usr/local/sb[2019-05-27 11:12:04] WARNING[102203][C-00000001] asterisk/asterisk-stable-16.2.1/res/res_rtp_asterisk.c: RTP Read error: Bad file descriptor.  Hanging up.

I found out that the issue is connected to tcptls.c code.
Asterisk is configured to register at TCP peer.
However the TCP peer is offline.
And there is a bug in Asterisk TCP connection error handling code.
Asterisk closes the socket FD twice!
If this socket FD has been reused by some other Asterisk thread, it's closed, just like it happens in above trace, when the socket is reused for RTP.

So, the issue flow is as follows:

1. Thread 1: starts TCP registration process to peer A, creating socket FD 60.
2. Thread 1: there is a TCP connection issue, so Asterisk closes the socket FD 60 : ast_tcptls_client_start() -> close(FD 60).
3. Thread 2: a new SIP call, peer B -> peer C.
The operating system sees that socket FD 60 is currently free, so it re-uses it for RTP socket.
4. Thread 1: ast_tcptls_client_start() -> ao2_ref(tcptls_session, -1) -> session_instance_destructor() -> ast_iostream_close() -> close(FD 60).
So FD 60 is closed again, but  FD 60 is now used for RTP of a totally different call!
5. Thread 2: attempts to read from closed RTP socket which leads to errno = EBADF and assert.

Comments:By: Asterisk Team (asteriskteam) 2019-05-27 04:39:47.305-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.

By: under (under) 2019-05-27 05:22:34.916-0500

It seems to me, that ast_iostream_from_fd(int *fd) has an FD-ownership transfer semantics, when ast_iostream becomes responsible for closing FD.

However, ast_tcptls_client_create() uses ast_iostream_from_fd() in a way, that the FD didn't transfer to iostream, but also has been saved in desc->accept_fd.

I guess, this is not what the author of ast_iostream_from_fd(int *fd) wanted to happen.

The FD saving to desc->accept_fd caused double close() issue, when close() for the same FD is called both from iostream.c and tcptls.c.
So I guess it's better to follow the FD-ownership transfer semantics of ast_iostream_from_fd(int *fd) and don't have duplicates of FD saved.

Moreover, using desc->accept_fd inside ast_tcptls_client_create() could be frustrating, because accept() makes sense only in TCP server side, and not in TCP client side.
So I think, it's better not to use accept_fd inside ast_tcptls_client_create().

Attaching the patch which implements this and fixes this bug.


By: Benjamin Keith Ford (bford) 2019-05-28 09:22:36.947-0500

Would you be willing to submit this patch to Gerrit [1]? If you've never submitted to Gerrit before, instructions on how to do so can be found here [2].

[1]: https://gerrit.asterisk.org/q/status:open
[2]: https://wiki.asterisk.org/wiki/display/AST/Gerrit+Usage

By: under (under) 2019-05-29 04:17:11.780-0500

submitted:
https://gerrit.asterisk.org/c/asterisk/+/11419

By: Benjamin Keith Ford (bford) 2019-05-29 08:54:50.538-0500

Thanks! I'll assign the issue to you and open it. When the code reviews go through, this issue will be updated automatically.

By: Friendly Automation (friendly-automation) 2020-10-08 04:03:17.425-0500

Change 15024 merged by Friendly Automation:
tcptls.c: Don't close TCP client file descriptors more than once

[https://gerrit.asterisk.org/c/asterisk/+/15024|https://gerrit.asterisk.org/c/asterisk/+/15024]

By: Friendly Automation (friendly-automation) 2020-10-08 05:47:55.162-0500

Change 15018 merged by Joshua Colp:
tcptls.c: Don't close TCP client file descriptors more than once

[https://gerrit.asterisk.org/c/asterisk/+/15018|https://gerrit.asterisk.org/c/asterisk/+/15018]

By: Friendly Automation (friendly-automation) 2020-10-08 05:48:05.623-0500

Change 15019 merged by Joshua Colp:
tcptls.c: Don't close TCP client file descriptors more than once

[https://gerrit.asterisk.org/c/asterisk/+/15019|https://gerrit.asterisk.org/c/asterisk/+/15019]

By: Friendly Automation (friendly-automation) 2020-10-08 05:50:52.713-0500

Change 15020 merged by Joshua Colp:
tcptls.c: Don't close TCP client file descriptors more than once

[https://gerrit.asterisk.org/c/asterisk/+/15020|https://gerrit.asterisk.org/c/asterisk/+/15020]