Icecast Streaming Media Server

[DJ-Zath]

hi everyone and kudos to karl

I've got an issue here where I have been noticing Icecast isn't CLOSING sockets which were opened to it and thus the clients dropped..

This appears to be happening to clients, players and web-calls to http on Icecast's ports..

Now, its not much of a problem YET..being only a few listeners logging in at this time.. but I have noticed that this gets increasing worse as the number of clients connect (and disconnect).

When they disconnect, the socket is still OPEN and doesn't close for a long LONG time.. sometimes it doesn't close AT ALL and eventually, (worst case) the server will CRASH once it runs out of connection handles.

I'm not entirely sure as to why this is.. I suspect my ISP's fedora FC9 router is playing strange games with sockets.. (perhaps the rputer is holding the sockets open to Icecast since everything proxied through the ISP's router..) The box, itself is FreeBSD 6x..

any ideas?

-DjZ-

[karlH]

You would have to check the state the socket is in first, ie netstat. if those sockets are still in a connected state then icecast hasn't dropped them yet. I would like to hear if the trunk code is better at this and then to isolated the problem further.

karl.

[DJ-Zath]

Hi Karl and thanks for the reply..

I should have stated that running netstat is where I'm seeing this issue..

I have to explain things a little, here.

Although I see this with most every connection to icecast, I'm seeing it mostly with a bot that connects locally to gather playing information.

The bot will open a connection once every 4 seconds, logs in through the admin login, gather stats and then close the connection. The bot uses fetch since using TCL sockets causes even more problems where the bot hangs almost indefinately when trying to call up icecast- even locally on the same machine! Having the bot call up "fetch" and having fetch then call into icecast seems to solve the problem for the bot- but. now, the socket hanging issues to fetch seems to be the issue.

At this point, I see (at least) 50 to 100 "TIME_WAIT"s or "FIN_WAIT"s and even some "FIN_WAIT_2"s from icecast... and the addresses are mostly from the bot.. but I also see clients as well..

"trunk code":

I have seen you mention the term "trunk code" before, but I'm not aware of what that is.. is it a patch or something I have missed?

I have a custom install of icecast.. This is because I've had problems when I initially-installed Icecast.. Icecast wouldn't install properly (through the ports) and to get around this I ended up installing it (ports), then uninstalling it then loading the raw files manually.. since this, it seems to have been running flawlessly (asside the hanging sockets issue, that is) Since the sockets DO eventually close on their own, I left it be for that time-being.. but now, I better further address this and see what I can do to correct it.

note:
I didn't display the netstat results here because I figured it would be pointless.. it may also render a security-risk since internal info to what and where things connect internally (and thus invite possable hacks?) would be displayed. but, if you believe this will help, then I will display this info.

on second thought...

(xx.xx.xx.xx = internal/studio IP)

Active Internet connections
Proto Recv-Q Send-Q Local Address Foreign Address (state)
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16592 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.49905 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16591 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16590 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16589 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.50016 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16588 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16587 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16586 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.56231 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16585 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16584 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16583 TIME_WAIT
tcp4 0 0 warp-radio.outfi.22 xx.xx.xx.xx.1466 ESTABLISHED
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.61279 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16582 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16581 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16580 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.52864 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16579 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16578 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16577 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.64188 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16576 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16575 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16574 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.52382 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16573 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16572 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16571 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.62380 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16570 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16569 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.59378 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16568 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16567 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16566 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.57393 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16565 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16564 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16563 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.56741 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16562 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16561 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16560 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.53602 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16559 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16558 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16557 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.64184 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16556 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16555 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16554 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.64218 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16553 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16552 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.55334 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16551 TIME_WAIT
tcp4 0 0 warp-radio.outfi.56164 www.radiotoolbox.80 CLOSE_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16550 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16549 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.53573 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16548 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16547 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16546 TIME_WAIT
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.57402 TIME_WAIT
tcp4 0 0 warp-radio.outfi.8000 xx.xx.xx.xx.16545 TIME_WAIT
tcp4 0 0 warp-radio.outfi.63424 www.radiotoolbox.80 LAST_ACK
tcp4 0 0 warp-radio.outfi.6667 CPE-60-224-20-70.3597 ESTABLISHED
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.53205 ESTABLISHED
tcp4 0 0 localhost.warp-r.53205 localhost.warp-r.8000 ESTABLISHED
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.50905 ESTABLISHED
tcp4 19 0 localhost.warp-r.50905 localhost.warp-r.8000 ESTABLISHED
tcp4 0 0 localhost.warp-r.8000 localhost.warp-r.55922 ESTABLISHED
tcp4 0 0 localhost.warp-r.55922 localhost.warp-r.8000 ESTABLISHED
tcp4 0 0 warp-radio.outfi.6667 xx.xx.xx.xx.17664 ESTABLISHED
tcp4 0 0 localhost.warp-r.60500 localhost.warp-r.60127 ESTABLISHED
tcp4 0 0 localhost.warp-r.60127 localhost.warp-r.60500 ESTABLISHED
tcp4 0 0 localhost.warp-r.60100 localhost.warp-r.60200 ESTABLISHED
tcp4 0 0 localhost.warp-r.60200 localhost.warp-r.60100 ESTABLISHED
Active UNIX domain sockets
Address Type Recv-Q Send-Q Inode Conn Refs Nextref Addr
c5367ea0 stream 0 0 0 c5367b40 0 0
c5367b40 stream 0 0 0 c5367ea0 0 0
c5367000 stream 0 0 c52a8dd0 0 0 0 /var/run/dee

-DjZ-

[karlH]

The trunk code can be retrieved from subversion at svn.xiph.org/icecast/trunk/ or as a daily tarball from http://people.xiph.org/~brendan/snapshots/icecast/

As a test I would stop the stats extraction (bot) and duplicate the requests with something else to see if the same thing occurs, eg

for i in `seq 1 500`; do
curl -o /dev/null http://admin:pw@host:port/admin/stats
sleep 1
done

If that does not produce similar results as your current script (ie lots of time wait sockets) then you will know it's something to do with how the socket is read/closed by the bot.

I don't know whether it will help but you could use a stats client to extract the data eg

curl -X STATS http://admin:pw@host:port/

and filter what you need, just an idea and will save all those connections and entries in access log

karl.

[DJ-Zath]

Hi there Karl buddy!

actually, in the example above: that netstat output shows the state of things with the bot in stand by mode (reduced stats retrieval mode) The bot calls are the "localhost" connections.. The majority of those are the studio client/player (Ruku soundbridge) attempting a connection.. I have allready varified the problem being icecast and not the clients/bot stats...

I'll try your curl thingy to see what that shows...

and I still didn't understand what "trunk" is.. is that a patch or an icecast update?

thanks for your reply Karl.. you earned a beer!

-DjZ-

[karlH]

trunk is the current code base as-is post 2.3.2.

karl.

[DJ-Zath]

hi Karl and thanks for the reply.. AWESOME!

I forgot to mention about the "stats client" bot.. stats are actually pulled into memory where they are parsed and then used to drive logic commands and other effects such as "onair" lights and image displays..

i.e:

128k Stream Online:


24k Stream Online:


live Cam Online:


Current DJ/song Image:


all done in TCL.. and even generates dynamic elements of the website..

having a "stats collector" read then generate a file- only to be read by the bot again.. would mean a LOT of unnessessary disk activity!

I opted for this system after a lot of planning and thinking.

oh, I also got myself one of those "trunk shapshots".. I'll compile it and try to see if that helps any...

-DjZ-

[karlH]

The stats client I had in mind would just sit there looking for specific stats, essentially a NEW or DELETE and run something appropriate when they are received. The NEW/DELETE messages were added in my branch work to be explicit, the idea is for them to be used for master/slave communication, something similar could be done for trunk as well. Assuming the web image is to be swapped then you could trigger a copy or ln with that, very little disk activity and a lot of entries from access log removed. It really depends on what you want out of it.

You should find that trunk is quicker at handling those admin requests

karl.

[DJ-Zath]

HI there Karl.. sir, I owe you dinner and a movie! LOL

I have popped in the trunk code.. went in without a single problem..

at the time of this posting, I am currently running various tests.. trunk seems to be working VERY well.. I have noticed a slight improvement in the audio quality and slightly better stream handling by clients.

Theres been an ongoing problem with a local winamp tuned into the feed, that loses packets to the poiint where the stream receves a negative buffer.. it happens about 2 songs in.. as I was writing this very line, That winamp has now went into the negative buffer again (where the stream starts breaking up excessively) I have never blamed Icecast for this issue, however, rather I think its my ISP.. noone on the outside has reported this problem on any player.. seems to only happen on my OWN computers/network (I have to find someone else in town to run this test with)

Now, for the TIME_WAIT's and sockets.. let's have a look..

yep.. no change.. they still are there.. lets see what that "curl" script reports..

UPDATE:

the cirl script didn't work I get an error "seq not found" so I just made a 10-turn cascaded script instead of a loop (I can't recall how to make a loop in SH/BSD)

heres what Curl reports:

% Total % Received % Xferd Average Speed Time Time Time Curret
------------------------- Dload Upload Total Spent Left Speed
100 3399 100 3399 0 0 17703 0 --:--:-- --:--:-- --:--:-- 0

(sorry, I cannot get the curl report to display correctly, here)

and, of course I see a TIME_WAIT for each connection Curl opens to icecast.

-DjZ-

[karlH]

Is the bot located in a similar location to your local winamp, because if so then that could explain the network socket issue. Check with ping and traceroute to see the path of packets between winamp and icecast see if there are unexpected diversions, I can't see network errors only affecting local connections but always a good thing to rule out (ifconfig)

Regarding seq, not sure why you don't have that, but 10 clients is not a heavy test try a different loop

#!/bin/sh
let x=400
while [ $x -gt 0 ]; do
curl -o /dev/null http://.......
sleep 1
let x=$x-1
done

will kick off 400 curls in sequence with a second delay between each.

karl.

[DJ-Zath]

Hi there Karl!

[karlH]

The time_wait occurs when icecast closes the socket and the OS is waiting to get confirmation from the peer. At that point, icecast does not have any handles to work on even if there was something we could do. Seeing that a looped curl test shows this up and the requests occur in sequence then I would try the tcpdump (or similar) of those connection (over loopback) and see what is actually going across the interface.

karl.

[DJ-Zath]

Hi there Karl!

[karlH]

I don't know much about FBSD specific settings but check to see if there are any fixes regarding time wait to the version you have. A quick google check does show up a few cases of this sort of issue cropping up with some commenting on the setting

sysctl net.inet.tcp.nolocaltimewait=1

karl.

[DJ-Zath]

Hi Kerl!

hehehe

oh, I know EXACTLY where to put that setting you posted .. and I'll plug that puppy right in right now!

I have been all over the FreeeBSD website.. and didn't see much reguarding sockets and timeouts... (asside of issues relating to an invalid RFC mode that has to be fixed with a specific kernel upgrade which I did do... )

I guess I should ask.. what search keywords did you use?

I took that command you posted and put it right into the sysctl.conf file.. and about to reboot the server and see!

GOOD CALL! you are most-definately a tresure-trove of knowledge and help!
_________________
-DjZ-