search

karlheyes / icecast-kh

KH branch of icecast
GNU General Public License v2.0
300 stars 107 forks source link

Icecast http streaming latency over 30 seconds #149

Closed bhelx closed 7 years ago

bhelx commented 7 years ago

I've originally posted this over at stackoverflow but have had no luck: http://stackoverflow.com/questions/42331357/icecast-http-connection-latency-over-30-seconds

I'm currently running the xiph release but also experiencing this on 2.4.0-kh4 so I thought I may be able to get some help here.

I'm running an icecast server (2.4.3) on Debian 8 and experiencing a very long "time to first byte". It's strange because this does not seem to be occurring from clients (like mplayer), but only when using HTML5 audio. It takes anywhere from 30 seconds to 120 seconds to start playing the audio.

I'm thinking it's not a buffering issue because I don't seem to be getting ANY bytes back during this time. For instance, if I run a curl command with the verbose flag:

~ben ~: curl http://radio.example.com:8000/radio.mp3 -v
*   Trying XX.XX.XX.XXX...
* TCP_NODELAY set
* Connected to radio.example.com (XX.XX.XX.XXX) port 8000 (#0)
> GET /radio.mp3 HTTP/1.1
> Host: radio.example.com:8000
> User-Agent: curl/7.51.0
> Accept: */*
>

It will sit like this for at minimum 28 seconds before I see any bytes coming in. Conversely, if I run mplayer:

~ben ~: mplayer http://radio.example.com:8000/radio.mp3
MPlayer 1.3.0-4.2.1 (C) 2000-2016 MPlayer Team
Can't init Apple Remote.

Playing http://radio.example.com:8000/radio.mp3.
Resolving radio.example.com for AF_INET6...

Couldn't resolve name for AF_INET6: radio.example.com
Resolving radio.example.com for AF_INET...
Connecting to server radio.example.com[XX.XX.XX.XXX]: 8000...

Cache size set to 320 KBytes
Cache fill:  0.00% (0 bytes)
ICY Info: StreamTitle='';
Cache fill:  5.00% (16384 bytes)
ICY Info: StreamTitle='';
Cache fill: 10.00% (32768 bytes)
ICY Info: StreamTitle='';
Cache fill: 15.00% (49152 bytes)
ICY Info: StreamTitle='';

ICY Info: StreamTitle='';

Audio only file format detected.
==========================================================================
Requested audio codec family [mpg123] (afm=mpg123) not available.
Enable it at compilation.
Opening audio decoder: [ffmpeg] FFmpeg/libavcodec audio decoders
libavcodec version 57.24.102 (internal)
AUDIO: 44100 Hz, 2 ch, floatle, 128.0 kbit/4.54% (ratio: 16000->352800)
Selected audio codec: [ffmp3float] afm: ffmpeg (FFmpeg MPEG layer-3 audio)
==========================================================================
AO: [coreaudio] 44100Hz 2ch floatle (4 bytes per sample)
Video: no video
Starting playback...

It buffers and starts playing within a couple seconds.

I'm also seeing this line added for both curl and mplayer right when I connect:

[2017-03-04  02:18:20] INFO source/source_main listener count on /radio.mp3 now 4

So I know it's accepting the connection at least.

Icecast config

Here are what I think are the relevant configs

<icecast>
    <limits>
        <clients>100</clients>
        <sources>2</sources>
        <queue-size>102400</queue-size>
        <client-timeout>30</client-timeout>
        <header-timeout>15</header-timeout>
        <source-timeout>1</source-timeout>
        <burst-size>943718</burst-size>
        <mp3-metadata-interval>4096</mp3-metadata-interval>
    </limits>

    <mount>
        <mount-name>/radio.mp3</mount-name>
        <password>*****************</password>

        <bitrate>128</bitrate>
        <type>audio/mpeg</type>
        <subtype>mp3</subtype>
        <hidden>0</hidden>
        <fallback-mount>/whitenoise.mp3</fallback-mount>
        <fallback-override>1</fallback-override>
    </mount>
</icecast>

Attempts to fix

I've tried this on a few different versions including 2.3.3, 2.3.3-kh-11, 2.4.0-kh4. I even tried switching to an Ubuntu VM :) I've also tried fiddling with all the of the burst and buffer configs but this problem doesn't seem to be related to those.

I'd be happy to provide any icecast logs or any more details if that could help. Also, I'm not sure if the fallback mount and the related file could be causing any problems. I have gotten this to work in the past without the fallback mount.

karlheyes commented 7 years ago

first thing is to fix your queue-size, 100k is rubbish, especially if you are trying to burst 900k. Make queue-size larger than burst, 128k mp3 is 16kbytes/s so a simple length check is fine, default is 512k.

second, there was an issue with really small intervals for icy metadata, default is about 16k, 8k should be ok. This should not be an issue in kh4 though.

check the stats, eg incoming bitrate on the admin page. If those haven't improve things then up the log level to 4 and send the error log over, if may be some frame issue being triggered.

karl

bhelx commented 7 years ago

@karlheyes Thanks for the quick response! Those values were so wild because I was experimenting with them. I've removed them all for now to get back to default values:

    <limits>
        <clients>100</clients>
        <sources>2</sources>
        <client-timeout>30</client-timeout>
        <header-timeout>15</header-timeout>
        <source-timeout>1</source-timeout>
    </limits>

    <mount>
        <mount-name>/radio.mp3</mount-name>
        <password>*****************</password>
        <fallback-mount>/whitenoise.mp3</fallback-mount>
        <fallback-override>1</fallback-override>
    </mount>

None of these changed the situation. Still fast to start with mplayer and VLC but takes about 28 seconds to start in the browser or with curl. I've also noticed that my source stream and file seem to be at 160kb and not 128. Not sure if that is a problem.

I've updated the log level to 4. Here are the logs captured beginning from right before restarting the icecast instance.

[2017-03-04  03:38:23] INFO sighandler/_sig_die Caught signal 15, shutting down...
[2017-03-04  03:38:23] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:23] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (0)
[2017-03-04  03:38:23] INFO main/main Icecast 2.4.3 server started
[2017-03-04  03:38:23] WARN main/main YP server handling has been disabled
[2017-03-04  03:38:23] INFO connection/get_ssl_certificate No SSL capability
[2017-03-04  03:38:23] INFO stats/_stats_thread stats thread started
[2017-03-04  03:38:23] INFO source/source_fallback_file mountpoint /whitenoise.mp3 is reserved
[2017-03-04  03:38:23] DBUG connection/connection_complete_source sources count is 0
[2017-03-04  03:38:23] WARN format/format_get_type Unsupported or legacy stream type: "audio/mpeg". Falling back to generic minimal handler for best effort.
[2017-03-04  03:38:23] DBUG connection/connection_complete_source source is ready to start
[2017-03-04  03:38:23] DBUG source/source_init Source creation complete
[2017-03-04  03:38:23] INFO source/source_main listener count on /whitenoise.mp3 now 0
[2017-03-04  03:38:23] DBUG stats/modify_node_event update global sources (1)
[2017-03-04  03:38:23] DBUG stats/process_source_event new source stat /whitenoise.mp3
[2017-03-04  03:38:23] DBUG stats/modify_node_event update global source_client_connections (1)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node listeners (0)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node listenurl (http://localhost:8000/whitenoise.mp3)
[2017-03-04  03:38:23] DBUG stats/modify_node_event update global source_total_connections (1)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node slow_listeners (0)
[2017-03-04  03:38:23] DBUG stats/modify_node_event update "/whitenoise.mp3" listeners (0)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node listener_peak (0)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node stream_start (Sat, 04 Mar 2017 03:38:23 +0000)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node stream_start_iso8601 (2017-03-04T03:38:23+0000)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node total_bytes_read (0)
[2017-03-04  03:38:23] DBUG stats/process_source_event new node total_bytes_sent (0)
[2017-03-04  03:38:23] DBUG stats/modify_node_event update "/whitenoise.mp3" listeners (0)
[2017-03-04  03:38:24] DBUG slave/_slave_thread checking master stream list
[2017-03-04  03:38:28] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:28] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (0)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global clients (1)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global connections (1)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global clients (2)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global connections (2)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global clients (3)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global connections (3)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global clients (4)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global connections (4)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global clients (5)
[2017-03-04  03:38:32] DBUG stats/modify_node_event update global connections (5)
[2017-03-04  03:38:33] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:33] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (0)
[2017-03-04  03:38:33] DBUG auth/add_listener_to_source max on /whitenoise.mp3 is -1 (cur 0)
[2017-03-04  03:38:33] DBUG auth/add_listener_to_source Added client to /whitenoise.mp3
[2017-03-04  03:38:33] DBUG auth/add_authenticated_listener client authenticated, passed to source
[2017-03-04  03:38:33] DBUG source/source_main Client added for mountpoint (/whitenoise.mp3)
[2017-03-04  03:38:33] INFO source/source_main listener count on /whitenoise.mp3 now 1
[2017-03-04  03:38:33] DBUG stats/modify_node_event update global client_connections (1)
[2017-03-04  03:38:33] DBUG stats/modify_node_event update "/whitenoise.mp3" listener_peak (1)
[2017-03-04  03:38:33] DBUG stats/modify_node_event update "/whitenoise.mp3" listeners (1)
[2017-03-04  03:38:33] DBUG format/format_check_http_buffer processing pending client headers
[2017-03-04  03:38:34] DBUG stats/modify_node_event update global listeners (1)
[2017-03-04  03:38:34] DBUG stats/modify_node_event update global listener_connections (1)
[2017-03-04  03:38:38] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:38] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (348348)
[2017-03-04  03:38:43] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:43] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (757948)
[2017-03-04  03:38:47] DBUG stats/modify_node_event update global clients (4)
[2017-03-04  03:38:47] DBUG stats/modify_node_event update global clients (3)
[2017-03-04  03:38:47] DBUG stats/modify_node_event update global clients (2)
[2017-03-04  03:38:47] DBUG stats/modify_node_event update global clients (1)
[2017-03-04  03:38:48] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:48] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (1167548)
[2017-03-04  03:38:53] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:53] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (1577148)
[2017-03-04  03:38:58] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:38:58] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (1986748)
[2017-03-04  03:39:03] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_read (0)
[2017-03-04  03:39:03] DBUG stats/modify_node_event update "/whitenoise.mp3" total_bytes_sent (2396348)

I hit the /radio.mp3 endpoint from the browser at 03:38:23 and it started at 03:38:50.

bhelx commented 7 years ago

When I switch back over to the kh branch. I see this and requesting the radio.mp3 endpoint gives me a 404. This makes me think the fallback is not working here. I would like to have it fallback to whitenoise.mp3 when a source is not connected.


[2017-03-04  03:59:24] INFO thread/ lock abort set to 0
[2017-03-04  03:59:24] INFO main/server_process Icecast 2.4.0-kh4 server started
[2017-03-04  03:59:24] WARN slave/slave_startup process has 65536 max file descriptor limit
[2017-03-04  03:59:24] INFO client/workers_adjust requested worker count 1
[2017-03-04  03:59:24] DBUG yp/yp_recheck_config Updating YP configuration
[2017-03-04  03:59:24] DBUG fserve/find_fh /whitenoise.mp3 (4) not found in cache
[2017-03-04  03:59:24] DBUG source/source_recheck_mounts fallback checking /radio.mp3 (fallback has -1)
[2017-03-04  03:59:24] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:24] DBUG stats/modify_node_event update "global" clients (0)
[2017-03-04  03:59:24] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:24] INFO connection/get_ssl_certificate No SSL capability on any configured ports
[2017-03-04  03:59:24] INFO connection/connection_thread connection thread started
[2017-03-04  03:59:24] DBUG client/worker 0x7fe6a6ce68b0 now has 0 clients
[2017-03-04  03:59:25] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:25] DBUG stats/modify_node_event update "global" clients (0)
[2017-03-04  03:59:25] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:26] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:26] DBUG stats/modify_node_event update "global" clients (0)
[2017-03-04  03:59:26] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:27] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:27] DBUG stats/modify_node_event update "global" clients (0)
[2017-03-04  03:59:27] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:28] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:28] DBUG stats/modify_node_event update "global" clients (0)
[2017-03-04  03:59:28] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:29] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:29] DBUG stats/modify_node_event update "global" clients (0)
[2017-03-04  03:59:29] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:30] DBUG stats/modify_node_event update "global" connections (1)
[2017-03-04  03:59:30] DBUG client/worker_add_pending_clients Added 1 pending clients to 0x7fe6a6ce68b0
[2017-03-04  03:59:30] DBUG connection/_handle_get_request start with /radio.mp3
[2017-03-04  03:59:30] DBUG stats/modify_node_event update "global" client_connections (1)
[2017-03-04  03:59:30] DBUG fserve/fserve_client_create checking for file /radio.mp3 (/usr/share/icecast/web/radio.mp3)
[2017-03-04  03:59:30] WARN fserve/fserve_client_create req for file "/usr/share/icecast/web/radio.mp3" No such file or directory
[2017-03-04  03:59:30] DBUG client/client_destroy keepalive detected, placing back onto worker
[2017-03-04  03:59:30] DBUG client/worker_add_pending_clients Added 1 pending clients to 0x7fe6a6ce68b0
[2017-03-04  03:59:30] DBUG client/worker 0x7fe6a6ce68b0 now has 1 clients
[2017-03-04  03:59:30] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:30] DBUG stats/modify_node_event update "global" clients (1)
[2017-03-04  03:59:30] DBUG stats/modify_node_event update "global" outgoing_kbitrate (3)
[2017-03-04  03:59:31] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:31] DBUG stats/modify_node_event update "global" clients (1)
[2017-03-04  03:59:31] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
[2017-03-04  03:59:32] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  03:59:32] DBUG stats/modify_node_event update "global" clients (1)
[2017-03-04  03:59:32] DBUG stats/modify_node_event update "global" outgoing_kbitrate (0)
bhelx commented 7 years ago

When the radio.mp3 source is connected and streaming it no longer gives me 404 but does still take a long time to connect.

[2017-03-04  04:29:55] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:29:55] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:29:55] DBUG stats/modify_node_event update "global" outgoing_kbitrate (147)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" outgoing_kbitrate (147)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" incoming_bitrate (150552)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_read (2702928)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_sent (2380800)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" total_mbytes_sent (2)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" queue_size (480720)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" connected (143)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" stream_kbytes_sent (2325)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" stream_kbytes_read (2638)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" outgoing_kbitrate (146)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" connections (14)
[2017-03-04  04:29:56] DBUG client/worker_add_pending_clients Added 1 pending clients to 0x7fc6e45e68b0
[2017-03-04  04:29:56] DBUG connection/_handle_get_request start with /radio.mp3
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" client_connections (7)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" listener_connections (5)
[2017-03-04  04:29:56] INFO source/source_add_listener max on /radio.mp3 is -1 (cur 2)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" listeners (3)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "global" listener_connections (5)
[2017-03-04  04:29:56] DBUG source/locate_start_on_queue 174.73.19.227 Joining queue on /radio.mp3 (2714563, 2650339)
[2017-03-04  04:29:56] DBUG client/worker 0x7fc6e45e68b0 now has 4 clients
[2017-03-04  04:29:56] INFO source/source_read listener count on /radio.mp3 now 3
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" listeners (3)
[2017-03-04  04:29:56] DBUG stats/modify_node_event update "/radio.mp3" listener_peak (3)
[2017-03-04  04:29:57] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:29:57] DBUG stats/modify_node_event update "global" clients (4)
[2017-03-04  04:29:57] DBUG stats/modify_node_event update "global" outgoing_kbitrate (819)
[2017-03-04  04:29:57] INFO source/source_queue_advance Client 10 (174.73.19.227) has fallen too far behind (2224925) on /radio.mp3, removing
[2017-03-04  04:29:57] DBUG stats/modify_node_event update "/radio.mp3" slow_listeners (2)
[2017-03-04  04:29:57] DBUG stats/modify_node_event update "global" listeners (2)
[2017-03-04  04:29:57] DBUG source/source_listener_release Listener 10 leaving /radio.mp3
[2017-03-04  04:29:57] DBUG client/worker 0x7fc6e45e68b0 now has 3 clients
[2017-03-04  04:29:57] INFO source/source_read listener count on /radio.mp3 now 2
[2017-03-04  04:29:57] DBUG stats/modify_node_event update "/radio.mp3" listeners (2)
[2017-03-04  04:29:58] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:29:58] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:29:58] DBUG stats/modify_node_event update "global" outgoing_kbitrate (336)
[2017-03-04  04:29:59] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:29:59] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:29:59] DBUG stats/modify_node_event update "global" outgoing_kbitrate (311)
[2017-03-04  04:30:00] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:00] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:00] DBUG stats/modify_node_event update "global" outgoing_kbitrate (281)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" outgoing_kbitrate (253)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" incoming_bitrate (150976)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_read (2798880)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_sent (2597888)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" total_mbytes_sent (2)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" queue_size (313968)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "/radio.mp3" connected (148)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "global" stream_kbytes_sent (2537)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "global" stream_kbytes_read (2732)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:01] DBUG stats/modify_node_event update "global" outgoing_kbitrate (246)
[2017-03-04  04:30:02] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:02] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:02] DBUG stats/modify_node_event update "global" outgoing_kbitrate (226)
[2017-03-04  04:30:03] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:03] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:03] DBUG stats/modify_node_event update "global" outgoing_kbitrate (212)
[2017-03-04  04:30:04] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:04] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:04] DBUG stats/modify_node_event update "global" outgoing_kbitrate (203)
[2017-03-04  04:30:05] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:05] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:05] DBUG stats/modify_node_event update "global" outgoing_kbitrate (195)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" outgoing_kbitrate (201)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" incoming_bitrate (150792)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_read (2894688)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_sent (2693120)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" total_mbytes_sent (2)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" queue_size (126432)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "/radio.mp3" connected (153)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "global" stream_kbytes_sent (2630)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "global" stream_kbytes_read (2826)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:06] DBUG stats/modify_node_event update "global" outgoing_kbitrate (191)
[2017-03-04  04:30:07] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:07] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:07] DBUG stats/modify_node_event update "global" outgoing_kbitrate (187)
[2017-03-04  04:30:08] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:08] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:08] DBUG stats/modify_node_event update "global" outgoing_kbitrate (183)
[2017-03-04  04:30:09] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:09] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:09] DBUG stats/modify_node_event update "global" outgoing_kbitrate (181)
[2017-03-04  04:30:10] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:10] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:10] DBUG stats/modify_node_event update "global" outgoing_kbitrate (177)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" outgoing_kbitrate (154)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" incoming_bitrate (150976)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_read (2987616)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" total_bytes_sent (2786304)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" total_mbytes_sent (2)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" queue_size (219312)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "/radio.mp3" connected (158)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "global" stream_kbytes_sent (2721)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "global" stream_kbytes_read (2917)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:11] DBUG stats/modify_node_event update "global" outgoing_kbitrate (175)
[2017-03-04  04:30:12] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2017-03-04  04:30:12] DBUG stats/modify_node_event update "global" clients (3)
[2017-03-04  04:30:12] DBUG stats/modify_node_event update "global" outgoing_kbitrate (172)
bhelx commented 7 years ago

Any ideas @karlheyes?

karlheyes commented 7 years ago

the incoming bitrate seems at odds with a 128k stream, seems more like 150k, is this VBR? There doesn't seem to be any errors reported so looks a valid MP3. The outgoing bitrate looks valid for 2 listeners so it would indicate data is being sent. Is there a proxy in use?

karl.

bhelx commented 7 years ago

the incoming bitrate seems at odds with a 128k stream, seems more like 150k, is this VBR? There doesn't seem to be any errors reported so looks a valid MP3.

I'm not sure. I'm using mopdiy as a source https://docs.mopidy.com/en/latest/audio/#streaming-through-icecast I guess it's possible that uses a variable bit rate but I'm not very sure. It's playing directly from some mp3 files on the machine. I think I'll try to switch to using mpd for a moment to see if that changes things. It could have something to do with mopidy.

The outgoing bitrate looks valid for 2 listeners so it would indicate data is being sent. Is there a proxy in use?

The client is hitting the icecast server directly.

bhelx commented 7 years ago

Okay I'm closing this issue. I'm still not sure what the problem is, but I switched computers and I'm not having this problem on the other computer. That tells me that something is wrong on the client side.

Thanks @karlheyes and sorry for mis-filing!