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.34k stars 49 forks source link

"Currently playing" not updating in queue flow mode #2940

Open johnboiles opened 3 weeks ago

johnboiles commented 3 weeks ago

What version of Music Assistant has the issue?

2.2.5

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

2024.9.1

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

The problem

Sometimes, in queue flow mode, despite playing normally, the track in MA doesn't update -- it just shows the same track having been playing for a long time. When this happens the playlist continues to progress in the player just fine.

image

Could this be somehow related to the player not reporting it's playback position?

I'm also having this issue #2893, perhaps there's a shared root cause.

How to reproduce

I'm playing a playlist via automation. Not sure on repro steps yet as it seems to only happen sometimes.

Music Providers

Apple Music

Player Providers

ESPHome Media Player (using https://github.com/gnumpi/esphome_audio)

Full log output

music-assistant (3).log

Additional information

No response

What version of Home Assistant Core are your running

2024.9.2

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Raspberry Pi

marcelveldt commented 3 weeks ago

Oof, please disable verbose logging. It makes the log super hard to read and its only needed on special request. Debug level is verbose enough, verbose is really only needed to zoom into a specific issue but it also comes with some side effects due to the added overhead.

johnboiles commented 3 weeks ago

I have verbose logging on to try to investigate #2893 (the ffmpeg logs are useful to understand what the streamer is doing). That's the worse issue since it interrupts our office music ~4x per day

johnboiles commented 3 weeks ago

Here's the log with VERBOSE filtered out (via grep -v " VERBOSE " music-assistant.3.log > music-assistant.3-debug.log)

music-assistant.3-debug.log

OzGav commented 1 week ago

Do you have other player types you can try? (I assume this is using the HA provider)

marcelveldt commented 1 week ago

Here's the log with VERBOSE filtered out (via grep -v " VERBOSE " music-assistant.3.log > music-assistant.3-debug.log)

music-assistant.3-debug.log

Thanks for that but at the same time I recommend to disable verbose logging (especially at global level) as it comes with some side effects. Only enable it on a PER PROVIDER base when asked specifically by one of the developers. It can cause issue son its own because the code acts a bit different when running in verbose mode (and per definition not nice to performance). So just a tip to not leave it enabled at all times or like you say, investigate the issue where the music stops. I would turn it on only on the stream controller.

That said. I think all these issues are related. So issue https://github.com/music-assistant/hass-music-assistant/issues/2893 is related to this one. If streaming fails under the hood, the queue controller has no more way to calculate where we are in the stream to show the correct song info.

If flow mode is enabled we stitch together all songs as one long stream of audio and we depend on the players accuracy of elapsed (total)time together with a calculation of how many exact bytes we processed of pcm audio per song.

Somehow we are recently experiencing some issues with Spotify (since we had to update our librespot fork due to spotify changes to the auth api) which we're trying to tackle. Let's see if the fixes from yesterday (in b29) solve this

marcelveldt commented 1 week ago

Hmm, I now see you are not using Spotify but Apple music so this is not the same issue as the spotify issue. Nevertheless I think that its still related to your other issue.

The log you just shared. Is that from the playback attempt from the screenshot ? So the song that got stuck as "now playing" was Karma from Taylor Swift ?

johnboiles commented 1 week ago

Do you have other player types you can try?

I could install https://github.com/sle118/squeezelite-esp32 on my esp32. Would that help?

I think that its still related to your other issue.

Agreed, I think it's likely that both #2893 and #2927 are related since they all have something to do with the ffmpeg stream process in queue flow mode.

Is that from the playback attempt from the screenshot ?

It's been a couple weeks so i'm not 100% sure, but I would be surprised if I shared a log and a screenshot that were from different sessions.

OzGav commented 4 days ago

You can install the Snapcast provider and try streaming to a browser tab. Likely this is an ESP32 issue but this will confirm it.