hass-music-assistant icon indicating copy to clipboard operation
hass-music-assistant copied to clipboard

Not able to get anything to play through youtube music

Open muddro1 opened this issue 2 years ago • 11 comments

What version of Music Assistant has the issue?

2022.8

The problem

I've installed Music Assistant and appear to have linked it to my premium youtube account just fine. When I go to the music assistant tab, it appears that many of the artist just continue to spin without ever properly loading. Additionally, when I try to play something, seems like it connects to my cast device (i hear the ping), but nothing plays and it doesn't appear to play in music assistant (the play button doesn't turn to pause or give any other appearance of playing.

How to reproduce

Just trying to play something

Relevant log output

2-08-04 08:51:50.221 INFO (MainThread) [music_assistant.db] Database connected.
2022-08-04 08:51:50.650 DEBUG (MainThread) [music_assistant.event] background_job_updated 
2022-08-04 08:51:51.585 DEBUG (MainThread) [music_assistant.event] background_job_updated 
2022-08-04 08:51:51.657 INFO (MainThread) [music_assistant.stream] Started stream server on port 8095
2022-08-04 08:51:51.657 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-08-04 08:51:51.657 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup removed items from database
2022-08-04 08:51:51.997 INFO (MainThread) [music_assistant] Finished job [Cleanup cache] in 0.34 seconds.
2022-08-04 08:51:51.997 DEBUG (MainThread) [music_assistant.event] background_job_finished Cleanup cache
2022-08-04 08:51:52.007 INFO (MainThread) [music_assistant] Finished job [Cleanup removed items from database] in 0.35 seconds.
2022-08-04 08:51:52.007 DEBUG (MainThread) [music_assistant.event] background_job_finished Cleanup removed items from database
2022-08-04 08:52:19.653 DEBUG (MainThread) [music_assistant.event] background_job_updated 
2022-08-04 08:52:19.653 DEBUG (MainThread) [music_assistant.event] background_job_updated 
2022-08-04 08:52:19.662 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Youtube Music
2022-08-04 08:52:19.662 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider URL
2022-08-04 08:52:19.665 DEBUG (MainThread) [music_assistant.music.ytmusic] Start sync of artist items.
2022-08-04 08:52:19.678 INFO (MainThread) [music_assistant] Finished job [Library sync for provider URL] in 0.02 seconds.
2022-08-04 08:52:19.678 DEBUG (MainThread) [music_assistant.event] background_job_finished Library sync for provider URL
2022-08-04 08:52:21.588 DEBUG (MainThread) [music_assistant.event] queue_added media_player.ethans_speaker
2022-08-04 08:52:21.589 INFO (MainThread) [music_assistant.players] Player registered: media_player.ethans_speaker/Ethans Speaker
2022-08-04 08:52:21.589 DEBUG (MainThread) [music_assistant.event] player_added media_player.ethans_speaker
2022-08-04 08:52:21.608 DEBUG (MainThread) [music_assistant.event] queue_added media_player.living_room_speaker
2022-08-04 08:52:21.610 INFO (MainThread) [music_assistant.players] Player registered: media_player.living_room_speaker/Living Room speaker
2022-08-04 08:52:21.610 DEBUG (MainThread) [music_assistant.event] player_added media_player.living_room_speaker
2022-08-04 08:52:21.611 DEBUG (MainThread) [music_assistant.event] queue_added media_player.bedroom_clock
2022-08-04 08:52:21.611 INFO (MainThread) [music_assistant.players] Player registered: media_player.bedroom_clock/Bedroom clock
2022-08-04 08:52:21.611 DEBUG (MainThread) [music_assistant.event] player_added media_player.bedroom_clock
2022-08-04 08:52:21.714 DEBUG (MainThread) [music_assistant.music.ytmusic] Start sync of album items.
2022-08-04 08:52:21.752 DEBUG (MainThread) [music_assistant.event] queue_added media_player.bathroom_speaker
2022-08-04 08:52:21.752 INFO (MainThread) [music_assistant.players] Player registered: media_player.bathroom_speaker/Bathroom speaker
2022-08-04 08:52:21.753 DEBUG (MainThread) [music_assistant.event] player_added media_player.bathroom_speaker
2022-08-04 08:52:21.773 DEBUG (MainThread) [music_assistant.event] queue_added media_player.home_group
2022-08-04 08:52:21.773 INFO (MainThread) [music_assistant.players] Player registered: media_player.home_group/Home group
2022-08-04 08:52:21.774 DEBUG (MainThread) [music_assistant.event] player_added media_player.home_group
2022-08-04 08:52:21.777 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.ethans_speaker
2022-08-04 08:52:21.780 DEBUG (MainThread) [music_assistant.event] player_updated media_player.ethans_speaker
2022-08-04 08:52:21.782 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.living_room_speaker
2022-08-04 08:52:21.785 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_room_speaker
2022-08-04 08:52:21.786 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.bathroom_speaker
2022-08-04 08:52:21.789 DEBUG (MainThread) [music_assistant.event] player_updated media_player.bathroom_speaker
2022-08-04 08:52:21.792 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.bedroom_clock
2022-08-04 08:52:21.797 DEBUG (MainThread) [music_assistant.event] player_updated media_player.bedroom_clock
2022-08-04 08:52:21.801 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:21.806 DEBUG (MainThread) [music_assistant.event] player_updated media_player.office_speaker
2022-08-04 08:52:21.816 DEBUG (MainThread) [music_assistant.event] player_updated media_player.home_group
2022-08-04 08:52:21.818 DEBUG (MainThread) [music_assistant.event] queue_added media_player.office_speaker
2022-08-04 08:52:21.818 INFO (MainThread) [music_assistant.players] Player registered: media_player.office_speaker/Office Speaker
2022-08-04 08:52:21.818 DEBUG (MainThread) [music_assistant.event] player_added media_player.office_speaker
2022-08-04 08:52:23.365 DEBUG (MainThread) [music_assistant.event] queue_items_updated media_player.ethans_speaker
2022-08-04 08:52:23.365 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.ethans_speaker
2022-08-04 08:52:23.697 DEBUG (MainThread) [music_assistant.music.ytmusic] Start sync of track items.
2022-08-04 08:52:25.185 INFO (SyncWorker_6) [pychromecast.controllers] Receiver:Launching app CC1AD845
2022-08-04 08:52:25.188 DEBUG (MainThread) [music_assistant.players.stream] Starting Queue audio stream for Queue Ethans Speaker (PCM format: s16le - sample rate: 44100)
2022-08-04 08:52:25.188 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: database://track/688 (Arcade Fire - The Suburbs) for queue Ethans Speaker - crossfade: False
2022-08-04 08:52:25.188 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.ethans_speaker
2022-08-04 08:52:25.204 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: ytmusic://track/BWuYbxdrJoA
2022-08-04 08:52:26.726 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.ethans_speaker
2022-08-04 08:52:26.727 DEBUG (MainThread) [music_assistant.event] player_updated media_player.ethans_speaker
2022-08-04 08:52:32.674 DEBUG (MainThread) [music_assistant.music.ytmusic] Start sync of playlist items.
2022-08-04 08:52:33.908 DEBUG (MainThread) [music_assistant.music.playlist] updated Your Likes in database: 1
2022-08-04 08:52:33.926 DEBUG (MainThread) [music_assistant.music.playlist] updated Classic Rock Instrumentals in database: 2
2022-08-04 08:52:33.937 DEBUG (MainThread) [music_assistant.music.playlist] updated Classic Children's Songs in database: 3
2022-08-04 08:52:33.948 DEBUG (MainThread) [music_assistant.music.playlist] updated Handclapping & Footstomping in database: 4
2022-08-04 08:52:33.959 DEBUG (MainThread) [music_assistant.music.playlist] updated Alt-8 06/09/2018 in database: 5
2022-08-04 08:52:33.971 DEBUG (MainThread) [music_assistant.music.playlist] updated Alt-8 Week Ending 06-16-18 in database: 6
2022-08-04 08:52:33.980 DEBUG (MainThread) [music_assistant.music.playlist] updated Ethan in database: 7
2022-08-04 08:52:33.989 DEBUG (MainThread) [music_assistant.music.playlist] updated Classic Rock Lullabies in database: 8
2022-08-04 08:52:33.998 DEBUG (MainThread) [music_assistant.music.playlist] updated Flanagan Home Videos in database: 9
2022-08-04 08:52:34.007 DEBUG (MainThread) [music_assistant.music.playlist] updated Classical in database: 10
2022-08-04 08:52:34.015 DEBUG (MainThread) [music_assistant.music.playlist] updated 90s Workout in database: 11
2022-08-04 08:52:34.032 DEBUG (MainThread) [music_assistant.music.playlist] updated Rock & Run! in database: 12
2022-08-04 08:52:34.041 DEBUG (MainThread) [music_assistant.music.playlist] updated SiriusXM Alt Nation Alt-18 - Updated in database: 13
2022-08-04 08:52:34.051 DEBUG (MainThread) [music_assistant.music.playlist] updated Unofficial Alt-Nation Alt-18 Countdown in database: 14
2022-08-04 08:52:34.060 DEBUG (MainThread) [music_assistant.music.playlist] updated Wedding potential in database: 15
2022-08-04 08:52:34.069 DEBUG (MainThread) [music_assistant.music.playlist] updated Paste's 50 Best Grunge Songs in database: 16
2022-08-04 08:52:34.588 DEBUG (MainThread) [music_assistant.music.playlist] updated New Release Mix in database: 17
2022-08-04 08:52:34.598 DEBUG (MainThread) [music_assistant.music.playlist] updated Baby Driver Soundtrack in database: 18
2022-08-04 08:52:34.612 DEBUG (MainThread) [music_assistant.music.playlist] updated Dream a Little Dream Soundtrack in database: 19
2022-08-04 08:52:34.624 DEBUG (MainThread) [music_assistant.music.playlist] updated Guardians of the Galaxy Awesome Mix Vol. 2 in database: 20
2022-08-04 08:52:34.635 DEBUG (MainThread) [music_assistant.music.playlist] updated Boombox Radio in database: 21
2022-08-04 08:52:34.648 DEBUG (MainThread) [music_assistant.music.playlist] updated A Happy Alternative in database: 22
2022-08-04 08:52:34.662 DEBUG (MainThread) [music_assistant.music.playlist] updated Conditions Underground in database: 23
2022-08-04 08:52:34.679 DEBUG (MainThread) [music_assistant.music.playlist] updated Electric swing in database: 24
2022-08-04 08:52:34.700 DEBUG (MainThread) [music_assistant.music.playlist] updated Today's Coffee Shop Blend in database: 25
2022-08-04 08:52:34.713 DEBUG (MainThread) [music_assistant.music.playlist] updated INDIE MIXTAPE Best Indie New Rock in database: 26
2022-08-04 08:52:34.727 DEBUG (MainThread) [music_assistant.music.playlist] updated '00s Indie Scene in database: 27
2022-08-04 08:52:34.740 DEBUG (MainThread) [music_assistant.music.playlist] updated Best New Alt/Indie in database: 28
2022-08-04 08:52:34.753 DEBUG (MainThread) [music_assistant.music.playlist] updated Best New Alt/Indie - 18 November 2013 in database: 29
2022-08-04 08:52:34.761 INFO (MainThread) [music_assistant] Finished job [Library sync for provider Youtube Music] in 15.1 seconds.
2022-08-04 08:52:34.761 DEBUG (MainThread) [music_assistant.event] background_job_finished Library sync for provider Youtube Music
2022-08-04 08:52:35.188 WARNING (MainThread) [music_assistant.players.stream] Abort: client(s) did not connect within 10 seconds.
2022-08-04 08:52:35.190 DEBUG (MainThread) [music_assistant.helpers.audio] media stream aborted for: ytmusic://track/BWuYbxdrJoA
2022-08-04 08:52:41.595 DEBUG (MainThread) [music_assistant.event] queue_items_updated media_player.office_speaker
2022-08-04 08:52:41.606 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:41.843 INFO (SyncWorker_0) [pychromecast.controllers] Not launching app CC1AD845 - already running
2022-08-04 08:52:41.843 DEBUG (MainThread) [music_assistant.players.stream] Starting Queue audio stream for Queue Office Speaker (PCM format: s16le - sample rate: 44100)
2022-08-04 08:52:41.843 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: ytmusic://track/BWuYbxdrJoA (Arcade Fire - The Suburbs) for queue Office Speaker - crossfade: False
2022-08-04 08:52:41.843 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:41.857 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: ytmusic://track/BWuYbxdrJoA
2022-08-04 08:52:42.918 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:42.919 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:42.921 DEBUG (MainThread) [music_assistant.event] player_updated media_player.office_speaker
2022-08-04 08:52:42.957 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:45.338 INFO (SyncWorker_1) [pychromecast.controllers] Not launching app CC1AD845 - already running
2022-08-04 08:52:45.339 DEBUG (MainThread) [music_assistant.players.stream] Starting Queue audio stream for Queue Office Speaker (PCM format: s16le - sample rate: 44100)
2022-08-04 08:52:45.339 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: database://track/688 (Arcade Fire - The Suburbs) for queue Office Speaker - crossfade: False
2022-08-04 08:52:45.339 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.office_speaker
2022-08-04 08:52:45.354 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: ytmusic://track/BWuYbxdrJoA
2022-08-04 08:52:51.845 WARNING (MainThread) [music_assistant.players.stream] Abort: client(s) did not connect within 10 seconds.
2022-08-04 08:52:51.846 DEBUG (MainThread) [music_assistant.helpers.audio] media stream aborted for: ytmusic://track/BWuYbxdrJoA

Additional information

No response

What version of Home Assistant Core are your running

2022.8

What type of installation are you running?

Home Assistant Core

On what type of hardware are you running?

Linux

muddro1 avatar Aug 04 '22 13:08 muddro1

I see you're running HA core yourself. In that case note the following:

  • Make sure that TCP port 8095 can be accessed from your speakers on the local network to the HA server.
  • Make sure that in HA settings the "internal URL" field has a valid value
  • Try if the TTS feature of HA works on the cast speaker

Looking at your log the streaming part (Music Assistant) works correctly and the client simply failed to connect, meaning that your cast speaker can't reach the HA server on port 8095

marcelveldt avatar Aug 04 '22 15:08 marcelveldt

@muddro1 we need more information to assist you. If you have fixed this yourself please close this issue. We will close this issue in a few days if we don’t hear back. Thanks.

OzGav avatar Aug 10 '22 12:08 OzGav

Sorry havent gotten back. Been very busy.

Make sure that TCP port 8095 can be accessed from your speakers on the local network to the HA server. - opened up this port on my container instance, did not fix it.
Make sure that in HA settings the "internal URL" field has a valid value - This has a valid local IP
Try if the TTS feature of HA works on the cast speaker - works

Music assistant still does not work

muddro1 avatar Aug 16 '22 12:08 muddro1

Can you do any more testing to confirm that the speakers can actually connect to your HA server via port 8095. Anything in the logs?

OzGav avatar Aug 18 '22 00:08 OzGav

Have a look at this https://github.com/music-assistant/hass-music-assistant/issues/865 You may have the same problem. Try and play something from Tune-In radio and TTS. If that all fails then it is likely an issue in your installation. Marcel will add some additional debugging in a few weeks that might help solve it. If you work out the problem yourself please let us know.

OzGav avatar Aug 21 '22 12:08 OzGav

Ok so I had some issues with TTS that I have resolved, as I had a firewall issue. I thought maybe that would be the root cause of the issue here, but it isn't. It seems from the logs that its trying to reach my docker network ip:8095, when it should be trying to reach my local network ip:8095.

Basically I have my local network properly setup to 192.168.20.2:8123. I see in the logs something along these lines:

2022-08-29 17:56:23.840 ERROR (Thread-12) [homeassistant.components.cast.media_player] Failed to cast media http://172.19.0.11:8095/control/media_player.bathroom_speaker/next.mp3. Please make sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address
2022-08-29 17:56:24.135 ERROR (Thread-12) [homeassistant.components.cast.media_player] Failed to cast media http://172.19.0.11:8095/control/media_player.bathroom_speaker/next.mp3. Please make sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address
2022-08-29 17:56:24.164 ERROR (Thread-12) [homeassistant.components.cast.media_player] Failed to cast media http://172.19.0.11:8095/control/media_player.bathroom_speaker/next.mp3. Please make sure the URL is: Reachable from the cast device and either a publicly resolvable hostname or an IP address

It should be directed at http://192.168.20.2:8095

muddro1 avatar Aug 29 '22 21:08 muddro1

Thanks for continuing to work through this. Please wait for @marcelveldt to comment on this docker situation.

OzGav avatar Aug 29 '22 23:08 OzGav

.164

I have the same problem MA send a wrong ip of the HA server #https://github.com/music-assistant/hass-music-assistant/issues/835#issuecomment-1233329520, so i can t play anythings with MA

lucasimons avatar Sep 01 '22 15:09 lucasimons

@muddro1 in your Home Assistant settings, please configure the "internal URL" with your internal IP, so something like http://192.168.20.2:8123 in your case. It may also be an internal resolvable DNS-name.

Music Assistant will derive the stream URL from that field (DNS name will be auto resolved). If you correct that field and restart HA it should automagically work.

marcelveldt avatar Sep 01 '22 15:09 marcelveldt

when was this function introduced which recognizes the ip? because previously it worked perfectly for me I think until realizes 2022.8.1 then there was no way I could reproduce anything

lucasimons avatar Sep 01 '22 15:09 lucasimons

It has always been like that, since the very beginning so it must be something in your network or config that is wrong, sorry.

marcelveldt avatar Sep 01 '22 16:09 marcelveldt

Just checking if this is still a problem. We will close this soon if we don’t hear back.

OzGav avatar Oct 01 '22 22:10 OzGav

Yeah I gave up. Tried those other fixes mentioned. Turned off all firewalls between lans. Just wasn't working.

On Sat, Oct 1, 2022, 6:00 PM OzGav @.***> wrote:

Just checking if this is still a problem. We will close this soon if we don’t hear back.

— Reply to this email directly, view it on GitHub https://github.com/music-assistant/hass-music-assistant/issues/801#issuecomment-1264490201, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADZFCH33FWQIBZU4ICN4APTWBCYATANCNFSM55SPF2YA . You are receiving this because you were mentioned.Message ID: @.***>

muddro1 avatar Oct 01 '22 22:10 muddro1

Sorry then. It will be a network issue but we don’t seem to be able to help you further at this time. Perhaps the discussion in the middle of this thread may help? https://github.com/music-assistant/hass-music-assistant/issues/898

OzGav avatar Oct 01 '22 22:10 OzGav

That seems to be a similar issue. My issue was that it would not try to connect to my internal IP as I have it set in Home Assistant, but the adapter IP. Seems to be a bug to me if its not utilizing that IP.

muddro1 avatar Oct 01 '22 22:10 muddro1

I would like to see if this is an issue with HA and not your network setup. Please try and send a regular TSS message to the orginal HA speaker entity and then the mass entity and let us know what happens

OzGav avatar Oct 03 '22 08:10 OzGav

Also I note you mention turning off firewalls BETWEEN LANs. MA must be able to access your speakers LOCALLY on port 8095.

OzGav avatar Oct 03 '22 20:10 OzGav

Also I note you mention turning off firewalls BETWEEN LANs. MA must be able to access your speakers LOCALLY on port 8095.

Yes, I ensured 8095 was open. What appeared to be happening was that Music Assistant tried to send it directly to my docker network ip:8095, instead of my set up internalip:8095, which I had mapped to docker network IP. Basically should be Cast-->ServerIP:8095-->DockerInternalNetworkHomeAssistantIP:8095. Instead logs showed it as Cast --> DockerInternalNetworkHomeAssistantIP:8095.

muddro1 avatar Oct 03 '22 21:10 muddro1

Can you post a picture from HA SETTINGS>>SYSTEM>>NETWORK and show the bottom two boxes

OzGav avatar Oct 03 '22 23:10 OzGav

Screenshot_20221003-202254~2

Apologies, took it from my phone, but local network says http://192.168.20.2:8123

muddro1 avatar Oct 04 '22 00:10 muddro1

Higher up you showed a log where MA was trying to cast to 172.19.0.11:8095 . Above your adapter is 172.20.0.3 so it appears you are running multiple subnets which is not supported.

OzGav avatar Oct 04 '22 01:10 OzGav

Ah that is recent as I've been working on migrating to another server. At the time there was only 172.19...

muddro1 avatar Oct 04 '22 01:10 muddro1

So what errors are you getting now then?

OzGav avatar Oct 04 '22 01:10 OzGav

If you have solved this issue then please close this. If not then if you can please advise what errors you are getting now.

OzGav avatar Oct 17 '22 08:10 OzGav

Hi!

Your issue is based on the IP address, that you're runnig Haas in a docker container. Default docker creates an inner network, which is independent from your home network. So, what happens is the 172.20.X.X is a docker basd IP. It cannot be resolved from any of your devices in your network, just from the server OS. The solution is to migrate your container into host network mode, where you will get a proper network IP from your DHCP server. Or forget docker, and use Home Assistant OS instead in a VM for example.

chriske avatar Oct 22 '22 13:10 chriske