Discussion:
[Icecast] How to log querystring values?
s***@nextdial.com.br
2018-05-06 11:35:15 UTC
Permalink
Hello,

I need to get some values passed in the querystring request in the log
file.

Something like that bellow:

ie: "GET /radio?id=1 HTTP/1.1" instead of only "GET /radio HTTP/1.1"

Do I need to change something in the source and compile? Or there is
another way?


Best,
Thiago
Philipp Schafft
2018-05-06 12:23:53 UTC
Permalink
Dear Mr./Ms. subscription,
Post by s***@nextdial.com.br
I need to get some values passed in the querystring request in the log
file.
ie: "GET /radio?id=1 HTTP/1.1" instead of only "GET /radio HTTP/1.1"
Do I need to change something in the source and compile? Or there is
another way?
What exactly is your goal? Maybe you can give us a bit of an
understanding of the context.

Query parameters are to be interpreted by the server, in this case
Icecast, not external software. Therefore I suspect that there is a
better solution for your problem.

With best regards,
--
Philipp.
(Rah of PH2)
s***@nextdial.com.br
2018-05-06 13:23:48 UTC
Permalink
Dear Philipp,

Thanks for you reply.

My goal is to show in our analytics page segmented data (official apps,
partner apps, third-party apps, demographic and geo). To do so each app
pass some values in the query string (ie: app id, user id, lat, lng). And I
need to know those values in order to do that.

Today we are using nginx as a reverse proxy to Icecast to get those data
but it double the cpu/mem usage =(

I am welcome to any idea. =)


Best,
Thiago



----------------------------------------
De: "Philipp Schafft" <***@lion.leolix.org>
Enviado: domingo, 6 de maio de 2018 09:30
Para: ***@nextdial.com.br, "Icecast streaming server user
discussions" <***@xiph.org>
Assunto: Re: [Icecast] How to log querystring values?
Dear Mr./Ms. subscription,
Post by s***@nextdial.com.br
I need to get some values passed in the querystring request in the log
file.
ie: "GET /radio?id=1 HTTP/1.1" instead of only "GET /radio HTTP/1.1"
Do I need to change something in the source and compile? Or there is
another way?
What exactly is your goal? Maybe you can give us a bit of an
understanding of the context.

Query parameters are to be interpreted by the server, in this case
Icecast, not external software. Therefore I suspect that there is a
better solution for your problem.

With best regards,

--
Philipp.
(Rah of PH2)
Philipp Schafft
2018-05-07 06:28:59 UTC
Permalink
Good Morning Thiago,
Post by s***@nextdial.com.br
Dear Philipp,
Thanks for you reply.
My goal is to show in our analytics page segmented data (official apps,
partner apps, third-party apps, demographic and geo).
To do so each app pass some values in the query string (ie: app id,
user id, lat, lng). And I need to know those values in order to do
that.
I would recommend to add those to (a) custom header field(s). You can
then log that by using URL auth. This is to the standards and will also
add more flexibility to the system, such as real time stats.

If you really, really need to pass the parameters using query string
parameters we could implement a separate logfile for that. That would
keep the main log intact and provide a (probably better) parseable log
for those data. (If you're interested in this option contact me
off-list.)
Post by s***@nextdial.com.br
Today we are using nginx as a reverse proxy to Icecast to get those data
but it double the cpu/mem usage =(
using a rproxy is not ideal and should be avoided. :)


with best regards,
Post by s***@nextdial.com.br
----------------------------------------
Enviado: domingo, 6 de maio de 2018 09:30
Assunto: Re: [Icecast] How to log querystring values?
Dear Mr./Ms. subscription,
Post by s***@nextdial.com.br
I need to get some values passed in the querystring request in the log
file.
ie: "GET /radio?id=1 HTTP/1.1" instead of only "GET /radio HTTP/1.1"
Do I need to change something in the source and compile? Or there is
another way?
What exactly is your goal? Maybe you can give us a bit of an
understanding of the context.
Query parameters are to be interpreted by the server, in this case
Icecast, not external software. Therefore I suspect that there is a
better solution for your problem.
--
Philipp Schafft (CEO/GeschÀftsfÌhrer)
Telephon: +49.3535 490 17 92

Löwenfelsen UG (haftungsbeschrÀnkt) Registration number:
Bickinger Straße 21 HRB 12308 CB
04916 Herzberg (Elster) VATIN/USt-ID:
Germany DE305133015
s***@nextdial.com.br
2018-05-07 12:09:44 UTC
Permalink
Philipp,

Thanks so much for your time and relpy.

This dawn, before read your email, I worked to implement the URL authentication and it worked like a charm. I am still using querystring instead of custom header field because I have no control over the player. But, the excelent news is, no more rproxy! =)

And you were right, this way I have more possibilities than before!

Again, thanks so much and congrats for the awesome job.

ps: Icecast is so far more efficient than SHOUTcast and a lot websites says they have no big differences, why?


Best,
Thiago




----------------------------------------
De: "Philipp Schafft" <***@de.loewenfelsen.net>
Enviado: segunda-feira, 7 de maio de 2018 03:40
Para: ***@nextdial.com.br, "Icecast streaming server user discussions" <***@xiph.org>
Assunto: Re: [Icecast] How to log querystring values?
Good Morning Thiago,
Post by s***@nextdial.com.br
Dear Philipp,
Thanks for you reply.
My goal is to show in our analytics page segmented data (official apps,
partner apps, third-party apps, demographic and geo).
To do so each app pass some values in the query string (ie: app id,
user id, lat, lng). And I need to know those values in order to do
that.
I would recommend to add those to (a) custom header field(s). You can
then log that by using URL auth. This is to the standards and will also
add more flexibility to the system, such as real time stats.

If you really, really need to pass the parameters using query string
parameters we could implement a separate logfile for that. That would
keep the main log intact and provide a (probably better) parseable log
for those data. (If you're interested in this option contact me
off-list.)
Post by s***@nextdial.com.br
Today we are using nginx as a reverse proxy to Icecast to get those data
but it double the cpu/mem usage =(
using a rproxy is not ideal and should be avoided. :)

with best regards,
Post by s***@nextdial.com.br
----------------------------------------
Enviado: domingo, 6 de maio de 2018 09:30
Assunto: Re: [Icecast] How to log querystring values?
Dear Mr./Ms. subscription,
Post by s***@nextdial.com.br
I need to get some values passed in the querystring request in the log
file.
ie: "GET /radio?id=1 HTTP/1.1" instead of only "GET /radio HTTP/1.1"
Do I need to change something in the source and compile? Or there is
another way?
What exactly is your goal? Maybe you can give us a bit of an
understanding of the context.
Query parameters are to be interpreted by the server, in this case
Icecast, not external software. Therefore I suspect that there is a
better solution for your problem.
--
Philipp Schafft (CEO/Geschäftsführer)
Telephon: +49.3535 490 17 92

Löwenfelsen UG (haftungsbeschränkt) Registration number:
Bickinger Straße 21 HRB 12308 CB
04916 Herzberg (Elster) VATIN/USt-ID:
Germany DE305133015
s***@nextdial.com.br
2018-05-14 12:35:39 UTC
Permalink
Hello,

After removing a mount from the xml config file and reloading the Icecast
with the bellow command why it don't close the current mount connection?

/etc/init.d/icecast2 reload

There is another way?

Best,
Thiago
Jake
2018-05-14 19:22:48 UTC
Permalink
Well I am only guessing here, but I suspect if icecast works like other daemons reload just reloads the config but doesn't terminate current connections. You probably want /etc/init.d/icecast restart
Post by s***@nextdial.com.br
Hello,
After removing a mount from the xml config file and reloading the Icecast
with the bellow command why it don't close the current mount
connection?
/etc/init.d/icecast2 reload
There is another way?
Best,
Thiago
s***@nextdial.com.br
2018-05-14 19:54:39 UTC
Permalink
Hello Jake,

Thanks for you reply.

If I restart all listeners's connections would be droped (not only those
related to the droped mount). Nginx, for example, would reload the
configuration droping the server/location that don't exists anymore and
active the new ones. Icecast has not the same behaviour.

Am I wrong? Is there any other way to do what I want to do?



Best,
Thiago




----------------------------------------
De: "Jake" <***@jakebriggs.com>
Enviado: segunda-feira, 14 de maio de 2018 16:28
Para: ***@nextdial.com.br, "Icecast streaming server user
discussions" <***@xiph.org>
Assunto: Re: [Icecast] Why current mount connection don't close after
remove from config and reload?
Well I am only guessing here, but I suspect if icecast works like other
daemons reload just reloads the config but doesn't terminate current
connections. You probably want /etc/init.d/icecast restart

On 15 May 2018 12:35:39 AM NZST, "***@nextdial.com.br"
<***@nextdial.com.br> wrote: Hello,

After removing a mount from the xml config file and reloading the Icecast
with the bellow command why it don't close the current mount connection?

/etc/init.d/icecast2 reload

There is another way?

Best,
Thiago
Philipp Schafft
2018-05-15 08:42:29 UTC
Permalink
Good morning,
Post by s***@nextdial.com.br
Hello Jake,
Thanks for you reply.
If I restart all listeners's connections would be droped (not only those
related to the droped mount). Nginx, for example, would reload the
configuration droping the server/location that don't exists anymore and
active the new ones. Icecast has not the same behaviour.
Am I wrong? Is there any other way to do what I want to do?
You are both right.

The logic in Icecast is a bit different from general-purpose web servers
(or exactly the same, depending on how you look at it).

With a general-purpose web server an resource is created by creating the
file on the file system. Config is then applied to that resource.

With Icecast there is a different kind of resource, a source connection.
It is "mounted" when the source connects. This is the point the resource
is created. And it's destroyed on disconnect (like unlinking a flat file
for a normal web server). At the point the resource is created (mounted)
the config is applied to it.


When you reload the config with the source running the resource is still
there. Icecast tries to update it based on the new config. If there is
none it just doesn't get updated.


Your reference to nginx is a bit more complicated. nginx has more a
focus on how you organize your namespace. You likely think of the
"location" statement. Icecast has something similar, it's called <alias>
(2.4.x) / <resource> (2.5.x). If you change those the effects are also
active directly after reload.

So, how do you remove the resource in Icecast?: Just log into the admin
interface and select "Kill source" for the given source. It will
disconnect the source client, therefore unmount the resource and destroy
it.

Little side node: There is no need in Icecast to configure mount points.
It's just needed if you really need options that are not defaults
(Icecast defaults, or defaults set in other parts of your
configuration).

With best regards,
Post by s***@nextdial.com.br
----------------------------------------
Enviado: segunda-feira, 14 de maio de 2018 16:28
Assunto: Re: [Icecast] Why current mount connection don't close after
remove from config and reload?
Well I am only guessing here, but I suspect if icecast works like other
daemons reload just reloads the config but doesn't terminate current
connections. You probably want /etc/init.d/icecast restart
After removing a mount from the xml config file and reloading the Icecast
with the bellow command why it don't close the current mount connection?
/etc/init.d/icecast2 reload
There is another way?
--
Philipp Schafft (CEO/GeschÀftsfÌhrer)
Telephon: +49.3535 490 17 92

Löwenfelsen UG (haftungsbeschrÀnkt) Registration number:
Bickinger Straße 21 HRB 12308 CB
04916 Herzberg (Elster) VATIN/USt-ID:
Germany DE305133015
s***@nextdial.com.br
2018-05-23 01:46:05 UTC
Permalink
Hello,

We are seeing in Firebase this kind of errors:


com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeExc
eption: Response code: 401

So, after 12h trying to reproduce the error we saw what's happening. If
the listener connection buffer due to anything, Icecast remove it's
connection and log the item bellow:

[2018-05-22 23:17:24] INFO source/send_to_listener Client 220977
(xxx.xxx.xxx.xxx) has fallen too far behind, removing

My question is:
Why Icecast need to do this? Why the client can't reconnect? The error
401 is when the client tries to reconnect and our auth deny?

Best,
Thiago
Greg Ogonowski
2018-05-23 02:42:00 UTC
Permalink
"The man with two clocks knoweth not the time."

The audio source clock does not match the audio destination clock, and
sooner or later, something needs to "give." This causes buffer under/over
flows.

The ICY protocol has no provision for timestamps which can be used to help
circumvent this in player clients, if supported.

HLS and DASH have this ability.



/greg.

StreamS



From: Icecast <icecast-***@xiph.org> On Behalf Of
***@nextdial.com.br
Sent: Tuesday, 22 May, 2018 18:46
To: ***@xiph.org
Subject: [Icecast] Why "has fallen too far behind"?



Hello,



We are seeing in Firebase this kind of errors:




com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeExc
eption: Response code: 401



So, after 12h trying to reproduce the error we saw what's happening. If the
listener connection buffer due to anything, Icecast remove it's connection
and log the item bellow:



[2018-05-22 23:17:24] INFO source/send_to_listener Client 220977
(xxx.xxx.xxx.xxx) has fallen too far behind, removing



My question is:

1. Why Icecast need to do this?
2. Why the client can't reconnect?
3. The error 401 is when the client tries to reconnect and our auth
deny?



Best,

Thiago
Ross Levis
2018-05-23 04:58:16 UTC
Permalink
That answers question 1 but not 2 or 3.



From: Icecast [mailto:icecast-***@xiph.org] On Behalf Of Greg Ogonowski
Sent: Wednesday, 23 May 2018 2:42 p.m.
To: ***@nextdial.com.br; 'Icecast streaming server user
discussions'
Subject: Re: [Icecast] Why "has fallen too far behind"?



"The man with two clocks knoweth not the time."

The audio source clock does not match the audio destination clock, and
sooner or later, something needs to "give." This causes buffer under/over
flows.

The ICY protocol has no provision for timestamps which can be used to help
circumvent this in player clients, if supported.

HLS and DASH have this ability.



/greg.

StreamS



From: Icecast <icecast-***@xiph.org> On Behalf Of
***@nextdial.com.br
Sent: Tuesday, 22 May, 2018 18:46
To: ***@xiph.org
Subject: [Icecast] Why "has fallen too far behind"?



Hello,



We are seeing in Firebase this kind of errors:




com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeExc
eption: Response code: 401



So, after 12h trying to reproduce the error we saw what's happening. If the
listener connection buffer due to anything, Icecast remove it's connection
and log the item bellow:



[2018-05-22 23:17:24] INFO source/send_to_listener Client 220977
(xxx.xxx.xxx.xxx) has fallen too far behind, removing



My question is:

1. Why Icecast need to do this?

2. Why the client can't reconnect?

3. The error 401 is when the client tries to reconnect and our auth
deny?



Best,

Thiago
Greg Ogonowski
2018-05-23 06:41:20 UTC
Permalink
The client should be able to reconnect, IF the client supports
auto-reconnect.

This is a client responsibility.

IF for some reason, the client is not able to reconnect manually, something
at the server level is preventing a reconnect. That should not be.

Is that the case here?

/g.

StreamS



From: Icecast <icecast-***@xiph.org> On Behalf Of Ross Levis
Sent: Tuesday, 22 May, 2018 21:58
To: 'Icecast streaming server user discussions' <***@xiph.org>
Subject: Re: [Icecast] Why "has fallen too far behind"?



That answers question 1 but not 2 or 3.



From: Icecast [mailto:icecast-***@xiph.org] On Behalf Of Greg Ogonowski
Sent: Wednesday, 23 May 2018 2:42 p.m.
To: ***@nextdial.com.br <mailto:***@nextdial.com.br> ;
'Icecast streaming server user discussions'
Subject: Re: [Icecast] Why "has fallen too far behind"?



"The man with two clocks knoweth not the time."

The audio source clock does not match the audio destination clock, and
sooner or later, something needs to "give." This causes buffer under/over
flows.

The ICY protocol has no provision for timestamps which can be used to help
circumvent this in player clients, if supported.

HLS and DASH have this ability.



/greg.

StreamS



From: Icecast <icecast-***@xiph.org <mailto:icecast-***@xiph.org> >
On Behalf Of ***@nextdial.com.br
<mailto:***@nextdial.com.br>
Sent: Tuesday, 22 May, 2018 18:46
To: ***@xiph.org <mailto:***@xiph.org>
Subject: [Icecast] Why "has fallen too far behind"?



Hello,



We are seeing in Firebase this kind of errors:




com.google.android.exoplayer2.upstream.HttpDataSource$InvalidResponseCodeExc
eption: Response code: 401



So, after 12h trying to reproduce the error we saw what's happening. If the
listener connection buffer due to anything, Icecast remove it's connection
and log the item bellow:



[2018-05-22 23:17:24] INFO source/send_to_listener Client 220977
(xxx.xxx.xxx.xxx) has fallen too far behind, removing



My question is:

1. Why Icecast need to do this?
2. Why the client can't reconnect?
3. The error 401 is when the client tries to reconnect and our auth
deny?



Best,

Thiago
s***@nextdial.com.br
2018-05-23 01:54:17 UTC
Permalink
Hello,

We are using Icecast in a 2 vCPU VPS running Ubuntu 16 LTS.

In our lastest test we saw in HTOP that Icecast was consuming about 94% in
one CPU and, in the other one, ~57%. We had ~2400 simultaneous listeners
96Kbps AAC.

Shouldn't Icecast scale both vCPUs? Is that the expected behaviour?

Best,
Thiago
s***@nextdial.com.br
2018-08-12 02:04:12 UTC
Permalink
Hello,

At a test VPS running Ubuntu 16.04 LTS I did this:
sudo apt-get update sudo add-apt-repository ppa:certbot/certbot sudo
apt-get install certbot sudo apt-get install icecast2 sudo certbot
certonly --standalone -d domain.com cat cert.pem privkey.pem | sudo tee
/etc/icecast2/icecast.pem sudo vi /etc/icecast2/icecast.xml
<listen-socket>
<port>8443</port>
<ssl>1</ssl>
</listen-socket>
<ssl-certificate>/etc/icecast2/icecast.pem</ssl-certificate> sudo chown
icecast2:icecast /etc/icecast2/icecast.pem sudo /etc/init.d/icecast2
restart

After that, I have this at the log:

[2018-08-12 01:47:07] INFO stats/_stats_thread stats thread started
[2018-08-12 01:47:07] INFO main/main Icecast 2.4.2 server started
[2018-08-12 01:47:07] INFO connection/get_ssl_certificate No SSL
capability
[2018-08-12 01:47:07] INFO yp/yp_update_thread YP update thread started


I tried restart the VPS and a lot of things (change the order of the pem
creation, etc), all with no success.

What I am doing wrong?


Best,
Thiago
Thomas B. Rücker
2018-08-12 06:55:00 UTC
Permalink
Hi,
Post by s***@nextdial.com.br
Hello,
 
1. sudo apt-get update
2. sudo add-apt-repository ppa:certbot/certbot
3. sudo apt-get install certbot
You'll need an additional step at this point, see below.
Post by s***@nextdial.com.br
1. sudo apt-get install icecast2
2. sudo certbot certonly --standalone -d domain.com
3. cat cert.pem privkey.pem | sudo tee /etc/icecast2/icecast.pem
4. sudo vi /etc/icecast2/icecast.xml
5. <listen-socket>
    <port>8443</port>
    <ssl>1</ssl>
</listen-socket>
<ssl-certificate>/etc/icecast2/icecast.pem</ssl-certificate>
6. sudo chown icecast2:icecast /etc/icecast2/icecast.pem
7. sudo /etc/init.d/icecast2 restart
 
 
[2018-08-12  01:47:07] INFO stats/_stats_thread stats thread started
[2018-08-12  01:47:07] INFO main/main Icecast 2.4.2 server started
[2018-08-12  01:47:07] INFO connection/get_ssl_certificate No SSL
capability
[2018-08-12  01:47:07] INFO yp/yp_update_thread YP update thread started
 
This is because Debian (and Ubuntu, as they recycle the same packaging)
refuse to compile Icecast (and other software) with openSSL support for
political reasons.
Post by s***@nextdial.com.br
What I am doing wrong
You didn't do anything wrong as such. You just didn't know that there
are additional steps if you need TLS support.
The official Xiph.org packages are built with openSSL support:
https://wiki.xiph.org/Icecast_Server/Installing_latest_version_(official_Xiph_repositories)

$ curl
https://download.opensuse.org/repositories/multimedia:/xiph/xUbuntu_16.04/Release.key
Post by s***@nextdial.com.br
/tmp/multimedia-obs.key
$ gpg /tmp/multimedia-obs.key

It should yield:
pub rsa2048 2017-11-21 [SC] [expires: 2020-01-30]
0E313DB7936B4E76E720065B77EC2301F23C6AA3
uid multimedia OBS Project

$ sudo apt-key add /tmp/multimedia-obs.key
$ sudo sh -c "echo deb
http://download.opensuse.org/repositories/multimedia:/xiph/xUbuntu_16.04/
./ >>/etc/apt/sources.list.d/icecast.list"
$ sudo apt-get update
$ sudo apt-get install icecast2

Make sure it downloads the package from an OBS address and not from an
ubuntu.com or mirror. (Newer versions like 18.04 require an explicit
version or other tricks at the moment: sudo apt-get install
icecast2/2.4.2-2 )

At this point your server should already be running the Xiph.org build
of Icecast and port 8443 should answer to HTTPS.

If you would prefer to listen to the standard port of 443, please follow
these additional directions:
http://lists.xiph.org/pipermail/icecast/2015-February/013198.html
Under no circumstances you should try to reverse proxy Icecast 2.4.x -
while one can make it mostly work, it is far from trivial to set things
up in a way that will avoid most of the corner cases. Most famously,
taking down your webserver.

Cheers,

Thomas
Thomas B. Rücker
2018-08-12 07:09:37 UTC
Permalink
Post by Thomas B. Rücker
Post by s***@nextdial.com.br
What I am doing wrong
You didn't do anything wrong as such. You just didn't know that there
are additional steps if you need TLS support.
https://wiki.xiph.org/Icecast_Server/Installing_latest_version_(official_Xiph_repositories)
$ curl
https://download.opensuse.org/repositories/multimedia:/xiph/xUbuntu_16.04/Release.key
Post by s***@nextdial.com.br
/tmp/multimedia-obs.key
That should be:

curl
https://download.opensuse.org/repositories/multimedia:/xiph/xUbuntu_16.04/Release.key
\
-o /tmp/multimedia-obs.key


TBR
s***@nextdial.com.br
2018-08-24 23:51:30 UTC
Permalink
Hello,
We are using url authentication and getting the item bellow at the log:

[2018-08-24 23:26:05] INFO auth_url/url_add_listener client auth
(http://127.0.0.1:8001/listener/add) failed with ""

I put try/catch and reviewed all my code ensure always return a proper
status and header error code, so what trigger this kind of error?



Regards,
Thiago
Thomas B. Rücker
2018-08-25 09:50:20 UTC
Permalink
Post by s***@nextdial.com.br
Hello,
 
[2018-08-24  23:26:05] INFO auth_url/url_add_listener client auth
(http://127.0.0.1:8001/listener/add) failed with ""
 
I put try/catch and reviewed all my code ensure always return a proper
status and header error code, so what trigger this kind of error?
Have you checked if there are corresponding log entries on the server
that Icecast was trying to access at 2018-08-24T23:26:05?
Could it be that your authentication backend was e.g. overloaded and
failed to answer the request?

Cheers,

Thomas
s***@nextdial.com.br
2018-08-29 12:45:38 UTC
Permalink
Hello,

In order to identify if was some issue regard to the auth api we include
some trace logs and we move it to other machine.

Bellow is what trace we are generating (date, result, elapsed time in
milleseconds, request):
[8/29/18 11:49:00 AM] 200 0.3721
action=listener_add&server=r22&port=443&client=2616&mount=/alphafmsp&user=&p
ass=&ip=177.223.XX&agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:00 AM] 200 0.6181
action=listener_remove&server=r22&port=443&client=673&mount=/aradiorock&user
=&pass=&duration=983&ip=191.206.XX&agent=NxApp/1.18.07.10 (Xamarin;
Android; 27; Mi A2 Lite; Xiaomi)
[8/29/18 11:49:00 AM] 200 0.4407
action=listener_add&server=r22&port=443&client=2618&mount=/alphafmsp&user=&p
ass=&ip=177.138.XX&agent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36
(KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:00 AM] 200 0.3872
action=listener_add&server=r20&port=443&client=3040&mount=/aradiorock&user=&
pass=&ip=189.8.XX&agent=Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36

Even with responses quickly responses we still getting:

[2018-08-29 11:49:08] INFO auth_url/url_add_listener client auth
(http://10.68.0.136:8001/listener/add) failed with ""

And sometimes the icecast process just shutdown! Bellow is the last second
logged:

AUTH ACCESS.LOG

[8/29/18 11:49:10 AM] 200 0.3864
action=listener_add&server=r20&port=443&client=3071&mount=/amorfm&user=&pass
=&ip=191.39.XXX&agent=App/2.4.2 (Linux;Android 7.0) ExoPlayerLib/2.5.4
[8/29/18 11:49:10 AM] 200 0.204
action=listener_add&server=r20&port=443&client=3070&mount=/alphafmsp&user=&p
ass=&ip=201.81.XXX&agent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36
(KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.2598
action=listener_remove&server=r22&port=443&client=2625&mount=/alphafmsp&user
=&pass=&duration=6&ip=177.95.XXX&agent=Mozilla/5.0 (Windows NT 6.1)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.1067
action=listener_remove&server=r20&port=443&client=512&mount=/aradiorock&user
=&pass=&duration=1087&ip=179.127.XXX&agent=Mozilla/5.0 (Windows NT 6.1;
Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.139
Safari/537.36
[8/29/18 11:49:10 AM] 200 0.4311
action=listener_add&server=r20&port=443&client=3072&mount=/alphafmsp&user=&p
ass=&ip=201.52.XXX&agent=Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36
(KHTML, like Gecko) Chrome/43.0.2357.132 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.3617
action=listener_add&server=r22&port=443&client=2638&mount=/aradiorock&user=&
pass=&ip=179.241.XXX&agent=NxApp/1.18.07.10 (Xamarin; Android; 26; moto x4;
motorola)

ICECAST ERROR.LOG (machine named "r20")

[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/amorfm
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/alphafmsp
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source max on /amorfm is
-1 (cur 6)
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source Added client to
/amorfm
[2018-08-29 11:49:10] DBUG auth/add_authenticated_listener client
authenticated, passed to source
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source max on /alphafmsp
is 750 (cur 750)
[2018-08-29 11:49:10] DBUG fserve/fserve_add_client Adding client to file
serving engine
[2018-08-29 11:49:10] DBUG fserve/fserve_add_pending fserve handler waking
up
[2018-08-29 11:49:10] DBUG auth/auth_release ...refcount on auth_t
/alphafmsp is now 751
[2018-08-29 11:49:10] INFO auth/auth_new_listener client 3070 failed
[2018-08-29 11:49:10] DBUG fserve/fserv_thread_function fserve handler
exit
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
client_connections (2719)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
client_connections (2720)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1331)
[2018-08-29 11:49:10] DBUG client/client_read_bytes reading from
connection has failed
[2018-08-29 11:49:10] INFO source/send_to_listener Client 512
(179.127.XXX) has fallen too far behind, removing
[2018-08-29 11:49:10] DBUG auth/queue_auth_client ...refcount on auth_t
/aradiorock is now 502
[2018-08-29 11:49:10] INFO auth/queue_auth_client auth on /aradiorock has
1 pending
[2018-08-29 11:49:10] DBUG source/source_main Client removed
[2018-08-29 11:49:10] INFO source/source_main listener count on
/aradiorock now 500
[2018-08-29 11:49:10] DBUG source/source_main Client added for mountpoint
(/amorfm)
[2018-08-29 11:49:10] INFO source/source_main listener count on /amorfm
now 7
[2018-08-29 11:49:10] INFO auth/auth_add_listener adding client for
authentication
[2018-08-29 11:49:10] DBUG auth/queue_auth_client ...refcount on auth_t
/alphafmsp is now 752
[2018-08-29 11:49:10] INFO auth/queue_auth_client auth on /alphafmsp has 1
pending
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/aradiorock
[2018-08-29 11:49:10] DBUG auth/auth_release ...refcount on auth_t
/aradiorock is now 501
[2018-08-29 11:49:10] DBUG format/format_check_http_buffer processing
pending client headers
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/alphafmsp
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source max on /alphafmsp
is 750 (cur 750)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1332)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
connections (3046)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1331)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/aradiorock"
slow_listeners (63)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global listeners
(1317)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/aradiorock"
listeners (500)
[2018-08-29 11:49:10] DBUG fserve/fserve_add_client Adding client to file
serving engine
[2018-08-29 11:49:10] DBUG fserve/fserve_add_pending fserve handler waking
up
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1332)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
connections (3047)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/amorfm"
listener_peak (7)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/amorfm"
listeners (7)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
client_connections (2721)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1331)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global listeners
(1318)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
listener_connections (2347)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1332)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
connections (3048)
[2018-08-29 11:49:10] DBUG auth/auth_release ...refcount on auth_t
/alphafmsp is now 751
[2018-08-29 11:49:10] INFO auth/auth_new_listener client 3072 failed
[2018-08-29 11:49:10] DBUG auth/queue_auth_client ...refcount on auth_t
/alphafmsp is now 751
[2018-08-29 11:49:10] INFO auth/queue_auth_client auth on /alphafmsp has 1
pending
[2018-08-29 11:49:10] DBUG fserve/fserv_thread_function fserve handler
exit
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/alphafmsp

I can't figure out why icecast is shutting down and why sometimes it can't
authenticate the request.

It happens with different loads. Sometimes with about 2500, others with
3000 and others with about 4200 listeners.

Other useful info: we have a hearbeat api that do a "status-json.xsl"
request at every 4s.

Any ideas?




Best,
Thiago



----------------------------------------
De: "***@nextdial.com.br" <***@nextdial.com.br>
Enviado: sexta-feira, 24 de agosto de 2018 20:51
Para: ***@xiph.org
Assunto: Client auth failed with ""
Hello,
We are using url authentication and getting the item bellow at the log:

[2018-08-24 23:26:05] INFO auth_url/url_add_listener client auth
(http://127.0.0.1:8001/listener/add) failed with ""

I put try/catch and reviewed all my code ensure always return a proper
status and header error code, so what trigger this kind of error?



Regards,
Thiago
Sytze Visser
2018-08-29 14:25:33 UTC
Permalink
Hi all

I still have to analyze my problem comma but I'll let you know if it is
exactly the same.

Luckily my server is not in production yet. I am still testing.

Running Ubuntu 16.04 and Ice cast 2.4.2.

Is there anyone out there that has also had a similar problem of the
service coming to an abrupt stop.
Post by s***@nextdial.com.br
Hello,
In order to identify if was some issue regard to the auth api we include
some trace logs and we move it to other machine.
Bellow is what trace we are generating (date, result, elapsed time in
[8/29/18 11:49:00 AM] 200 0.3721
action=listener_add&server=r22&port=443&client=2616&mount=/alphafmsp&user=&pass=&ip=177.223.XX&agent=Mozilla/5.0
(Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:00 AM] 200 0.6181
action=listener_remove&server=r22&port=443&client=673&mount=/aradiorock&user=&pass=&duration=983&ip=191.206.XX&agent=NxApp/
1.18.07.10 (Xamarin; Android; 27; Mi A2 Lite; Xiaomi)
[8/29/18 11:49:00 AM] 200 0.4407
action=listener_add&server=r22&port=443&client=2618&mount=/alphafmsp&user=&pass=&ip=177.138.XX&agent=Mozilla/5.0
(Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:00 AM] 200 0.3872
action=listener_add&server=r20&port=443&client=3040&mount=/aradiorock&user=&pass=&ip=189.8.XX&agent=Mozilla/5.0
(Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/68.0.3440.106 Safari/537.36
[2018-08-29 11:49:08] INFO auth_url/url_add_listener client auth (
http://10.68.0.136:8001/listener/add) failed with ""
And sometimes the icecast process just shutdown! Bellow is the last second
AUTH ACCESS.LOG
[8/29/18 11:49:10 AM] 200 0.3864
action=listener_add&server=r20&port=443&client=3071&mount=/amorfm&user=&pass=&ip=191.39.XXX&agent=App/2.4.2
(Linux;Android 7.0) ExoPlayerLib/2.5.4
[8/29/18 11:49:10 AM] 200 0.204
action=listener_add&server=r20&port=443&client=3070&mount=/alphafmsp&user=&pass=&ip=201.81.XXX&agent=Mozilla/5.0
(Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.2598
action=listener_remove&server=r22&port=443&client=2625&mount=/alphafmsp&user=&pass=&duration=6&ip=177.95.XXX&agent=Mozilla/5.0
(Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/68.0.3440.106 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.1067
action=listener_remove&server=r20&port=443&client=512&mount=/aradiorock&user=&pass=&duration=1087&ip=179.127.XXX&agent=Mozilla/5.0
(Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/66.0.3359.139 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.4311
action=listener_add&server=r20&port=443&client=3072&mount=/alphafmsp&user=&pass=&ip=201.52.XXX&agent=Mozilla/5.0
(Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko)
Chrome/43.0.2357.132 Safari/537.36
[8/29/18 11:49:10 AM] 200 0.3617
action=listener_add&server=r22&port=443&client=2638&mount=/aradiorock&user=&pass=&ip=179.241.XXX&agent=NxApp/
1.18.07.10 (Xamarin; Android; 26; moto x4; motorola)
ICECAST ERROR.LOG (machine named "r20")
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/amorfm
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/alphafmsp
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source max on /amorfm is
-1 (cur 6)
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source Added client to
/amorfm
[2018-08-29 11:49:10] DBUG auth/add_authenticated_listener client
authenticated, passed to source
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source max on /alphafmsp
is 750 (cur 750)
[2018-08-29 11:49:10] DBUG fserve/fserve_add_client Adding client to file
serving engine
[2018-08-29 11:49:10] DBUG fserve/fserve_add_pending fserve handler
waking up
[2018-08-29 11:49:10] DBUG auth/auth_release ...refcount on auth_t
/alphafmsp is now 751
[2018-08-29 11:49:10] INFO auth/auth_new_listener client 3070 failed
[2018-08-29 11:49:10] DBUG fserve/fserv_thread_function fserve handler
exit
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
client_connections (2719)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
client_connections (2720)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1331)
[2018-08-29 11:49:10] DBUG client/client_read_bytes reading from
connection has failed
[2018-08-29 11:49:10] INFO source/send_to_listener Client 512
(179.127.XXX) has fallen too far behind, removing
[2018-08-29 11:49:10] DBUG auth/queue_auth_client ...refcount on auth_t
/aradiorock is now 502
[2018-08-29 11:49:10] INFO auth/queue_auth_client auth on /aradiorock has
1 pending
[2018-08-29 11:49:10] DBUG source/source_main Client removed
[2018-08-29 11:49:10] INFO source/source_main listener count on
/aradiorock now 500
[2018-08-29 11:49:10] DBUG source/source_main Client added for mountpoint
(/amorfm)
[2018-08-29 11:49:10] INFO source/source_main listener count on /amorfm
now 7
[2018-08-29 11:49:10] INFO auth/auth_add_listener adding client for
authentication
[2018-08-29 11:49:10] DBUG auth/queue_auth_client ...refcount on auth_t
/alphafmsp is now 752
[2018-08-29 11:49:10] INFO auth/queue_auth_client auth on /alphafmsp has
1 pending
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/aradiorock
[2018-08-29 11:49:10] DBUG auth/auth_release ...refcount on auth_t
/aradiorock is now 501
[2018-08-29 11:49:10] DBUG format/format_check_http_buffer processing
pending client headers
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/alphafmsp
[2018-08-29 11:49:10] DBUG auth/add_listener_to_source max on /alphafmsp
is 750 (cur 750)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1332)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
connections (3046)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1331)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/aradiorock"
slow_listeners (63)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
listeners (1317)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/aradiorock"
listeners (500)
[2018-08-29 11:49:10] DBUG fserve/fserve_add_client Adding client to file
serving engine
[2018-08-29 11:49:10] DBUG fserve/fserve_add_pending fserve handler
waking up
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1332)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
connections (3047)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/amorfm"
listener_peak (7)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update "/amorfm"
listeners (7)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
client_connections (2721)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1331)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
listeners (1318)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
listener_connections (2347)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global clients
(1332)
[2018-08-29 11:49:10] DBUG stats/modify_node_event update global
connections (3048)
[2018-08-29 11:49:10] DBUG auth/auth_release ...refcount on auth_t
/alphafmsp is now 751
[2018-08-29 11:49:10] INFO auth/auth_new_listener client 3072 failed
[2018-08-29 11:49:10] DBUG auth/queue_auth_client ...refcount on auth_t
/alphafmsp is now 751
[2018-08-29 11:49:10] INFO auth/queue_auth_client auth on /alphafmsp has
1 pending
[2018-08-29 11:49:10] DBUG fserve/fserv_thread_function fserve handler
exit
[2018-08-29 11:49:10] DBUG auth/auth_run_thread 1 client(s) pending on
/alphafmsp
I can't figure out why icecast is shutting down and why sometimes it can't
authenticate the request.
It happens with different loads. Sometimes with about 2500, others with
3000 and others with about 4200 listeners.
Other useful info: we have a hearbeat api that do a "status-json.xsl"
request at every 4s.
Any ideas?
Best,
Thiago
------------------------------
*Enviado*: sexta-feira, 24 de agosto de 2018 20:51
*Assunto*: Client auth failed with ""
Hello,
[2018-08-24 23:26:05] INFO auth_url/url_add_listener client auth (
http://127.0.0.1:8001/listener/add) failed with ""
I put try/catch and reviewed all my code ensure always return a proper
status and header error code, so what trigger this kind of error?
Regards,
Thiago
_______________________________________________
Icecast mailing list
http://lists.xiph.org/mailman/listinfo/icecast
s***@nextdial.com.br
2018-09-06 12:45:52 UTC
Permalink
Hello,

I have a dedicated host and the server is a 2 x Intel Xeon X5560 Clock
2.80 GHZ x 8 Cores.

Looking at htop command report and +8k listeners streaming in 48Kbps AAC:
Icecast has peak of 85% CPU usage in 1 core; Sometimes show 4 cores
usage; Rarely show 8 cores usage;
So, how to improve the server usage? KVM virtualize it with 1 VM per core?
Or theres anything else to do?


ps: Ubuntu 16.04 and Icecast 2.4.2 with SSL
(http://download.opensuse.org/repositories/multimedia:/xiph/xUbuntu_16.04/)






Best,
Thiago
Marvin Scholz (ePirat)
2018-09-06 13:47:54 UTC
Permalink
Please stop hijacking other threads for new questions, this is incredibly annoying.

What you should do is send a new email to the list with a descriptive subject and not reply to existing ones with completely unrelated questions, this makes it really hard for everyone to find your email properly later.
Post by s***@nextdial.com.br
Hello,
I have a dedicated host and the server is a 2 x Intel Xeon X5560 Clock 2.80 GHZ x 8 Cores.
Icecast has peak of 85% CPU usage in 1 core;
Sometimes show 4 cores usage;
Rarely show 8 cores usage;
So, how to improve the server usage? KVM virtualize it with 1 VM per core? Or theres anything else to do?
ps: Ubuntu 16.04 and Icecast 2.4.2 with SSL (http://download.opensuse.org/repositories/multimedia:/xiph/xUbuntu_16.04/)
Best,
Thiago
_______________________________________________
Icecast mailing list
http://lists.xiph.org/mailman/listinfo/icecast
Continue reading on narkive:
Loading...