Playback randomly stops between tracks when casting to GHome Speakers and Groups

[TheWebMachine]

What version of Music Assistant has the issue?

2024.1.0

The problem

When casting to a Google Home speaker or GHome Group, without crossfade on, playback will stop between tracks randomly. Sometimes after just one track, sometimes it will play for an hour and then just stop.

How to reproduce

1. Queue up some tracks from YT Music - only provider I use/have setup at the moment
2. Cast to a single GHome speaker or Group with crossfade turned off
3. Wait for music to randomly stop between tracks, usually when you are far away from your phone or elbow deep in something 🤦🏻‍♂️

Relevant log output

2024-01-26 04:35:28.288 ERROR (MainThread) [asyncio] Task exception was never retrieved future: <Task finished name='Task-3724' coro=<PlayerQueuesController._check_enqueue_next.._enqueue_next() done, defined at /usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py:847> exception=AttributeError("'MediaStatus' object has no attribute 'items'")> Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 851, in _enqueue_next await self.mass.players.enqueue_next_queue_item( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/players.py", line 631, in enqueue_next_queue_item await player_prov.enqueue_next_queue_item(player_id=player_id, queue_item=queue_item) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/chromecast/init.py", line 301, in enqueue_next_queue_item if (cast_queue_items := getattr(castplayer.cc.media_controller.status, "items")) and len( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ AttributeError: 'MediaStatus' object has no attribute 'items'

Additional information

• HAOS in OVA
• Installed via HACS with native container add-on
• YT Music is provider
• After the error above appears in log, playback stops within 1-3 tracks
• Happens with both UVloop enabled and disabled

Versions:

• Integration 2024.1.0
• Add-on 2.0.0b86
• Core 2024.1.5
• Supervisor 2023.12.1
• Operating System 11.4

What version of Home Assistant Core are your running

2024.1.5

What type of installation are you running?

Home Assistant Container

On what type of hardware are you running?

Linux

[rcluver]

Same issue seen with Spotify. Usually is after 2 tracks for me, so thought is related to the prior 1-track issue with chromecast devices. B86

[OzGav]

Has been reproduced and is being looked at

[TheWebMachine]

I'm not sure if this was intentional work on the issue or by chance in addressing another issue, but it appears thus far that this has been resolved in 2.0.0b87.

To clarify, this is without the new Queue Flow Mode or Crossfade enabled, which is now disabled on GHome/Chromecast devices in lieu of the new Flow Mode. (I'll put Queue Flow Mode through its paces later...)

I started testing about 30 minutes on a single speaker. No errors and no halt of playback. Now, I've got 6 speakers that I'm playing independent queues on simultaneously. So far, all is well. I'll report back later today if it pops up, but I think the bug is squashed.

[TheWebMachine]

Now it isn't playing through a full song before skipping to the next. Some songs will play entirely, some for minutes but not until the end, some get 15-30 seconds in and then just skip to the next in queue. Currently testing with a 6-speaker group and it just randomly does it.

Nothing noteworthy in the logs. Streaming from YT Music. Not sure how much MA caches of my tracks, but I'm playing the same queue on repeat.

This could be a different issue and maybe already reported, but it only started for me in b87 after the original issue of stopping playback was no longer an issue.

[TheWebMachine]

I decided to give Queue Flow Mode a try and it seems to have the same issue where it will randomly stop playing in the middle of a track and skip to the next. That said, it seems to happen less frequently with QFM on than if its turned off. In the log it appears to restart the QFM task:

2024-01-27 16:46:15.863 INFO (MainThread) [music_assistant.streams] Start Queue Flow stream for Queue Whole House - crossfade: False 2024-01-27 17:02:33.591 INFO (MainThread) [music_assistant.streams] Start Queue Flow stream for Queue Whole House - crossfade: False 2024-01-27 17:12:03.932 INFO (MainThread) [music_assistant.streams] Start Queue Flow stream for Queue Whole House - crossfade: False

Perhaps music_assistant.streams is crashing, but nothing shows in the logs as to what might be causing it.

With debug on and casting to a group, individual participating speakers report UNKNOWN status, but this may be unrelated:

2024-01-27 17:18:02.334 DEBUG (Thread-11) [music_assistant.providers.chromecast.Whole House] Received media status update: PLAYING 2024-01-27 17:18:02.335 DEBUG (Thread-13) [music_assistant.providers.chromecast.Guest Bedroom speaker] Received media status update: UNKNOWN 2024-01-27 17:18:02.339 DEBUG (Thread-12) [music_assistant.providers.chromecast.Guest Bath speaker] Received media status update: UNKNOWN 2024-01-27 17:18:02.342 DEBUG (Thread-14) [music_assistant.providers.chromecast.Master Bath speaker] Received media status update: UNKNOWN 2024-01-27 17:18:02.432 DEBUG (Thread-7) [music_assistant.providers.chromecast.Master Bedroom speaker] Received media status update: UNKNOWN

Right as the issue occurs, this is the debug output:

2024-01-27 17:23:22.674 DEBUG (Thread-11) [music_assistant.providers.chromecast.Whole House] Received media status update: BUFFERING 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast] Master Bedroom speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast] Den Speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast] Master Bath speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast] Guest Bedroom speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast] Guest Bath speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast] Gym speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:22.918 DEBUG (Thread-11) [music_assistant.providers.chromecast.Whole House] Received media status update: BUFFERING 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast] Master Bedroom speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast] Den Speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast] Master Bath speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast] Guest Bedroom speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast] Guest Bath speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast] Gym speaker got new media_status for group: c403644e-f8de-4149-bea0-42f4c1e0211f 2024-01-27 17:23:23.670 DEBUG (Thread-11) [music_assistant.providers.chromecast.Whole House] Received media status update: PLAYING

Buffering is not a product of network conditions, as I can pull 50Mbit across a 1x1 MIMO iperf test with less than 2ms jitter and 400Mbit on a 2x2. CPU and memory in the add-on are negligibly low. Besides, a buffer underrun on the network shouldn't cause a full track skip, anyway.

[TheWebMachine]

Beginning testing of b88

[marcelveldt]

This should be fixed in beta88

[TheWebMachine]

It appears to be so far, but I've only had a few hours to test and only with QFM disabled so far. Can't continue testing until my other issue with TTS is addressed, so I have no further input to provide.

[rcluver]

Will check on 88, but testing on 87 seemed to have also corrected the issue.