Google cast : plays a few seconds then stops

SeeDborg commented 3 months ago

What version of Music Assistant has the issue?

2.1.0

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

Latest

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

[X] Yes

The problem

When I try to play a song or an album on a Google Cast speaker, it just plays a few seconds then stops.

How to reproduce

IDK if the problem is general or just for me

Music Providers

SubSonic

Player Providers

Google Cast

Full log output

No response

Additional information

No response

What version of Home Assistant Core are your running

2024.7.3

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Generic x86-64 (e.g. Intel NUC)

OzGav commented 3 months ago

You havent attached the log?

SeeDborg commented 3 months ago

Sorry, here it is :

File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/receiver.py", line 119, in receive_message self._process_get_status(data) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/receiver.py", line 313, in _process_get_status listener.new_cast_status(self.status) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/multizone.py", line 126, in new_cast_status listener.multizone_new_cast_status(self._group_uuid, status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/helpers.py", line 205, in multizone_new_cast_status self.new_cast_status(self.castplayer.cc.status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/helpers.py", line 156, in new_cast_status self.prov.on_new_cast_status(self.castplayer, status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/__init__.py", line 439, in on_new_cast_status self.mass.loop.call_soon_threadsafe(self.mass.players.update, castplayer.player_id) Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 850, in update self.mass.player_queues.on_player_update(player, changed_values) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 882, in on_player_update self._check_enqueue_next(player, queue, prev_state, new_state) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 1173, in _check_enqueue_next self.clear(queue.queue_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 548, in clear player = self.mass.players.get(queue_id, True) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 151, in get raise PlayerUnavailableError(msg) music_assistant.common.models.errors.PlayerUnavailableError: Player d00b4b85-78a3-a9c0-fa21-6f4c8c6c298e is not available 2024-07-22 18:25:21.719 DEBUG (Thread-9) [music_assistant.providers.chromecast] [Partie Jour] Cast device availability changed: CONNECTED 2024-07-22 18:25:21.723 INFO (Thread-9) [pychromecast.socket_client] [Partie Jour(192.168.1.202):32009] Connection reestablished! 2024-07-22 18:25:21.768 DEBUG (Thread-9) [music_assistant.providers.chromecast] Cuisine is added to multizone: d287995b-02a0-488a-8eef-c9afe23af7af 2024-07-22 18:25:21.770 DEBUG (Thread-9) [music_assistant.providers.chromecast] Bose salon is added to multizone: d287995b-02a0-488a-8eef-c9afe23af7af 2024-07-22 18:25:21.774 DEBUG (MainThread) [music_assistant.player_queues] End of queue reached for Bose salon 2024-07-22 18:25:21.775 ERROR (MainThread) [music_assistant] Error doing job: Exception in callback PlayerController.update('d00b4b85-78a...-6f4c8c6c298e'): File "/usr/local/lib/python3.12/site-packages/pychromecast/socket_client.py", line 638, in _run_once self._route_message(message, data) File "/usr/local/lib/python3.12/site-packages/pychromecast/socket_client.py", line 705, in _route_message handled = handler.receive_message(message, data) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/multizone.py", line 329, in receive_message self._add_member(uuid, members[uuid]) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/multizone.py", line 253, in _add_member listener.multizone_member_added(uuid) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/multizone.py", line 158, in multizone_member_added listener.added_to_multizone(self._group_uuid) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/helpers.py", line 175, in added_to_multizone self.new_cast_status(self.castplayer.cc.status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/helpers.py", line 156, in new_cast_status self.prov.on_new_cast_status(self.castplayer, status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/__init__.py", line 439, in on_new_cast_status self.mass.loop.call_soon_threadsafe(self.mass.players.update, castplayer.player_id) Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 850, in update self.mass.player_queues.on_player_update(player, changed_values) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 882, in on_player_update self._check_enqueue_next(player, queue, prev_state, new_state) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 1173, in _check_enqueue_next self.clear(queue.queue_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 548, in clear player = self.mass.players.get(queue_id, True) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 151, in get raise PlayerUnavailableError(msg) music_assistant.common.models.errors.PlayerUnavailableError: Player d00b4b85-78a3-a9c0-fa21-6f4c8c6c298e is not available 2024-07-22 18:25:21.786 DEBUG (MainThread) [music_assistant.player_queues] End of queue reached for Bose salon 2024-07-22 18:25:21.787 ERROR (MainThread) [music_assistant] Error doing job: Exception in callback PlayerController.update('d00b4b85-78a...-6f4c8c6c298e'): File "/usr/local/lib/python3.12/site-packages/pychromecast/socket_client.py", line 638, in _run_once self._route_message(message, data) File "/usr/local/lib/python3.12/site-packages/pychromecast/socket_client.py", line 705, in _route_message handled = handler.receive_message(message, data) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/receiver.py", line 119, in receive_message self._process_get_status(data) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/receiver.py", line 313, in _process_get_status listener.new_cast_status(self.status) File "/usr/local/lib/python3.12/site-packages/pychromecast/controllers/multizone.py", line 126, in new_cast_status listener.multizone_new_cast_status(self._group_uuid, status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/helpers.py", line 205, in multizone_new_cast_status self.new_cast_status(self.castplayer.cc.status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/helpers.py", line 156, in new_cast_status self.prov.on_new_cast_status(self.castplayer, status) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/chromecast/__init__.py", line 439, in on_new_cast_status self.mass.loop.call_soon_threadsafe(self.mass.players.update, castplayer.player_id) Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/events.py", line 88, in _run self._context.run(self._callback, *self._args) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 850, in update self.mass.player_queues.on_player_update(player, changed_values) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 882, in on_player_update self._check_enqueue_next(player, queue, prev_state, new_state) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 1173, in _check_enqueue_next self.clear(queue.queue_id) File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/player_queues.py", line 548, in clear player = self.mass.players.get(queue_id, True) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 151, in get raise PlayerUnavailableError(msg) music_assistant.common.models.errors.PlayerUnavailableError: Player d00b4b85-78a3-a9c0-fa21-6f4c8c6c298e is not available 2024-07-22 18:25:30.055 DEBUG (Thread-11) [music_assistant.providers.chromecast] [Bose salon] Cast device availability changed: CONNECTED 2024-07-22 18:25:30.058 DEBUG (MainThread) [music_assistant.player_queues] End of queue reached for Bose salon 2024-07-22 18:25:30.061 INFO (Thread-11) [pychromecast.socket_client] [Bose salon(192.168.1.202):8009] Connection reestablished! 2024-07-22 18:25:33.502 DEBUG (Thread-4) [music_assistant.providers.chromecast] Discovered new or updated chromecast CastInfo(services={HostServiceInfo(host='192.168.1.24', port=32196), MDNSServiceInfo(name='Google-Cast-Group-b2f3851546cd48489f185ab105e8da6a-1._googlecast._tcp.local.')}, uuid=UUID('b2f38515-46cd-4848-9f18-5ab105e8da6a'), model_name='Google Cast Group', friendly_name='Toute la maison', host='192.168.1.24', port=32196, cast_type='group', manufacturer='Google Inc.') 2024-07-22 18:25:33.505 DEBUG (Thread-4) [music_assistant.providers.chromecast] Discovered new or updated chromecast CastInfo(services={MDNSServiceInfo(name='Google-Cast-Group-d287995b02a0488a8eefc9afe23af7af-1._googlecast._tcp.local.')}, uuid=UUID('d287995b-02a0-488a-8eef-c9afe23af7af'), model_name='Google Cast Group', friendly_name='Partie Jour', host='192.168.1.202', port=32009, cast_type='group', manufacturer='Google Inc.') 2024-07-22 18:25:33.678 DEBUG (Thread-4) [music_assistant.providers.chromecast] Discovered new or updated chromecast CastInfo(services={MDNSServiceInfo(name='Google-Cast-Group-d287995b02a0488a8eefc9afe23af7af-1._googlecast._tcp.local.'), HostServiceInfo(host='192.168.1.202', port=32009)}, uuid=UUID('d287995b-02a0-488a-8eef-c9afe23af7af'), model_name='Google Cast Group', friendly_name='Partie Jour', host='192.168.1.202', port=32009, cast_type='group', manufacturer='Google Inc.')

OzGav commented 3 months ago

The issue report template and troubleshooting instructions are clear that you need to ATTACH logs. This report is unreadable at present.

OzGav commented 3 months ago

Please edit your post as well and remove the logs

OzGav commented 3 months ago

@SeeDborg we will close this soon as you have not fixed the original post and attached the full logs.

SeeDborg commented 3 months ago

Sorry I'm currently on vacation, I'll do it soon !

S-Starvey commented 3 months ago

Same thing here (Chromecast troubles AND on vacation with no access to the logs). The music plays then stops after a few seconds. Sometimes, MA manages to play a whole song, then stops on the next one.

erkr commented 3 months ago

Sad to hear it fails for some of you. Please note that Chromecast works for most of us, so details are needed to derive what makes your setup fail. @S-Starvey please tell what is your setup. What music provider? Also subsonic?

S-Starvey commented 3 months ago

Sad to hear it fails for some of you. Please note that Chromecast works for most of us, so details are needed to derive what makes your setup fail. @S-Starvey please tell what is your setup. What music provider? Also subsonic?

Thanks! Yeah, so, as I said, on holydays. So no logs for now :-) Although, since I spent enough time on this, I can give you some infos from memory.

I am using HA in a Proxmox VM (not a CT) and MA as a module (latest stable version, unless there was an update since then).
My providers are Music Assistant, Subsonic (actually Navidrome, but that's Open Subsonic) and an SMB mount from my NAS. I tried every variations with those 3 sources; same results everytime.
Of course, everything is on the same subnet. Other casts from that same subnet work perfectly, be it Plex (in a Proxmox CT) or VLC from my computer.
I fiddled many time with every option in MA, to no avail. It's always the same thing.
From memory, the logs simply say that MA lost connection and then kinda freeze. When pressing stop, it says something like 10 seconds delay expired and failed stopping.

That's kinda frustrating, especially since where I am now, at a friend's, it works flawlessly and I wake up every morning to his horrendous music :-D

I'll send the logs once I'm back.

Cheers and thanks for your time.

S-Starvey commented 3 months ago

OK. I've been switching everything to debug, so there's a lot of noise. music-assistant.log I'm sorry, beside it lost connection and connection reestablished after it stopped playing, I don't know how to decipher that :-/

Cheers.

OzGav commented 3 months ago

We ask that you don’t enable debug unless requested. Please attach another log without debug enabled.

OzGav commented 3 months ago

Also are all the players wireless? If so you might have a bandwidth issue.

erkr commented 3 months ago

So both of you are using subsonic as provider. Do you experience the issue also with other providers?

S-Starvey commented 3 months ago

@OzGav Oh! Sorry about the debug. My apologies. And yeah, all players are wireless, but the bandwidth is fine, as far as I tested it. Beside the occasional laptop, a repeater, a vacuum cleaner and my phone, they're the only wireless devices. I tried Plex wireless and it worked fine (otherwise, I use plex with an ethernet connexion). I still might be mistaken, though, but I think I'm OK on that front. Here, I made a run with debug off: music-assistant.log

@erkr Yes. I tried with Music Assistant and SMB/CIFS. Currently I let MA choose its provider, but I tried with only MA/Subsonic, SMB/Subsonic, and each one one its own, with the same result.

Cheers.

OzGav commented 3 months ago

MA streams at a high quality which requires a lot of bandwidth. You will need to test with a wired connection or move a player very close to your wireless access point and see if that makes a difference.

S-Starvey commented 3 months ago

@OzGav Well, the players are wireless only. But one of them is very close to the wireless access (the one I usually do the tests with). One other is near the repeater. The last one is 5 meters from the access, behind a door (thin door, thin wall). Although the steam can't be much larger than the source, though, can it? I'm talking about files between 5 and 20 mb, that I cast from another player, from the same NAS, without any trouble, be it from my phone or my computer. Even much larger files like FLAC are cast without a hiccup to the three players at the same time (group cast). I thought interferences at some point, but the server hosting HA is wired to the router through a switch.

I'm gonna try to install HA and MA on a Raspberry if it's still working and see if it works. In which case, I guess Proxmox would be the culprit.

Once again, thanks for your time.

OzGav commented 3 months ago

I use Proxmox and don't have this problem.

Looking at your logs. Firstly, unrelated but you have a bunch of tagging problems.

Next you are getting a bunch of disconnections. Is everything on the same subnet/VLAN? If you are using MDNS forwarders that isn't supported. Is there anything else unusual about your network?

SeeDborg commented 3 months ago

MA streams at a high quality which requires a lot of bandwidth. You will need to test with a wired connection or move a player very close to your wireless access point and see if that makes a difference.

75% of my players are connected with ethernet and I have the same issue.

S-Starvey commented 3 months ago

@OzGav

Well, that rules out Proxmox. Which is a thing.
And yeah, the tagging is weired. I use MP3Tag for years now, and it seems to produce strange things. But honestly, I don't care about it for now. Maybe I'll re-tag the whole things once I've sorted things out :-D
Yes, that's what I gathered from the logs. "Hello, we're online; sorry I lost you. Bye". And I can't see the reason why. Firewall set, check; same subnet, check; 20-something VM/LXC/devices working just fine together, check. And for the life of me, I can't understand what's wrong here. I mean, if I couldn't connect at all that'd be somewhat easy. But it connects, starts playing, and disconnects.

I'm not sure I'm of much help :-D

Cheers

OzGav commented 3 months ago

Yes this isn't widespread so likely something in the local setup. This will take some time before it gets looked at with all the other things being worked on unfortunately. If you can keep trying different things. Again if you can try different player types to see if this defintiiely is a cast issue

S-Starvey commented 3 months ago

@OzGav I'll keep trying. I can live without it, but it bothers me and I'm stubborn :-D If I find anything, I'll post it here, just in case it can help someone sometime. In the meantime, I'm gonna try to dig up a pair of old Google Homes and test it out. After all, maybe it's the players themsleves (in which case I'd be pissed, let's face it). And if someone has any idea, I'll keep the discussion bookmarked.

Cheers!

github-actions[bot] commented 2 months ago

This issue is stale because it has been open 21 days with no activity. Comment or this will be closed in 7 days.

marcelveldt commented 2 months ago

Not stale

S-Starvey commented 2 months ago

The more I look into it, the more I think @OzGav was right about bandwidth issue. And yet it doesn't make any sense to me. The speakers are almost alone on a 5GHz wifi (I don't rely much on wireless), and I don't see how a few MB could saturate the bandwith. I even tested a few GB transfer to be sure and it went perfectly.

But nothing else makes sense whatsoever, since MA always looses the connection after a few seconds. If I'm lucky, one song goes through (quite rarely) and it occurs during the second one. But it always looses the connection no matter the speaker. So it gotta be something on my end, because it doesn't seem to be a common issue and I've seen the exact same configuration working perfectly a few weeks back: same brand of speakers (JBL A200), MA in a HA Proxmox VM on a 5GHz wireless from the same router (Freebox Pop, FR) from the same provider (Free, FR). Boggles the mind.

OzGav commented 2 months ago

@S-Starvey Have you got any wired devices to just check that works ok?

S-Starvey commented 2 months ago

@OzGav I'm gonna try to wire up one speaker and I let you know. Damn, this is an insane amount of work just not to rent my music via Spotify or whatnot :D

Cheers!

OzGav commented 1 month ago

Please try again with 2.2.4 or beta 23

SeeDborg commented 1 month ago

Now I can't play anything. The player can be turned on or off (I hear the sound), I can set the volume (hearing sound too), but when I play a song, no sound.

OzGav commented 1 month ago

Do you have anything unusual about your MA install or network setup as no one else is reporting no playback on Cast devices. I use a lot of them. Exactly what device are you using? What other player providers have you tried?

github-actions[bot] commented 1 month ago

This issue is stale because it has been open 7 days with no activity after asking for more info. Comment or this will be closed in 3 days.

github-actions[bot] commented 1 month ago

This issue was closed because it has been stalled for 10 days with no activity. This can be reopened if additional information is provided.

S-Starvey commented 1 month ago

So. News from the front, so to speak, if it can help some people.

When you hit a wall, go around.

I haven't been able to play any file gathered from the NAS for more than a few seconds, when the access was configured from MA.

Don't know how I didn't think about it earlier, but I mounted the music folder (from the NAS, then) directly in Home Assistant. I named it "Music" (because I'm really strong on originality). And I then fed the files to MA through Music Provider/Filesystem (local disk). For me, the path is /media/Music, no surprise here. And that's it. It works like a charm so far. It casts even large FLAC files to all 3 players with no hiccups.

So, yay me (hope I'm not jinxing it), and many thanks to the people involved and those who helped. If something fails big time, I'll necro the topic, but I consider it closed since everything runs smoothly.

S-Starvey commented 1 month ago

One last detail I forgot to mention. I use the media players from Home Assistant for everything to work, not the MA Chromecast thing. It's still casting (no DLNA; it plays fine but it's hell to stop the players).

In fine, MA just plays the music, everything else is set up on HA (the music folder and the players).

Cheers

SeeDborg commented 1 week ago

After running some tests, it seems that running home assistant NOT with ssl is fixing the issue.

Though it would be nice to be able to run music assistant with ssl 😅

OzGav commented 1 week ago

The troubleshooting page of the docs state clearly that LOCAL SSL IS NOT SUPPORTED.

SeeDborg commented 1 week ago

My bad. What's strange is that it was working some time ago, and I've always been in SSL.

music-assistant / hass-music-assistant