Bug when massconnection

[dj28]

From time to time one or several of our servers gets "attacked". The attack is a form av massconnection of a lot of clients in a short time. I've been studying more carefully of what really happens and come to this conclution:

When we hade AutoDumpSourceTime=30 and the massconnection happened, some seconds after that it dropped all the connections it had including the relay. It then reconnected to the relay but then it got NAK error saying that "supporting only mp3 aac streams" etc etc. Also for some reasons the connections to it was very few afterwards. Doing a kill -WINCH didn't help so I had to shutdown and startup the server again. Then it all worked out.

After that i changed AutoDumpSourceTime=30 to 0 to prevent disconnection of the relay.

Yesterday this happend again on one of our servers. Maxlisteners of that server is 80. The server didn't get disconnected from the delay so I thought everything was ok. But today i saw that the server only had 4 listeners and normal is around 50 and higher. So I looked at the logfiles but everything looked ok from there. I started to listen on that server and after a couple of seconds it started to buffer really hard and at my suprise i saw that it still played the song from last night when the massconnection occured.

I also noticed that when the massconnection occured every client was with RadioTracker 2.*
When the connections disconnected everyone had transfered 256000 bytes.

Here is the part of the logfile:

<09/26/06@21:50:53> [dest: 84.152.108.176] starting stream (UID: 10379)[L: 32]{A: RadioTracker 2.x}(P: 31)
<09/26/06@21:50:53> [dest: 89.59.156.144] starting stream (UID: 10380)[L: 33]{A: RadioTracker 2.x}(P: 32)
<09/26/06@21:50:53> [dest: 217.85.93.178] starting stream (UID: 10381)[L: 34]{A: sr-POSIX/1.60.13}(P: 33)
<09/26/06@21:50:54> [dest: 85.177.169.188] starting stream (UID: 10382)[L: 35]{A: RadioTracker2.0}(P: 34)
<09/26/06@21:50:54> [dest: 219.214.78.36] starting stream (UID: 10383)[L: 36]{A: Winnap5.0}(P: 35)
<09/26/06@21:50:54> [dest: 89.59.156.144] starting stream (UID: 10384)[L: 37]{A: RadioTracker 2.x}(P: 36)
<09/26/06@21:50:54> [dest: 80.134.125.33] starting stream (UID: 10385)[L: 38]{A: RadioTracker 2.x}(P: 37)
<09/26/06@21:50:54> [dest: 80.145.123.39] starting stream (UID: 10386)[L: 39]{A: RadioTracker 2.x}(P: 38)
<09/26/06@21:50:54> [dest: 84.152.108.176] starting stream (UID: 10387)[L: 40]{A: RadioTracker 2.x}(P: 39)
<09/26/06@21:50:54> [dest: 85.177.169.188] starting stream (UID: 10388)[L: 41]{A: RadioTracker2.0}(P: 40)
<09/26/06@21:50:54> [dest: 217.85.93.178] starting stream (UID: 10389)[L: 42]{A: sr-POSIX/1.60.13}(P: 41)
<09/26/06@21:51:54> [dest: 89.59.156.144] starting stream (UID: 10390)[L: 43]{A: RadioTracker 2.x}(P: 42)
<09/26/06@21:51:54> [dest: 80.145.123.39] starting stream (UID: 10391)[L: 44]{A: RadioTracker 2.x}(P: 43)
<09/26/06@21:51:54> [dest: 85.177.169.188] starting stream (UID: 10392)[L: 45]{A: RadioTracker2.0}(P: 44)
<09/26/06@21:51:54> [dest: 219.214.78.36] starting stream (UID: 10393)[L: 46]{A: Winnap5.0}(P: 45)
<09/26/06@21:51:54> [dest: 80.134.125.33] starting stream (UID: 10394)[L: 47]{A: RadioTracker 2.x}(P: 46)
<09/26/06@21:51:54> [dest: 84.152.108.176] starting stream (UID: 10395)[L: 48]{A: RadioTracker 2.x}(P: 47)
<09/26/06@21:51:54> [dest: 89.59.156.144] starting stream (UID: 10396)[L: 49]{A: RadioTracker 2.x}(P: 48)
<09/26/06@21:51:54> [dest: 85.177.169.188] starting stream (UID: 10397)[L: 50]{A: RadioTracker2.0}(P: 49)
<09/26/06@21:51:54> [dest: 80.145.123.39] starting stream (UID: 10398)[L: 51]{A: RadioTracker 2.x}(P: 50)
<09/26/06@21:51:55> [dest: 84.152.108.176] connection closed (0 seconds) (UID: 10395)[L: 50]{Bytes: 133307}(P: 47)
<09/26/06@21:51:55> [dest: 217.85.93.178] starting stream (UID: 10399)[L: 51]{A: sr-POSIX/1.60.13}(P: 47)
<09/26/06@21:51:55> [dest: 219.214.78.36] starting stream (UID: 10400)[L: 52]{A: Winnap5.0}(P: 51)
<09/26/06@21:51:55> [dest: 80.134.125.33] starting stream (UID: 10401)[L: 53]{A: RadioTracker 2.x}(P: 52)
<09/26/06@21:51:55> [dest: 89.59.156.144] starting stream (UID: 10402)[L: 54]{A: RadioTracker 2.x}(P: 53)
<09/26/06@21:51:55> [dest: 85.177.169.188] starting stream (UID: 10403)[L: 55]{A: RadioTracker2.0}(P: 54)
<09/26/06@21:51:55> [dest: 80.145.123.39] starting stream (UID: 10404)[L: 56]{A: RadioTracker 2.x}(P: 55)
<09/26/06@21:51:55> [dest: 219.214.78.36] starting stream (UID: 10405)[L: 57]{A: Winnap5.0}(P: 56)
<09/26/06@21:51:55> [dest: 89.59.156.144] starting stream (UID: 10406)[L: 58]{A: RadioTracker 2.x}(P: 57)
<09/26/06@21:51:55> [dest: 85.177.169.188] starting stream (UID: 10407)[L: 59]{A: RadioTracker2.0}(P: 58)
<09/26/06@21:51:55> [dest: 217.85.93.178] starting stream (UID: 10408)[L: 60]{A: sr-POSIX/1.60.13}(P: 59)
<09/26/06@21:51:55> [dest: 80.134.125.33] starting stream (UID: 10409)[L: 61]{A: RadioTracker 2.x}(P: 60)
<09/26/06@21:52:02> [yp_tch] error connecting to yp.shoutcast.com
<09/26/06@21:52:02> [dest: 217.85.93.178] connection closed (191 seconds) (UID: 10408)[L: 60]{Bytes: 174047}(P: 59)
<09/26/06@21:52:03> [dest: 69.119.113.70] connection closed (212 seconds) (UID: 10351)[L: 59]{Bytes: 256000}(P: 0)
<09/26/06@21:52:03> [dest: 84.152.108.176] connection closed (207 seconds) (UID: 10352)[L: 58]{Bytes: 256000}(P: 1)
<09/26/06@21:52:03> [dest: 219.214.78.36] connection closed (205 seconds) (UID: 10353)[L: 57]{Bytes: 256000}(P: 2)
<09/26/06@21:52:03> [dest: 80.134.125.33] connection closed (227 seconds) (UID: 10345)[L: 56]{Bytes: 256000}(P: 3)
<09/26/06@21:52:03> [dest: 83.226.218.231] connection closed (215 seconds) (UID: 10349)[L: 55]{Bytes: 256000}(P: 4)
<09/26/06@21:52:03> [dest: 84.165.206.105] connection closed (194 seconds) (UID: 10357)[L: 54]{Bytes: 256000}(P: 5)
<09/26/06@21:52:03> [dest: 219.214.78.36] connection closed (225 seconds) (UID: 10346)[L: 53]{Bytes: 256000}(P: 6)
<09/26/06@21:52:03> [dest: 89.59.156.144] connection closed (221 seconds) (UID: 10347)[L: 52]{Bytes: 256000}(P: 7)
<09/26/06@21:52:03> [dest: 217.85.93.178] connection closed (219 seconds) (UID: 10348)[L: 51]{Bytes: 256000}(P: 8)
<09/26/06@21:52:03> [dest: 84.165.206.105] connection closed (214 seconds) (UID: 10350)[L: 50]{Bytes: 256000}(P: 9)
<09/26/06@21:52:03> [dest: 89.59.156.144] connection closed (203 seconds) (UID: 10354)[L: 49]{Bytes: 256000}(P: 10)
<09/26/06@21:52:03> [dest: 80.134.125.33] connection closed (202 seconds) (UID: 10355)[L: 48]{Bytes: 256000}(P: 11)
<09/26/06@21:52:03> [dest: 85.177.169.188] connection closed (202 seconds) (UID: 10356)[L: 47]{Bytes: 256000}(P: 12)
<09/26/06@21:52:03> [dest: 89.59.156.144] connection closed (192 seconds) (UID: 10358)[L: 46]{Bytes: 256000}(P: 13)
<09/26/06@21:52:03> [dest: 89.59.156.144] connection closed (192 seconds) (UID: 10364)[L: 45]{Bytes: 256000}(P: 14)
<09/26/06@21:52:03> [dest: 219.214.78.36] connection closed (192 seconds) (UID: 10360)[L: 44]{Bytes: 256000}(P: 15)
<09/26/06@21:52:03> [dest: 84.152.108.176] connection closed (192 seconds) (UID: 10361)[L: 43]{Bytes: 256000}(P: 16)
<09/26/06@21:52:03> [dest: 80.134.125.33] connection closed (192 seconds) (UID: 10362)[L: 42]{Bytes: 256000}(P: 17)
<09/26/06@21:52:03> [dest: 84.165.206.105] connection closed (192 seconds) (UID: 10363)[L: 41]{Bytes: 256000}(P: 18)
<09/26/06@21:52:03> [dest: 219.214.78.36] connection closed (192 seconds) (UID: 10365)[L: 40]{Bytes: 256000}(P: 19)
<09/26/06@21:52:03> [dest: 84.152.108.176] connection closed (192 seconds) (UID: 10366)[L: 39]{Bytes: 256000}(P: 20)

More disconnections follows but they are all the same. Around maybe 70 at max.

Is this a bug in shoutcast server? Has anyone else had the same problem? Any solution for this? Can it depend on a slow computer?

Oh i forgot to mention that we use V1.9.7

[dotme]

Originally posted by dj28
After that i changed AutoDumpSourceTime=30 to 0 to prevent disconnection of the relay.

No. Never set it to zero. Your relay disconnected in the night. It couldn't reconnect because the DNAS was holding the connection open.

Originally posted by dj28
When the connections disconnected everyone had transfered 256000 bytes.

Right - see my answer above. Because there was actually no stream, the server delivered what was left in the buffer at the time of the relay disconnect - 256kilobytes of data.

On the other issue, I have seen reports elsewhere of mass attachments by RadioTracker clients simultaneously from many different IPs. It is a function of the program - a particularly nasty one. It is against forum rules to discuss ripping software, but I would urge anybody that cares about these kind of attacks to read up on this program and how it works. The "attacks" are actually unattended ripping of your stream.

[dj28]

I don't know if we missunderstood eachother here or I was unclear with the definitions (probably the later). The server I'm talking about is not the mainserver but a relay.

First time I i've checked what happened AutoDumpSourceTime was 30s. When the attack came our relayserver went crazy, disconnected every listener and then disconnected from our mainserver. Then it connected again and yp gave NAK error saying that it only supported mp3 aac+ streams etc etc so it couldnt get listet on the yellow pages. I had to shutdown the server to get it to work properly.

This means it's a problem cause a shoutcast server is built to handle connections in the right way. AND report to YP in the right way to. Both of these two functions failed.

After that I tried to change AutoDumpSourceTime to 0 just to see if anything went different when the next attack came. Our relay didn't disconnect from our mainserver though and the YP report worked fine...but the relay somehow hade the same song in buffer from the night before when it happened. I just kicked the relay so it could connect again. And it worked...til right know...it went crazy again so I had to shutdown and startup the server again.

Nevertheless it's something that isn't working as it should. I hopefully want a solution to that problem :P

P.s. I hate radiotracker.

[dotme]

Well, I'd suggest a 5 second timeout on the source time, and a backup file. I've seen a time of zero create a lot of problems when the connection is broken between relay and master. The two don't reconnect.

I am studying the behavior of this application today... very inventive. It can cause what appears to be a denial of service attack against a shoutcast server, and i can certainly see where a DNAS might get unhappy about getting slammed with multiple simultaneous connection requests. Such a flood could, in some cases, kill your available bandwidth - which could cause the source and connected players to all die.