music-assistant / hass-music-assistant

Turn your Home Assistant instance into a jukebox, hassle free streaming of your favorite media to Home Assistant media players.
Apache License 2.0
1.31k stars 48 forks source link

BBC Music stream stops after a minute or so #2818

Closed eamonnsullivan closed 2 weeks ago

eamonnsullivan commented 2 weeks ago

What version of Music Assistant has the issue?

2.3.0b6

What version of the Home Assistant Integration have you got installed?

2024.8.3

Have you tried everything in the Troubleshooting FAQ and reviewed the Open and Closed Issues and Discussions to resolve this yourself?

The problem

The BBC Radio 6 stream stops after 1-3 minutes (it varies). It breaks in the middle of a song, so doesn't seem to be related to a new song or commercial-like break (BBC is non-commercial, but there are promo breaks for other radio shows, etc.).

How to reproduce

  1. Radio Browser
  2. Choose United Kingdom
  3. Choose BBC Radio 6 or BBC Radio 4 (any seem to have the issue)
  4. Play
  5. Wait

Music Providers

RadioBrowser

Player Providers

Both Chromecast and Airplay

Full log output

music-assistant.log

Additional information

No response

What version of Home Assistant Core are your running

2024.8.3

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Raspberry Pi

eamonnsullivan commented 2 weeks ago

I've observed this on the Radio 4 links too, so I've updated the report.

marcelveldt commented 2 weeks ago

Probably it happens on all HLS based streams (which BBC all are) - we've got a report for another radio station as wlel, probably that one is also HLS based. I will do some investigating.

marcelveldt commented 2 weeks ago

Please re-test this with 2.3.0 beta 8 - I listened today for hours to BBC and other hls based streams without issues.

smcmnz commented 2 weeks ago

I was experiencing this on 2.2.2 with an I/O error in the logs. Upgrading to 2.3.0b8 and am still experiencing this frequently. Enabled verbose debug and got this

musicassistant | 2024-08-29 05:04:54.696 VERBOSE (MainThread) [music_assistant.streams.media_stream] [http @ 0x55cbeed3c5c0] Opening 'http://as-hls-ww-live.akamaized.net/pool_904/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio=96000-269516863.ts' for reading musicassistant | 2024-08-29 05:04:55.793 VERBOSE (MainThread) [music_assistant.streams.media_stream] Error demuxing input file 0: Operation not permitted musicassistant | 2024-08-29 05:04:55.793 VERBOSE (MainThread) [music_assistant.streams.media_stream] http://as-hls-ww-live.akamaized.net/pool_904/live/ww/bbc_radio_five_live/bbc_radio_five_live.isml/bbc_radio_five_live-audio%3d96000.norewind.m3u8: Operation not permitted musicassistant | 2024-08-29 05:04:55.793 VERBOSE (MainThread) [music_assistant.streams.media_stream] size= 207270kB time=00:20:03.19 bitrate=1411.2kbits/s speed= 1x musicassistant | 2024-08-29 05:04:55.794 VERBOSE (MainThread) [music_assistant.streams.media_stream] video:0kB audio:207270kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.000000% musicassistant | 2024-08-29 05:04:55.802 VERBOSE (MainThread) [music_assistant.streams.media_stream] Process ffmpeg with PID 282 stopped with returncode 0 musicassistant | 2024-08-29 05:04:55.802 DEBUG (MainThread) [music_assistant.streams.media_stream] stream finished (with code 0) for radiobrowser://radio/7fe99458-b6f2-4af0-95bc-e05977964622 - seconds streamed: 1203.2 musicassistant | 2024-08-29 05:04:55.804 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] [flac @ 0x55ed933dc800] unable to rewrite FLAC header. musicassistant | 2024-08-29 05:04:55.804 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] size= 67470kB time=00:20:05.20 bitrate= 458.6kbits/s speed=1.01x musicassistant | 2024-08-29 05:04:55.804 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] video:0kB audio:67461kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.011995% musicassistant | 2024-08-29 05:04:55.814 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] Process ffmpeg with PID 281 stopped with returncode 0

eamonnsullivan commented 2 weeks ago

I just listened to Radio 6 on b8 and it stopped after a couple of minutes. I'm listening to Radio 4 now (more my speed -- I'm old) and will time it.

Update: It lasted about 15 minutes. It's very possible -- likely even -- that people in the U.K. get different streams.

eamonnsullivan commented 2 weeks ago

Since I work in the BBC (but not in this area at all), I could pass on any specific questions to the developers, if it turns out to be a BBC-specific issue.

OzGav commented 2 weeks ago

@eamonnsullivan please review this discussion for more info https://discord.com/channels/753947050995089438/753947050995089442/1278453897819721811

eamonnsullivan commented 2 weeks ago

I listened to Radio 6 on radio-browser.info and it kept going for 30 minutes or more. I tried to listen to the same stream url on MA and I just heard silence. The theory is the radio-browser.info embedded player gets around the geo-locking in some way.

2024-08-29 10:30:22.632 INFO (MainThread) [music_assistant.streams] Detected ffmpeg version 6.0.1 with libsoxr support
2024-08-29 10:30:22.633 INFO (MainThread) [music_assistant.streams] Starting server on  0.0.0.0:8098 - base url: http://192.168.50.62:8098
2024-08-29 10:30:34.381 WARNING (MainThread) [music_assistant.audio] Error while parsing radio URL http://as-hls-ww-live.akamaized.net/pool_904/live/ww/bbc_6music/bbc_6music.isml/bbc_6music-audio=320000.m3u8: 
2024-08-29 10:30:35.902 VERBOSE (MainThread) [music_assistant.streams] Got GET request to /single/98812a02-cf79-66bb-105a-d687068e108b/5d2080edd3b74ca585ed7d25e108fc76.flac from 192.168.50.76
headers: <CIMultiDictProxy('Host': '192.168.50.62:8098', 'Connection': 'keep-alive', 'User-Agent': 'Mozilla/5.0 (X11; Linux aarch64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.0 Safari/537.36 CrKey/1.56.500000 DeviceType/SmartSpeaker', 'Range': 'bytes=0-', 'Accept-Encoding': 'identity;q=1, *;q=0', 'Accept': '*/*', 'Accept-Language': 'en-GB', 'CAST-DEVICE-CAPABILITIES': '{"audio_assistant":true,"bluetooth_supported":true,"display_supported":false,"hi_res_audio_supported":false,"remote_control_input_supported":false,"touch_input_supported":false}')>

2024-08-29 10:30:35.907 DEBUG (MainThread) [music_assistant.streams] Start serving audio stream for QueueItem library://radio/6 to office speaker
2024-08-29 10:30:35.908 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] starting ffmpeg with args: -hide_banner -loglevel info -nostats -ignore_unknown -protocol_whitelist file,hls,http,https,tcp,tls,crypto,pipe,data,fd,rtp,udp -ac 2 -channel_layout stereo -ar 48000 -acodec pcm_s16le -f s16le -i - -f flac -ar 48000 -ac 2 -
2024-08-29 10:30:35.915 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] Process ffmpeg started with PID 97
eamonnsullivan commented 2 weeks ago

Here's another run of BBC Radio 6 Music (128K) via Radio Browser that stopped after a couple of minutes. music-assistant.log

smcmnz commented 2 weeks ago

This isn't isolated to BBC, I came here after problems with another Radio browser HLS stream and replicated with BBC to rule out the stream I was using. Error occurs when opening a new segment

024-08-29 20:29:29.696 VERBOSE (MainThread) [music_assistant.streams.media_stream] [https @ 0x7fc538016f80] Opening 'https://ais-sa1.streamon.fm:443/7358_128k.aac/playlist.m3u8?listeningSessionID=651168f00072bb5b_29323260_qnk8SSyI_MjE2LjIzNS44OS4xNzg6ODA!_00000290m6p&downloadSessionID=0' for reading 2024-08-29 20:29:30.282 VERBOSE (MainThread) [music_assistant.streams.media_stream] [hls @ 0x560d7213bc00] Skip ('#EXT-X-VERSION:3') 2024-08-29 20:29:30.282 VERBOSE (MainThread) [music_assistant.streams.media_stream] [hls @ 0x560d7213bc00] Skip ('#EXT-X-DISCONTINUITY-SEQUENCE:0') 2024-08-29 20:29:30.282 VERBOSE (MainThread) [music_assistant.streams.media_stream] [https @ 0x7fc53805c7c0] Opening 'https://acache.cdnstream1.com/ais-edge109-futuri-nyc04.cdnstream.com/7358_128k.aac/97n0BMZbi2F-347144961-4969.aac' for reading 2024-08-29 20:29:30.283 VERBOSE (MainThread) [music_assistant.streams.media_stream] [hls @ 0x560d7213bc00] Opening 'https://acache.cdnstream1.com/ais-edge109-futuri-nyc04.cdnstream.com/7358_128k.aac/97n0BMZbi2F-347144961-4969.aac' for reading 2024-08-29 20:29:31.469 VERBOSE (MainThread) [music_assistant.streams.media_stream] Error demuxing input file 0: Operation not permitted 2024-08-29 20:29:31.469 VERBOSE (MainThread) [music_assistant.streams.media_stream] https://ais-sa1.streamon.fm:443/7358_128k.aac/playlist.m3u8?listeningSessionID=651168f00072bb5b_29323260_qnk8SSyI_MjE2LjIzNS44OS4xNzg6ODA!_00000290m6p&downloadSessionID=0: Operation not permitted 2024-08-29 20:29:31.469 VERBOSE (MainThread) [music_assistant.streams.media_stream] size= 55336kB time=00:05:21.20 bitrate=1411.3kbits/s speed=1.02x 2024-08-29 20:29:31.470 VERBOSE (MainThread) [music_assistant.streams.media_stream] video:0kB audio:55336kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.000000% 2024-08-29 20:29:31.480 VERBOSE (MainThread) [music_assistant.streams.media_stream] Process ffmpeg with PID 298 stopped with returncode 0 2024-08-29 20:29:31.480 DEBUG (MainThread) [music_assistant.streams.media_stream] stream finished (with code 0) for radiobrowser://radio/94849e09-82db-4d33-b8ec-a041e8be516f - seconds streamed: 321.22485260770975 2024-08-29 20:29:31.482 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] [flac @ 0x55f71607c800] unable to rewrite FLAC header. 2024-08-29 20:29:31.482 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] size= 39471kB time=00:05:23.22 bitrate=1000.4kbits/s speed=1.01x 2024-08-29 20:29:31.482 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] video:0kB audio:39463kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.020505% 2024-08-29 20:29:31.493 VERBOSE (MainThread) [music_assistant.audio.ffmpeg] Process ffmpeg with PID 297 stopped with returncode 0

eamonnsullivan commented 2 weeks ago

On b12, I tried it on the BBC Radio 6 Music (128K) one we were using on Discourse and a Radio 4 one and I got silence, and a lot of errors in the logs. Radioparadise still works (you can see me trying that one in the logs between Radio 6 and Radio 4), so streaming isn't totally broken.

music-assistant.log

I also see an error in the UI: "Unable to locate RAOP Play binary for linux/aarch64" and my two airplay speakers are AWOL. I'll try restarting. (Didn't help.)

marcelveldt commented 2 weeks ago

Please ignore versions b9-b15 people as those were flawed after our base container switch. Update to b16 and check if you still have any issues (I don't think so)

marcelveldt commented 2 weeks ago

As for the BBC streams: We have updated our base image for a reason; now we finally have a newer ffmpeg version, version 6.1.1 (still not 7.x but this is already a lot better). I couldn't reproduce the stopping stream on my development machine which could be because of 2 reasons;

1) I'm not based in the UK (BBC streams are geo blocked WITHIN the UK and available outside) 2) I'm running ffmpeg 7 on my dev machine

In the logs that were shared with me from a stream that suddenly stopped, you can simply see ffmpeg exit reading the HLS playlist and logs "Operation not permitted". That last message could relate to the geo blocking of BBC but it can also be completely unrelated and just an internal ffmpeg error while it chokes on the next segment of the stream.

Anyways, long story short. Can you folks please give 2.3.0 beta 16 a good try ?

eamonnsullivan commented 2 weeks ago

Thanks for your attention on this! I hope it's worth it.

I'm attaching a log with streaming set to verbose. First I tried Radio 6 ("BBC Radio 6 Music (128K)"), then BBC Radio 4. Both continue to play, for at least the first minutes I tried them, but are silent. No sound. Next I tried "Radio Paradise" (which I think is a non HLS stream) and my own Liked Songs from Spotify. Both played fine. So, nothing wrong with the play path, but a bit worse for the HLS (no sound at all).

music-assistant.log

Update: They do also stop. Because there's no sound, I didn't play long enough.

ministryofsillywalks commented 2 weeks ago

Thanks for your attention on this! I hope it's worth it.

I'm attaching a log with streaming set to verbose. First I tried Radio 6 ("BBC Radio 6 Music (128K)"), then BBC Radio 4. Both continue to play, for at least the first minutes I tried them, but are silent. No sound. Next I tried "Radio Paradise" (which I think is a non HLS stream) and my own Liked Songs from Spotify. Both played fine. So, nothing wrong with the play path, but a bit worse for the HLS (no sound at all).

music-assistant.log

Update: They do also stop. Because there's no sound, I didn't play long enough.

Same for me. No sound at all and stops playing quite soon. Let me know if you want more logs and I can provide mine

OzGav commented 2 weeks ago

Please try beta 17

smcmnz commented 2 weeks ago

Successfully streamed an HLS on b17 for nearly 8 hours that was dropping frequently with operation not permitted error. Note this is not a BBC stream but I was getting the same error on BBC streams before.

ministryofsillywalks commented 2 weeks ago

Can confirm that my BBC Radio6 stream has been playing for over an hour on b17 Thanks so much everyone!

eamonnsullivan commented 2 weeks ago

Beta 17 seems to be working for me too, although I have a completely separate issue when I try to sync to airplay speakers (it stops after a few seconds). But on sync'd chromecast and single airplay, it's working well for me.

music-assistant.log

OzGav commented 2 weeks ago

One issue per report thanks.