Jump to content

Too Many Open Files and Sockets Remaining Established


Recommended Posts

Posted

I am running the following:

 

Application version: 3.3.1.0
Emby Command line: /usr/lib/emby-server/bin/MediaBrowser.Server.Mono.exe -programdata /var/lib/emby-server -restartpath /usr/lib/emby-server/restart.sh
        Operating system: Unix 4.16.0.41600
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: False
        Mono: 4.8.1 (Stable 4.8.1.0/22a39d7 Tue May  2 22:26:20 UTC 2017)
        Processor count: 6
        Program data path: /var/lib/emby-server
        Application directory: /usr/lib/emby-server/bin
Plugins:
        Kodi companion 2.0.2.0
 

My main Emby client is the Kodi plugin running on a Sony XBR-49X700D:

 

Kodi 17.6 Git:20171114-a9a7a20

Android 7.0.0 API level 24

Kernel Linux 2.10.79

 

I also have client running as a Kodi plugin on a Raspberry Pi 3, a client running on an iPad 2 and one running on an Android phone, but the issue seems to be related with the client on the TV.

 

I haven't isolated the client issue yet, but every once and a while, the client on the TV floods the server with requests (current hypothesis is that it may have to do with the client trying to run when the TV is in standby, but not really running completely/correctly).  In the server log file I see the following set of entries repeated every minute, or quicker:

 

Info HttpServer: WS ws://<server_ip>:8096/embywebsocket?api_key=<api_key>&deviceId=<device_id>. UserAgent:

Info HttpServer: HTTP POST http://<server_ip>:8096/emby/Sessions/Capabilities/Full?format=json. UserAgent: Emby-Kodi
Info HttpServer: HTTP Response 204 to <client_ip>. Time: 11ms. http://<server_ip>:8096/emby/Sessions/Capabilities/Full?format=json
Info HttpServer: HTTP GET http://<server_ip>:8096/emby/Sessions?DeviceId=<device_id>&format=json. UserAgent: Emby-Kodi
Info HttpServer: HTTP Response 200 to <client_ip>. Time: 4ms. http://<server_ip>:8096/emby/Sessions?DeviceId=<device_id>&format=json

 

This will happen until a scheduled task starts and then I see the following repeated quite a few times:

 

Error HttpServer: Error in SharpWebSocket: An exception has occurred while receiving a message.. Exception.Message: Connection reset by peer

 

as well as:

 

Warn HttpServer: Unrecognized WebSocketState: Closing

Warn HttpServer: Unrecognized WebSocketState: Closed

 

Eventually after several hours this will stop and the following error will be in the log:

 

2018-04-07 12:01:22.689 Info HttpClient: HttpClientManager GET: https://emby.media/community/index.php?/blog/rss/1-media-browser-developers-blog
2018-04-07 12:01:22.697 Error HttpClient: Error NameResolutionFailure getting response from https://emby.media/community/index.php?/blog/rss/1-media-browser-developers-blog
        *** Error Report ***
        Version: 3.3.1.0
        Command line: /usr/lib/emby-server/bin/MediaBrowser.Server.Mono.exe -programdata /var/lib/emby-server -restartpath /usr/lib/emby-server/restart.sh
        Operating system: Unix 4.16.0.41600
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: False
        Mono: 4.8.1 (Stable 4.8.1.0/22a39d7 Tue May  2 22:26:20 UTC 2017)
        Processor count: 6
        Program data path: /var/lib/emby-server
        Application directory: /usr/lib/emby-server/bin
        System.Net.WebException: Error: NameResolutionFailure
          at System.Net.HttpWebRequest.EndGetResponse (System.IAsyncResult asyncResult) [0x00064] in <5641e4edad4f4464ba58c620a7b8ea48>:0
          at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (System.IAsyncResult iar, System.Func`2[T,TResult] endFunction, System.Action`1[T] endAction, System.Threading.Tasks.Task`1[TResult] promise, System.Boolean requiresSynchronization) [0x00014] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
        System.Net.WebException
          at System.Net.HttpWebRequest.EndGetResponse (System.IAsyncResult asyncResult) [0x00064] in <5641e4edad4f4464ba58c620a7b8ea48>:0
          at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (System.IAsyncResult iar, System.Func`2[T,TResult] endFunction, System.Action`1[T] endAction, System.Threading.Tasks.Task`1[TResult] promise, System.Boolean requiresSynchronization) [0x00014] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
2018-04-07 12:01:22.700 Error App: Error downloading news
        *** Error Report ***
        Version: 3.3.1.0
        Command line: /usr/lib/emby-server/bin/MediaBrowser.Server.Mono.exe -programdata /var/lib/emby-server -restartpath /usr/lib/emby-server/restart.sh
        Operating system: Unix 4.16.0.41600
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: False
        Mono: 4.8.1 (Stable 4.8.1.0/22a39d7 Tue May  2 22:26:20 UTC 2017)
        Processor count: 6
        Program data path: /var/lib/emby-server
        Application directory: /usr/lib/emby-server/bin
        MediaBrowser.Model.Net.HttpException: Error: NameResolutionFailure ---> System.Net.WebException: Error: NameResolutionFailure
          at System.Net.HttpWebRequest.EndGetResponse (System.IAsyncResult asyncResult) [0x00064] in <5641e4edad4f4464ba58c620a7b8ea48>:0
          at System.Threading.Tasks.TaskFactory`1[TResult].FromAsyncCoreLogic (System.IAsyncResult iar, System.Func`2[T,TResult] endFunction, System.Action`1[T] endAction, System.Threading.Tasks.Task`1[TResult] promise, System.Boolean requiresSynchronization) [0x00014] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
           --- End of inner exception stack trace ---
          at Emby.Server.Implementations.HttpClientManager.HttpClientManager+<SendAsyncInternal>c__async4.MoveNext () [0x00753] in <07306ae2f140476099e69d171d6871b3>:0
        --- End of stack trace from previous location where exception was thrown ---
          at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0004e] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x0002e] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x0000b] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1+ConfiguredTaskAwaiter[TResult].GetResult () [0x00000] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at Emby.Server.Implementations.HttpClientManager.HttpClientManager+<SendAsync>c__async1.MoveNext () [0x00096] in <07306ae2f140476099e69d171d6871b3>:0
        --- End of stack trace from previous location where exception was thrown ---
          at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0004e] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Threading.Tasks.Task task) [0x0002e] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd (System.Threading.Tasks.Task task) [0x0000b] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1+ConfiguredTaskAwaiter[TResult].GetResult () [0x00000] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at Emby.Server.Implementations.News.NewsEntryPoint+<DownloadNews>c__async1.MoveNext () [0x00107] in <07306ae2f140476099e69d171d6871b3>:0
        --- End of stack trace from previous location where exception was thrown ---
          at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Threading.Tasks.Task task) [0x0004e] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0

 

After which I don't see any more of the HTTP logs.  Eventually the following error appears several times:

 

        *** Error Report ***
        Version: 3.3.1.0
        Command line: /usr/lib/emby-server/bin/MediaBrowser.Server.Mono.exe -programdata /var/lib/emby-server -restartpath /usr/lib/emby-server/restart.sh
        Operating system: Unix 4.16.0.41600
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: False
        Mono: 4.8.1 (Stable 4.8.1.0/22a39d7 Tue May  2 22:26:20 UTC 2017)
        Processor count: 6
        Program data path: /var/lib/emby-server
        Application directory: /usr/lib/emby-server/bin
        System.IO.IOException: Too many open files
          at System.IO.Directory+<EnumerateKind>c__Iterator0.MoveNext () [0x0017d] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.IO.DirectoryInfo+<CreateEnumerateFilesIterator>c__Iterator1.MoveNext () [0x00096] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Linq.Enumerable+WhereSelectEnumerableIterator`2[TSource,TResult].MoveNext () [0x00078] in <2392cff65f724abaaed9de072f62bc4a>:0
          at System.Linq.Enumerable+WhereEnumerableIterator`1[TSource].MoveNext () [0x00062] in <2392cff65f724abaaed9de072f62bc4a>:0
          at System.Collections.Generic.List`1[T]..ctor (System.Collections.Generic.IEnumerable`1[T] collection) [0x0008b] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Linq.Enumerable.ToList[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x00011] in <2392cff65f724abaaed9de072f62bc4a>:0
          at Emby.Server.Implementations.ScheduledTasks.Tasks.DeleteCacheFileTask.DeleteCacheFilesFromDirectory (System.Threading.CancellationToken cancellationToken, System.String directory, System.DateTime minDateModified, System.IProgress`1[T] progress) [0x00032] in <07306ae2f140476099e69d171d6871b3>:0
          at Emby.Server.Implementations.ScheduledTasks.Tasks.DeleteCacheFileTask.Execute (System.Threading.CancellationToken cancellationToken, System.IProgress`1[T] progress) [0x00024] in <07306ae2f140476099e69d171d6871b3>:0
          at Emby.Server.Implementations.ScheduledTasks.ScheduledTaskWorker+<ExecuteInternal>c__async2.MoveNext () [0x00146] in <07306ae2f140476099e69d171d6871b3>:0
        System.IO.IOException
          at System.IO.Directory+<EnumerateKind>c__Iterator0.MoveNext () [0x0017d] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.IO.DirectoryInfo+<CreateEnumerateFilesIterator>c__Iterator1.MoveNext () [0x00096] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Linq.Enumerable+WhereSelectEnumerableIterator`2[TSource,TResult].MoveNext () [0x00078] in <2392cff65f724abaaed9de072f62bc4a>:0
          at System.Linq.Enumerable+WhereEnumerableIterator`1[TSource].MoveNext () [0x00062] in <2392cff65f724abaaed9de072f62bc4a>:0
          at System.Collections.Generic.List`1[T]..ctor (System.Collections.Generic.IEnumerable`1[T] collection) [0x0008b] in <dbb16e0bacdc4a0f87478e401bc29b6c>:0
          at System.Linq.Enumerable.ToList[TSource] (System.Collections.Generic.IEnumerable`1[T] source) [0x00011] in <2392cff65f724abaaed9de072f62bc4a>:0
          at Emby.Server.Implementations.ScheduledTasks.Tasks.DeleteCacheFileTask.DeleteCacheFilesFromDirectory (System.Threading.CancellationToken cancellationToken, System.String directory, System.DateTime minDateModified, System.IProgress`1[T] progress) [0x00032] in <07306ae2f140476099e69d171d6871b3>:0
          at Emby.Server.Implementations.ScheduledTasks.Tasks.DeleteCacheFileTask.Execute (System.Threading.CancellationToken cancellationToken, System.IProgress`1[T] progress) [0x00024] in <07306ae2f140476099e69d171d6871b3>:0
          at Emby.Server.Implementations.ScheduledTasks.ScheduledTaskWorker+<ExecuteInternal>c__async2.MoveNext () [0x00146] in <07306ae2f140476099e69d171d6871b3>:0


Looking up the process in /proc/<pid>/fd, I notice that the process has indeed opened 1024 file handles (the processes ulimit), most of which are sockets.  Doing a netstat, I notice that hundreds of sockets on port 8096 are opened with the TV on port 8096, most of which in the ESTABLISHED state.

 

If I leave the server overnight in this state, I notice at the end of the last log file that the last entry is a millisecond before midnight, after which the server attempts to open a new log file, but can't as the process has exceeded its ulimit for open file handles.

 

At this point, no clients can connect to the server (connection attempts time-out).

 

While there seems to be a client issue (which I haven't quite isolated yet), there may also be a server issue too as I can close the client application and restart the TV, but the open sockets are never released at the server end (their TCP state also appears to not change as most connections to the restarted TV still say ESTABLISHED, even though I have yet to open the app).

 

I have to issue a "systemctl stop emby-server" and "systemctl start emby-server" in order for the files/sockets to get released, at which point I notice that the client on the TV makes no attempt to contact the server until I open Kodi on the TV.

 

Is it possible for the server to detect these open yet inactive sockets and close them so that it can handle new requests without having to be restarted?

 

Posted

Hi, it looks like you're using our older installation package. When did you originally install?

Posted

Its been about a year now I think.

Posted

Ok unfortunately I don't have an answer for this other than increasing the open file limit on your system. We are disposing of handles properly but the issues are in the mono runtime.

 

I can give you a better solution, but it's a little more destructive. You could switch to our newer installation package:

https://emby.media/download

 

This is based on Microsoft .NET core now and runs much more efficiently, but just be forewarned it requires a complete uninstallation and purge of your existing version. Thanks.

Posted

Thanks for looking into it.

 

I can use the instructions on https://github.com/MediaBrowser/Wiki/wiki/Backup to keep the configuration after uninstallation/purge?

 

Also, I have been using the PPA at http://download.opensuse.org/repositories/home:/emby/xUbuntu_16.04/. Is it safe to still use this after switching to the newer installation package or should I disable/remove it?

 

BTW I've really enjoyed using Emby.  Thanks!

Posted

Yes those backup instructions will help. You need to make sure it's both uninstall and purge.

 

After you purge you will no longer be using the PPA, it will just be the .deb installation going forward. Thanks.

Posted

I've purged the old Emby and installed the new one, but now I notice that there are many FDs being held open to sockets where the state is in CLOSE_WAIT, but there is a few more bytes (32) left in the receive queue.  For example:

 

Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp       32      0 <server_ip>:53208      163.172.219.181:443     CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:60736      23.21.107.252:443       CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:53354      173.230.139.54:443      CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:49076      52.84.1.121:443         CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:49068      52.84.1.121:443         CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:40164      163.172.72.73:443       CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:49072      52.84.1.121:443         CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:53358      173.230.139.54:443      CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:53360      173.230.139.54:443      CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:49078      52.84.1.121:443         CLOSE_WAIT  22828/EmbyServer
tcp       32      0 <server_ip>:49074      52.84.1.121:443         CLOSE_WAIT  22828/EmbyServer
 

This list grows over time and there are multiple sockets held open to the same server too.

 

In the log I see connections being made to www.thetvdb.com and assets.fanart.tv and I see the following error:

 

2018-04-09 08:41:31.540 Error HttpClient: Connection to https://assets.fanart.tv/fanart/tv/269613/hdtvlogo/fargo-532178fadf836.png timed out
2018-04-09 08:41:31.552 Error HttpServer: Error processing request
        *** Error Report ***
        Version: 3.3.1.0
        Command line: /opt/emby-server/system/EmbyServer.dll -programdata /var/lib/emby -ffmpeg /opt/emby-server/bin/ffmpeg -ffprobe /opt/emby-server/bin/ffprobe -restartexitcode 3 -updatepackage emby-server-deb_{version}_amd64.deb
        Operating system: Unix 4.16.0.41600
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: True
        Processor count: 6
        Program data path: /var/lib/emby
        Application directory: /opt/emby-server/system
        MediaBrowser.Model.Net.HttpException: Connection to https://assets.fanart.tv/fanart/tv/269613/hdtvlogo/fargo-532178fadf836.png timed out ---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
           at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
           at System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsyncInternal>d__20.MoveNext()
           --- End of inner exception stack trace ---
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsyncInternal>d__20.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsync>d__17.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at MediaBrowser.Providers.Manager.ProviderManager.<SaveImage>d__33.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.Library.LibraryManager.<ConvertImageToLocal>d__191.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Drawing.ImageProcessor.<ProcessImage>d__29.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at MediaBrowser.Api.Images.ImageService.<GetImageResult>d__24.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.Services.ServiceExecGeneral.<Execute>d__2.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.Services.ServiceHandler.<ProcessRequestAsync>d__15.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpServer.HttpListenerHost.<RequestHandler>d__74.MoveNext()
        MediaBrowser.Model.Net.HttpException
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsyncInternal>d__20.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsync>d__17.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at MediaBrowser.Providers.Manager.ProviderManager.<SaveImage>d__33.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.Library.LibraryManager.<ConvertImageToLocal>d__191.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Drawing.ImageProcessor.<ProcessImage>d__29.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at MediaBrowser.Api.Images.ImageService.<GetImageResult>d__24.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.Services.ServiceExecGeneral.<Execute>d__2.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.Services.ServiceHandler.<ProcessRequestAsync>d__15.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpServer.HttpListenerHost.<RequestHandler>d__74.MoveNext()
        InnerException: System.Threading.Tasks.TaskCanceledException
        System.Threading.Tasks.TaskCanceledException: A task was canceled.
           at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
           at System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsyncInternal>d__20.MoveNext()
           at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at System.Runtime.CompilerServices.ConfiguredTaskAwaitable`1.ConfiguredTaskAwaiter.GetResult()
           at System.Net.Http.HttpClient.<FinishSendAsyncUnbuffered>d__59.MoveNext()
        --- End of stack trace from previous location where exception was thrown ---
           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
           at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
           at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
           at Emby.Server.Implementations.HttpClientManager.CoreHttpClientManager.<SendAsyncInternal>d__20.MoveNext()

This may be related to getting metadata and I really noticed it now as my whole library was rescanned after putting on the new Emby.

Posted

Are all requests timing out?

Posted

No.  I restarted the server and this time there is no timeout in the log, but I still have 9 sockets in CLOSE_WAIT for EmbyServer with 32 bytes in the receive queue.

  • 4 weeks later...
BJamin99
Posted

I've updated to 3.4.  The original issue posted still remains.  I've tried to dig a bit deeper.  Here is what I see:

 

 

The plugin on the TV sends WebSocket Pings every 10 seconds until there is a gap longer than 10 seconds
EMBY.websocket_client has on_error called with error "argument of type 'int' is not iterable"
EMBY.websocket_client has on_close called

EMBY Kodi plugin establishes new websocket connection

TCP reset is sent on the old connection to emby server
Emby server logs an error: Error HttpServer: Error in SharpWebSocket: An exception has occurred while receiving a message.. Exception.Message: Connection reset by peer
At this point the emby server doesn't seem to actually close the socket.

WebSocket Pings every 10 seconds, until on_error is called again and then cycle repeats.

This causes many "ESTABLISHED" connections to remain on the emby-server, even though those connections have been reset by the peer.  The only way I have found to clear them is to reboot the emby-server process.

 

I haven't been able to completely wrap my head around how the sockets are handled in the emby-server, but it seems like there may be an issue as to how the WebSocket.processException actually works when it is called in the startReceiving function and there is a tcp reset condition.  I believe processException would call "close".  close looks at the _readyState.  At this point, I am assuming that the _readyState is still "Open".  Then it appears that a "closehandshake" will be attempted.  I'm not really sure what will end up happening here, but it doesn't seem to be working.  Given this, is it possible to specifically handle a TCP reset instead of trying to gracefully close the reset connection?

 

Posted

I've updated to 3.4.  The original issue posted still remains.  I've tried to dig a bit deeper.  Here is what I see:

 

 

The plugin on the TV sends WebSocket Pings every 10 seconds until there is a gap longer than 10 seconds

EMBY.websocket_client has on_error called with error "argument of type 'int' is not iterable"

EMBY.websocket_client has on_close called

EMBY Kodi plugin establishes new websocket connection

TCP reset is sent on the old connection to emby server

Emby server logs an error: Error HttpServer: Error in SharpWebSocket: An exception has occurred while receiving a message.. Exception.Message: Connection reset by peer

At this point the emby server doesn't seem to actually close the socket.

 

WebSocket Pings every 10 seconds, until on_error is called again and then cycle repeats.

 

This causes many "ESTABLISHED" connections to remain on the emby-server, even though those connections have been reset by the peer.  The only way I have found to clear them is to reboot the emby-server process.

 

I haven't been able to completely wrap my head around how the sockets are handled in the emby-server, but it seems like there may be an issue as to how the WebSocket.processException actually works when it is called in the startReceiving function and there is a tcp reset condition.  I believe processException would call "close".  close looks at the _readyState.  At this point, I am assuming that the _readyState is still "Open".  Then it appears that a "closehandshake" will be attempted.  I'm not really sure what will end up happening here, but it doesn't seem to be working.  Given this, is it possible to specifically handle a TCP reset instead of trying to gracefully close the reset connection?

 

Hi there, can you please attach the emby server log? thanks.

Posted

I've gone through this and I've confirmed we're closing the connection in this situation. Even if the close handshake fails it still cleans up the server resources. Let's keep an eye on this as we're about to update to .net core 2.1 and that may help with this, as there has been an overhaul to the sockets layer in the runtime. Thanks.

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