search

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.24k stars 45 forks source link

Timeouts when syncing Apple Music tracks #2604

Closed faelenor closed 1 week ago

faelenor commented 2 weeks ago

What version of Music Assistant has the issue?

2.1.0b14

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

2024.6.2

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

The problem

Apple Music track sync always fails with timeouts (the 5 retries are failing). There is a lot of "Skipping track. No catalog version found for ..." warnings in the logs before it happens. Most of these warnings (possibly all?) are from CDs that were imported a long time ago, so maybe the timeouts are related.

Artists and albums are correctly synced, but tracks and playlists are empty. BTW, shouldn't you do the playlist sync even if the tracks sync failed?

How to reproduce

Sync Apple Music provider.

Music Providers

Apple Music RadioBrowser Music Assistant

Player Providers

AirPlay

Full log output

music-assistant.log

Additional information

No response

What version of Home Assistant Core are your running

2024.6.4

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)

MarvinSchenkel commented 2 weeks ago

Thanks a lot for this extensive log. I will try and see if I can figure out why some of your requests are timing out. The timeouts are probably not related to missing catalog items, since all those numbers you are seeing are catalog id's. Do you have any other type of music in your library, e.g. purchased music?

The reason you do not have playlists is because the sync stops because of an error in the tracks (playlist sync happens after tracks). I see your point about just continuing the sync, but we'd rather just fix the errors and make sure we can sync everything, or at least gracefully log what cannot be synced.

faelenor commented 2 weeks ago

Afaik, we don't have any purchased music.

faelenor commented 2 weeks ago

It seems that it partially worked during last night, but I had another crash:

2024-07-10 07:35:36.951 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-74' coro=<MusicController._start_provider_sync.<locals>.run_sync() running at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:694> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:449> cb=[MusicAssistant.create_task.<locals>.task_done_callback() at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:349, MusicController._start_provider_sync.<locals>.on_sync_task_done() at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:708] created at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:340> took 0.123 seconds
2024-07-10 07:35:42.626 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-74' coro=<MusicController._start_provider_sync.<locals>.run_sync() running at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:694> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:449> cb=[MusicAssistant.create_task.<locals>.task_done_callback() at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:349, MusicController._start_provider_sync.<locals>.on_sync_task_done() at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:708] created at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:340> took 0.129 seconds
2024-07-10 07:35:42.723 WARNING (MainThread) [music_assistant] Exception in task Task-74 - target: <coroutine object MusicController._start_provider_sync.<locals>.run_sync at 0x7fa0547f6d40>: 'NoneType' object has no attribute 'lower'
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py", line 694, in run_sync
    await provider.sync_library(media_types)
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/models/music_provider.py", line 402, in sync_library
    async for prov_item in self._get_library_gen(media_type):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 221, in get_library_tracks
    yield self._parse_track(item)
          ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 534, in _parse_track
    track.artists = [self._parse_artist(artist) for artist in artists["data"]]
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 388, in _parse_artist
    artist = Artist(
             ^^^^^^^
  File "<string>", line 15, in __init__
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/models/media_items.py", line 288, in __post_init__
    self.sort_name = create_sort_name(self.name)
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/helpers/util.py", line 74, in create_sort_name
    input_str = input_str.lower().strip()
                ^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'lower'
2024-07-10 07:35:42.725 WARNING (MainThread) [music_assistant.music] Sync task for Apple Music completed with errors
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py", line 694, in run_sync
    await provider.sync_library(media_types)
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/models/music_provider.py", line 402, in sync_library
    async for prov_item in self._get_library_gen(media_type):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 221, in get_library_tracks
    yield self._parse_track(item)
          ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 534, in _parse_track
    track.artists = [self._parse_artist(artist) for artist in artists["data"]]
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 388, in _parse_artist
    artist = Artist(
             ^^^^^^^
  File "<string>", line 15, in __init__
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/models/media_items.py", line 288, in __post_init__
    self.sort_name = create_sort_name(self.name)
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/helpers/util.py", line 74, in create_sort_name
    input_str = input_str.lower().strip()
                ^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'lower'

Is there a way to debug this on my side? I added a couple of logs in the files in the docker container, but my changes are reverted when the addon is restarted.

MarvinSchenkel commented 2 weeks ago

It seems that it partially worked during last night, but I had another crash:

2024-07-10 07:35:36.951 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-74' coro=<MusicController._start_provider_sync.<locals>.run_sync() running at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:694> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:449> cb=[MusicAssistant.create_task.<locals>.task_done_callback() at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:349, MusicController._start_provider_sync.<locals>.on_sync_task_done() at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:708] created at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:340> took 0.123 seconds
2024-07-10 07:35:42.626 WARNING (MainThread) [asyncio] Executing <Task pending name='Task-74' coro=<MusicController._start_provider_sync.<locals>.run_sync() running at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:694> wait_for=<Future pending cb=[Task.task_wakeup()] created at /usr/local/lib/python3.12/asyncio/base_events.py:449> cb=[MusicAssistant.create_task.<locals>.task_done_callback() at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:349, MusicController._start_provider_sync.<locals>.on_sync_task_done() at /usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py:708] created at /usr/local/lib/python3.12/site-packages/music_assistant/server/server.py:340> took 0.129 seconds
2024-07-10 07:35:42.723 WARNING (MainThread) [music_assistant] Exception in task Task-74 - target: <coroutine object MusicController._start_provider_sync.<locals>.run_sync at 0x7fa0547f6d40>: 'NoneType' object has no attribute 'lower'
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py", line 694, in run_sync
    await provider.sync_library(media_types)
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/models/music_provider.py", line 402, in sync_library
    async for prov_item in self._get_library_gen(media_type):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 221, in get_library_tracks
    yield self._parse_track(item)
          ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 534, in _parse_track
    track.artists = [self._parse_artist(artist) for artist in artists["data"]]
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 388, in _parse_artist
    artist = Artist(
             ^^^^^^^
  File "<string>", line 15, in __init__
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/models/media_items.py", line 288, in __post_init__
    self.sort_name = create_sort_name(self.name)
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/helpers/util.py", line 74, in create_sort_name
    input_str = input_str.lower().strip()
                ^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'lower'
2024-07-10 07:35:42.725 WARNING (MainThread) [music_assistant.music] Sync task for Apple Music completed with errors
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/music.py", line 694, in run_sync
    await provider.sync_library(media_types)
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/models/music_provider.py", line 402, in sync_library
    async for prov_item in self._get_library_gen(media_type):
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 221, in get_library_tracks
    yield self._parse_track(item)
          ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 534, in _parse_track
    track.artists = [self._parse_artist(artist) for artist in artists["data"]]
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/apple_music/__init__.py", line 388, in _parse_artist
    artist = Artist(
             ^^^^^^^
  File "<string>", line 15, in __init__
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/models/media_items.py", line 288, in __post_init__
    self.sort_name = create_sort_name(self.name)
                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/music_assistant/common/helpers/util.py", line 74, in create_sort_name
    input_str = input_str.lower().strip()
                ^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'lower'

Is there a way to debug this on my side? I added a couple of logs in the files in the docker container, but my changes are reverted when the addon is restarted.

This seems to be due to a track with an artist that does not have a valid name. Will fix this!

OzGav commented 2 weeks ago

@faelenor please check with 2.1.0rc1

faelenor commented 2 weeks ago

It still fails, but the error is different this time. I forgot to set the log level to debug, tell me if you need another log file.

logs.txt

OzGav commented 1 week ago

@MarvinSchenkel

MarvinSchenkel commented 1 week ago

This is a different error totally unrelated to Apple Music, will be solved anyway. Good news if you're not seeing any timeouts though!

xmirakulix commented 1 week ago

Found it in my installation as well, see PR https://github.com/music-assistant/server/pull/1499

faelenor commented 1 week ago

It works now, thank you!