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.22k stars 43 forks source link

Playback doesn't actually start #72

Closed Stooovie closed 2 years ago

Stooovie commented 2 years ago

My sole source is Spotify Premium atm. I can browse my favs and playlist just fine but no playback to any of my devices (Volumio, Sonos, Kodi, Samsung TV and various Echo Dot devices) actually starts. I can play and pause playback that's been added from a different source (such as Spotify app on my PC) but that's it (and the UI doesn't reflect that - it stays on what I picked to play from Music Assistant and the Play button stays on Play no matter when paused or playing).

I don't see anything relevant in log despite being set to "debug".

erkr commented 2 years ago

For me playback works as expected. I still have the official Spotify integration and spotcast installed. Tomorrow I will deinstall them and see what happens. Will report back on that

marcelveldt commented 2 years ago

Did you try to start playback from the Music Assistant panel or the HA default Media panel ? Playback should work with all devices that support playback by url but I did not actually test it all. Important to know is that the streamport (default tcp 8095) needs to be accessible from your players, do you have a non default HA setup perhaps ?

Stooovie commented 2 years ago

I did try. I have no issue starting playback from the built-in Media Browser but with Music Assistant, I can't play to any of my devices.

I use fairly typical HAOS setup on Rpi4.

marcelveldt commented 2 years ago

Hmmm, are you running 32 bits or 64 bits OS on your pi ? I did test with 64 bits HAOS on pi4 but not with 32 bits...

Nothing in the logs ? Playback should work out of the box, that's where this project is for in the first place ;-)

Stooovie commented 2 years ago

Nothing in the log except info about scraping and adding stuff to the database such as:
2022-05-08 00:05:01 DEBUG (MainThread) [music_assistant.mass.fanarttv] Fetching metadata for Artist Olivier Deriviere on Fanart.tv No errors. I'm on 32bit HAOS install as this setup is so old, 64bit was barely in beta :) I may try to switch to 64bit tomorrow.

marcelveldt commented 2 years ago

OK, I assumed everybody is running 64bits OS nowadays so I did not care about being 32 bits compatible. I wouldn't be surprised if that's causing the issues.

I'll have a look what I can do to proof make the library 32 bits compatible.

marcelveldt commented 2 years ago

Had a quick look and so far I could not spot any 32 bits incompitabilities. I'l try to fire up a pi4 with 32 bits OS tomorrow.

Stooovie commented 2 years ago

Thank you. Another thing I've noticed - sorting doesn't stick. I prefer albums to be sorted by date descending (so, new on the top), whenever I re-enter the albums view, it's back to alphabetical ascending.

Stooovie commented 2 years ago

Aaand also the music index is lost after every HA restart. Something is obviously wrong with this install. I don't have any other issues with my stuff though.

marcelveldt commented 2 years ago

Sorting should be remembered as is the list/panel preference so probably a small bug in there, I will have a look and provide a fix.

What do you mean about "music index" is lost ?

Stooovie commented 2 years ago

The library is empty and slowly fills up (with the spinner indicating there are background processes). The index was fully built overnight with all metadata and completely lost after HA restart.

marcelveldt commented 2 years ago

The library is empty and slowly fills up (with the spinner indicating there are background processes).

Ah yes, I fixed that yesterday. Are you on version 1.0.9 ?

Stooovie commented 2 years ago

Ah, updating right now

Stooovie commented 2 years ago

Update: playback does actually start on a single one of my devices: a Rpi4 running Kodi but even that is so slow it's not really usable (took roughly 20s to start). And even this is borked - it doesn't play what I actually select to play through the Music Assistant UI, but what was in the queue before.

Playback does not start at all on a Sonos (Ikea Symfonisk), Samsung TV, Volumio and Echo Dot 3rd gen.

I'm seeing these in the log but there really seem to be no errors when attempting playback.

2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter BrokenPipeError 2022-05-08 09:09:28 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/process.py", line 103, in write await self._proc.stdin.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 197, in _drain_helper await waiter

What does MA actually do? Does it transcode the actual music media? The Rpi4 is probaby just too slow to do that (which seems weird to me but it's what it is).

Thanks!

erkr commented 2 years ago

Stooovie

Hi, I previously ran into similar cast problems of local media files in the standard media browser. I noticed the text "default media Receiver" in my Chromecast players when using Music Assistant. The same happens when I cast local media files. So it can be related to your issue! The solution was simple. I learned it was an SSL issue. In the network settings, I had the internal and external URLs configured as "https" without having SLL certificates configured. Most of the HA usage was working, except for casting! Just by only changing my URL's to "http" and reboot the PI fixed casting.

marcelveldt commented 2 years ago

I'm not sure what's going on your setup. Playback should work on almost every device that allows playback from an URL as long as it can reach the HA machine on the local network.

MA does transcode when needed but a pi4 is fast enough to handle that. It even runs on a pi0 but a bit slower. Is your machine perhaps running out of memory/cpu ?

All those BrokenPipeErrors you notice are probably a result of failing streams. Are you trying to stream Spotify or other provider ? For simplicity perhaps start with TuneIn radio station ?

I'm working on the code to fix another bug atm. I will add some more logging at several places.

Stooovie commented 2 years ago

Stooovie

Hi, I previously ran into similar cast problems of local media files in the standard media browser. I noticed the text "default media Receiver" in my Chromecast players when using Music Assistant. The same happens when I cast local media files. So it can be related to your issue! The solution was simple. I learned it was an SSL issue. In the network settings, I had the internal and external URLs configured as "https" without having SLL certificates configured. Most of the HA usage was working, except for casting! Just by only changing my URL's to "http" and reboot the PI fixed casting.

Thank you, I'm no network expert but HA seems to be configured to use plain HTTP internally and HA Cloud externally, and inside my home, I'm usually accessing it via plain HTTP in Edge or the HA app on iPhone. Even connecting with plain HTTP via Edge on my iPhone doesn't fix the issue.

marcelveldt commented 2 years ago

The streaming of Music Assistant is independent of HA network setup and uses a dedicated (internal only) port, defaults to 8095. The only thing important is that any audio players are able to reach the HA server directly on the same network so unless you're running some complex VLAN network that should work out of the box.

I'm currently installing a pi4 32 bits to test if I can reproduce the issues.

Stooovie commented 2 years ago

I changed the config to disable Spotify and only enable TuneIn. I restarted HA. After restart, I still see all my Spotify stuff and no trace of TuneIn. The integration basically doesn't work at all on my system, for whatever reason.

This is the log after disabling spotify and enabling TuneIn:

2022-05-08 10:53:44 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [2442593856] Error handling message: Unknown error (unknown_error) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response await func(hass, connection, msg) File "/config/custom_components/mass/websockets.py", line 89, in async_get_mass_func await orig_func(hass, connection, msg, mass) File "/config/custom_components/mass/websockets.py", line 649, in websocket_item if item := await mass.music.get_item_by_uri( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py", line 160, in get_item_by_uri return await self.get_item( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py", line 174, in get_item return await ctrl.get( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/tracks.py", line 29, in get track = await super().get(*args, **kwargs) File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 62, in get details = await self.get_provider_item(provider_item_id, provider_id) File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 174, in get_provider_item raise ProviderUnavailableError(f"Provider {provider_id} is not available!") music_assistant.models.errors.ProviderUnavailableError: Provider spotify is not available! 2022-05-08 10:53:53 WARNING (MainThread) [music_assistant.mass.music] Provider spotify is not available 2022-05-08 10:53:53 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [2490248184] Error handling message: Unknown error (unknown_error) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response await func(hass, connection, msg) File "/config/custom_components/mass/websockets.py", line 89, in async_get_mass_func await orig_func(hass, connection, msg, mass) File "/config/custom_components/mass/websockets.py", line 649, in websocket_item if item := await mass.music.get_item_by_uri( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py", line 160, in get_item_by_uri return await self.get_item( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py", line 174, in get_item return await ctrl.get( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/tracks.py", line 29, in get track = await super().get(*args, **kwargs) File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 62, in get details = await self.get_provider_item(provider_item_id, provider_id) File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 174, in get_provider_item raise ProviderUnavailableError(f"Provider {provider_id} is not available!") music_assistant.models.errors.ProviderUnavailableError: Provider spotify is not available! 2022-05-08 10:54:37 ERROR (MainThread) [custom_components.localtuya.common] [681...d99] Connect to 192.168.0.151 failed Traceback (most recent call last): File "/config/custom_components/localtuya/common.py", line 145, in _make_connection self._interface = await pytuya.connect( File "/config/custom_components/localtuya/pytuya/__init__.py", line 669, in connect _, protocol = await loop.create_connection( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1056, in create_connection raise exceptions[0] File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1041, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 955, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 502, in sock_connect return await fut File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 537, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') OSError: [Errno 113] Connect call failed ('192.168.0.151', 6668) 2022-05-08 10:55:37 ERROR (MainThread) [custom_components.localtuya.common] [681...d99] Connect to 192.168.0.151 failed Traceback (most recent call last): File "/config/custom_components/localtuya/common.py", line 145, in _make_connection self._interface = await pytuya.connect( File "/config/custom_components/localtuya/pytuya/__init__.py", line 669, in connect _, protocol = await loop.create_connection( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1056, in create_connection raise exceptions[0] File "/usr/local/lib/python3.9/asyncio/base_events.py", line 1041, in create_connection sock = await self._connect_sock( File "/usr/local/lib/python3.9/asyncio/base_events.py", line 955, in _connect_sock await self.sock_connect(sock, address) File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 502, in sock_connect return await fut File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 537, in _sock_connect_cb raise OSError(err, f'Connect call failed {address}') OSError: [Errno 113] Connect call failed ('192.168.0.151', 6668) 2022-05-08 10:55:56 WARNING (MainThread) [music_assistant.mass.music] Provider spotify is not available 2022-05-08 10:55:56 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [2442593856] Error handling message: Unknown error (unknown_error) Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response await func(hass, connection, msg) File "/config/custom_components/mass/websockets.py", line 89, in async_get_mass_func await orig_func(hass, connection, msg, mass) File "/config/custom_components/mass/websockets.py", line 649, in websocket_item if item := await mass.music.get_item_by_uri( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py", line 160, in get_item_by_uri return await self.get_item( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py", line 174, in get_item return await ctrl.get( File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/tracks.py", line 29, in get track = await super().get(*args, **kwargs) File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 62, in get details = await self.get_provider_item(provider_item_id, provider_id) File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 174, in get_provider_item raise ProviderUnavailableError(f"Provider {provider_id} is not available!") music_assistant.models.errors.ProviderUnavailableError: Provider spotify is not available!

erkr commented 2 years ago

HA seems to be configured to use plain HTTP internally and HA Cloud externally

I guess if you have HA Cloud, SSL is configured. I'm not an expert either but understood the URL's and SSL have to be consistent for casting. Give it another try and configure your internal URL as HTTPS instead of HTTP then. Don't forget to reboot. I really hope this resolves your issue,

Update: This was the hint https://github.com/home-assistant/core/issues/65689#issuecomment-1030401544

marcelveldt commented 2 years ago

@Stooovie I've just installed a pi4 (2gb ram) with 32 bits OS and everything is working smooth. Playback works as expected and everything is responsive/fast. I will now have a look at trying a few other media players because you mentioned a few I did never test before.

marcelveldt commented 2 years ago

Hmm, I think I found what's going on. Have to perform a few more tests but I think a stupid typo was to blame for the issues. Strange that some players did actually work.

Stooovie commented 2 years ago

That sounds good... I really don't want to mess with my system (32bit to 64bit) as it's working great unless absolutely necessary.

Stooovie commented 2 years ago

Chiming in to report that 1.0.11 fixes playback on Sonos but that's it. Echo devices (integrated via this) complain about not being able to call the service ("Sorry, text to speech can be only called by the notify service"), Volumio doesn't do anything at all and radio stations (automatically imported by MA from the HA Sonos integration) don't play anywhere, not even the Sonos unit itself.

It's probably why the Media stuff is so half-assed in Home Assistant in the first place, all the players, integrations and devices are using different calls, methods and stuff and it's very hard to consolidate it all.

marcelveldt commented 2 years ago

Damn... Turns out that every media player integration handles playback differently (it's a bit of mess). I do not own all devices to test myself but I'll take a look at the source code of each to work out the differences.

So, you will be able to test:

marcelveldt commented 2 years ago

I am going to implement device specific "quirks" in the Music Assistant code for each media player. I guess I have been way too optimistic in believing the play media by url works with each integration. Besides that created an architecture discussion for HA core to clean up the mess some day: https://github.com/home-assistant/architecture/discussions/766

I will let you know once I have implemented the quirks for Amazon Echo and Volumio

Stooovie commented 2 years ago

Very cool, thanks! Too bad I'm not a dev, I'd help out in a heartbeat. The architecture discussion is a great step, the team should somewhat consolidate this mess.

marcelveldt commented 2 years ago

No need to be a dev, helping out with testing and reporting bugs is very appreciated to create great software!

marcelveldt commented 2 years ago

So, a small status update:

Stooovie commented 2 years ago

Thank you! That's a shame about Echos but completely understandable.

vk2him commented 2 years ago

Just adding that AppleTV doesn't also seem to work - here is the error log. I have only been able to get it to work with Nvidia Shield

Logger: homeassistant.components.apple_tv.media_player
Source: components/apple_tv/media_player.py:303
Integration: Apple TV (documentation, issues)
First occurred: 10:14:48 PM (3 occurrences)
Last logged: 10:48:16 PM

Media streaming is not possible with current configuration
marcelveldt commented 2 years ago

closing this one as it's getting a bit hard to follow. May any issues still exist, please open a new issue report for each issue or feature request. Thanks!

@vk2him there are various issues with atv integration regarding playback, most are generic so not specific to HA. I've added an issue to my TODO list to have a look if we can workaround the current limitations by sending the audio stream directly... See #124