BJamin99 0 Posted April 17, 2018 Share Posted April 17, 2018 I am running the following Emby Server: Application version: 3.3.1.0Emby 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/systemPlugins: Server Configuration Backup 1.2.2.0 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 with Libreelec, 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. Every so often I notice the following repeated in the server log several times (approximately every 30 seconds to 1 minute): 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-KodiInfo HttpServer: HTTP Response 204 to <client_ip>. Time: 3ms. http://<server_ip>:8096/emby/Sessions/Capabilities/Full?format=jsonInfo HttpServer: HTTP GET http://<server_ip>:8096/emby/Sessions?DeviceId=<device-id>&format=json. UserAgent: Emby-KodiInfo HttpServer: HTTP Response 200 to <client_ip>. Time: 3ms. http://<server_ip>:8096/emby/Sessions?DeviceId=<device-id>&format=json This will happen until a scheduled task is triggered in the server, at which point I see the following repeated several times: Error HttpServer: Error in SharpWebSocket: An exception has occurred while receiving a message.. Exception.Message: Connection reset by peer And then the the WS/HTTP messages start appearing again. This appears to continue until the Emby process reaches its open files ulimit of 1024 at which time no more connections can be made to the process. Looking at netstat, I see hundreds of ESTABLISHED TCP sessions on server port 8096 with the client. These ESTABLISHED sessions never seem to get closed until the Emby server process is restarted. It seems that this happens when the TV is put in standby and Kodi is running. I'm not sure if this is specifically an Emby issue, but it is where I see the symptoms. I'm not sure if the Emby for Kodi plugin can handle this situation on its own, or if this also needs to be addressed on the Kodi end as well. Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted April 17, 2018 Share Posted April 17, 2018 Can you provide your Kodi log capturing this issue? The post capability is associate with the websocket opening. But perhaps it can be improved when Kodi is on standby. We already pause a few things for that. Sent from my iPhone using Tapatalk 1 Link to comment Share on other sites More sharing options...
BJamin99 0 Posted April 20, 2018 Author Share Posted April 20, 2018 The behaviour changes a bit when I turn logging on. Instead of every 30 seconds to a minute it seems to be happening every five minutes. Here is a snippet from the log during one of these five minute intervals: 18:50:28.756 T:18446744071756085536 DEBUG: CWebServer[8080]: request received for /acr_enabled 18:55:36.303 T:1569192224 DEBUG: Previous line repeats 3 times. 18:55:36.303 T:1569192224 DEBUG: CSMBFile::Open - opened smb://nas/photo/slide show/Scan0066.tif, fd=10000 18:55:36.515 T:2099247392 NOTICE: EMBY.downloadutils -> SessionId: 0b140b53333fef78100f82b66cc965cf 18:55:37.210 T:1569192224 DEBUG: CSMBFile::Close closing fd 10000 18:55:37.211 T:1569192224 DEBUG: DoWork - took 911 ms to load smb://nas/photo/slide show/Scan0066.tif 18:55:37.297 T:18446744071638087968 DEBUG: CSMBFile::Open - opened smb://nas/photo/slide show/Scan0066.tif, fd=10000 18:55:37.322 T:18446744071638087968 DEBUG: CSMBFile::Close closing fd 10000 18:55:37.924 T:18446744071756085536 DEBUG: CWebServer[8080]: request received for /acr_enabled 18:55:51.356 T:1569192224 DEBUG: Previous line repeats 4 times. 18:55:51.357 T:1569192224 DEBUG: CSMBFile::Open - opened smb://nas/photo/2015-04-26/1430054191088.jpg, fd=10000 18:55:51.388 T:1569192224 DEBUG: ffmpeg[5D87F920]: [swscaler] No accelerated colorspace conversion found from yuv420p to bgra. 18:55:51.391 T:1569192224 DEBUG: CSMBFile::Close closing fd 10000 18:55:52.351 T:18446744071638087968 DEBUG: CSMBFile::Open - opened smb://nas/photo/2015-04-26/1430054191088.jpg, fd=10000 18:55:52.356 T:18446744071638087968 DEBUG: CSMBFile::Close closing fd 10000 18:55:52.932 T:18446744071756085536 DEBUG: CWebServer[8080]: request received for /acr_enabled Most of the log seems to have to do with the slideshow screensaver accessing the nas to get a picture and the WebUI. Link to comment Share on other sites More sharing options...
sualfred 677 Posted April 20, 2018 Share Posted April 20, 2018 @@BJamin99 Please always post a complete log. A lot of important informations are getting lost with snippets. 1 Link to comment Share on other sites More sharing options...
BJamin99 0 Posted April 22, 2018 Author Share Posted April 22, 2018 Please find attached the log. Cheers. kodi.log Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted April 23, 2018 Share Posted April 23, 2018 I am looking at your log, this doesn't trigger any kodi events so I don't think it is fixable in a direct way. I guess I could change the websocket to ask to restart rather than retry by itself?... 1 Link to comment Share on other sites More sharing options...
BJamin99 0 Posted May 6, 2018 Author Share Posted May 6, 2018 I've updated to emby-server 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 secondsEMBY.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 serverEmby server logs an error: Error HttpServer: Error in SharpWebSocket: An exception has occurred while receiving a message.. Exception.Message: Connection reset by peerAt 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. I'm not sure where the "argument of type 'int' is not iterable" actually comes from though. Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted May 6, 2018 Share Posted May 6, 2018 It's when the connection to your server is ended unexpectedly. We already know why this is happening, just don't have a solution other than not retry to connect automatically. I also don't understand why turning off your TV would mess with your connection to your server. I also leave Kodi running and turn off my TV, but my websocket connection persists. 1 Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted May 10, 2018 Share Posted May 10, 2018 (edited) I've changed the behavior around the websocket connection. Hopefully it will resolve your issue. Thank you for your patience, let me know if 3.0.23 helps any. Edited May 11, 2018 by Angelblue05 1 Link to comment Share on other sites More sharing options...
Recommended Posts