Consistent Server Crashing on FreeNAS

[radioactivesqrl 0]

I've been using Emby for some time and have been loving it. Though recently been seeing the Emby Server plugin for FreeNAS crash multiple times per day. Once I finally found the server logs, the following message appears multiple times for moves, tv, and collections:

kqueue() FileSystemWatcher has reached the maximum nunmber of files to watch.	System.IO.IOException	  at System.IO.KqueueMonitor.Add (System.String path, Boolean postEvents, System.Collections.Generic.List`1& fds) [0x00000] in <filename unknown>:0 	  at System.IO.KqueueMonitor.Scan (System.String path, Boolean postEvents, System.Collections.Generic.List`1& fds) [0x00000] in <filename unknown>:0 	  at System.IO.KqueueMonitor.Setup () [0x00000] in <filename unknown>:0 	  at System.IO.KqueueMonitor.DoMonitor () [0x00000] in <filename unknown>:0 

I currently have ~600 Movies + ~400 trailers and 1800 TV episodes across 25 different series. While this is a decent number, I doubt it's the largest library out there.

 

Is there a configuration change I can make or a structural change to the library to reduce the load on the FileSystemWatcher?

[Luke 37090]

Disable it using the opposite of the procedure I outlined in this thread:

 

http://emby.media/community/index.php?/topic/26024-realtime-monitoring-of-network-share/page-2&do=findComment&comment=281016

 

The realtime monitor is not stable under BSD.

[radioactivesqrl 0]

Disable it using the opposite of the procedure I outlined in this thread:

 

http://emby.media/community/index.php?/topic/26024-realtime-monitoring-of-network-share/page-2&do=findComment&comment=281016

 

The realtime monitor is not stable under BSD.

 

Thanks. I'll try that out.

Just for future clarification for others... In version 3.0.5781.8, I found the configuration option under /var/db/emby-server/config/system.xml within the Emby jail. This path may have changed since the other thread.

[sluggo45 47]

I've always found it better to just set the scheduler to update the library every 30 minutes, and have download apps (Sonar, Couch, etc.) automatically notify Emby server when they get something new. The latter will insta-update your library across all your clients anyway. If you are manually adding stuff like DVD rips just fire off a library update when you do. 

[razzfazz 11]

The version of Mono that's currently in FreeBSD ports has a hard-coded limit for kqueue monitoring of at most 200 files/directories, and it will throw this particular exception whenever you're trying to monitor more. This appears to be a completely arbitrary limit, and it's gone in the current upstream version of Mono (now Int32.MaxValue instead by default).

[razzfazz 11]

To get real-time monitoring to work in the meantime, the maintainer of the FreeNAS plugin could apply this patch to the bundled Mono version:

 

https://github.com/mono/mono/compare/mono:mono-4.2.1.124...razzfazz:mono-4.2.1.124-increase_maxfds.diff

 

EDIT: Also submitted a PR for FreeBSD: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=205919

Edited January 9, 2016 by razzfazz

[kjp4756 41]

To get real-time monitoring to work in the meantime, the maintainer of the FreeNAS plugin could apply this patch to the bundled Mono version:

 

https://github.com/razzfazz/mono/commit/1e27b754d7918402f442fd4ce3470ecea44fd165

 

EDIT: Also submitted a PR for FreeBSD: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=205919

Thanks for posting this.  The patch does appear to take care of the too many files error.  However, I now get these errors, any ideas?

 

 

2016-01-06 17:18:52.4253 Error LibraryMonitor: Error in Directory watcher for: /media/Movies
*** Error Report ***
Version: 3.0.5782.0
Command line: /usr/local/lib/emby-server/MediaBrowser.Server.Mono.exe -ffmpeg /usr/local/bin/ffmpeg -ffprobe /usr/local/bin/ffprobe -programdata /var/db/mediabrowser
Operating system: Unix 9.3.28.0
Processor count: 4
64-Bit OS: True
64-Bit Process: True
Program data path: /var/db/mediabrowser
Mono: 4.2.1 (Stable 4.2.1.124/39edf24 Wed Jan  6 17:11:40 UTC 2016)
Application Path: /usr/local/lib/emby-server/MediaBrowser.Server.Mono.exe
fcntl() error while attempting to get path for fd '1091', error code = '22'
System.IO.IOException
No Stack Trace Available
 
2016-01-06 17:18:52.4253 Info LibraryMonitor: Stopping directory watching for path /media/Movies

[razzfazz 11]

EDIT: Never mind, the error message was right there:

fcntl() error while attempting to get path for fd '1091', error code = '22'

Permission error, perhaps? The relevant code is around line 618 here:

 

https://github.com/mono/mono/blob/mono-4.2.1.124/mcs/class/System/System.IO/KeventWatcher.cs

 

Looks like it's failing while trying to get the corresponding directory path for a file descriptor.

Edited January 6, 2016 by razzfazz

[kjp4756 41]

Can you paste this into a file called WatchTest.cs: 

using System;
using System.IO;

public class WatchTest {
	public static void Main (string[] args)
	{
		FileSystemWatcher watcher = new FileSystemWatcher (args[0]);

		watcher.IncludeSubdirectories = true;

		watcher.Changed += OnChangedEvent;
		watcher.Created += OnCreatedEvent;
		watcher.Deleted += OnDeletedEvent;
		watcher.Renamed += OnRenamedEvent;

		watcher.EnableRaisingEvents = true;

		while (true) {
			watcher.WaitForChanged(WatcherChangeTypes.All);
		}
	}

	static void OnChangedEvent (object source, FileSystemEventArgs args)
	{
		Console.WriteLine ("OnChangedEvent {0}", args.FullPath);
	}

	static void OnCreatedEvent (object source, FileSystemEventArgs args)
	{
		Console.WriteLine ("OnCreatedEvent {0}", args.FullPath);
	}

	static void OnDeletedEvent (object source, FileSystemEventArgs args)
	{
		Console.WriteLine ("OnDeletedEvent {0}", args.FullPath);
	}

	static void OnRenamedEvent (object source, FileSystemEventArgs args)
	{
		Console.WriteLine ("OnRenamedEvent {0}", args.FullPath);
	}
}

And then compile:

mcs WatchTest.cs

And run:

mono WatchTest.exe /media/Movies

Hopefully that will actually let the exception propagate out and give you a somewhat more concrete error message.

 

I compiled then ran and no errors appeared.  The test program is still running and I can kill it with CONTROL-C

 

 

root@emby:~ # mcs WatchTest.cs 
root@emby:~ # mono WatchTest.exe /media/Movies

[razzfazz 11]

Hm, looking through my logs, I'm actually seeing the same thing. Curious...

[razzfazz 11]

 

I compiled then ran and no errors appeared.  The test program is still running and I can kill it with CONTROL-C

root@emby:~ # mcs WatchTest.cs 
root@emby:~ # mono WatchTest.exe /media/Movies

 

Yeah, sorry, you'll actually have to touch some file in /media/Movies from another terminal session, and WatchTest should see this activity.

[razzfazz 11]

I wonder if this happens when a file is deleted; seems like in that case getting the path for the corresponding descriptor does not make sense...

[kjp4756 41]

Tried touching /media/Movies and nothing happened.  Tried touching one of my movies in /media/Movies and nothing happened.  Then tried creating a new file in /media/Movies and nothing happened.  Test program still running fine with nothing displayed.

[kjp4756 41]

I wonder if this happens when a file is deleted; seems like in that case getting the path for the corresponding descriptor does not make sense...

You know that may make sense.  I wonder if some old movies/file names are in the emby database.  I'll see if I can make sense of anything in the sqlite database.

[razzfazz 11]

I played a bit with the test app and I don't think that's it; it prints a vald path even for delete events, and Emby never calls the failing function directly. Will have to do some more debuging...

[razzfazz 11]

What kind of path is your /media/Movies? Local? Remote? What FS?

[Luke 37090]

You should also subscribe to the watcher's Error event and log those messages. Apart from that, here are the differences between the above code and what emby does:

 

• We don't use watcher.WaitForChanged - which is fine, I imagine you're just doing it to keep the test app from exiting
• We instantiate like this:

                    var newWatcher = new FileSystemWatcher(path, "*")
                    {
                        IncludeSubdirectories = true,
                        InternalBufferSize = 32767
                    };

                    newWatcher.NotifyFilter = NotifyFilters.CreationTime |
                        NotifyFilters.DirectoryName |
                        NotifyFilters.FileName |
                        NotifyFilters.LastWrite |
                        NotifyFilters.Size |
                        NotifyFilters.Attributes;

[Luke 37090]

The InternalBufferSize that we're setting is specifically related to an issue in windows so I think I should make that conditional and leave it at default for all other operating systems. I will make that change.

[kjp4756 41]

What kind of path is your /media/Movies? Local? Remote? What FS?

Local jail with zfs

 

Sent from my LG-D852 using Tapatalk

[kjp4756 41]

I just compared a list of my movies in /media/Movies to what is in Library.db and they match.  I was thinking the entries in the db weren't being erased when a file was erased and causing emby's file monitor to look for a file that isn't there.   

 

edit: Got some activity from the test program.  I deleted some left over idx files that I don't need.

 

 

OnDeletedEvent /media/Movies/American Ultra (2015).idx
OnDeletedEvent /media/Movies/Furious 7 (2015).idx
OnDeletedEvent /media/Movies/Maze Runner The Scorch Trials (2015).idx

Edited January 6, 2016 by kjp4756

[kjp4756 41]

Now the test program works for all events. Not sure why it didn't work before.  I was probably doing things in the wrong folder (doing too much at once)

 

Anyway, I created a file called test.  I then moved test to test_moved.  I then deleted test.  

 

 

OnCreatedEvent /media/Movies/test
OnDeletedEvent /media/Movies/test
OnCreatedEvent /media/Movies/test_moved
OnDeletedEvent /media/Movies/test_moved

[razzfazz 11]

FWIW, this is the stack trace for where the exception gets thrown:

  at System.IO.KqueueMonitor.GetFilenameFromFd (Int32 fd) [0x00000] in <filename unknown>:0 
  at System.IO.KqueueMonitor.Setup () [0x00000] in <filename unknown>:0 
  at System.IO.KqueueMonitor.DoMonitor () [0x00000] in <filename unknown>:0 
  at System.IO.KqueueMonitor.<Start>m__0 () [0x00000] in <filename unknown>:0 
  at System.Threading.ThreadHelper.ThreadStart_Context (System.Object state) [0x00000] in <filename unknown>:0 
  at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, Boolean preserveSyncCtx) [0x00000] in <filename unknown>:0 
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, Boolean preserveSyncCtx) [0x00000] in <filename unknown>:0 
  at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x00000] in <filename unknown>:0 
  at System.Threading.ThreadHelper.ThreadStart () [0x00000] in <filename unknown>:0 

Edited January 7, 2016 by razzfazz

[razzfazz 11]

D'oh... Looks like the arguments to fcntl() are Darwin-specific; at least I don't see F_GETPATH in any of the system headers on my FreeBSD box, nor O_EVTONLY. That would explain the 22 return code (EINVAL), too...

Edited January 7, 2016 by razzfazz

[razzfazz 11]

Yup: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=198570

[razzfazz 11]

OK, so basically the Rename event doesn't work on FreeBSD because there's no easy way to determine the new filename. However, it looks like renaming a file actually triggers a Delete event on the old name and a Create event on the new name, so it seems like we should be able to get by without even listening for Rename, no? If so, all that remains to be done is avoiding the GetFilenameFromFd() in the setup code, which only seems to be used to resolve symlinks in the path -- there is probably a better way of doing that to begin with.