[Home]

Summary:ASTERISK-19916: Asterisk gets exhausted of all the file resources
Reporter:Jim Boykin (boykinjim)Labels:
Date Opened:2012-05-26 05:43:05Date Closed:2012-06-29 18:04:34
Priority:MajorRegression?
Status:Closed/CompleteComponents:General
Versions:1.8.11.1 Frequency of
Occurrence		Occasional
Related
Issues:
Environment:CentOS 6 32 bitAttachments:( 0) 270512_Jim_Boykin_netstatoutput.txt
Description:Asterisk gets exhausted of all the file resources, CPU is at 100% after following since it's in tight loop. Only way to recover is to kill asterisk.

[May 26 05:14:12] WARNING[19323] asterisk.c: Accept returned -1: Too many open files
[May 26 05:14:12] WARNING[19323] asterisk.c: Accept returned -1: Too many open files
[May 26 05:14:12] WARNING[19323] asterisk.c: Accept returned -1: Too many open files
[EDIT - Rusty Newton - 5/30/12 - removed a few dozen redundant log entries that didn't add anything to report. Messages above happen many times...]

However above is not the only place - I can see many related errors from the log



[May 23 20:04:35] ERROR[20788] res_timing_timerfd.c: Failed to create timerfd timer: Too many open files
[May 23 20:38:31] WARNING[20885] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[May 23 20:38:31] WARNING[20885] chan_network.c: Unable to allocate channel structure

[May 24 00:11:48] ERROR[19365] cdr_csv.c: Unable to re-open master file /var/log/asterisk//cdr-csv//Master.csv : Too many open files

[May 24 00:13:26] WARNING[19369] res_rtp_asterisk.c: Unable to allocate RTCP socket: Too many open files
Comments:By: Michael L. Young (elguero) 2012-05-26 08:11:14.361-0500

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: Jim Boykin (boykinjim) 2012-05-27 12:18:21.895-0500

I will try to send you debug logs however it's in production system so I need be more careful. However I have some more info and it seems like RTP sockets are not closed. Following is my rtp.conf and list of all the open sockets (netstat output). As you can see, all the open sockets are between rtpstart and rtpend.


[general]
;
; RTP start and RTP end configure start and end addresses
;
; Defaults are rtpstart=5000 and rtpend=31000
;
rtpstart=25000
rtpend=30000

[Edit-Rusty Newton-30/May/12- removed debug output and attached as: 270512_Jim_Boykin_netstatoutput.txt]
   

 
By: Jim Boykin (boykinjim) 2012-05-27 13:39:01.328-0500

Did a bit of debugging and it seems like one RTP destroy is not called when gtalk channel is bridged to SIP channel. This does not happen when two SIP channels are bridged in that case two RTP destroy are called.

By: Rusty Newton (rnewton) 2012-05-30 15:09:27.632-0500

Removing netstat output from Jim Boykin's comment and attaching as file to prevent scrolling a dozen pages.
By: Rusty Newton (rnewton) 2012-05-30 15:17:40.769-0500

Still need additional debug:  https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

Likely will need a full log, with verbose and debug of at least 5, especially covering the time before this issue starts happening and the moment it does.

Since we don't have any others reporting this, we also want to know what is unique about your scenario. If you can describe what is happening on the system when this happens that will help as well. AGI, AMI in use? Database connectivity?, can you post your dialplan (sanitized of course)?

Also, please attach any debug as text files and do not post debug inline with comments.
By: Rusty Newton (rnewton) 2012-06-29 18:04:19.963-0500

Suspended due to lack of activity. Please request a bug marshal in #asterisk-bugs on the IRC network irc.freenode.net to reopen the issue should you have the additional information requested.  Further information can be found at https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines


By: Brian (iptelecom) 2012-12-07 05:04:44.771-0600

Hi Guys,

This just happened to me today on version 1.8.12.0

Literally thousands of this line in log file:

[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor


Then a segfault.

[1459311.730565] asterisk[23967]: segfault at b583eeb8 ip b767bcfa sp b583eebc error 6 in libc-2.11.3.so[b763f000+140000]

The logfile leading up to the event:

Dec  7 10:24:01] WARNING[23940] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:24:01] WARNING[23940] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:24:01] WARNING[23940] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:24:11] WARNING[23941] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:24:11] WARNING[23941] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:24:11] WARNING[23941] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:24:20] WARNING[23942] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:24:20] WARNING[23942] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:24:20] WARNING[23942] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:25:18] WARNING[23947] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:25:18] WARNING[23947] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:25:18] WARNING[23947] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:25:28] WARNING[23948] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:25:28] WARNING[23948] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:25:28] WARNING[23948] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:25:35] WARNING[23949] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:25:35] WARNING[23949] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:25:35] WARNING[23949] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:26:04] WARNING[23960] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:26:04] WARNING[23960] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:26:04] WARNING[23960] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:26:10] WARNING[23961] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:26:10] WARNING[23961] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:26:10] WARNING[23961] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:26:25] ERROR[23962] acl.c: Cannot create socket
[Dec  7 10:26:25] ERROR[23962] res_timing_timerfd.c: Failed to create timerfd timer: Too many open files
[Dec  7 10:26:25] WARNING[23962] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:26:25] WARNING[23962] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:26:25] WARNING[23962] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:26:25] WARNING[23930] res_rtp_asterisk.c: RTP Read error: Socket operation on non-socket. Hanging up.
[Dec  7 10:26:25] ERROR[23930] cdr_sqlite.c: cdr_sqlite: database disk image is malformed
[Dec  7 10:26:36] WARNING[23964] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:26:36] WARNING[23964] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:26:36] WARNING[23964] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:26:37] ERROR[23939] cdr_sqlite.c: cdr_sqlite: database disk image is malformed
[Dec  7 10:28:36] WARNING[23966] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:28:36] WARNING[23966] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:28:36] WARNING[23966] app_dial.c: Unable to create channel of type 'SIP' (cause 0 - Unknown)
[Dec  7 10:32:08] WARNING[23967] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:08] WARNING[23967] chan_local.c: Unable to allocate channel structure(s)
[Dec  7 10:32:08] WARNING[23967] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:08] WARNING[23967] chan_local.c: Unable to allocate channel structure(s)
[Dec  7 10:32:20] WARNING[23967] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:20] WARNING[23967] chan_local.c: Unable to allocate channel structure(s)
[Dec  7 10:32:20] WARNING[23967] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:20] WARNING[23967] chan_local.c: Unable to allocate channel structure(s)
[Dec  7 10:32:25] ERROR[23967] res_timing_timerfd.c: Failed to create timerfd timer: Too many open files
[Dec  7 10:32:25] WARNING[23967] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:25] WARNING[23967] chan_local.c: Unable to allocate channel structure(s)
[Dec  7 10:32:25] WARNING[23967] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:25] WARNING[23967] chan_local.c: Unable to allocate channel structure(s)
[Dec  7 10:32:25] WARNING[23963] res_rtp_asterisk.c: RTP Read error: Bad file descriptor. Hanging up.
[Dec  7 10:32:25] ERROR[23963] cdr_sqlite.c: cdr_sqlite: database disk image is malformed
[Dec  7 10:32:55] ERROR[2018] res_timing_timerfd.c: Failed to create timerfd timer: Too many open files
[Dec  7 10:32:55] WARNING[2018] channel.c: Channel allocation failed: Can't create alert pipe! Try increasing max file descriptors with ulimit -n
[Dec  7 10:32:55] WARNING[2018] chan_sip.c: Unable to allocate AST channel structure for SIP channel
[Dec  7 10:32:55] NOTICE[2018] chan_sip.c: Unable to create/find SIP channel for this INVITE
[Dec  7 10:32:55] ERROR[23967] res_timing_timerfd.c: Call to timerfd_gettime() error: Bad file descriptor

There was no load on this box at the time. 1 active call.

OS is Debian squeeze latest 2.6.32-5-686

PLease let me know if I can do anything else.

Brian

By: Matt Jordan (mjordan) 2012-12-07 06:56:50.046-0600

All the log file shows is that your system ran out of file descriptors. This could either be a limitation of your system, or it could be an actual file descriptor leak. In either case, it does not provide sufficient information to debug the problem.

Are you using chan_gtalk, as the original issue reporter was?

In any case, we'll need your .conf files, your dialplan, and a scenario that reproduces this behavior. You can determine whether or not you have a file descriptor leak by using the DEBUG_FD_LEAKS build option and observing the output of 'core show fd'. If the output of that continues to accrue file descriptors after calls have been terminated, that may indicate where the leak is coming from.
By: Paul Belanger (pabelanger) 2013-03-01 22:35:03.565-0600

I'm running into this issue too, however for the sake of discussion I am using 1.8.7.1.  For me, upgrading to 1.8.19.0+ is not an option but I am going to backport a patch from ASTERISK-20032.  Also, I'd be curious to see what ulimit -n is setup for.

In my cases, I am only using chan_dahdi and chan_sip