Jump to content

"Refresh metadata" crashing


grl

Recommended Posts

The functions to refresh metadata are crashing when there is a directory that can not be accessed and parts of the directory tree will not be scanned for files.

In a networked environment that might happen frequently - so I think it would be better if emby would ignore such directories - e.g. catching that exception and going on with the next directory or file.

 

 

Error message is:

2021-01-15 18:45:17.914 Error LibraryMonitor: Error watching path: /media/INET
        *** Error Report ***
        Version: 4.5.4.0
        Command line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby-server -ffdetect /opt/emby-server/bin/ffdetect -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -r
estartexitcode 3 -updatepackage emby-server-deb_{version}_amd64.deb
        Operating system: Linux version 4.19.0-12-amd64 (debian-kernel@lists.debian.org) (gcc version 8.3.0 (Debian 8.3.0-6)) #1 SMP Debian 4.19.152-1 (2020-10-18)
        Framework: .NET Core 3.1.8
        OS/Process: x64/x64
        Runtime: opt/emby-server/system/System.Private.CoreLib.dll
        Processor count: 1
        Data path: /var/lib/emby-server
        Application path: /opt/emby-server/system
        System.UnauthorizedAccessException: System.UnauthorizedAccessException: Access to the path '/media/01/speech/2019/01' is denied.
         ---> System.IO.IOException: Permission denied
           --- End of inner exception stack trace ---
           at System.IO.Enumeration.FileSystemEnumerator`1.FindNextEntry(Byte* entryBufferPtr, Int32 bufferLength)
           at System.IO.Enumeration.FileSystemEnumerator`1.MoveNext()
           at System.IO.FileSystemWatcher.RunningInstance.AddDirectoryWatchUnlocked(WatchedDirectory parent, String directoryName)
           at System.IO.FileSystemWatcher.RunningInstance.AddDirectoryWatchUnlocked(WatchedDirectory parent, String directoryName)
           at System.IO.FileSystemWatcher.RunningInstance.AddDirectoryWatchUnlocked(WatchedDirectory parent, String directoryName)
           at System.IO.FileSystemWatcher.RunningInstance.AddDirectoryWatchUnlocked(WatchedDirectory parent, String directoryName)
           at System.IO.FileSystemWatcher.RunningInstance..ctor(FileSystemWatcher watcher, SafeFileHandle inotifyHandle, String directoryPath, Boolean includeSubdirectories, NotifyFilters notifyFilters, Cancella
tionToken cancellationToken)
           at System.IO.FileSystemWatcher.StartRaisingEvents()
           at System.IO.FileSystemWatcher.StartRaisingEventsIfNotDisposed()
           at System.IO.FileSystemWatcher.set_EnableRaisingEvents(Boolean value)
           at Emby.Server.Implementations.IO.LibraryMonitor.<>c__DisplayClass37_0.<StartWatchingPath>b__0()
        Source: System.IO.FileSystem
        TargetSite: Void FindNextEntry(Byte*, Int32)
        InnerException: System.IO.IOException: Permission denied
        Source:
        TargetSite:

 

Link to comment
Share on other sites

The collection containing the inaccessible folder will not show any file at all. After the message copied above the CPU-usage of the emby-processes will go to almost 0 so I think it just stopped the library scanning.

FYI: in the collection creating that error above the root of the collection was /media/01/speech/2019. So the inaccessible folder was in the first directory scanned.

 

Lukas

 

 

 

Link to comment
Share on other sites

Sorry, I don't get what you want from me.

I corrected the folders for now but I can try to recreate the situation - but what additional information do you need then?

The error message is in the first post.

The (in my opinion faulty) behavior is in post #3.

 

What additional information do you need?

Link to comment
Share on other sites

For example, I clicked on A and selected X. I expected Y to happen but instead Z happened, and here is the server log from that period of time.

Link to comment
Share on other sites

OK - once again after recreating the issue with demo data:

 

 

I add a collection to emby (type "home videos & photos").

base path: /media/tmp/embytest

under this path there are 4 folders: "2002", "2003" and "2004" containing all additional subfolders with jpgs. They are visible AND accessible to emby.

the fourth folder ("notaccessibledemofolder") is visible but NOT accessible to emby.

If I check in emby web no content of this collection is shown - not the jpgs from the 2002, 2003, 2004 folders, not the folders itsself - the collection is just empty.

 

So I do a "refresh metadata"/"replace metadata" in the server administration page / library management.

The server creates the following output in its logs:

2021-01-18 19:35:23.184 Info Server: http/1.1 GET http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:35:23.205 Info Server: http/1.1 Response 200 to 192.168.12.117. Time: 22ms. http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:35:31.476 Info Server: http/1.1 POST http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:35:31.511 Info Server: http/1.1 Response 204 to 192.168.12.117. Time: 35ms. http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:35:31.617 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:35:31.620 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:35:31.623 Debug App: Running CollectionFolderImageProvider for /var/lib/emby-server/root/default/embytest
2021-01-18 19:35:31.630 Debug App: Running FolderImageProvider for /media/tmp/embytest

and stops - no further logs, cpu going back to idle. (this time no exception as well - last time I got the exception posted in this thread, post #1.

And still no content shown in this collection.

 

then I delete the "notaccessibledemofolder" from the directory at the server console and do a "refresh metadata"/"replace metadata". it takes significantly longer, I can see the black/green circle with the percentage showing and filling.

server log starts the same as before but then continues:

2021-01-18 19:35:23.184 Info Server: http/1.1 GET http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:35:23.205 Info Server: http/1.1 Response 200 to 192.168.12.117. Time: 22ms. http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:35:31.476 Info Server: http/1.1 POST http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:35:31.511 Info Server: http/1.1 Response 204 to 192.168.12.117. Time: 35ms. http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:35:31.617 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:35:31.620 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:35:31.623 Debug App: Running CollectionFolderImageProvider for /var/lib/emby-server/root/default/embytest
2021-01-18 19:35:31.630 Debug App: Running FolderImageProvider for /media/tmp/embytest
2021-01-18 19:37:02.098 Info Server: http/1.1 GET http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:37:02.102 Info Server: http/1.1 Response 200 to 192.168.12.117. Time: 4ms. http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:37:02.123 Info Server: http/1.1 GET http://mediaserver01:8096/emby/Users/e2644b3cc3d64a7687a8294e2296d1fd?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:37:02.125 Info Server: http/1.1 Response 200 to 192.168.12.117. Time: 2ms. http://mediaserver01:8096/emby/Users/e2644b3cc3d64a7687a8294e2296d1fd?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:37:08.884 Info Server: http/1.1 POST http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:37:08.885 Info Server: http/1.1 Response 204 to 192.168.12.117. Time: 1ms. http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:37:08.987 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:37:08.995 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:37:08.999 Debug App: Running CollectionFolderImageProvider for /var/lib/emby-server/root/default/embytest
2021-01-18 19:37:09.003 Debug App: Running FolderImageProvider for /media/tmp/embytest
2021-01-18 19:37:15.489 Debug XmlSerializer: Deserializing file /var/lib/emby-server/config/notifications.xml
2021-01-18 19:37:59.282 Debug App: Begin Sending Alive Notifications For All Devices
2021-01-18 19:37:59.282 Debug App: Sending alive notification MediaServer - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:37:59.583 Debug App: Sending alive notification MediaServer - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:37:59.883 Debug App: Sending alive notification MediaServer - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:38:00.184 Debug App: Sending alive notification ContentDirectory - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:38:00.485 Debug App: Sending alive notification ContentDirectory - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:38:00.786 Debug App: Sending alive notification ConnectionManager - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:38:01.089 Debug App: Sending alive notification ConnectionManager - 31676751d5104157ad6633e567fdd5db
2021-01-18 19:38:01.389 Debug App: Completed Sending Alive Notifications For All Devices
2021-01-18 19:38:19.012 Debug App: Running FolderImageProvider for /media/tmp/embytest/2003
2021-01-18 19:38:19.018 Debug App: Running FolderImageProvider for /media/tmp/embytest/2003/2003-05-25
2021-01-18 19:38:19.022 Debug App: Running PhotoAlbumImageProvider for /media/tmp/embytest/2003/2003-05-25/Ford
2021-01-18 19:38:19.028 Debug App: Running PhotoProvider for /media/tmp/embytest/2003/2003-05-25/Ford/PICT0832.JPG
2021-01-18 19:38:19.786 Debug ImageProcessor: Getting image size for item Photo /media/tmp/embytest/2003/2003-05-25/Ford/PICT0832.JPG
2021-01-18 19:38:19.852 Debug Skia: Getting image size from /media/tmp/embytest/2003/2003-05-25/Ford/PICT0832.JPG
2021-01-18 19:38:20.237 Debug App: Running PhotoProvider for /media/tmp/embytest/2003/2003-05-25/Ford/PICT0844.JPG
2021-01-18 19:38:20.268 Debug ImageProcessor: Getting image size for item Photo /media/tmp/embytest/2003/2003-05-25/Ford/PICT0844.JPG
2021-01-18 19:38:20.268 Debug Skia: Getting image size from /media/tmp/embytest/2003/2003-05-25/Ford/PICT0844.JPG
2021-01-18 19:38:20.273 Debug App: Running PhotoProvider for /media/tmp/embytest/2003/2003-05-25/Ford/PICT0846.JPG
2021-01-18 19:38:20.281 Debug ImageProcessor: Getting image size for item Photo /media/tmp/embytest/2003/2003-05-25/Ford/PICT0846.JPG
2021-01-18 19:38:20.281 Debug Skia: Getting image size from /media/tmp/embytest/2003/2003-05-25/Ford/PICT0846.JPG
2021-01-18 19:38:20.285 Debug App: Running PhotoProvider for /media/tmp/embytest/2003/2003-05-25/Ford/PICT0848.JPG
2021-01-18 19:38:20.291 Debug ImageProcessor: Getting image size for item Photo /media/tmp/embytest/2003/2003-05-25/Ford/PICT0848.JPG

then all the files in the collection get processed in a similar way and after some time the contents of the collection are accessible as expected in the web gui.

only change: removal of the folder that was visible to emby but NOT accessible by emby.

 

expected behavior: emby should just ignore that folder but process all the others.

 

 

Link to comment
Share on other sites

Quote

I add a collection to emby (type "home videos & photos").

base path: /media/tmp/embytest

Is this the only emby library you created?

Link to comment
Share on other sites

No - there are several other collections already active.

I switched off real time monitoring for all of them but I didn't remove them because they are quite big and would take some time to recreate

Also I'm not sure about collections and favourites - would they get lost if I remove and recreate the underlying collections?

 

L.

Link to comment
Share on other sites

Fotos / Home videos & photos / /media/multimedia/Fotos

Uni / Home videos & photos / /media/Uni

Musik / Mixed content / media/multimedia/Musik

Videos / Home videos & photos / /media/Videos

 

Link to comment
Share on other sites

Sorry - that's the test library I made for creating the logs - in addition to the other ones...

So including that its:

Fotos / Home videos & photos / /media/multimedia/Fotos

Uni / Home videos & photos / /media/Uni

Musik / Mixed content / media/multimedia/Musik

Videos / Home videos & photos / /media/Videos

embytest / Home videos & photos / /media/tmp/embytest

Link to comment
Share on other sites

  • 2 weeks later...

Hi, This looks like a permission problem.  See the error given.

System.UnauthorizedAccessException: System.UnauthorizedAccessException: Access to the path '/media/01/speech/2019/01' is denied.
         ---> System.IO.IOException: Permission denied

Make sure the file actually exists there and that it has read/write access.

Also what kind of library is this?

Link to comment
Share on other sites

3 hours ago, cayars said:

Hi, This looks like a permission problem.  See the error given.

System.UnauthorizedAccessException: System.UnauthorizedAccessException: Access to the path '/media/01/speech/2019/01' is denied.
         ---> System.IO.IOException: Permission denied

Make sure the file actually exists there and that it has read/write access.

Also what kind of library is this?

Did you actually read the thread and understood the question?

Regards

L.

 

Link to comment
Share on other sites

Just saying a permission denied is often different then not finding the file so I only suggested you check that.

In any event in the first message you asked if Emby could continue on but this exactly what it already does.  What you showed as "crash" is not at all a crash but a logged exception.

Link to comment
Share on other sites

OK, Once again:

The problem is that the emby-library monitor / indexer stops working when there's a file or directory with a problem.

It should ignore that file, perhaps log the problem but in all cases continue with the next file/directory.

Especially in networked environments it happens quite frequently that files or directory get the wrong permissions, get deleted or whatever. Just think of that hidden files that OSes like OSx or Windows create on every drive and that have restricted access.

The solution can NOT be to fix the filesystems all the time - the solution HAS to be that the library monitor / indexer is tolerant to such problems and continues with the next file/directory instead of stopping.

 

L.

Link to comment
Share on other sites

Can you upload the full log of the file you show fragments from?

Or take a look past those fragments.  Do you not see it continuing?

Link to comment
Share on other sites

3 minutes ago, cayars said:

Can you upload the full log of the file you show fragments from?

Or take a look past those fragments.  Do you not see it continuing?

A full log is not so easy as the other collection contain sensible information in the file and directory names.

Thats why I created the test-case described on post #9 in this thread.

The first (rather short) log is the full log from the moment I press "refresh metadata" in the gui till it stops completely. No further lines till I set another action in the gui ("real time monitoring" is switched off in all collections to avoid the other collections spam the log).

Link to comment
Share on other sites

On 1/18/2021 at 7:56 PM, grl said:

OK - once again after recreating the issue with demo data:

 

 

I add a collection to emby (type "home videos & photos").

base path: /media/tmp/embytest

under this path there are 4 folders: "2002", "2003" and "2004" containing all additional subfolders with jpgs. They are visible AND accessible to emby.

the fourth folder ("notaccessibledemofolder") is visible but NOT accessible to emby.

If I check in emby web no content of this collection is shown - not the jpgs from the 2002, 2003, 2004 folders, not the folders itsself - the collection is just empty.

 

So I do a "refresh metadata"/"replace metadata" in the server administration page / library management.

The server creates the following output in its logs:


2021-01-18 19:35:23.184 Info Server: http/1.1 GET http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:35:23.205 Info Server: http/1.1 Response 200 to 192.168.12.117. Time: 22ms. http://mediaserver01:8096/emby/Library/VirtualFolders?X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:35:31.476 Info Server: http/1.1 POST http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0. UserAgent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Firefox/78.0
2021-01-18 19:35:31.511 Info Server: http/1.1 Response 204 to 192.168.12.117. Time: 35ms. http://mediaserver01:8096/emby/Items/3a363adfb2736bf0d14bccc72b4753ab/Refresh?Recursive=true&ImageRefreshMode=FullRefresh&MetadataRefreshMode=FullRefresh&ReplaceAllImages=false&ReplaceAllMetadata=true&X-Emby-Client=Emby Web&X-Emby-Device-Name=Firefox&X-Emby-Device-Id=37b49a29-4d5b-4c9d-b5e4-53aba22a74ed&X-Emby-Client-Version=4.5.4.0
2021-01-18 19:35:31.617 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:35:31.620 Debug XmlSerializer: Deserializing file /var/lib/emby-server/root/default/embytest/options.xml
2021-01-18 19:35:31.623 Debug App: Running CollectionFolderImageProvider for /var/lib/emby-server/root/default/embytest
2021-01-18 19:35:31.630 Debug App: Running FolderImageProvider for /media/tmp/embytest

and stops - no further logs, cpu going back to idle. (this time no exception as well - last time I got the exception posted in this thread, post #1.

And still no content shown in this collection.

Post #9 in this thread.

Link to comment
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
×
×
  • Create New...