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

mass.play_media error #2034

Closed drjjr2 closed 5 months ago

drjjr2 commented 6 months ago

What version of Music Assistant has the issue?

2.0.0b116

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

2024.3.3

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

The problem

Occasionally when starting a Tidal playlist using the mass.play_media service call, the playlist does not start. The service call returns an error mentioning artist but I am playing a playlist. MA log seems to indicate a 404 error at the same time.

How to reproduce

Doesn't happen 100% of the time. The service call is:

service: mass.play_media
metadata: {}
data:
  media_type: playlist
  enqueue: replace
  media_id: "{{ playlist_name }}"
target:
  entity_id: "{{ media_player }}"

Music Providers

Tidal HiFi Plus

Player Providers

DLNA

Full log output

HA and MA logs are attached here. ma-log.txt ha-log.txt

Additional information

Have not tried other music providers. Player is DLNA: Denon AVR-X4400H Player is not grouped Playback is initiated with the service call mentioned. Shuffled Tidal playlist. Using HAOS Unclear why it works sometimes. As I mentioned there is an intermittent 404 error. I suspect that this is the root and it coincidentally is the first song it tries to play

What version of Home Assistant Core are your running

2024.3.1

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 6 months ago

Please REREAD the instructions. DOWNLOAD and ATTACH the logs. Please edit the report

OzGav commented 6 months ago

Furthermore, the troubleshooting instructions ask for much more info in ALL reports. Please provide that information.

drjjr2 commented 6 months ago

Furthermore, the troubleshooting instructions ask for much more info in ALL reports. Please provide that information.

Understood. I have reformatted the original report and added information. Unfortunately this doesn't happen 100% of the time which leads me to believe that it's a particular track or tracks within the Tidal playlist that Tidal is returning some error or response for when we try to play it. That's when we get the error.

drjjr2 commented 6 months ago

Also did not mention this is all wired ethernet connections. No wireless playback of HiRes files. I will see if I can get more meaningful logs.

drjjr2 commented 6 months ago

I did turn on debug logging for Tidal and caught this error today. For some reason Tidal is returning that it doesn't find the track but it's a playlist from Tidal. Hope you like Reggae :) The track in question is No Sympathy (Remastered 2001) Tidal web player has that as track 1212703. MA is thinking it's track 574886. Which apparently doesn't exist. Where would the disconnect be?


2024-03-21 06:57:21.308 WARNING (ThreadPoolExecutor-0_19) [tidalapi.request] HTTP error on 404
2024-03-21 06:57:21.308 DEBUG (ThreadPoolExecutor-0_19) [tidalapi.request] Response text
{"status":404,"subStatus":2001,"userMessage":"Track [574886] not found"}
2024-03-21 06:57:21.308 DEBUG (ThreadPoolExecutor-0_19) [tidalapi.request] request: https://api.tidal.com/v1/tracks/574886?sessionId=e42a8a82-9475-4f17-8a36-4167f133adbd&countryCode=US&limit=10000
2024-03-21 06:57:21.308 DEBUG (ThreadPoolExecutor-0_19) [tidalapi.request] response: {
    "status": 404,
    "subStatus": 2001,
    "userMessage": "Track [574886] not found"
}
2024-03-21 06:57:21.310 ERROR (MainThread) [music_assistant.webserver] Error handling message: players/queue/play_media: 'artists'
2024-03-21 06:58:06.948 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Request timeout set to 1
2024-03-21 06:58:06.949 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Sending GetVolume [('InstanceID', 0), ('Channel', 'Master')] to 192.168.0.188
2024-03-21 06:58:06.950 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Sending {'Content-Type': 'text/xml; charset="utf-8"', 'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetVolume'}, <?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:GetVolume xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetVolume>
  </s:Body>
</s:Envelope>

2024-03-21 06:58:06.972 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Received {'CONTENT-LENGTH': '287', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'EXT': '', 'Server': 'Linux UPnP/1.0 Sonos/78.1-51070 (ZPS39)', 'Connection': 'close'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetVolumeResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentVolume>6</CurrentVolume></u:GetVolumeResponse></s:Body></s:Envelope>
2024-03-21 06:58:06.972 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Received status 200 from 192.168.0.188
OzGav commented 6 months ago

Please DOWNLOAD and ATTACH the full logs

drjjr2 commented 6 months ago

I got ya. Just trying to save you the trouble of poring through this massive file. ma-log-03.21.2024.txt

The bigger question is why does MA think it's track 574886 and Tidal has it as track 1212703? That's the root of the problem.

drjjr2 commented 6 months ago

I see that there is another version listed under "Other Versions" for the same Album that has this track in MA but I can't click on it or get more info. Or delete it. Now that I'm looking several albums have "Other Versions" listed that I can't click on. They are all listed as being from Tidal (which is the only music provider I have enabled)

OzGav commented 6 months ago

The UI isn't great with this. You can click on it but if all the details are the same then you won't see any change in the page or it might be very subtle. If you want to see that it does do something then go to the global search and search for Taylor Swift's 1989 album. It has significantly different versions so you will be able to see the change

edit: Look closely at the provider details at the bottom as that changes

drjjr2 commented 6 months ago

The UI isn't great with this. You can click on it but if all the details are the same then you won't see any change in the page or it might be very subtle. If you want to see that it does do something then go to the global search and search for Taylor Swift's 1989 album. It has significantly different versions so you will be able to see the change

edit: Look closely at the provider details at the bottom as that changes

In my instance when I click "Show Info" it does nothing and the provider details don't change when I click on the "Other Version". The other version also doesn't have any album art.

Should I nuke the Tidal provider completely and clear out old info and re-install it? Seems like there is something fishy going on.

Edit: I did see the behavior you're describing with a different album. Just doesn't seem to be that way with all of them.

OzGav commented 6 months ago

There is an outstanding item to improve the cleanup when providers are removed. You can remove it but you have to wait for quite a while without restarting MA to be confident that the cleanup has completed. If it is interrupted it wont start again. If you haven't done that much setup then removing and reinstalling MA guarantees a clean DB but don't do that if it is going to be a major inconvenience and just wait until this can get looked at

drjjr2 commented 6 months ago

Understood. I'll keep you posted. It's not like my music is mission critical so I'm willing to help out any way I can to get this figured out.

drjjr2 commented 6 months ago

I uninstalled and re-installed MA. Relinked Tidal. The sync process starts and then the following logfile (attached this time) is the result. Looks like it gets part way into it and then hits a 404 error. I will check this evening and see how much progress it makes. Thanks for your help on all of this.

MA-03.21.2024-2.txt

OzGav commented 6 months ago

Just letting @jozefKruszynski know about this issue

jozefKruszynski commented 6 months ago

This is annoying, I had all these errors covered previously and have no idea why they have resurfaced. I need to do a larger refactoring for the new tidal api version anyway which also revolves around errors so I guess I better get a move on

drjjr2 commented 6 months ago

This is annoying, I had all these errors covered previously and have no idea why they have resurfaced. I need to do a larger refactoring for the new tidal api version anyway which also revolves around errors so I guess I better get a move on

Is it possible that this has to do with HiRes? Does Tidal sometimes serve different files for HiRes? Or does it throttle bitrate for lower res subscribers. Which won't matter on April 10th but until then maybe?

drjjr2 commented 6 months ago

This is annoying, I had all these errors covered previously and have no idea why they have resurfaced. I need to do a larger refactoring for the new tidal api version anyway which also revolves around errors so I guess I better get a move on

On a different note I notice that the links in Provider details in the UI are broken. http://www.tidal.com/tracks/{track number} returns an error. When copying the link to a track in the Tidal Web Player it returns: https://tidal.com/browse/track/{track number} So maybe something needs to change there as well?

jozefKruszynski commented 6 months ago

Strange. This also worked perfectly previously.

Having tested the provider preview links, I have no issues playing those in the UI.

I'll take a look at the http errors though as this was reported elsewhere too

drjjr2 commented 6 months ago

Under Provider details, previewing using the play button next to the link works. Clicking on the link does not. Or at least not for me on two different computers. image

jozefKruszynski commented 6 months ago

Gotcha, I'll test that out too

drjjr2 commented 6 months ago

Gotcha, I'll test that out too

Let me know if you need any logs or anything else that I can do to help test.

MdeBoer3 commented 6 months ago

Have you tried adjusting the quality setting of the Tidal provider to ‘HI_RES’ ? Had a similar issue myself and found this setting solved it. Probably because Tidal changed it subscriptions not so long ago. Hope it helps

jozefKruszynski commented 6 months ago

I did turn on debug logging for Tidal and caught this error today. For some reason Tidal is returning that it doesn't find the track but it's a playlist from Tidal. Hope you like Reggae :) The track in question is No Sympathy (Remastered 2001) Tidal web player has that as track 1212703. MA is thinking it's track 574886. Which apparently doesn't exist. Where would the disconnect be?


2024-03-21 06:57:21.308 WARNING (ThreadPoolExecutor-0_19) [tidalapi.request] HTTP error on 404
2024-03-21 06:57:21.308 DEBUG (ThreadPoolExecutor-0_19) [tidalapi.request] Response text
{"status":404,"subStatus":2001,"userMessage":"Track [574886] not found"}
2024-03-21 06:57:21.308 DEBUG (ThreadPoolExecutor-0_19) [tidalapi.request] request: https://api.tidal.com/v1/tracks/574886?sessionId=e42a8a82-9475-4f17-8a36-4167f133adbd&countryCode=US&limit=10000
2024-03-21 06:57:21.308 DEBUG (ThreadPoolExecutor-0_19) [tidalapi.request] response: {
    "status": 404,
    "subStatus": 2001,
    "userMessage": "Track [574886] not found"
}
2024-03-21 06:57:21.310 ERROR (MainThread) [music_assistant.webserver] Error handling message: players/queue/play_media: 'artists'
2024-03-21 06:58:06.948 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Request timeout set to 1
2024-03-21 06:58:06.949 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Sending GetVolume [('InstanceID', 0), ('Channel', 'Master')] to 192.168.0.188
2024-03-21 06:58:06.950 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Sending {'Content-Type': 'text/xml; charset="utf-8"', 'SOAPACTION': 'urn:schemas-upnp-org:service:RenderingControl:1#GetVolume'}, <?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
  <s:Body>
    <u:GetVolume xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1">
      <InstanceID>0</InstanceID>
      <Channel>Master</Channel>
    </u:GetVolume>
  </s:Body>
</s:Envelope>

2024-03-21 06:58:06.972 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Received {'CONTENT-LENGTH': '287', 'CONTENT-TYPE': 'text/xml; charset="utf-8"', 'EXT': '', 'Server': 'Linux UPnP/1.0 Sonos/78.1-51070 (ZPS39)', 'Connection': 'close'}, <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:GetVolumeResponse xmlns:u="urn:schemas-upnp-org:service:RenderingControl:1"><CurrentVolume>6</CurrentVolume></u:GetVolumeResponse></s:Body></s:Envelope>
2024-03-21 06:58:06.972 DEBUG (ThreadPoolExecutor-0_23) [soco.services] Received status 200 from 192.168.0.188

So, very often Tidal completely change the ID of tracks, albums etc. My only assumption for why this happens is that when licensing changes occur, the publishers simply upload new versions that deprecate the old ones and the IDs change. The exact same thing happens onSpotify, however, Spotify themselves have some kind of matching system that makes these changes mostly transparent to the end user, at least as far as I understand it.

This will always happen with Tidal, and there is nothing that can be done about this.

jozefKruszynski commented 6 months ago

Under Provider details, previewing using the play button next to the link works. Clicking on the link does not. Or at least not for me on two different computers. image

This was fixed in 2.0.0 beta 124. Please confirm. You might need to do a full clean. i.e. provider removal and re-add

OzGav commented 5 months ago

Is this issue resolved?

drjjr2 commented 5 months ago

Yes, this issue is resolved.