Jump to content

some libraries losing contact with external hard drive until Emby restart


Recommended Posts

Posted
Quote

"Is it permanent mount"  yes -- as much as external storage can be.

How did you confirm that it is a permanent mount?

  • 2 weeks later...
gogginguy
Posted (edited)

Please inform:  What Emby Server process has started at (or near) 07:32:21.222 that is evaluating the libraries?

 

2025-03-17 00:10:00.500 Info Backup & Restore: SyncDirectories /storage/walter-scheduled-emby-backup/embyserver-backup-full/data to /storage/walter-scheduled-emby-backup/Emby Server Databases - 2025-03-17 00.10.0. recursive: False
2025-03-17 00:10:00.521 Info Backup & Restore: Deleting database backups except for last 14
2025-03-17 00:10:00.521 Info Backup & Restore: Deleted database Backup /storage/walter-scheduled-emby-backup/Emby Server Databases - 2025-03-03 00.10.0 because fell outside of retention setting (14)
2025-03-17 00:10:00.521 Info Backup & Restore: SyncDirectories /config/metadata/musicartists to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/musicartists. recursive: True
2025-03-17 00:10:00.521 Info Backup & Restore: SyncDirectories /config/metadata/musicalbums to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/musicalbums. recursive: True
2025-03-17 00:10:00.521 Info Backup & Restore: SyncDirectories /config/metadata/library to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/library. recursive: True
2025-03-17 00:10:00.959 Info Backup & Restore: SyncDirectories /config/metadata/people to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/people. recursive: True
2025-03-17 07:32:21.222 Error App: Error in validateChildren for 51349 /storage/4KMOVIES/Thriller
    *** Error Report ***
    Version: 4.8.10.0
    Command line: /system/EmbyServer.dll -programdata /config -ffdetect /bin/ffdetect -ffmpeg /bin/ffmpeg -ffprobe /bin/ffprobe -restartexitcode 3
    Operating system: Linux version 3.10.0-1160.81.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Fri Dec 1
    Framework: .NET 6.0.31
    OS/Process: x64/x64
    Runtime: system/System.Private.CoreLib.dll
    Processor count: 8
    Data path: /config
    Application path: /system
    System.IO.IOException: System.IO.IOException: Input/output error : '/storage/4KMOVIES/Thriller'
       at System.IO.Enumeration.FileSystemEnumerator`1.MoveNext()
       at System.Collections.Generic.LargeArrayBuilder`1.AddRange(IEnumerable`1 items)
       at System.Collections.Generic.EnumerableHelpers.ToArray[T](IEnumerable`1 source)
       at Emby.Server.Implementations.IO.ManagedFileSystem.EnumerateFileSystemInfos(DirectoryInfo dir, Boolean recursive)
       at Emby.Server.Implementations.IO.ManagedFileSystem.GetFileSystemEntries(String path, Boolean recursive, FileSystemCredentials credentials)
       at MediaBrowser.Controller.Providers.DirectoryService.GetFileSystemEntriesInternal(String path)
       at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
       at MediaBrowser.Controller.Entities.Folder.GetNonCachedChildren(IDirectoryService directoryService, LibraryOptions libraryOptions)
       at MediaBrowser.Controller.Entities.BaseItem.ValidateChildrenInternal(IProgress`1 progress, CancellationToken cancellationToken, Boolean recursive, Boolean refreshChildMetadata, BaseItem[] collectionFolders, LibraryOptions libraryOptions, Dictionary`2 newItemIds, MetadataRefreshOptions refreshOptions, IDirectoryService directoryService)
       at Emby.Server.Implementations.Library.LibraryManager.ValidatePhysicalRoots(IProgress`1 progress, IDirectoryService directoryService, CancellationToken cancellationToken)
    Source: System.Private.CoreLib
    TargetSite: Boolean MoveNext()

Edited by gogginguy
Posted
11 minutes ago, gogginguy said:

Please inform:  What Emby Server process has started at (or near) 07:32:21.222 that is evaluating the libraries?

 

2025-03-17 00:10:00.500 Info Backup & Restore: SyncDirectories /storage/walter-scheduled-emby-backup/embyserver-backup-full/data to /storage/walter-scheduled-emby-backup/Emby Server Databases - 2025-03-17 00.10.0. recursive: False
2025-03-17 00:10:00.521 Info Backup & Restore: Deleting database backups except for last 14
2025-03-17 00:10:00.521 Info Backup & Restore: Deleted database Backup /storage/walter-scheduled-emby-backup/Emby Server Databases - 2025-03-03 00.10.0 because fell outside of retention setting (14)
2025-03-17 00:10:00.521 Info Backup & Restore: SyncDirectories /config/metadata/musicartists to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/musicartists. recursive: True
2025-03-17 00:10:00.521 Info Backup & Restore: SyncDirectories /config/metadata/musicalbums to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/musicalbums. recursive: True
2025-03-17 00:10:00.521 Info Backup & Restore: SyncDirectories /config/metadata/library to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/library. recursive: True
2025-03-17 00:10:00.959 Info Backup & Restore: SyncDirectories /config/metadata/people to /storage/walter-scheduled-emby-backup/embyserver-backup-full/metadata/people. recursive: True
2025-03-17 07:32:21.222 Error App: Error in validateChildren for 51349 /storage/4KMOVIES/Thriller
    *** Error Report ***
    Version: 4.8.10.0
    Command line: /system/EmbyServer.dll -programdata /config -ffdetect /bin/ffdetect -ffmpeg /bin/ffmpeg -ffprobe /bin/ffprobe -restartexitcode 3
    Operating system: Linux version 3.10.0-1160.81.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Fri Dec 1
    Framework: .NET 6.0.31
    OS/Process: x64/x64
    Runtime: system/System.Private.CoreLib.dll
    Processor count: 8
    Data path: /config
    Application path: /system
    System.IO.IOException: System.IO.IOException: Input/output error : '/storage/4KMOVIES/Thriller'
       at System.IO.Enumeration.FileSystemEnumerator`1.MoveNext()
       at System.Collections.Generic.LargeArrayBuilder`1.AddRange(IEnumerable`1 items)
       at System.Collections.Generic.EnumerableHelpers.ToArray[T](IEnumerable`1 source)
       at Emby.Server.Implementations.IO.ManagedFileSystem.EnumerateFileSystemInfos(DirectoryInfo dir, Boolean recursive)
       at Emby.Server.Implementations.IO.ManagedFileSystem.GetFileSystemEntries(String path, Boolean recursive, FileSystemCredentials credentials)
       at MediaBrowser.Controller.Providers.DirectoryService.GetFileSystemEntriesInternal(String path)
       at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
       at MediaBrowser.Controller.Entities.Folder.GetNonCachedChildren(IDirectoryService directoryService, LibraryOptions libraryOptions)
       at MediaBrowser.Controller.Entities.BaseItem.ValidateChildrenInternal(IProgress`1 progress, CancellationToken cancellationToken, Boolean recursive, Boolean refreshChildMetadata, BaseItem[] collectionFolders, LibraryOptions libraryOptions, Dictionary`2 newItemIds, MetadataRefreshOptions refreshOptions, IDirectoryService directoryService)
       at Emby.Server.Implementations.Library.LibraryManager.ValidatePhysicalRoots(IProgress`1 progress, IDirectoryService directoryService, CancellationToken cancellationToken)
    Source: System.Private.CoreLib
    TargetSite: Boolean MoveNext()

hi, that is most likely your scheduled library scan.

gogginguy
Posted

OK --  thanks.  Now all i need to do is schedule the library scan immediately after automatic restart, which should restore any lost connections.
...
Done.   Fingers crossed.

Happy2Play
Posted

Might need to enable debug logging to possibly see more information but to me it is a little odd the 7 hour time gap with nothing.

Posted

Obviously It would be better if you didn't have to do that in the first place.

gogginguy
Posted

DEBUG log for a successful restart at 5am, followed by a library scan at 5:15.  Next activity at 5:24   Log excerpts below to use as a successful standard.

 

2025-03-18 05:00:06.077 Info Main: Application path: /system/EmbyServer.dll
2025-03-18 05:00:06.317 Info App: Setting default culture to en-US
2025-03-18 05:00:06.322 Info Main: Emby
    Command line: /system/EmbyServer.dll -programdata /config -ffdetect /bin/ffdetect -ffmpeg /bin/ffmpeg -ffprobe /bin/ffprobe -restartexitcode 3
    Operating system: Linux version 3.10.0-1160.81.1.el7.x86_64 (mockbuild@kbuilder.bsys.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Fri Dec 1
    Framework: .NET 6.0.31
    OS/Process: x64/x64
    Runtime: system/System.Private.CoreLib.dll
    Processor count: 8
    Data path: /config
    Application path: /system
2025-03-18 05:00:06.322 Info Main: Logs path: /config/logs
2025-03-18 05:00:06.322 Info Main: Cache path: /config/cache
2025-03-18 05:00:06.322 Info Main: Internal metadata path: /config/metadata
2025-03-18 05:00:06.324 Info App: Emby Server Version: 4.8.10.0
2025-03-18 05:00:06.327 Info App: Loading assemblies
...
2025-03-18 05:00:28.372 Info LibraryMonitor: /storage/walter/MOVIES480/Thriller - Legal is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43731
2025-03-18 05:00:28.372 Info LibraryMonitor: /storage/walter/MOVIES480/Thriller - Political is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43732
2025-03-18 05:00:28.372 Info LibraryMonitor: /storage/walter/MOVIES480/Thriller - Psychological is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43733
2025-03-18 05:00:28.373 Info LibraryMonitor: /storage/walter/MOVIES480/Thriller - War is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43735
2025-03-18 05:00:28.373 Info LibraryMonitor: /storage/walter/MOVIES480/War is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43738
2025-03-18 05:00:28.373 Info LibraryMonitor: /storage/walter/MOVIES480/Westerns is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43739
2025-03-18 05:00:38.052 Debug App: Ping test result to http://192.168.132.74:8097/system/ping. Success: False Connection to http://192.168.132.74:8097/system/ping timed out
2025-03-18 05:00:38.061 Debug App: CreateSsdpUdpSocket 0.0.0.0:1900
2025-03-18 05:00:38.065 Debug App: CreateSsdpUdpSocket 0.0.0.0:0
2025-03-18 05:00:38.065 Info App: Init BeginReceive on 0.0.0.0
2025-03-18 05:00:38.065 Info App: Init BeginReceive on 0.0.0.0
2025-03-18 05:00:38.449 Debug XmlSerializer: Deserializing file /config/config/users/3ee60eb60d234f058fc7782fb0e1fc75/config.xml
2025-03-18 05:15:00.000 Debug TaskManager: DailyTrigger fired for task: Scan media library
2025-03-18 05:15:00.000 Debug TaskManager: Queueing task RefreshMediaLibraryTask
2025-03-18 05:15:00.001 Debug TaskManager: Executing Scan media library
2025-03-18 05:15:00.049 Debug SqliteItemRepository: GetitemById AggregateFolder 1 root
2025-03-18 05:15:00.438 Debug App: Found extra Clip /storage/walter/MOVIES/Action-Adventure/Predator [imdbid=tt0093773]/Featurettes/Predator Ww-100.mkv for /storage/walter/MOVIES/Action-Adventure/Predator [imdbid=tt0093773]/Predator [imdbid=tt0093773].mkv
2025-03-18 05:15:00.438 Debug App: Found extra Clip /storage/walter/MOVIES/Action-Adventure/Predator [imdbid=tt0093773]/Featurettes/Predator Ww-101.mkv for /storage/walter/MOVIES/Action-Adventure/Predator [imdbid=tt0093773]/Predator [imdbid=tt0093773].mkv
...
025-03-18 05:15:08.337 Debug App: Setting image url into item 39148
2025-03-18 05:15:08.341 Debug App: CollectionFolderImageProvider reports change to 40519 - /config/root/default/Film Noir Archive
2025-03-18 05:15:08.341 Debug App: Running CollectionFolderImageProvider for /config/root/default/Film Noir Archive
2025-03-18 05:15:08.343 Debug App: Setting image url into item 40519
2025-03-18 05:15:08.364 Debug App: CollectionFolderImageProvider reports change to 43662 - /config/root/default/480
2025-03-18 05:15:08.364 Debug App: Running CollectionFolderImageProvider for /config/root/default/480
2025-03-18 05:15:08.365 Debug App: Setting image url into item 43662
2025-03-18 05:15:08.368 Debug App: CollectionFolderImageProvider reports change to 54451 - 
2025-03-18 05:15:08.368 Debug App: Running CollectionFolderImageProvider for 2025
2025-03-18 05:15:08.369 Debug App: Setting image url into item 54451
2025-03-18 05:15:08.371 Debug ProviderManager: WaitForRefreshQueue waiting for 0 items in refresh queue
2025-03-18 05:15:08.378 Debug App: Running post-scan task RefreshIntrosScanTask
2025-03-18 05:15:08.382 Debug App: Running post-scan task CleanDatabaseScheduledTask
2025-03-18 05:15:08.467 Debug App: Running post-scan task CollectionLibraryPostScanTask
2025-03-18 05:15:08.468 Debug TaskManager: Scan media library Completed after 0 minute(s) and 8 seconds
2025-03-18 05:15:08.469 Debug ProviderManager: WaitForRefreshQueue complete
2025-03-18 05:24:44.261 Debug Server: http/1.1 GET http://emby_remote_ip:8097/. Source Ip: host1, UserAgent: python-requests/2.32.3
2025-03-18 05:24:44.265 Debug Server: http/1.1 Response 302 to host1. Time: 8ms. GET http://emby_remote_ip:8097/

 

Happy2Play
Posted

I would say you have libraries that Emby does not technically support ie child libraries that already exist as part to another library.

one example from snippet above

2025-03-18 05:00:28.372 Info LibraryMonitor: /storage/walter/MOVIES480/Thriller - Legal is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43731
 

So you may need to go over all library path setup.

gogginguy
Posted
On 3/18/2025 at 9:50 AM, Happy2Play said:

I would say you have libraries that Emby does not technically support ie child libraries that already exist as part to another library.

one example from snippet above

2025-03-18 05:00:28.372 Info LibraryMonitor: /storage/walter/MOVIES480/Thriller - Legal is already being watched by watcher for /storage/walter/MOVIES480. Adding item 43731
 

So you may need to go over all library path setup.

Not sure what the remedy is -- not apparent by the log line above.   I'm assuming no location can "feed" two libraries?

Happy2Play
Posted
41 minutes ago, gogginguy said:

Not sure what the remedy is -- not apparent by the log line above.   I'm assuming no location can "feed" two libraries?

Parent locations yes, child and parent no.  As one library will absorb the content ie the parent library.

gogginguy
Posted

Earlier comment prompted removal of "480" library.  But, not the location or other libraries which read from a subdirectory of it.

 

Attached "embyserver.abbr.txt" is 'abbr' because of the necessary removal of repetitive lines between lines 6000 and 200,000.  You'll notice why.

I assume this was all prompted by moving "BUGSY MALONE" folder from external drive (the one which 'disappears') to usual library drive location where the bulk of movies hang out -- but both locations are part of the same "MUSICALS" library scan.

"4KMOVIES" again has disappeared for a few libraries... 
     System.IO.IOException: System.IO.IOException: Input/output error : '/storage/4KMOVIES'

 ...things I noticed in today's log but don't know what they mean (or why they were necessary):

"Deleting path .. "  (why?)
"FOREIGN KEY constraint failed"   ( I know what a foreign key is, but it doesn't specify what it was )

 

In short, doing the restart each morning before library scan isn't often enough to work around this problem.

 

embyserver.abbr.txt

Posted

@gogginguyare you willing to make a fresh start? The root problem is the overlapping folders across different libraries, and the current release version of the server doesn't handle this very well right now.  There are numerous fixes for it coming though.

gogginguy
Posted (edited)

I understand.  Well, i think i understand that it means a single folder (with no sub-folders) belong to only one library. I will search out where there are overlaps.  

But that doesn't explain the "BUGSY MALONE" logging.  There's no overlap there.

Edited by gogginguy
Happy2Play
Posted (edited)
15 hours ago, gogginguy said:

"Deleting path .. "  (why?)
"FOREIGN KEY constraint failed"   ( I know what a foreign key is, but it doesn't specify what it was )

This will be caused by your overlapping library and my require all libraries to be removed and readded as it can from /storage/walter/MOVIES480/Comedy.

Not sure what you are doing but you freaked out RTM as there is over 788373 lines just for /storage/walter/MOVIES blu-ray/Musicals/BUGSY MALONE [imdbid=tt0074256]

But not sure as it was processed.

2025-03-19 22:15:27.798 Debug LibraryMonitor: Timer stopped.

2025-03-19 22:15:28.319 Debug App: Running FFProbeProvider for /storage/walter/MOVIES blu-ray/Musicals/BUGSY MALONE [imdbid=tt0074256]/BUGSY MALONE [imdbid=tt0074256].mkv
2025-03-19 22:15:28.343 Info MediaProbeManager: ProcessRun 'ffprobe' Execute: /bin/ffprobe -i file:"/storage/walter/MOVIES blu-ray/Musicals/BUGSY MALONE [imdbid=tt0074256]/BUGSY MALONE [imdbid=tt0074256].mkv" -threads 0 -v info -print_format json -show_streams -show_chapters -show_format -show_data
2025-03-19 22:15:28.348 Debug MediaProbeManager: ProcessRun 'ffprobe' Started.
2025-03-19 22:15:28.682 Info MediaProbeManager: ProcessRun 'ffprobe' Process exited with code 0 - Succeeded

 

Edited by Happy2Play
gogginguy
Posted

image.png.296128ac691b2d2beefb5d263446db51.png
Are these folder locations for this library OK?   If they are, why would moving a movie from one to another cause a "freak out"?

Happy2Play
Posted
2 minutes ago, gogginguy said:

Are these folder locations for this library OK?   If they are, why would moving a movie from one to another cause a "freak out"?

Well RTM is monitoring each file and see the change over 700000 time during your move I am assuming.

Posted

Right, the server's realtime monitor is picking up all of your file moving and constantly scanning in reaction to that. 

If you are moving large directories around then you might want to shutdown the server while you are doing this.

gogginguy
Posted
3 hours ago, Happy2Play said:

Well RTM is monitoring each file and see the change over 700000 time during your move I am assuming.

But, there's no overlap.  So, I'm going to delete and recreate it as you see here.  If i read you correctly you're tying overlap to a possible cause for the server losing connection with /server/4KMOVIES/ locations.

Posted
2 minutes ago, gogginguy said:

But, there's no overlap.  So, I'm going to delete and recreate it as you see here.  If i read you correctly you're tying overlap to a possible cause for the server losing connection with /server/4KMOVIES/ locations.

The realtime monitor has nothing to do with overlap. What you see in the log is very much normal. It's just the server reacting to you moving lots of files around. That's why I suggested you may want to shut down the server while you do this.

  • Thanks 1

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...