Errors during NAS sleeptime on Network Mount

Mariusthvdb commented 2 years ago

What version of Music Assistant has the issue?

2022.6.4

The problem

running the shell_command to mount my Nas drive (testing that functionality) works just fine. But.... my Nas is turned down to sleepmode each night for power savings.

I didnt realize that could inhibit the Music Assistant install using that Mount until now.

this morning I see below errors in the logs, which of course relate to that. To my surprise the actual files in the mount are still visible, via the Media/Local files browser, and, more surprisingly after reading that error in the log, to Music Assistant!

I would have expected Music Assistant, sensing the drive had disappeared, to update the DB and delete those files in a whim. It didnt.

Only posting it here as a FYI, and maybe for others to test this functionality.

There's no use in automating some kind of re-mount in the morning, because this is a) a temporary configuration, and b) it wont prevent MA from wiping during the Sleep time.

Yet is is something to consider going forward, in designing the MA's core support for NAS drives, and not delete the DB during sleep time

How to reproduce

mount a nas drive with the known shell command

auto sleep the Nas

Relevant log output

Logger: music_assistant
Source: /usr/local/lib/python3.9/site-packages/music_assistant/mass.py:244 
First occurred: 02:22:24 (2 occurrences) 
Last logged: 05:22:25

Job [Library sync for provider Filesystem] failed with error [Errno 112] Host is down: '/media/music/nas/mp3/Wagner'.
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/music_assistant/music_providers/filesystem.py", line 155, in sync_library
    async for entry in scantree(self.config.path):
  File "/usr/local/lib/python3.9/site-packages/music_assistant/music_providers/filesystem.py", line 67, in scantree
    async for subitem in scantree(entry.path):
  File "/usr/local/lib/python3.9/site-packages/music_assistant/music_providers/filesystem.py", line 67, in scantree
    async for subitem in scantree(entry.path):
  File "/usr/local/lib/python3.9/site-packages/music_assistant/music_providers/filesystem.py", line 67, in scantree
    async for subitem in scantree(entry.path):
  File "/usr/local/lib/python3.9/site-packages/music_assistant/music_providers/filesystem.py", line 65, in scantree
    for entry in await loop.run_in_executor(None, os.scandir, path):
OSError: [Errno 112] Host is down: '/media/music/nas/mp3/Wagner'

Additional information

No response

What version of Home Assistant Core are your running

2022.7.0.dev20220621

What type of installation are you running?

Home Assistant OS

erkr commented 2 years ago

Thank you Marius for sharing these observations. I also feel some tension between the wish to remove files that where delete versus a net share being not available.

marcelveldt commented 2 years ago

MA will only delete entries from the db if the file is actually deleted from disk. The whole disk (or streaming provider) not available will just error the sync but not trigger any deletions.

So in fact this is all good behavior. Good thing it errors the sync when the NAS is sleeping and good thing that it cancels the sync and not trigger any deletes.

I'd classify this as "by design"

Mariusthvdb commented 2 years ago

Add it to the docs, as being smart about it ;-)

erkr commented 2 years ago

And close this issue for now 😎

Mariusthvdb commented 2 years ago

so this is still happening after all:

restart Home Assistant (Including Music Assistant) before power NAS, fails the mount shell_command.

After some time (7:15 ;-) ) my NAS awakes and restarts once again, seeing:

2022-06-28 07:26:48 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/Walkure - Stein, Bayreuth 1970, 11597-3/Walkuere - Disc 2/02. Was verlangst du.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:26:48 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/Walkure - Stein, Bayreuth 1970, 11597-3/Walkuere - Disc 2/05. Ein andres ist's.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:26:48 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/Walkure - Stein, Bayreuth 1970, 11597-3/Walkuere - Disc 2/10. So grüße mir Walhall, grüße mir Wotan.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:26:48 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/Walkure - Stein, Bayreuth 1970, 11597-3/Walkuere - Disc 2/09. Siegmund! Sieh auf mich!.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:26:49 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/Walkure - Stein, Bayreuth 1970, 11597-3/Walkuere - Disc 2/07. So sah ich Siegvater nie.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback

etc etc.

Appears not to be as obvious as we thought it was. Apparently all tracks are re-indexed/added to the DB. So they must have been deleted too? Dont think that deletion is logged, so I cant tell.

Since I dont have a large Mount yet (only testing for now), this doesnt take too long, 7 minutes for 3400 tracks, but it still is something to think about going forward

DB size seems to be growing also, though no new files have been added. currently 44.1 MB. Will keep an eye on that.

Mariusthvdb commented 2 years ago

what's more, when I click the Various Artists tab on Albums:

note the swirling icons, keep swirling forever...

and then an Album in that:

there are no Tracks.

errors in the log:

This error originated from a custom integration.

Logger: aiohttp.server
Source: custom_components/mass/panel.py:91 
Integration: Music Assistant (documentation, issues) 
First occurred: 07:36:28 (40 occurrences) 
Last logged: 07:39:45

Error handling request
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/aiohttp/web_protocol.py", line 435, in _handle_request
    resp = await request_handler(request)
  File "/usr/local/lib/python3.10/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
  File "/usr/local/lib/python3.10/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 236, in auth_middleware
    return await handler(request)
  File "/usr/src/homeassistant/homeassistant/components/http/view.py", line 136, in handle
    result = await result
  File "/config/custom_components/mass/panel.py", line 91, in get
    data = await mass.metadata.get_thumbnail(url, size=size)
  File "/usr/local/lib/python3.10/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.10/site-packages/music_assistant/helpers/images.py", line 47, in create_thumbnail
    return await mass.loop.run_in_executor(None, _create_image)
  File "/usr/local/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/images.py", line 43, in _create_image
    img.thumbnail((size, size), Image.ANTIALIAS)
  File "/usr/local/lib/python3.10/site-packages/PIL/Image.py", line 2475, in thumbnail
    im = self.resize(size, resample, box=box, reducing_gap=reducing_gap)
  File "/usr/local/lib/python3.10/site-packages/PIL/Image.py", line 2043, in resize
    self.load()
  File "/usr/local/lib/python3.10/site-packages/PIL/ImageFile.py", line 251, in load
    raise OSError(
OSError: image file is truncated (59 bytes not processed)

and maybe even more important:

Logger: music_assistant.music
Source: /usr/local/lib/python3.10/site-packages/music_assistant/controllers/music/__init__.py:121 
First occurred: 07:39:00 (4 occurrences) 
Last logged: 07:40:51

Provider ProviderType.DATABASE is not available

while that keeps growing and growing. currently at 156 MB!

Maybe the size explodes because of things like:

2022-06-28 07:39:22 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:22 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:24 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:24 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:24 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:34 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:34 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:44 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:44 WARNING (MainThread) [music_assistant.music.file] /media/music/nas/mp3/Wagner/FGC572~D/Flagstad Sings Wagner - Disc 2/01.  Die Zeit ist da.mp3 is missing ID3 tag [albumartist], using Various Artists as fallback
2022-06-28 07:39:45 ERROR (MainThread) [aiohttp.server] Error handling request

Mariusthvdb commented 2 years ago

@erkr Eric, please re-open this is not resolved

marcelveldt commented 2 years ago

I think the only proper way to solve this is when MA directly talks to the samba share and "knows" when its not available. Current approach with mounting is just too risky. BTW: a small tip could be to have the files in a subfolder on the NAS.

So e.g. mount //nas/data to /media/data but have the music files in //nas/data/music. If you add /media/data/music to MA it will error on the directory not existing (/media/data/music) and skip the sync

vk2him commented 2 years ago

I'm wondering if sending a Wake on Lan command will wake up the NAS as I'm sure my NAS responds to that if asleep - FYI my NAS is on 24/7 as it hosting a security camera NVR system.

Perhaps @Mariusthvdb could test this theory by sending a WOL command (there's a number of free utilities that will do this). If it wakes, could the WOL command be sent preceding all MA commands?

Mariusthvdb commented 2 years ago

Well not sure I like that approach . Sure I have the Wol service, but I don’t want to wake the Nas during those off hours.

I agee with Marcel this should be a integration feature and not rely on external mount commands.

if the source is offline, just wait until it’s back online again and continue. Don’t manipulate the Db if source is offline

marcelveldt commented 2 years ago

I'm going to close this issue report as it's a non-issue:

If you want to guard against the NAS in standby, make sure to add a subfolder to MA config so that folder itself will become unavailable. That will skip the scan.
Mounting the NAS in a folder is a workaround for the missing direct smb support in MA

music-assistant / hass-music-assistant