ASTERISK-19192: ERROR we couldn't allocate a port for RTP instance

[Home]

Summary: ASTERISK-19192: ERROR we couldn't allocate a port for RTP instance

Reporter: Tyuta Vitalii (zeratyl) Labels:

Date Opened: 2012-01-12 06:17:35.000-0600 Date Closed: 2012-01-23 06:04:23.000-0600

Priority: Blocker Regression? Yes

Status: Closed/Complete Components: Resources/res_rtp_asterisk

Versions: 1.8.8.1 Frequency of
Occurrence Frequent

Related
Issues:
must be completed before resolving ASTERISK-19040 Asterisk 1.8.9.0 Blockers

must be completed before resolving ASTERISK-19041 Asterisk 10.1.0 Blockers

is the original version of this clone: ASTERISK-19578 ERROR we couldn't allocate a port for RTP instance while DAHDI bridgeing

is related to ASTERISK-19579 ERROR we couldn't allocate a port for RTP instance while DAHDI bridgeing

Environment: Attachments: ( 0) ASTERISK-19192.patch
( 1) issue_19192_full_log.7z

Description: Good afternoon. Once a day there's a problem and asterisk stops processing calls:

[Jan 12 12:41:01] ERROR[28213] res_rtp_asterisk.c: Oh dear... we couldn't allocate a port for RTP instance '0x7f0c981f8d28'
[Jan 12 12:41:35] ERROR[28216] res_rtp_asterisk.c: Oh dear... we couldn't allocate a port for RTP instance '0x12b8818'
[Jan 12 12:41:41] ERROR[25298] res_rtp_asterisk.c: Oh dear... we couldn't allocate a port for RTP instance '0x7f0ca0538218'

If you look at when the server is working properly, that is strange::

{noformat}
CLI> sip show channels
Peer User/ANR Call ID Format Hold Last Message Expiry Peer
192.168.254.95 (None) b6d1d2d4-afa76a 0x0 (nothing) No Rx: NOTIFY <guest>
192.168.250.107 7306 5922 0x200000000 (sp No Rx: ACK 7306
212.53.40.40 78314142019 666b8e9348f9b60 0x8 (alaw) No Tx: ACK sipnet
192.168.254.75 (None) ec5f0901-6b5631 0x0 (nothing) No Rx: NOTIFY <guest>
192.168.245.81 (None) 18391270948646- 0x0 (nothing) No Rx: REGISTER <guest>
192.168.250.111 (None) 13f78bd1c5b582a 0x0 (nothing) No Rx: REGISTER <guest>
192.168.254.33 (None) 37b30012763ae7e 0x0 (nothing) No Rx: REGISTER <guest>
192.168.250.109 7304 acdf1de6-1106-1 0x200200000 (sp No Rx: ACK 7304
192.168.245.74 (None) 5710313997309-2 0x0 (nothing) No Rx: REGISTER <guest>
192.168.250.108 (None) 27588 0x0 (nothing) No Rx: REGISTER <guest>
78.46.95.118 380679754572 4786e4cd0c9f03f 0x8 (alaw) No Tx: INVITE zadarma_ua
192.168.254.96 (None) eac1fa18-aa31ce 0x0 (nothing) No Rx: NOTIFY <guest>
192.168.250.74 (None) f2347a64-dc52a8 0x0 (nothing) No Rx: NOTIFY <guest>
192.168.254.97 (None) 34a5d163-618d67 0x0 (nothing) No Rx: NOTIFY <guest>
192.168.245.80 (None) 294091669921902 0x0 (nothing) No Rx: OPTIONS <guest>
192.168.250.75 (None) 632a5364-bae66b 0x0 (nothing) No Rx: NOTIFY <guest>
192.168.245.77 (None) 23185318496852- 0x0 (nothing) No Rx: REGISTER <guest>
192.168.250.103 (None) 28354 0x0 (nothing) No Rx: REGISTER <guest>
192.168.245.73 (None) 23851116934316- 0x0 (nothing) No Rx: REGISTER <guest>
19 active SIP dialogs
{noformat}

{noformat}
netstat -lup | grep 10
(Not all processes could be identified, non-owned process info
will not be shown, you would have to be root to see it all.)
udp 0 0 *:10218 *:* -
udp 3600 0 *:10346 *:* -
udp 0 0 *:10219 *:* -
udp 0 0 *:10347 *:* -
udp 3960 0 *:10092 *:* -
udp 0 0 *:10093 *:* -
udp 3600 0 *:10224 *:* -
udp 0 0 *:10225 *:* -
udp 3600 0 *:10356 *:* -
udp 0 0 *:10357 *:* -
udp 3960 0 *:10360 *:* -
udp 0 0 *:10361 *:* -
udp 3600 0 *:10362 *:* -
udp 0 0 *:10363 *:* -
udp 3600 0 *:10368 *:* -
udp 0 0 *:10369 *:* -
udp 3240 0 *:10370 *:* -
udp 0 0 *:10371 *:* -
udp 3960 0 *:10246 *:* -
udp 0 0 *:10247 *:* -
udp 0 0 *:10248 *:* -
udp 0 0 *:10249 *:* -
udp 3600 0 *:10378 *:* -
udp 3600 0 *:10250 *:* -
udp 0 0 *:10379 *:* -
udp 0 0 *:10251 *:* -
udp 3600 0 *:10252 *:* -
udp 3600 0 *:10124 *:* -
udp 0 0 *:10253 *:* -
udp 0 0 *:10125 *:* -
udp 0 0 *:10382 *:* -
udp 0 0 *:10383 *:* -
udp 3600 0 *:10002 *:* -
udp 0 0 *:10003 *:* -
udp 3600 0 *:10268 *:* -
udp 3600 0 *:10396 *:* -
udp 0 0 *:10269 *:* -
udp 0 0 *:10397 *:* -
udp 3240 0 *:10270 *:* -
udp 0 0 *:10271 *:* -
udp 3600 0 *:10144 *:* -
udp 0 0 *:10145 *:* -
udp 3600 0 *:10018 *:* -
udp 0 0 *:10019 *:* -
udp 3600 0 *:10278 *:* -
udp 3600 0 *:10150 *:* -
udp 0 0 *:10279 *:* -
udp 0 0 *:10151 *:* -
udp 3600 0 *:10280 *:* -
udp 0 0 *:10281 *:* -
udp 3600 0 *:10026 *:* -
udp 0 0 *:10027 *:* -
udp 3600 0 *:10158 *:* -
udp 0 0 *:10159 *:* -
udp 3960 0 *:10160 *:* -
udp 0 0 *:10161 *:* -
udp 3600 0 *:10034 *:* -
udp 3960 0 *:10290 *:* -
udp 0 0 *:10035 *:* -
udp 0 0 *:10291 *:* -
udp 3600 0 *:10292 *:* -
udp 0 0 *:10293 *:* -
udp 3240 0 *:10294 *:* -
udp 0 0 *:10295 *:* -
udp 3600 0 *:10040 *:* -
udp 0 0 *:10041 *:* -
udp 3240 0 *:10042 *:* -
udp 0 0 *:10043 *:* -
udp 3600 0 *:10300 *:* -
udp 3960 0 *:10044 *:* -
udp 0 0 *:10301 *:* -
udp 0 0 *:10045 *:* -
udp 3960 0 *:10302 *:* -
udp 3600 0 *:10174 *:* -
udp 3960 0 *:10046 *:* -
udp 0 0 *:10303 *:* -
udp 0 0 *:10175 *:* -
udp 0 0 *:10047 *:* -
udp 3600 0 *:10306 *:* -
udp 0 0 *:10307 *:* -
udp 3600 0 *:10052 *:* -
udp 3600 0 *:10180 *:* -
udp 0 0 *:10053 *:* -
udp 0 0 *:10181 *:* -
udp 3600 0 *:10310 *:* -
udp 3600 0 *:10182 *:* -
udp 0 0 *:10311 *:* -
udp 0 0 *:10183 *:* -
udp 3600 0 *:10184 *:* -
udp 0 0 *:10185 *:* -
udp 3600 0 *:10186 *:* -
udp 0 0 *:10187 *:* -
udp 3600 0 *:10188 *:* -
udp 0 0 *:10189 *:* -
udp 3600 0 *:10190 *:* -
udp 0 0 *:10191 *:* -
udp 3600 0 *:10192 *:* -
udp 3600 0 *:10320 *:* -
udp 0 0 *:10193 *:* -
udp 0 0 *:10321 *:* -
udp 3600 0 *:10322 *:* -
udp 0 0 *:10323 *:* -
udp 3240 0 *:10326 *:* -
udp 3600 0 *:10070 *:* -
udp 0 0 *:10327 *:* -
udp 0 0 *:10071 *:* -
udp 3240 0 *:10200 *:* -
udp 0 0 *:10201 *:* -
udp 3600 0 *:10202 *:* -
udp 0 0 *:10203 *:* -
udp 3600 0 *:10332 *:* -
udp 3960 0 *:10204 *:* -
udp 0 0 *:10333 *:* -
udp 0 0 *:10205 *:* -
udp 3600 0 *:10334 *:* -
udp 0 0 *:10335 *:* -
udp 3600 0 *:10336 *:* -
udp 0 0 *:10337 *:* -
udp 3240 0 *:10082 *:* -
udp 0 0 *:10083 *:* -
udp 3600 0 *:10084 *:* -
udp 0 0 *:10085 *:* -
udp 3960 0 *:10216 *:* -
udp 0 0 *:10217 *:* -
{noformat}

/etc/asterisk/rtp.conf

[general]

rtpstart=10000
rtpend=10400

Comments: By: Matt Jordan (mjordan) 2012-01-12 08:23:07.945-0600

That error message occurs when res_rtp_asterisk has attempted to bind to every even socket within the range of rtpstart to rtpend and failed to do so. Note that it means that your range only allows for 200 simultaneous RTP sessions to be present. Note as well that there is not always a single RTP session per dialog - a single dialog could have multiple RTP sessions if they support multiple media types.

This is a fairly small range - keeping in mind that the RTP sessions exist along with the associated SIP dialog until the SIP dialog's scheduled destruction is activated, which can occur some time after the actual call has ended.

I'm not sure of the correlation between your screenshot of the currently open ports coincides with the timestamps of your error message - it can be difficult to capture this accurately, as SIP dialogs can be destroyed immediately after a failure to bind to an RTP session occurred, thereby freeing the ports that prevented the session from being bound.

As it is, this does not look like a bug but rather a limitation that you've imposed based on your configuration.
By: Tyuta Vitalii (zeratyl) 2012-01-13 00:37:09.342-0600

Thanks for the clarification. Confused what to version 1.8.5, this error did not manifest itself at the same settings. I will try to extend the range of RTP ports and watch.
By: Tyuta Vitalii (zeratyl) 2012-01-13 04:34:49.135-0600

Channels used at the time of measurement is not the number of open rtp port 354. I think it's strange.
By: Tyuta Vitalii (zeratyl) 2012-01-17 02:49:29.175-0600

Increased the number of rtp ports several times. The number of open ports is growing. For two days there are more than 800 and the number is constantly increasing. tried

rtptimeout = 60
rtpholdtimeout = 300

but the problem is not solved.
By: Matt Jordan (mjordan) 2012-01-17 11:12:13.904-0600

We require a complete debug log to help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

By: Mark Michelson (mmichelson) 2012-01-19 10:22:49.301-0600

I have reproduced this issue. It requires some specific things to happen.

First, it requires that calls are not locally RTP bridged. By that, I mean that we are not doing what has typically been called a "packet 2 packet" bridge between the phones. Doing this will mean that Asterisk sends RTCP to the endpoints involved.

Second, it requires that a transfer is executed by a SIP phone by sending a REFER without previously sending a reINVITE to place the other side on hold.

Under these circumstances, when the transfer is complete, Asterisk will not properly signal to the RTP code that it needs to stop sending RTCP. The result is that the port stays up and RTCP is sent out forever at regular intervals.

I am working on a patch and will have it up as soon as I can.
By: Mark Michelson (mmichelson) 2012-01-19 16:47:20.999-0600

I am attaching ASTERISK-19192.patch to this issue. It fixes the problem for me and I have a strong suspicion that it will work for others experiencing the issue as well. Please let us know if this does the trick.

The patch was created against version 1.8.8.1 of Asterisk since that is what the issue was reported against.
By: Tyuta Vitalii (zeratyl) 2012-01-20 00:55:52.563-0600

Thank you very much. I'll check.
By: Mark Michelson (mmichelson) 2012-01-20 18:09:38.968-0600

I went ahead and committed the patch. I'm leaving this issue open for now so that you can report if the patch worked for you. If it did, I'll close the issue as well.
By: Tyuta Vitalii (zeratyl) 2012-01-23 06:04:23.215-0600

The patch works. Unnecessary open ports for a day of work did not appear. Thank you very much.
By: Sherwood McGowan (smcgowan) 2016-07-14 13:00:05.150-0500

Just a heads up, this issue cropped up today on one of our Asterisk servers. 17 calls were chewing up 20k RTP ports... If need be, I can upload a backtrace
By: Joshua C. Colp (jcolp) 2016-07-14 13:04:37.862-0500

[~smcgowan] Please open a new issue. It may have the same symptoms but the issue here was fixed long ago.