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.39k stars 51 forks source link

HA error updating home assistant media_player for MA group player #2395

Closed chasut closed 4 months ago

chasut commented 5 months ago

What version of Music Assistant has the issue?

2.1.0b1

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

2024.5.1

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

The problem

HA media_player entity does not update meta-data (title, artist, art, etc.) as expected. However, the player controls still work.

I have a AirTunes group player with several speakers in my home. Play/Pause, Forward/Reverse, volume work great. Even browse media works. However, after the first song, the media_player either doesn't update or just becomes unavailable when playing playlists from apple music. Playing radio stations from tune-in provider works fine.

How to reproduce

Play any apple playlist to a group player and monitor the associated media_player entity.

Music Providers

Apple Music

Player Providers

Airtunes/Group Player

Full log output

log.txt HA log error.txt

Additional information

I have tried reloading the integration several times with no luck (learning the hard way that it can automatically spin up another instance of the MA add-on). Tested with different music sources and it seems to be just with the Apple Music provider.

I added an HA log snippet of the error for more information. This error repeats each time the media_player entity is updated.

Best I can tell from reading for hours that a group player with a Lovelace media player card is the best way to control without an iframe/web card. I have read the docs, searched the issues and discussions, and even gandered at the discord server so hopefully this is not a duplicate and helpful to the cause.

BTW, absolutely love MA and appreciate all your efforts. Wish I could do more to help.

What version of Home Assistant Core are your running

2024.5.5

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

macOS

OzGav commented 5 months ago

You have listed the player provider as Airtunes/Group Player but there is no such player provider in MA. Do you mean Airplay or is this actually going via the HA player provider?

chasut commented 5 months ago

Airplay.

OzGav commented 5 months ago

So you are talking about the MA entity you see in HA? When you write this

Play any apple playlist to a group player and monitor the associated media_player entity.

Do you actually mean Play any apple playlist to an Airpay player and monitor the associated media_player entity.

Do you have other player types that you can play these Apple playlists to? If so do they work?

chasut commented 5 months ago

Yes, the MA entity in HA. No, Play any apple playlist to an Airplay player that is a Group Player (created in the MA UI using the "ADD GROUP PLAYER" of type Airplay

But now something interesting:

  1. I created a UPnP/DLNA Player provider to my AVR and got the same result. Same error in HA log.
  2. I played an apple playlist to an Airplay player (single player, no group) and could not reproduce the issue.
  3. Created a new group player that only contained a single player. Same issue, entity in HA not updated.
  4. Again, played to a single Airplay player and the first song did not update, but the 4 subsequent songs did update as expected
  5. It is a bit cumbersome, but figured out how to group two speakers via the icon on the players list. In this grouping, the main player in HA updated as expected.

So it would seem that the group player using the "ADD GROUP PLAYER" is the key element

chasut commented 5 months ago

Ok, a few more:

  1. Reloaded the MA integration in HA. If failed to initialize. Restarted the Add-on
  2. Noted that the Apple Music providers did a sync after the add-on restart
  3. Removed all but two speakers in the group. Tested a couple of apple playlists. On some, it did not update the entity in HA on the first song, but subsequent songs it worked as expected.
  4. Added additional speakers to the group. working as expected, but when queued up a different playlist, the first song did not get updated, subsequent did.
  5. In testing above, going to the next song was accomplished by hitting the "skip forward" button on the HA Media Control card. Next step was to just let the song play. This resulted in the entity NOT updated, just the last song information remained.
  6. I then hit the skip ahead, and oddly, the Media Control showed song information for the next song in the queue but the current song in MA continued to play
  7. Went back and played to a single airplay player and just let the song complete and unfortunately got the same behavior.
  8. Did the skip ahead in MA and got the same odd behavior of the media_player entity getting the information from the next song in the queue.

So, my earlier hypothesis that it had something to do with the group player is wrong. But rather, something about the song transition naturally versus skipping ahead.

Anyway, think I will go get some sleep after lucky number 13.

Thank you for your attention and patience with me. Please let me know what I can do to help further, or if I am just doing something wrong or the wrong way.

OzGav commented 5 months ago

If you can find anything out to further refine what you think the issue is that would be great otherwise this will be looked at in due course

chasut commented 5 months ago

My theory: The HA integration chokes on something (receive something unexpected or malformed, invalid stream_type?) but only on a particular event (song finished?) but not on whatever event happens on skip ahead, and only for the Apple Music Provider. (tune-in radio works fine, although admittedly a lower bar for meta-data)

I removed/reinstalled the integration to make sure something wasn't wrong there. Wouldn't make sense it is a network issue in this case, but double checked everything there as well. So I am confident that I have a "by the book" install net of running the beta add-on.

That's about all I can offer on my own at this point. I will stand by and hope for the best as you guys do your thing!

marcelveldt commented 5 months ago

I can't reproduce this issue at all so maybe this is something specific with Apple Music or its already resolved.

chasut commented 5 months ago

Yes, it is specific to Apple Music. I have no trouble with other music providers I tested. The behavior is the same on the latest beta. BTW, it is not just for group players, I get the same results on any of the MA media_player entities in HA.

OzGav commented 5 months ago

@MarvinSchenkel

MarvinSchenkel commented 4 months ago

@chasut before I do a deep dive into this issue, can you confirm it still exists in beta 9?

chasut commented 4 months ago

Yes, it still exists. I replicated the issue, and then completely wiped and re-installed the MA beta. Same thing. I did miss beta 9, so this is beta 10.

Thank you for looking at this. This is the only thing I need to be able to roll this out into my setup.

chasut commented 4 months ago

BTW, just noticed something, not sure it is related. The Tracks list is empty. They were there in earlier betas, but not now. I don't normally just play specific tracks, so had removed that item in the menu to clean it up a bit so unfortunately don't know when they stopped getting loaded. They were there for sure in the first few betas at least.

MarvinSchenkel commented 4 months ago

Anything interesting in the debug logs?

chasut commented 4 months ago

Just went through the recreation steps and this was in the logs for the sequence of events. On the front-end, this is what I did/observed:

  1. Navigated to playlist screen and pressed the play icon on the playlist [Classic Singer Songwriters]
  2. After a second or two, I thought I saw a brief flash of a James Taylor, then Bob Dylan, Tangled up in Blues showed on the "now playing" dialogue.
  3. Checked the HA media_player entity and it showed the information for James Taylor, Fire and Rain. I also have a media_player to that same device [an HomePod mini] from the native HA Apple TV integration. It showed the correct information for the playing Bob Dylan track.
  4. Once the Dylan track completed, the JT track began playing. The HA media_player entity from MA did not change
  5. Once the JT track finished, a Bill Withers track started playing. The HA media_player entity from MA did not change.

Dang, just realized I didn't have the logger set to debug after I re-installed. I will re-run and follow up. The error from the HA side is in the attached logs. MA Log 1.txt

chasut commented 4 months ago

Just ran again with log level debug. Different playlist with only slightly different results. This time the HA media_player entity was never updated.

Please let me know if you are having any difficulty re-creating this. Perhaps it has something to do with my Apple Music Library which is a mix of ripped CDs, purchased music, and Apple Music subscription with Sync Library turned on.

MA Log 2.txt

chasut commented 4 months ago

One last thing and I will stop until asked for additional info but thought this might be interesting. I did a refresh of "Tracks" with log set to debug and found this in the log. It was preceded by ~50 or so additional "skipping track items just like the first in the log snippet. Looking at all those there doesn't seem to be much rhyme or reason to which are skipped. A few are rips from obscure CDs I own, mixed with things I only "rent" from Apple Music subscription. But thought the traceback might be of interest.

Please let me know if there is anything I can do to help.

MA Log 3.txt

OzGav commented 4 months ago

@chasut can you edit your posts and attach those logs instead of pasting as this is getting too hard to read

chasut commented 4 months ago

There you go, hope that helps. BTW, this still has the [More info] tag. Is there anything else I need to do/provide? Thanks

MarvinSchenkel commented 4 months ago

Alright, couple of things:

EDIT: Beta 11 should be out today that has some fixes for custom music. Curious how that will work out for you

chasut commented 4 months ago
  1. It has been updated. That log snapshot was taken when I originally filed the issue. Let me know if you would like a refreshed file.
  2. Yes, at least that one is available for me I have not tried them all at this writing. Based on the album, I am guessing it is a regional availability thing. Will do some additional exploring on this one. I had another feature on this account (don't remember what apple called it) but essentially it replicated ripped music in the cloud with their own version so even those tracks could play anywhere. I wonder if that is the culprit. It might explain some of this.
  3. Makes sense.

I will try Beta 11.

Based on your comments I am assuming that you are not able to replicate. I am going to try from a different Apple Music account that I think is clean(er) and does not have any uploaded music in the library.

MarvinSchenkel commented 4 months ago

Sorry I meant beta 12, which will be out later today! Yes, please send me a new snapshot of the HA and MA log for the HA entity issue. What region are you using Apple music?

chasut commented 4 months ago

Here is the updated log entries from HA HA log 1.txt

I am in the U.S.

MarvinSchenkel commented 4 months ago

Here is the updated log entries from HA HA log 1.txt

I am in the U.S.

And you are 200% sure you are on the latest HACS (!) integration for MA? (so I am not talking about the MA beta addon)

chasut commented 4 months ago

There is no update notification from HACS anyway. It shows as 2024.6.2. I see no newer versions available on the repository. Will manually redownload and try again.

MarvinSchenkel commented 4 months ago

Beta 12 has also been released which should enhance your custom music a bit, your albums should now show up

chasut commented 4 months ago

Yep, got it and installed. Getting a weird error when attempting to play a playlist "Set of Tasks/Futures Empty". I am going to re-install everything from scratch to get a clean version. Will report back in a bit.

MarvinSchenkel commented 4 months ago

Yep, got it and installed. Getting a weird error when attempting to play a playlist "Set of Tasks/Futures Empty". I am going to re-install everything from scratch to get a clean version. Will report back in a bit.

Hm, this smells like a new bug introduced in beta 12 somewhere. I also see it in beta 12

MarvinSchenkel commented 4 months ago

Fixed it, beta 13 is building.

chasut commented 4 months ago

Ok, good to know. After the full re-install the Apple Music provider loaded artists and albums but no tracks or playlists. A refresh of the playlist and they loaded fine. No such luck with tracks. Thinking things stopped on loading tracks. Based on a quick review, I am thinking the issue is all of the garbage that my kids loaded on this back in the early iTunes days and is now causing issues due to the iTunes Match service. I will load the new version as soon as the build is available. But going to see if I can't confirm this hypothesis.

MarvinSchenkel commented 4 months ago

Ok, good to know. After the full re-install the Apple Music provider loaded artists and albums but no tracks or playlists. A refresh of the playlist and they loaded fine. No such luck with tracks. Thinking things stopped on loading tracks. Based on a quick review, I am thinking the issue is all of the garbage that my kids loaded on this back in the early iTunes days and is now causing issues due to the iTunes Match service. I will load the new version as soon as the build is available. But going to see if I can't confirm this hypothesis.

Can you provide a debug log when you are syncing your tracks? Might contain something interesting. Possibly the "garbage" contains some edge cases I need to take into account when syncing tracks.

chasut commented 4 months ago

Everything updated with the same results. There is nothing in "Tracks" and the MA media_player in HA fails to update. Logs attached. MA Log 4.txt

There is a timeout right after attempting to load a set of Beatles tracks. This is one of those garbage items that my daughter downloaded on the internet and onto our iTunes library back in the early 2000s.

I am going to load up my personal Apple Music account that does not have iTunes Match or any of that garbage in it and see what happens.

MarvinSchenkel commented 4 months ago

Everything updated with the same results. There is nothing in "Tracks" and the MA media_player in HA fails to update. Logs attached. MA Log 4.txt

There is a timeout right after attempting to load a set of Beatles tracks. This is one of those garbage items that my daughter downloaded on the internet and onto our iTunes library back in the early 2000s.

I am going to load up my personal Apple Music account that does not have iTunes Match or any of that garbage in it and see what happens.

You provide logs faster than I can ask them 😁. Beta 13 is out, so you can play items again. Can you also see if your HA Issue is fixed with the latest addon and hacs integration?

chasut commented 4 months ago

Saw your reply right as I hit the enter key. The logs are on Beta 13. I don't see any updates to the hacs integration and don't see a beta in the repository. I am on 2024.6.2. Let me know if I am missing something.

MarvinSchenkel commented 4 months ago

Saw your reply right as I hit the enter key. The logs are on Beta 13. I don't see any updates to the hacs integration and don't see a beta in the repository. I am on 2024.6.2. Let me know if I am missing something.

You should be good to go to test the HA side of things. Are you still seeing the error you posted before in the HA log? (About invalid value "encrypted_http" in enum)

chasut commented 4 months ago

Yes, was still getting that error in HA. But have some very interesting results from my latest set of tests.

I cleared the previous Apple Music account and loaded my personal account. It is pretty much the same base library but does not have the iTunes Match on it. It also has some unique items in the library. But, at least my understanding, is that this should just be what is on the Apple Music Service vs. a sync of my entire library. Anyway here is what I am observing:

  1. Artists, Albums, and even Tracks were loaded on first sync. Although the Tracks only contained 466 items (Artists/Albums are 1395/3128, respectively). But the Playlists were not loaded.
  2. Refreshed the Playlists (this is something I normally need to do in order to get them to show) but nothing changed; no playlists.
  3. Restarted the add-on and let the Apple Music Provider re-sync. Then refreshed Playlists. Nothing.

Log snippet from the Playlist refresh. MA Log 5.txt

chasut commented 4 months ago

Both of these accounts have cloud library sync turned on and chock full of garbage. The items that are in the library are not available in Apple Music. Some of these I see are ring tones from back in the day when we used to sync the iPhone with iTunes.

Are you able to confirm the MA media_player entity in HA works for you (or anybody really)? If so, then based on research so far I think that confirms these are edge-case library issues. I will go through the process of cleansing the offending stuff but that will take while. I will keep one plenty ugly if you are interested and I can be of help to chase down some of this nonsense.

Thank you for all our efforts... and patience with this

chasut commented 4 months ago

I just cleaned my library. There were several types of tracks "Apple Music", "Matched", "Uploaded", "No longer available", and unspecified (these turned out to be old music videos).

Removed them one at a time and slowly reduced the skipped tracks in the logs to nothing. So now the only thing remaining are "Apple Music" items.

Still getting stuck (timeout until failure) when attempting to load tracks. There is nothing in the log that looks particularly interesting. I did have to manually refresh the playlists, to get them to load. But no luck on the tracks. I am thinking that the lack of information in the tracks data table is why the HA entity is not updated.

MA Log 6.txt

I am going to continue to look through my playlists to see if they are causing issues, but running out of things to chase down. Any ideas?

chasut commented 4 months ago

Ok, solved most issues and can finally reliably get the tracks to load. It still almost always ends with a timeout so some digging still to do. The main problem was that it doesn't like playlists that I shared with another of my accounts. For some reason it does not actually add the songs to the library; has do be done manually.

Unfortunately I still have the issue with the MA media_player entity.

I will document everything I found that was problematic in the Apple Music Library when I get some time. But once again I am out of ideas about why this doesn't work for me.

MarvinSchenkel commented 4 months ago

Cool I figured out the HA error, we need to create a beta version of the HA integration that includes the new beta. We will probably combine this with the release of the release candidate 2.1, so let's check back on that issue once we get that out.

MarvinSchenkel commented 4 months ago

Update: I just release a new version of the HA integration (2024.7.1b0) that fixes all the weird HA issues. Make sure to enable 'beta release', install the integration and reboot HA.

chasut commented 4 months ago

Wonderful. Installed the beta integration and things are working.

The timeout is not the problem for sure. It does indicate that it is getting stuck loading a particular track for some reason and then is unable to continue. Occasionally there were clues in the log (found a wrong/bad version of a song just because alphabetically it would have been next to process). But the logs, even on debug, have not had much to assist in cleaning up the library. I am happy to send more when I get them, but there was nothing interesting above that snippet.

So far, these are what I found re: the library. These mostly affect the tracks, iirc you are already skipping these in artists, albums.

  1. Purchased Music. This has a lot of issues. It will not play from any device that is not authorized by apple. So I don't think they will work with MA. Good news is that there is (almost) always something in the Apple Music library that will replace it. I am fairly certain that these were causing unrecoverable timeouts.
  2. Matched Music. These are things in my personal collection that are matched in the cloud by apple. I am not certain how these are treated with regard to authorization. I am also not certain that they were causing timeouts. unfortunately I wiped them and didn't test in between them and uploaded.
  3. Uploaded Music. I was surprised apple does this, but these are tracks that cannot be matched in their library so apparently they are uploaded and made available to me from the cloud. This was a lot of my "garbage" tracks. They were definitely causing problems.
  4. Music Videos. I had two kinds, some were hard to find and imbedded within Purchased Music. There were three that were just sitting in a "waiting" state. I don't remember adding them to my library and certainly dont need them. They were causing a unrecoverable timeout problem.
  5. Tracks referenced in playlists that are Not added to the library. This was my biggest issue but didn't think it was even possible as normally tracks are just added to the library whenever something is added to a playlist. These were all from playlists that I shared with myself from another account. Really odd. You can manually click the add to library on every track or just "duplicate" the playlist and it will automatically add all the tracks to the library.

There is one or two more of these out there because I am still missing some tracks and I have not had a the timeout issue without it. Normally it recovers fine and carries on with its business.

Anyway, I am about 95% there, and everything that is there appears to be working. Thanks for the quick fix on the integration!

chasut commented 4 months ago

Couple of thoughts/suggestions.

  1. The revised HA integration code works great in the happy path (track is in the data table) but generates an error (it is a modal red popup block in the ui) if any track in the playlist is not in the table. This is both good and bad. Previously, the track would play, the meta data displayed correctly in the MA UI, but the HA entity would not get updated. I think that in this case the MA UI plays the track from Apple Music and then populates the meta-data from that information. If the integration could replicated this, I think it would be a smoother experience.
  2. At present, I am unable to see any pattern in when the track loading process stops with an unrecoverable timeout. I just completely reloaded my library and it is hanging at a place that it had no issues last time. This effect is repeatable but not definitive in my view. Perhaps tweaking the wait time might give Apple time to respond. I don't know if it is possible or even makes sense to skip a track on a slow/no response.

I am continuing to test to see if I can shed more light on the track loading and as such NOT forcing the load of playlists. Unfortunately I didn't save the error from the logs on the missing track in the playlist. But will send as soon as I get back there and recreate.

MarvinSchenkel commented 4 months ago

The next beta will contain a longer cool down period in case of a timeout. I feel somehow apple blocks extensive api requests. I don't think there's much I can do here besides increasing the cool down period and hoping that it'll start picking up after a while.

As for purchased music and all your other edge cases like playlists with songs that aren't in your library. I'm not sure how I can reproduce them and fix them. Do they cause problems for you whilst syncing? I am hoping MA just skips them and syncs the items that are actually playable / available.

chasut commented 4 months ago

Personally I don't think it is worth chasing down those edge cases. I think this provider is (and likely can only be) for the Apple Music service. Any owned (purchased or otherwise) are really best handled with a separate library management system/provider. That is what I intend to do. I will organize all those special high-res and unique items I own in a proper library and make it available in MA (haven't decided which way to go on that yet). It is the difference between Apple Music and what iTunes was.

So IMO the focus should be more on making that specific case as seamless as possible. e.g. my suggestion above about pulling the meta-data from Apple Music if a playlist item doesn't happen to be added to your library (This is a weird thing that apple does, not sure why they make a distinction between added or just available).

Anyway, let me know what I can do to help. Unfortunately I cannot make my library available to you to test directly as it relies on the appleid. But this is a great project, so anything I can do to help, just let me know.

chasut commented 4 months ago

Sorry, I got carried away with my thoughts and missed your direct questions.

You might be able to reproduce by removing a track that is on a playlist out of the MA tracks table. That is essentially what happens. It happens when a track is part of a playlist but does not have a corresponding entry in tracks (for me, due to the timeout while loading tracks).

Another random thought, but since the MA UI always correctly shows the playing track information, wouldn't it make more sense to just update the HA entities globally from MA proper whenever that changes vs. from the individual music providers?

MarvinSchenkel commented 4 months ago

Yeah I agree with you here. We're not gonna support all those edge cases, but they shouldn't block the syncing process. So I'm just curious if it successfully syncs all the items it should sync?

As for the HA entities. Those already get populated from the global MA info, so whatever you're seeing in MA in the Now Playing screen should be populated in your HA entity, regardless of the provider you are using.

chasut commented 4 months ago

I am still unable to complete a sync of the tracks. It is odd, but on initial load the sync stops at different places (based on alphabetic loading of tracks). But once there, any refresh seems to stop at or before the same place. Hopefully I can find some rationale for this at some point. and/or maybe the additional cool down will be enough to let apple catch its breath.

Interesting, because it was most definitely not. Through all my testing I have a high degree of confidence that the times the playlist was playing a song that was not in Tracks table, the MA UI was correct but the HA entity contained either no or wrong meta data. Of course now it is not possible to play a song from a playlist (or anything in that playlist) so that issue won't recur. Of course what this means for users is that their Apple Music library will need to be pristine, or at least with playlists only containing Apple Music songs, and also they will need to make sure that they check the box to have songs automatically added to their library when added to playlists. Though in my case that didn't always work!

chasut commented 4 months ago

I have a couple of anomalies (not an issue per se, but might point to some insight). Could you check the following albums and see if they are available on your Apple Music?

  1. apple_music://album/77821265 - I think this is The Best of Orleans, Dance with Me
  2. apple_music://album/270569185 - I think this is The Psychedelic Furs, Talk, Talk, Talk

They are consistently skipped as unavailable. But both are most definitely available on my account. I can play and download without issue. Not sure why they would be unavailable. Could it be the meta-data search failed?

Attached is the full log if you are interested in the detail. This is a first time load of the Apple Music provider. MA Log 7.txt

chasut commented 4 months ago

Nevermind. I went ahead and manually ran the playlist sync, went to eat dinner and ALL of the tracks were there. I can't explain what was different this time, but just very happy I am up and running.

Haven't been able to break it yet. So thanks for everything.