ddurdle 75 Posted October 11, 2018 Posted October 11, 2018 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
ddurdle 75 Posted October 11, 2018 Author Posted October 11, 2018 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.
Luke 40131 Posted October 11, 2018 Posted October 11, 2018 Those socket errors are resolved for the next release, thanks.
ddurdle 75 Posted October 11, 2018 Author Posted October 11, 2018 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.
ddurdle 75 Posted October 17, 2018 Author Posted October 17, 2018 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?
Luke 40131 Posted October 17, 2018 Posted October 17, 2018 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.
ddurdle 75 Posted December 24, 2018 Author Posted December 24, 2018 (edited) 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 December 24, 2018 by ddurdle
Luke 40131 Posted December 24, 2018 Posted December 24, 2018 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
ddurdle 75 Posted December 24, 2018 Author Posted December 24, 2018 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?
Luke 40131 Posted December 24, 2018 Posted December 24, 2018 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.
ddurdle 75 Posted December 24, 2018 Author Posted December 24, 2018 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.
Luke 40131 Posted December 24, 2018 Posted December 24, 2018 So whatever app that is is hammering the server with requests.
Luke 40131 Posted December 24, 2018 Posted December 24, 2018 Do you know what app that is? They are not supplying a user-agent with their http requests.
crypto 1 Posted December 27, 2018 Posted December 27, 2018 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.
Luke 40131 Posted December 27, 2018 Posted December 27, 2018 This is resolved for the upcoming 3.6 release of Emby Server, thanks.
crypto 1 Posted December 27, 2018 Posted December 27, 2018 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
Luke 40131 Posted December 27, 2018 Posted December 27, 2018 If you read my response I explained that it was not the same error.
DRAGUNSLAYER 2 Posted December 29, 2018 Posted December 29, 2018 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
ddurdle 75 Posted January 3, 2019 Author Posted January 3, 2019 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.
Luke 40131 Posted July 12, 2019 Posted July 12, 2019 Mind if I ask how can I use this script ? Hi there, what are you trying to accomplish?
borygo77 2 Posted July 12, 2019 Posted July 12, 2019 (edited) 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.735 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/f39aec51c55c13e161aa5c117253cc3f/Images/Primary/0?Format=original&Tag=304d02a61ad6a6541d0afc31099985f4. $ 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.322 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/c2ca0f3def1a8aab76ad1338ab259697/Images/Primary/0?Format=original&Tag=6303ffcffcaad40e280255b4595c5397. $ 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.342 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/59dbe91404ec9ea562029d41f7c24370/Images/Primary/0?Format=original&Tag=3a6400d86ec51b489ee9635ab478a222. $ 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.010 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/48db6500a0e6d68b593c30d6911d3067/Images/Primary/0?Format=original&Tag=c95275f53cb2a70c7f0fc3b946bb472c. $ 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.103 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/194586f1a00901d3a406524a22a9f376/Images/Primary/0?Format=original&Tag=2a08c6ad150018436b9cd17c1810d162. $ 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 04:46:58.118 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/058d5e76a48afc0f584b7ddf61b311e0/Images/Primary/0?Format=original&Tag=90cdf5fc92fc52600be10cd8db2d7a3c. 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.259 Info HttpServer: HTTP GET http://192.168.1.111:8096/emby/Users/087755af590f4cdab1b43cf0c2aa3753/Items?Fields=Path%2CGenres%2CSortName%2CStudios%2CWriter%2CTaglines%2CLo$ 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.914 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/47899c9507cbfcdfb50738ea5c445165/Images/Primary/0?EnableImageEnhancers=True&Tag=58243fabe282498c7bc5667e$ 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:43.967 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/46ae5467b3c40003cbf10c0f33873b27/Images/Primary/0?EnableImageEnhancers=True&Tag=12d49a4db7245d74a3c1669a$ 2019-07-12 07:43:44.046 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/46ae5467b3c40003cbf10c0f33873b27/Images/Primary/0?EnableImageEnhancers=True&Tag=12d49a4db7245d74a3c1669a$ 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.566 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/c2ca0f3def1a8aab76ad1338ab259697/Images/Primary/0?EnableImageEnhancers=True&Tag=6303ffcffcaad40e280255b4$ 2019-07-12 07:43:44.574 Info HttpServer: HTTP HEAD http://192.168.1.111:8096/emby/Items/c2ca0f3def1a8aab76ad1338ab259697/Images/Primary/0?EnableImageEnhancers=True&Tag=6303ffcffcaad40e280255b4$ 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 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 July 12, 2019 by borygo77
Luke 40131 Posted July 12, 2019 Posted July 12, 2019 Can you install the latest version of emby server?
Recommended Posts
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 accountSign in
Already have an account? Sign in here.
Sign In Now