[Icecast] Icecast is shutdown / client auth failed with ""

Sytze Visser sytze.visser at gmail.com
Wed Aug 29 14:25:33 UTC 2018


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.

On Wed, 29 Aug 2018, 14:45 subscription at nextdial.com.br, <
subscription at nextdial.com.br> wrote:

> 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=&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
>
> 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=&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
>
>
> ------------------------------
> *De*: "subscription at nextdial.com.br" <subscription at nextdial.com.br>
> *Enviado*: sexta-feira, 24 de agosto de 2018 20:51
> *Para*: icecast at 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
>
> _______________________________________________
> Icecast mailing list
> Icecast at xiph.org
> http://lists.xiph.org/mailman/listinfo/icecast
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.xiph.org/pipermail/icecast/attachments/20180829/b29daa14/attachment.htm>


More information about the Icecast mailing list