Jump to content

Emby 3.5.3 Web Socket error


ddurdle

Recommended Posts

ddurdle

I've ran into an issue on Oct 7 (twice) and today (Oct 10) on an emby 3.5.3 server running on Debian Stretch.  Emby starts to encounter a web socket error and begins to dump the same message repeately to the log, ballooning it in size from < 300mb to 3-5GB.  If I don't catch the condition right away (within 15 mins), Emby consumes all the system memory and bring the server down.

 

I've attached the log from the occurrence today.  I had to split the log to upload it.  The only thing suspicious was an innocent subtitle error that occurred before the first web socket errors.

 

embyserver.2.log.gz is the end of the log and embyserver.1.log.gz is the start of the log.

 

embyserver.2.log.gz

embyserver.1.log.gz

Link to comment
Share on other sites

ddurdle

Yes, Emby causes the server to hang with out of memory if emby is not forceably restarted right after these web socket errors begin to appear (within 30 mins).  This has happened 3 times in the last 4 days.

Link to comment
Share on other sites

ddurdle

Thank you.

 

Will that be a 3.5.4 (incremental stable release) or added to 3.6.x?

 

I have some helpers testing 3.6.x and it is going well.

Link to comment
Share on other sites

ddurdle

Is there a way to mitigate the risk?  I've had the server go down a few times now because of the issue.  Is there a particular client device type that causes it, or some behaviour of a client that induces the issue?

Link to comment
Share on other sites

I'm not sure. It's code that I took from the Microsoft's .net core repo and I've fixed it myself to avoid the error. I've never reproduced it myself and it's only been reported by a small number of people.

Link to comment
Share on other sites

  • 2 months later...
ddurdle

Still occurring in Emby 3.6 with log attached.

 

Might be far-reaching here, but could it be somehow related to IPTV?  I've been helping 4 users who are using Emby 3.6 and only 1 so far has encountered the issue (about the 12th time now) -- he's the only one using IPTV.

 

Log of most recent occurrence attached.

 

embyserver-63681137101.txt

Edited by ddurdle
Link to comment
Share on other sites

No, it's not occurring. Looks like you're trying to connect with an app that's using an unsupported version of the web socket protocol:

net_WebSockets_AcceptUnsupportedWebSocketVersion
Link to comment
Share on other sites

ddurdle

I saw from the previous logs posted here this error:

System.Net.WebSockets.WebSocketException: System.Net.WebSockets.WebSocketException (0x80004005): net_WebSockets_AcceptUnsupportedWebSocketVersion

 

So I assumed this was a re-occurrence of the same issue.  Are you saying now the error won't keep repeating itself until the server goes down?  

Link to comment
Share on other sites

We'll I'm not able to easily test this but I think it should be fine. It is quickly rejecting the web socket requests.

Link to comment
Share on other sites

ddurdle

Right now I deploy a monitor that watches the logs for this error and if detects, restart emby.  Without the monitor, the error normally occurs on a rapid repeating nature that it causes memory and disk usage to spike until the server goes down.  I'll ask the user if they want to remove the monitor to observe if the error subsides on it's own.

Link to comment
Share on other sites

Do you know what app that is? They are not supplying a user-agent with their http requests.

 

I would post the log but its 35GB...

 

I think im having the same problem as OP which is the same error on the tail end of my logs

2018-12-26 17:23:58.665 Error HttpServer: WebSocketException Success
	*** Error Report ***
	Version: 3.5.3.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.15.0.43
	64-Bit OS: True
	64-Bit Process: True
	User Interactive: True
	Processor count: 4
	Program data path: /var/lib/emby
	Application directory: /opt/emby-server/system
	System.Net.WebSockets.WebSocketException (2): net_WebSockets_InvalidState
	   at SocketHttpListener.Net.WebSockets.WebSocketValidate.ThrowIfInvalidState(WebSocketState currentState, Boolean isDisposed, WebSocketState[] validStates)
	   at SocketHttpListener.Net.WebSockets.ManagedWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
	--- End of stack trace from previous location where exception was thrown ---
	   at SocketHttpListener.Net.WebSockets.WebSocket.ReceiveAsync(Memory`1 buffer, CancellationToken cancellationToken)
	   at EmbyServer.SocketSharp.SharpWebSocket.StartReceive()
	System.Net.WebSockets.WebSocketException
	   at SocketHttpListener.Net.WebSockets.WebSocketValidate.ThrowIfInvalidState(WebSocketState currentState, Boolean isDisposed, WebSocketState[] validStates)
	   at SocketHttpListener.Net.WebSockets.ManagedWebSocket.ReceiveAsync(ArraySegment`1 buffer, CancellationToken cancellationToken)
	--- End of stack trace from previous location where exception was thrown ---
	   at SocketHttpListener.Net.WebSockets.WebSocket.ReceiveAsync(Memory`1 buffer, CancellationToken cancellationToken)
	   at EmbyServer.SocketSharp.SharpWebSocket.StartReceive()

I use Fire stick 4K, emby for android and browsers that cast to chromecast ultra.  

Link to comment
Share on other sites

This is resolved for the upcoming 3.6 release of Emby Server, thanks.

Sorry, I thought OP said he was on dev version and it was still happening, the second log posted shows the same error with Version: 3.6.0.76 but if its fixed then nvm thanks

Link to comment
Share on other sites

DRAGUNSLAYER

Right now I deploy a monitor that watches the logs for this error and if detects, restart emby. Without the monitor, the error normally occurs on a rapid repeating nature that it causes memory and disk usage to spike until the server goes down. I'll ask the user if they want to remove the monitor to observe if the error subsides on it's own.

Please share your wonderful monitor.

 

Sent from my SM-G965W using Tapatalk

Link to comment
Share on other sites

ddurdle

Please share your wonderful monitor.

 

Sent from my SM-G965W using Tapatalk

 

You can adapt it from here:

https://github.com/ddurdle/GoogleDrive-VideoStream_extra/blob/master/emby%20helpers/monitor_emby.pl

 

You would need these two files in the same directory:

https://github.com/ddurdle/GoogleDrive-VideoStream_extra/blob/master/crawler.pm

https://github.com/ddurdle/GoogleDrive-VideoStream_extra/blob/master/common.config

 

It's not doing anything sophisticated.  Simply looks for the websocket error in the embyserver.txt log and then restart the instance if it finds it.  There is also logic in the same script that monitors responsiveness of the instance and restarts it if it is not responding.  I have the script take an optional webhook to push out a notification so I can track when these events happen.

Link to comment
Share on other sites

  • 6 months later...

Mind if I ask how can I use this script ? 

 

Hi there, what are you trying to accomplish?

Link to comment
Share on other sites

borygo77

Hi Luke! Thank you for your quick response! The problem I'm facing is this error 

 

2019-07-12 04:46:47.639 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/2887667ae8c115a4b46e7b789c62d075/Images/Primary/0?Format=original&Tag=7924c04e257492b939a6dcef039e4253. $

2019-07-12 04:46:47.721 Info HttpServer: HTTP Response 200 to 192.168.1.112. Time: 82ms. http://192.168.1.111:8096/emby/Items/2887667ae8c115a4b46e7b789c62d075/Images/Primary/0?Format=original&$
2019-07-12 04:46:47.814 Info HttpServer: HTTP Response 200 to 192.168.1.112. Time: 79ms. http://192.168.1.111:8096/emby/Items/f39aec51c55c13e161aa5c117253cc3f/Images/Primary/0?Format=original&$
2019-07-12 04:46:52.324 Info HttpServer: HTTP Response 200 to 192.168.1.112. Time: 2ms. http://192.168.1.111:8096/emby/Items/c2ca0f3def1a8aab76ad1338ab259697/Images/Primary/0?Format=original&T$
2019-07-12 04:46:52.408 Info HttpServer: HTTP Response 200 to 192.168.1.112. Time: 65ms. http://192.168.1.111:8096/emby/Items/59dbe91404ec9ea562029d41f7c24370/Images/Primary/0?Format=original&$
2019-07-12 04:46:52.548 Error HttpServer: Error processing request
        *** Error Report ***
        Version: 3.5.3.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 -updatepack$
        Operating system: Unix 4.4.0.154
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: True
        Processor count: 2
        Program data path: /var/lib/emby
        Application directory: /opt/emby-server/system
        MediaBrowser.Common.Extensions.ResourceNotFoundException: Item 3b7cd99bc922f78ff6ec2f45fd86031c not found.
           at MediaBrowser.Api.Images.ImageService.GetImage(ImageRequest request, Guid itemId, BaseItem item, Boolean isHeadRequest)
           at Emby.Server.Implementations.Services.ServiceExecGeneral.Execute(Type serviceType, IRequest request, Object instance, Object requestDto, String requestName)
           at Emby.Server.Implementations.Services.ServiceController.Execute(HttpListenerHost appHost, Object requestDto, IRequest req)
           at Emby.Server.Implementations.Services.ServiceHandler.ProcessRequestAsync(HttpListenerHost appHost, IRequest httpReq, IResponse httpRes, ILogger logger, String operationName, Cance$
           at Emby.Server.Implementations.HttpServer.HttpListenerHost.RequestHandler(IHttpRequest httpReq, String urlString, String host, String localPath, CancellationToken cancellationToken)
        MediaBrowser.Common.Extensions.ResourceNotFoundException
           at MediaBrowser.Api.Images.ImageService.GetImage(ImageRequest request, Guid itemId, BaseItem item, Boolean isHeadRequest)
           at Emby.Server.Implementations.Services.ServiceExecGeneral.Execute(Type serviceType, IRequest request, Object instance, Object requestDto, String requestName)
           at Emby.Server.Implementations.Services.ServiceController.Execute(HttpListenerHost appHost, Object requestDto, IRequest req)
           at Emby.Server.Implementations.Services.ServiceHandler.ProcessRequestAsync(HttpListenerHost appHost, IRequest httpReq, IResponse httpRes, ILogger logger, String operationName, Cance$
           at Emby.Server.Implementations.HttpServer.HttpListenerHost.RequestHandler(IHttpRequest httpReq, String urlString, String host, String localPath, CancellationToken cancellationToken)
 
2019-07-12 04:46:52.549 Info HttpServer: HTTP Response 404 to 192.168.1.112. Time: 5247ms (slow). http://192.168.1.111:8096/emby/Items/3b7cd99bc922f78ff6ec2f45fd86031c/Images/Primary/0?Format=$
2019-07-12 04:46:58.093 Info HttpServer: HTTP Response 200 to 192.168.1.112. Time: 83ms. http://192.168.1.111:8096/emby/Items/48db6500a0e6d68b593c30d6911d3067/Images/Primary/0?Format=original&$
2019-07-12 04:46:58.107 Info HttpServer: HTTP Response 200 to 192.168.1.112. Time: 4ms. http://192.168.1.111:8096/emby/Items/194586f1a00901d3a406524a22a9f376/Images/Primary/0?Format=original&T$

 

 

 

2019-07-12 07:31:18.083 Error HttpServer: WebSocket ConnectionClosedPrematurely

2019-07-12 07:35:06.838 Info TaskManager: IntervalTrigger fired for task: Import playstates from Trakt.tv
2019-07-12 07:35:06.838 Info TaskManager: Queueing task SyncFromTraktTask
2019-07-12 07:35:06.839 Info TaskManager: Executing Import playstates from Trakt.tv
2019-07-12 07:35:06.839 Info HttpClient: GET https://api.trakt.tv/sync/watched/movies
2019-07-12 07:35:07.297 Info HttpClient: GET https://api.trakt.tv/sync/watched/shows
2019-07-12 07:35:07.637 Info Trakt: Trakt.tv watched Movies count = 657
2019-07-12 07:35:07.638 Info Trakt: Trakt.tv watched Shows count = 114
2019-07-12 07:35:08.401 Info TaskManager: Import playstates from Trakt.tv Completed after 0 minute(s) and 1 seconds
2019-07-12 07:35:08.419 Info TaskManager: ExecuteQueuedTasks
2019-07-12 07:39:29.642 Info HttpServer: HTTP Response 200 to 192.168.1.113. Time: 383ms. http://192.168.1.111:8096/emby/Users/087755af590f4cdab1b43cf0c2aa3753/Items?Fields=Path%2CGenres%2CSor$
2019-07-12 07:43:27.271 Error HttpServer: WebSocket ConnectionClosedPrematurely
2019-07-12 07:43:27.484 Error HttpServer: Error closing web socket response
        *** Error Report ***
        Version: 3.5.3.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 -updatepack$
        Operating system: Unix 4.4.0.154
        64-Bit OS: True
        64-Bit Process: True
        User Interactive: True
        Processor count: 2
        Program data path: /var/lib/emby
        Application directory: /opt/emby-server/system
        System.Net.Sockets.SocketException (32): Broken pipe
           at SocketHttpListener.SocketStream.Write(Byte[] buffer, Int32 offset, Int32 count)
           at SocketHttpListener.Net.HttpResponseStream.DisposeCore()
           at SocketHttpListener.Net.HttpResponseStream.Dispose(Boolean disposing)
           at SocketHttpListener.Net.HttpConnection.Close(Boolean force)
           at EmbyServer.SocketSharp.WebSocketSharpListener.TryClose(HttpListenerContext ctx, Int32 statusCode)
        System.Net.Sockets.SocketException
           at SocketHttpListener.SocketStream.Write(Byte[] buffer, Int32 offset, Int32 count)
           at SocketHttpListener.Net.HttpResponseStream.DisposeCore()
           at SocketHttpListener.Net.HttpResponseStream.Dispose(Boolean disposing)
           at SocketHttpListener.Net.HttpConnection.Close(Boolean force)
           at EmbyServer.SocketSharp.WebSocketSharpListener.TryClose(HttpListenerContext ctx, Int32 statusCode)
 
2019-07-12 07:43:43.920 Info HttpServer: HTTP Response 200 to 192.168.1.113. Time: 6ms. http://192.168.1.111:8096/emby/Items/47899c9507cbfcdfb50738ea5c445165/Images/Primary/0?EnableImageEnhanc$
2019-07-12 07:43:44.555 Info HttpServer: HTTP Response 200 to 192.168.1.113. Time: 588ms. http://192.168.1.111:8096/emby/Items/46ae5467b3c40003cbf10c0f33873b27/Images/Primary/0?EnableImageEnha$
2019-07-12 07:43:44.555 Info HttpServer: HTTP Response 200 to 192.168.1.113. Time: 509ms. http://192.168.1.111:8096/emby/Items/46ae5467b3c40003cbf10c0f33873b27/Images/Primary/0?EnableImageEnha$
2019-07-12 07:43:44.709 Info HttpServer: HTTP Response 200 to 192.168.1.113. Time: 135ms. http://192.168.1.111:8096/emby/Items/c2ca0f3def1a8aab76ad1338ab259697/Images/Primary/0?EnableImageEnh

 

 

As you can see it happens quite often. Emby eats my memory really bad ;)

 

5d28f7fe241f2_1.png

 

 

 

Got 4GB memory in my server and nearly all taken by emby.... Not sure if this error is the reason ? 


ID	Owner	Size	Command
1227	emby	3.39 GB	/opt/emby-server/system/EmbyServer -programdata /var/lib/emby -ffmpeg /opt/emby- ...
Edited by borygo77
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...