Icecast - Jun 2005 - Icecast locks with WARN connection/_accept_connection accept() failed with error 24: Too many open files

My icecast server has been running happily for months now, but just 
yesterday it locked up, chewing up all the cpu time it could find, and 
not allowing connections.  The last snippet of the error log shows this:

[2005-06-01  09:36:13] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:36:15] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:36:18] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:36:19] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:36:28] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:36:43] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:36:45] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:37:13] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:37:15] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:37:43] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:37:45] WARN connection/_accept_connection accept() 
failed with error 24: Too many open files
[2005-06-01  09:37:53] INFO format-mp3/mp3_get_no_meta End of stream 
/outofservicehq
[2005-06-01  09:37:53] INFO source/source_shutdown Source 
"/outofservicehq" exiting
[2005-06-01  09:37:53] INFO format-mp3/mp3_get_no_meta End of stream 
/outofservicemq
[2005-06-01  09:37:53] INFO source/source_shutdown Source 
"/outofservicemq" exiting
[2005-06-01  09:38:56] INFO sighandler/_sig_die Caught signal 15, 
shutting down...
[2005-06-01  09:39:58] INFO sighandler/_sig_die Caught signal 15, 
shutting down...
[2005-06-01  09:40:10] INFO sighandler/_sig_die Caught signal 15, 
shutting down...


The error had repeated itself for almost 24 hours before I noticed it. 
Obviously it had too many files open, but I can't account for how.  The 
logs before the repeating errors look completely normal.  I tried 
shutting down the streams, which didn't fix it, so I sent it some kills, 
and it didn't die.  I had to kill -9 it.  Once it restarted it was fine. 
  Is there some leak preventing icecast from running indefinitely?  Or 
will I just need to restart it every few months when this happens again? 
  Has anyone else seen this happen?

Joel

On Wed, 2005-06-01 at 14:51, Joel Ebel wrote:
> My icecast server has been running happily for months now, but just 
> yesterday it locked up, chewing up all the cpu time it could find, and 
> not allowing connections.  The last snippet of the error log shows this:
> 
> [2005-06-01  09:36:13] WARN connection/_accept_connection accept() 
> failed with error 24: Too many open files
> [2005-06-01  09:36:15] WARN connection/_accept_connection accept() 
> failed with error 24: Too many open files
...
> The error had repeated itself for almost 24 hours before I noticed it. 
> Obviously it had too many files open, but I can't account for how.  The
> logs before the repeating errors look completely normal.  I tried 
> shutting down the streams, which didn't fix it, so I sent it some
kills,
> and it didn't die.  I had to kill -9 it.  Once it restarted it was
fine.
>   Is there some leak preventing icecast from running indefinitely?  Or 
> will I just need to restart it every few months when this happens again? 
>   Has anyone else seen this happen?
I've only seen one other report of 'too many open files'.

Can you send the error and access log to me, so I can check through the
usage pattern. 

karl

On 6/1/05, Joel Ebel <jbebel@ncsu.edu> wrote:
> My icecast server has been running happily for months now, but just
> yesterday it locked up, chewing up all the cpu time it could find, and
> not allowing connections.  The last snippet of the error log shows this:
snip...
> The error had repeated itself for almost 24 hours before I noticed it.
> Obviously it had too many files open, but I can't account for how.  The
> logs before the repeating errors look completely normal.  I tried
> shutting down the streams, which didn't fix it, so I sent it some
kills,
> and it didn't die.  I had to kill -9 it.  Once it restarted it was
fine.
>   Is there some leak preventing icecast from running indefinitely?  Or
> will I just need to restart it every few months when this happens again?
>   Has anyone else seen this happen?
> 
There's at least one, and possibly two bugs here.

One is that, when the server runs out of file descriptors, from your
report, it looks like it spins - it should just reject
connections/fail gracefully. That one should be straightforward to
fix.

The second problem is either a) you legitimately ran out of file
descriptors (the per-process limit should be easy to change, but I
can't suggest how since you didn't mention your OS), or b) icecast
leaked file descriptors.

b) is more likely, unless you had a lot of clients connected (probably
at least several hundred), and is obviously much worse. You also
didn't mention what version you're running - if it isn't the latest
release, please upgrade.

Was there any strange/suspicious behaviour just before this happened
visible in the logs? If not, it's likely a slow leak caused in some
unusual case, which only becomes a problem after some weeks/months
(but might be exploitable as a DoS attack).

Mike$

I'm running Slackware Linux 10.0, kernel 2.4.26 and icecast 2.2.  We 
usually have less than 100 clients connected, but I have as many as 13 
sources connected at once.  Only 6 are heavily used, and 6 more are just 
fallbacks only used when the primary 6 go down.  There was no suspicious 
behavior I could find in the logs.  All looked just as it normally does. 
  I suspect this happened over time since this instance of icecast has 
probably been running non-stop since early January.

Thanks,
Joel

Michael Smith wrote:
> On 6/1/05, Joel Ebel <jbebel@ncsu.edu> wrote:
> 
>>My icecast server has been running happily for months now, but just
>>yesterday it locked up, chewing up all the cpu time it could find, and
>>not allowing connections.  The last snippet of the error log shows this:
> 
> snip...
> 
>>The error had repeated itself for almost 24 hours before I noticed it.
>>Obviously it had too many files open, but I can't account for how. 
The
>>logs before the repeating errors look completely normal.  I tried
>>shutting down the streams, which didn't fix it, so I sent it some
kills,
>>and it didn't die.  I had to kill -9 it.  Once it restarted it was
fine.
>>  Is there some leak preventing icecast from running indefinitely?  Or
>>will I just need to restart it every few months when this happens again?
>>  Has anyone else seen this happen?
>>
> 
> 
> There's at least one, and possibly two bugs here.
> 
> One is that, when the server runs out of file descriptors, from your
> report, it looks like it spins - it should just reject
> connections/fail gracefully. That one should be straightforward to
> fix.
> 
> The second problem is either a) you legitimately ran out of file
> descriptors (the per-process limit should be easy to change, but I
> can't suggest how since you didn't mention your OS), or b) icecast
> leaked file descriptors.
> 
> b) is more likely, unless you had a lot of clients connected (probably
> at least several hundred), and is obviously much worse. You also
> didn't mention what version you're running - if it isn't the
latest
> release, please upgrade.
> 
> Was there any strange/suspicious behaviour just before this happened
> visible in the logs? If not, it's likely a slow leak caused in some
> unusual case, which only becomes a problem after some weeks/months
> (but might be exploitable as a DoS attack).
> 
> Mike$