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

V1.1.7: exception looking up a local album #191

Closed erkr closed 2 years ago

erkr commented 2 years ago

I noticed this exception. Think it is due the 'Various Artists' preceded by a related warning?

Logger: homeassistant.components.websocket_api.http.connection
Source: custom_components/mass/websockets.py:292 
Integration: Home Assistant WebSocket API (documentation, issues) 
First occurred: 10:10:02 (4 occurrences) 
Last logged: 10:10:17

[547674686896] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/config/custom_components/mass/websockets.py", line 96, in async_get_mass_func
    await orig_func(hass, connection, msg, mass)
  File "/config/custom_components/mass/websockets.py", line 292, in websocket_album_tracks
    for item in await mass.music.albums.tracks(msg[ITEM_ID], msg[PROVIDER])
  File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/albums.py", line 54, in tracks
    tracks = itertools.chain.from_iterable(await asyncio.gather(*coros))
  File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/albums.py", line 111, in get_provider_album_tracks
    return await prov.get_album_tracks(item_id)
  File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/providers/filesystem.py", line 266, in get_album_tracks
    raise MediaNotFoundError(f"Album not found: {prov_album_id}")
music_assistant.models.errors.MediaNotFoundError: Album not found: variousartists10080shits

The warning:

Logger: music_assistant.mass.metadata
Source: /usr/local/lib/python3.9/site-packages/music_assistant/controllers/metadata/__init__.py:161 
First occurred: 10:10:01 (1 occurrences) 
Last logged: 10:10:01

Unable to get musicbrainz ID for artist Various Artists !
marcelveldt commented 2 years ago

The musicbrainz ID warnings are thrown a bit fanatic but it helps me during this phase to determine how good the auto lookup functions. In this case I think I need to hardcode the musicbrainz ID for various artists.

That error above should not be thrown unless the album could not be found. I think it's trying to lookup the album on disk while it shouldn't. I doubt there will be a separate album folder for such a collection album.

I will investigate

erkr commented 2 years ago

Correct, there is no such folder variousartists10080shits. It looks like a concatenation of folder names. I have various artists and there is a folder80's hits . The local media didn't change since the import.

The musicbrainz ID warnings are thrown a bit fanatic

These don't bother me, only added this one, as it can be related Best Eric

AvdWerfhorst commented 2 years ago

I think I have the same issue. btw, this is an album for which I added isrc codes to all tracks yesterday. Hoping that the different versions do not get mixed up somewhere. I believe the version in this error is the version as originally released.

Logger: homeassistant.components.websocket_api.http.connection Source: custom_components/mass/websockets.py:292 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 9:32:20 AM (2 occurrences) Last logged: 1:50:24 PM

[547815475424] Error handling message: Unknown error (unknown_error)
[547300519504] Error handling message: Unknown error (unknown_error)

Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response await func(hass, connection, msg) File "/config/custom_components/mass/websockets.py", line 96, in async_get_mass_func await orig_func(hass, connection, msg, mass) File "/config/custom_components/mass/websockets.py", line 292, in websocket_album_tracks for item in await mass.music.albums.tracks(msg[ITEM_ID], msg[PROVIDER]) File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/albums.py", line 54, in tracks tracks = itertools.chain.from_iterable(await asyncio.gather(*coros)) File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/albums.py", line 111, in get_provider_album_tracks return await prov.get_album_tracks(item_id) File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/providers/filesystem.py", line 266, in get_album_tracks raise MediaNotFoundError(f"Album not found: {prov_album_id}") music_assistant.models.errors.MediaNotFoundError: Album not found: freddiemercurymontserratcaballebarcelona

erkr commented 2 years ago

Looks identical indeed.

marcelveldt commented 2 years ago

I will publish a new version so we can test if my fixes of this morning fixes this issue.

marcelveldt commented 2 years ago

1.1.8 released. Can you check if the issue is resolved ?

erkr commented 2 years ago

Will install 1.1.8 now and keep an eye in exceptions like these

erkr commented 2 years ago

No I can still reproduce, or it's a similar issue. For example adding this track gives the same exception:

http://192.168.178.47:8123/media/MP3_normalized/Various/Typisch%20-%20Tachtig!%20CD4/Mp3/Typisch%20-%2017%20-%20Adam%20&%20The%20Ants.mp3

Think it is the name with the '&' in it: Typisch - 17 - Adam & The Ants.mp3.

Logging:

This error originated from a custom integration.

Logger: aiohttp.server
Source: custom_components/mass/panel.py:89 
Integration: Music Assistant (documentation, issues) 
First occurred: 18:31:31 (5 occurrences) 
Last logged: 18:33:40

Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 435, in _handle_request
    resp = await request_handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.9/site-packages/aiohttp/web_middlewares.py", line 117, in impl
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/security_filter.py", line 60, in security_filter_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/forwarded.py", line 100, in forwarded_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/request_context.py", line 28, in request_context_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/ban.py", line 79, in ban_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/auth.py", line 219, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 137, in handle
    result = await result
  File "/config/custom_components/mass/panel.py", line 89, in get
    data = await mass.metadata.get_thumbnail(url, size=size)
  File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/metadata/__init__.py", line 235, in get_thumbnail
    thumbnail = await create_thumbnail(self.mass, path, size)
  File "/usr/local/lib/python3.9/site-packages/music_assistant/helpers/images.py", line 37, in create_thumbnail
    raise FileNotFoundError(f"Image not found: {path}")
FileNotFoundError: Image not found: /media/MP3_normalized/Various/Typisch - Tachtig! CD4/Mp3/Typisch - 17 - Adam 
erkr commented 2 years ago

This one as well:

[547801654560] Error handling message: Unknown error (unknown_error)
18:45:11 – (ERROR) Home Assistant WebSocket API (custom integration)
Unable to get musicbrainz ID for artist Aphrodite’s Child !
18:45:06 – (WARNING) /usr/local/lib/python3.9/site-packages/music_assistant/controllers/metadata/__init__.py
Provider ProviderType.DATABASE is not available
18:45:06 – (WARNING) /usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py - message first occurred at 18:45:06 and shows up 2 times

Here something strange happened. When I opened the artist, there was just one track. Adding it to the queue failed. When I went back, there was suddenly a whole list of tracks, provided via Spotify. So This one can be slightly different (a race condition)

marcelveldt commented 2 years ago

I think you're right with the & character. Looks like the image proxy (for the embedded image) is choking on that, making the whole thing crash. I'm going to adjust that and make sure that image extraction can not crash the entire track fetching

marcelveldt commented 2 years ago

Yes, I was able to reproduce it finally

AvdWerfhorst commented 2 years ago

I expect something alike goes wrong with the "+" sign. I do not get thumbnails for names like "Queen + Paul Rodgers", "Florence + the Machine"

marcelveldt commented 2 years ago

Yes, I just created a fix for all those special cases.

marcelveldt commented 2 years ago
Schermafbeelding 2022-05-19 om 21 29 17

used this as test case and it works :-)

marcelveldt commented 2 years ago

@erkr and @AvdWerfhorst Just released small patch release v1.1.9 which contains the fix (no rescan needed). Please let me know if that fixes the issue

erkr commented 2 years ago

I will test that version tomorrow. Thanks for all your efforts 😎

erkr commented 2 years ago

It definitely works better. What I don't understand is that my first attempt te test failed with a slightly other error. Second time it worked??:

Logger: homeassistant.components.websocket_api.http.connection
Source: custom_components/mass/websockets.py:976 
Integration: Home Assistant WebSocket API (documentation, issues) 
First occurred: 12:31:13 (1 occurrences) 
Last logged: 12:31:13

[546819153248] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/config/custom_components/mass/websockets.py", line 96, in async_get_mass_func
    await orig_func(hass, connection, msg, mass)
  File "/config/custom_components/mass/websockets.py", line 976, in websocket_play_media
    await player_queue.play_media(msg[URI], msg[COMMAND])
  File "/usr/local/lib/python3.9/site-packages/music_assistant/models/player_queue.py", line 434, in play_media
    await self.mass.music.tracks.get(
  File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/tracks.py", line 30, in get
    track.album = await self.mass.music.albums.get(
  File "/usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/albums.py", line 35, in get
    album = await super().get(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 76, in get
    details = await self.get_provider_item(provider_item_id, provider_id)
  File "/usr/local/lib/python3.9/site-packages/music_assistant/models/media_controller.py", line 255, in get_provider_item
    raise MediaNotFoundError(
music_assistant.models.errors.MediaNotFoundError: album adamantadamantremastered not found on provider Filesystem

The test also triggered two other known issues:


[547090325568] Client unable to keep up with pending messages. Stayed over 512 for 5 seconds
12:38:41 – (ERROR) Home Assistant WebSocket API - message first occurred at 12:28:41 and shows up 118 times
Provider ProviderType.DATABASE is not available
12:32:59 – (WARNING) /usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py - message first occurred at 12:21:21 and shows up 3 times
marcelveldt commented 2 years ago

When did this happen ? When you tried to play the item ?

Maybe this happens when you click an album or track info from the very first time (or try to play it). At initial sync, all actual music files are discovered on disk, their ID3 tags read and any metadata within the files or folders. That is just stored in the DB, no additional metadata is acquired at this point from any online source.

As soon as you try to open the details page for a MediaItem (artist, album, track etc) and the metadata has never been requested before it will be at that point (lazy loaded). So maybe something is wrong at this point. The error however suggests that the entire album folder wasn't there strange enough or we have a race condition going on due to the async nature of this all (you're served the existing metadata while other info is requested in a separate task)

erkr commented 2 years ago

It was basically directly after the rescan of v1.1.11 was completed, so if additional meta data is retrieved, it was the case indeed.

The error however suggests that the entire album folder wasn't there strange enough

The album was just scanned and therefore it exists. The query of the second scan for some reason didn't match

marcelveldt commented 2 years ago

OK, in that case it's a race condition indeed. The second time you tried to open that album/artist/track did work without issues, right ?

erkr commented 2 years ago

OK, in that case it's a race condition indeed. The second time you tried to open that album/artist/track did work without issues, right ?

Yep, Second time it worked

erkr commented 2 years ago

Just tested the same scenario against v1.1.13. The exceptions/errors are fixed and the tracks are added to the queue 👍 Although it works, I still observed this strange warning:

Logger: music_assistant.mass.music
Source: /usr/local/lib/python3.9/site-packages/music_assistant/controllers/music/__init__.py:100 
First occurred: 12:57:29 (3 occurrences) 
Last logged: 13:07:20

Provider ProviderType.DATABASE is not available

It's for each play next action one warning is added, independent if it's a local track or Spotify

erkr commented 2 years ago

I don't see exceptions anymore when adding items to the queue 👍👍👍