Can not play any video content

[Legogris]

Plugin release: 0.5.9
Jellyfin version: 0.6.3 (SSL, CA trusted)

When trying to playing any video, eternally loading with logs:

2020-08-25 11:02:07.457 T:140041856677632  NOTICE: JELLYFIN.jellyfin.ws_client -> INFO::jellyfin_kodi/jellyfin/ws_client.py:50 Websocket url: wss://{jellyfin-server}/socket?api_key={jellyfin-token}&device_id=abc
2020-08-25 11:02:07.934 T:140041856677632  NOTICE: JELLYFIN.jellyfin.ws_client -> INFO::jellyfin_kodi/jellyfin/ws_client.py:70 --->[ websocket ]
2020-08-25 11:02:10.354 T:140042202052352  NOTICE: JELLYFIN.helper.utils -> INFO::jellyfin_kodi/helper/utils.py:513 Add-on playback: True
2020-08-25 11:02:10.509 T:140041846974208  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:83 --->[ library ]
2020-08-25 11:02:10.512 T:140042202052352  NOTICE: JELLYFIN.monitor -> INFO::jellyfin_kodi/monitor.py:299 --[ post capabilities/b8f14b5d217f401584fa553bcfb783d0 ]
2020-08-25 11:02:10.538 T:140043860498176  NOTICE: VideoInfoScanner: Starting scan ..
2020-08-25 11:02:10.546 T:140043860498176  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
2020-08-25 11:02:11.000 T:140042202052352  NOTICE: JELLYFIN.jellyfin.http -> ERROR::jellyfin_kodi/jellyfin/http.py:124 400 Client Error: Bad Request for url: https://{jellyfin-server}/Sessions/Capabilities/Full
2020-08-25 11:02:11.200 T:140041762367232  NOTICE: JELLYFIN.entrypoint.default -> INFO::jellyfin_kodi/entrypoint/default.py:56 path: ?content_type=video params: {
                                                "content_type": "video"
                                            }
2020-08-25 11:02:11.204 T:140042202052352   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <class 'helper.exceptions.HTTPException'>
                                            Traceback (most recent call last):
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/monitor.py", line 261, in onNotification
                                                self.server_instance(data['ServerId'])
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/monitor.py", line 281, in server_instance
                                                self.post_capabilities(server)
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/monitor.py", line 305, in post_capabilities
                                                "MoveUp,MoveDown,MoveLeft,MoveRight,Select,"
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 312, in post_capabilities
                                                return self.sessions("/Capabilities/Full", "POST", json=data)
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 80, in sessions
                                                return self._post("Sessions%s" % handler, json, params)
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 64, in _post
                                                return self._http("POST", handler, {'params': params, 'json': json})
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 58, in _http
                                                return self.client.request(request)
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/http.py", line 151, in request
                                                raise HTTPException(r.status_code, error)
                                            HTTPException
                                            -->End of Python script error report<--
2020-08-25 11:02:11.205 T:140041846974208  NOTICE: JELLYFIN.database -> ERROR::jellyfin_kodi/database/__init__.py:151 Database: /home/legogris/.kodi/userdata/Database/MyVideos107.db missing
                                            Traceback (most recent call last):
                                              File "jellyfin_kodi/database/__init__.py", line 149, in _sql
                                                loaded = self._get_database(databases[file]) if file in databases else file
                                              File "jellyfin_kodi/database/__init__.py", line 84, in _get_database
                                                raise Exception("Database: %s missing" % path)
                                            Exception: Database: /home/legogris/.kodi/userdata/Database/MyVideos107.db missing
2020-08-25 11:02:11.207 T:140041846974208  NOTICE: JELLYFIN.database -> INFO::jellyfin_kodi/database/__init__.py:175 Database locked in: /home/legogris/.kodi/userdata/Database/MyVideos116.db
2020-08-25 11:02:11.214 T:140042202052352  NOTICE: JELLYFIN.monitor -> INFO::jellyfin_kodi/monitor.py:43 -->[ kodi scan/video ]
2020-08-25 11:02:11.215 T:140042202052352  NOTICE: JELLYFIN.monitor -> INFO::jellyfin_kodi/monitor.py:46 --<[ kodi scan/video ]
2020-08-25 11:02:11.225 T:140041846974208  NOTICE: JELLYFIN.database -> ERROR::jellyfin_kodi/database/__init__.py:151 Database: /home/legogris/.kodi/userdata/Database/MyMusic60.db missing
                                            Traceback (most recent call last):
                                              File "jellyfin_kodi/database/__init__.py", line 149, in _sql
                                                loaded = self._get_database(databases[file]) if file in databases else file
                                              File "jellyfin_kodi/database/__init__.py", line 84, in _get_database
                                                raise Exception("Database: %s missing" % path)
                                            Exception: Database: /home/user/.kodi/userdata/Database/MyMusic60.db missing

I'm guessing at least the missing db errors are unrelated.

Then for any attempt:

20-08-25 11:08:48.022 T:140042202052352  NOTICE: JELLYFIN.jellyfin.http -> ERROR::jellyfin_kodi/jellyfin/http.py:124 400 Client Error: Bad Request for url: https://{jellyfin-server}/Items/0a1f2f7f-dd1c-36cd-b4f3-b521e2a2226e/PlaybackInf
o
2020-08-25 11:08:48.023 T:140042202052352   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <class 'helper.exceptions.HTTPException'>
                                            Traceback (most recent call last):
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/monitor.py", line 152, in onNotification
                                                sources = server.jellyfin.get_play_info(data['Id'], data['Profile'])
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 342, in get_play_info
                                                'AutoOpenLiveStream': True
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 96, in items
                                                return self._post("Items%s" % handler, json, params)
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 64, in _post
                                                return self._http("POST", handler, {'params': params, 'json': json})
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 58, in _http
                                                return self.client.request(request)
                                              File "/home/legogris/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/http.py", line 151, in request
                                                raise HTTPException(r.status_code, error)
                                            HTTPException
                                            -->End of Python script error report<--

I think this looks unrelated to #354

[oddstr13]

Behind reverse proxy?

Could you provide server logs?

[Legogris]

@oddstr13 Yes, but I do not think that is related in this case.

Server logs seem to point at what's going on. Note that I'm otherwise successfully logged in and library sync is working.

[21:39:45] [WRN] [68] Jellyfin.Server.Middleware.ResponseTimeMiddleware: Slow HTTP Response from http://[REDACTED]/Sessions/Playing/Progress to ::ffff:10.1.2.42 in 0:00:00.7953989 with Status Code 204
[21:39:55] [WRN] [36] Jellyfin.Server.Middleware.ResponseTimeMiddleware: Slow HTTP Response from http://[REDACTED]/Sessions/Playing/Progress to ::ffff:10.1.2.42 in 0:00:00.601481 with Status Code 204
[21:40:07] [INF] [22] Jellyfin.Api.Controllers.MediaInfoController: GetPostedPlaybackInfo profile: {"Name": "Kodi", "Id": null, "Identification": null, "FriendlyName": null, "Manufacturer": null, "ManufacturerUrl": null, "ModelName": null, "ModelDescription": null, "ModelNumber": null, "ModelUrl": null, "SerialNumber": null, "EnableAlbumArtInDidl": false, "EnableSingleAlbumArtLimit": false, "EnableSingleSubtitleLimit": false, "SupportedMediaTypes": "Audio,Photo,Video", "UserId": null, "AlbumArtPn": null, "MaxAlbumArtWidth": 0, "MaxAlbumArtHeight": 0, "MaxIconWidth": null, "MaxIconHeight": null, "MaxStreamingBitrate": 100000000, "MaxStaticBitrate": 8000000, "MusicStreamingTranscodingBitrate": 1280000, "MaxStaticMusicBitrate": null, "SonyAggregationFlags": null, "ProtocolInfo": null, "TimelineOffsetSeconds": 5, "RequiresPlainVideoItems": false, "RequiresPlainFolders": false, "EnableMSMediaReceiverRegistrar": false, "IgnoreTranscodeByteRangeRequests": false, "XmlRootAttributes": [], "DirectPlayProfiles": [{"Container": null, "AudioCodec": null, "VideoCodec": null, "Type": "Video", "$type": "DirectPlayProfile"}, {"Container": null, "AudioCodec": null, "VideoCodec": null, "Type": "Audio", "$type": "DirectPlayProfile"}, {"Container": null, "AudioCodec": null, "VideoCodec": null, "Type": "Photo", "$type": "DirectPlayProfile"}], "TranscodingProfiles": [{"Container": "m3u8", "Type": "Video", "VideoCodec": "h264,h265,hevc,mpeg4,mpeg2video", "AudioCodec": "aac,mp3,ac3,opus,flac,vorbis", "Protocol": null, "EstimateContentLength": false, "EnableMpegtsM2TsMode": false, "TranscodeSeekInfo": "Auto", "CopyTimestamps": false, "Context": "Streaming", "EnableSubtitlesInManifest": false, "MaxAudioChannels": "6", "MinSegments": 0, "SegmentLength": 0, "BreakOnNonKeyFrames": false, "$type": "TranscodingProfile"}, {"Container": null, "Type": "Audio", "VideoCodec": null, "AudioCodec": null, "Protocol": null, "EstimateContentLength": false, "EnableMpegtsM2TsMode": false, "TranscodeSeekInfo": "Auto", "CopyTimestamps": false, "Context": "Streaming", "EnableSubtitlesInManifest": false, "MaxAudioChannels": null, "MinSegments": 0, "SegmentLength": 0, "BreakOnNonKeyFrames": false, "$type": "TranscodingProfile"}, {"Container": "m3u8", "Type": "Video", "VideoCodec": "h264,mpeg4,mpeg2video", "AudioCodec": "aac,mp3,ac3,opus,flac,vorbis", "Protocol": null, "EstimateContentLength": false, "EnableMpegtsM2TsMode": false, "TranscodeSeekInfo": "Auto", "CopyTimestamps": false, "Context": "Streaming", "EnableSubtitlesInManifest": false, "MaxAudioChannels": "6", "MinSegments": 0, "SegmentLength": 0, "BreakOnNonKeyFrames": false, "$type": "TranscodingProfile"}, {"Container": "jpeg", "Type": "Photo", "VideoCodec": null, "AudioCodec": null, "Protocol": null, "EstimateContentLength": false, "EnableMpegtsM2TsMode": false, "TranscodeSeekInfo": "Auto", "CopyTimestamps": false, "Context": "Streaming", "EnableSubtitlesInManifest": false, "MaxAudioChannels": null, "MinSegments": 0, "SegmentLength": 0, "BreakOnNonKeyFrames": false, "$type": "TranscodingProfile"}], "ContainerProfiles": [], "CodecProfiles": [], "ResponseProfiles": [], "SubtitleProfiles": [{"Format": "srt", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "srt", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "ass", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "ass", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "sub", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "sub", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "ssa", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "ssa", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "smi", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "smi", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "pgssub", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "pgssub", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "dvdsub", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "dvdsub", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "pgs", "Method": "Embed", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}, {"Format": "pgs", "Method": "External", "DidlMode": null, "Language": null, "Container": null, "$type": "SubtitleProfile"}], "$type": "DeviceProfile"}
[21:40:07] [ERR] [22] Jellyfin.Server.Middleware.ExceptionMiddleware: Error processing request. URL POST /Items/[REDACTED]/PlaybackInfo.
System.ArgumentException: Guid can't be empty (Parameter 'id')
   at Jellyfin.Server.Implementations.Users.UserManager.GetUserById(Guid id)
   at Jellyfin.Api.Controllers.MediaInfoController.SetDeviceSpecificData(BaseItem item, MediaSourceInfo mediaSource, DeviceProfile profile, AuthorizationInfo auth, Nullable`1 maxBitrate, Int64 startTimeTicks, String mediaSourceId, Nullable`1 audioStreamIndex, Nullable`1 subtitleStreamIndex, Nullable`1 maxAudioChannels, String playSessionId, Guid userId, Boolean enableDirectPlay, Boolean enableDirectStream, Boolean enableTranscoding, Boolean allowVideoStreamCopy, Boolean allowAudioStreamCopy)
   at Jellyfin.Api.Controllers.MediaInfoController.GetPostedPlaybackInfo(Guid itemId, Nullable`1 userId, Nullable`1 maxStreamingBitrate, Nullable`1 startTimeTicks, Nullable`1 audioStreamIndex, Nullable`1 subtitleStreamIndex, Nullable`1 maxAudioChannels, String mediaSourceId, String liveStreamId, DeviceProfileDto deviceProfile, Boolean autoOpenLiveStream, Boolean enableDirectPlay, Boolean enableDirectStream, Boolean enableTranscoding, Boolean allowVideoStreamCopy, Boolean allowAudioStreamCopy)
   at lambda_method(Closure , Object )
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableObjectResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResourceFilter>g__Awaited|24_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeFilterPipelineAsync()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Swashbuckle.AspNetCore.ReDoc.ReDocMiddleware.Invoke(HttpContext httpContext)
   at Swashbuckle.AspNetCore.SwaggerUI.SwaggerUIMiddleware.Invoke(HttpContext httpContext)
   at Swashbuckle.AspNetCore.Swagger.SwaggerMiddleware.Invoke(HttpContext httpContext, ISwaggerProvider swaggerProvider)
   at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.ResponseCompression.ResponseCompressionMiddleware.Invoke(HttpContext context)
   at Jellyfin.Server.Middleware.ResponseTimeMiddleware.Invoke(HttpContext context)
   at Jellyfin.Server.Middleware.ExceptionMiddleware.Invoke(HttpContext context)

(Where the last [REDACTED] is an actual guid)

[Legogris]

This is a bit of a guess and haven't tried yet but possibly this is resolved by jellyfin/jellyfin@340f83c

[Legogris]

20200827.9-unstable gives same result as above so still an issue. Some trailing log context that I think I jut missed last time:

2020-08-27 22:29:39.680 T:140357442463488  NOTICE: JELLYFIN.objects.actions -> INFO::jellyfin_kodi/objects/actions.py:49 [ play/61251361-ea78-db8f-7a42-d5723ba8f6a7 ] Never Give In
2020-08-27 22:29:39.685 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:387 ---[ contact MU-TH-UR 6000/GetToken ]
2020-08-27 22:29:39.795 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/8282c3c2-940e-4f10-a31d-102da7d19db2 ]
2020-08-27 22:29:39.812 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:387 ---[ contact MU-TH-UR 6000/GetPlaybackInfo ]
2020-08-27 22:29:39.922 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:39.985 T:140356003940096  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:564 ---[ updated:2 ]
2020-08-27 22:29:39.989 T:140356003940096  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:340 --<[ retrieve changes ]
2020-08-27 22:29:40.006 T:140356003940096  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:218 -->[ q:download/140356022984016 ]
2020-08-27 22:29:40.029 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:40.368 T:140356419049216  NOTICE: Previous line repeats 2 times.
2020-08-27 22:29:40.368 T:140356419049216  NOTICE: JELLYFIN.jellyfin.http -> ERROR::jellyfin_kodi/jellyfin/http.py:124 400 Client Error: Bad Request for url: https://{jellyfin-server}/Items/61251361-ea78-db8f-7a42-d5723ba8f6a7/PlaybackInfo
2020-08-27 22:29:40.372 T:140356419049216   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <class 'helper.exceptions.HTTPException'>
                                            Traceback (most recent call last):
                                              File "/home/user/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/monitor.py", line 152, in onNotification
                                                sources = server.jellyfin.get_play_info(data['Id'], data['Profile'])
                                              File "/home/user/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 342, in get_play_info
                                                'AutoOpenLiveStream': True
                                              File "/home/user/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 96, in items
                                                return self._post("Items%s" % handler, json, params)
                                              File "/home/user/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 64, in _post
                                                return self._http("POST", handler, {'params': params, 'json': json})
                                              File "/home/user/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/api.py", line 58, in _http
                                                return self.client.request(request)
                                              File "/home/user/.kodi/addons/plugin.video.jellyfin/jellyfin_kodi/jellyfin/http.py", line 151, in request
                                                raise HTTPException(r.status_code, error)
                                            HTTPException
                                            -->End of Python script error report<--
2020-08-27 22:29:40.468 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:42.016 T:140356003940096  NOTICE: Previous line repeats 12 times.
2020-08-27 22:29:42.016 T:140356003940096  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:246 -->[ q:updated/Series/140356014056208 ]
2020-08-27 22:29:42.036 T:140355898959616  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:339 --<[ q:download/140356022984016 ]
2020-08-27 22:29:42.081 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:43.569 T:140355890566912  NOTICE: Previous line repeats 13 times.
2020-08-27 22:29:43.569 T:140355890566912  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:645 --<[ q:updated/140356014056208 ]
2020-08-27 22:29:43.574 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:44.028 T:140356003940096  NOTICE: Previous line repeats 4 times.
2020-08-27 22:29:44.028 T:140356003940096  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:246 -->[ q:updated/Movie/140356022984080 ]
2020-08-27 22:29:44.112 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:45.102 T:140355890566912  NOTICE: Previous line repeats 9 times.
2020-08-27 22:29:45.102 T:140355890566912  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:645 --<[ q:updated/140356022984080 ]
2020-08-27 22:29:45.156 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:46.046 T:140356003940096  NOTICE: Previous line repeats 8 times.
2020-08-27 22:29:46.046 T:140356003940096  NOTICE: JELLYFIN.library -> INFO::jellyfin_kodi/library.py:445 --[ sync/2020-08-27T13:27:42z ]
2020-08-27 22:29:46.092 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:29:46.099 T:140358134548224  NOTICE: VideoInfoScanner: Starting scan ..
2020-08-27 22:29:46.100 T:140358134548224  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
2020-08-27 22:29:46.190 T:140356419049216  NOTICE: JELLYFIN.monitor -> INFO::jellyfin_kodi/monitor.py:43 -->[ kodi scan/video ]
2020-08-27 22:29:46.193 T:140356419049216  NOTICE: JELLYFIN.monitor -> INFO::jellyfin_kodi/monitor.py:46 --<[ kodi scan/video ]
2020-08-27 22:29:46.197 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:31:01.960 T:140359396714624  NOTICE: Previous line repeats 718 times.
2020-08-27 22:31:01.960 T:140359396714624  NOTICE: Samba is idle. Closing the remaining connections
2020-08-27 22:31:02.060 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:33:03.268 T:140358793033472  NOTICE: Previous line repeats 1151 times.
2020-08-27 22:33:03.268 T:140358793033472  NOTICE: PulseAudio: Opened device Default in pcm mode with Buffersize 150 ms
2020-08-27 22:33:03.314 T:140357442463488  NOTICE: JELLYFIN.downloader -> INFO::jellyfin_kodi/downloader.py:413 --[ void/886dbc30-957d-4339-98f5-849dab6b0d7c ]
2020-08-27 22:33:08.276 T:140359396714624  NOTICE: Previous line repeats 46 times.
2020-08-27 22:33:08.276 T:140359396714624   ERROR: CPythonInvoker(9, /home/user/.kodi/addons/plugin.video.jellyfin/default.py): script didn't stop in 5 seconds - let's kill it
2020-08-27 22:33:08.276 T:140359396714624   ERROR: Playlist Player: skipping unplayable item: 0, path [plugin://plugin.video.jellyfin/2d7e7d8f-5bc4-9b6e-8274-e1006d10338d/?dbid=189&mode=play&id=[GUID]&filename=[FILENAME]]

I hope those "remaining" samba connections were never a thing - I never had samba enabled.

[mcarlton00]

The samba is just something internal to Kodi that it checks for regularly, shouldn't have anything to do with this.

The first log snippet you posted shows a 400 error when trying to tell the server what capabilities the client has (/Sessions/Capabilities/Full/), which is highly unusual. I've never seen it fail in that particular place. Generally if it's going to fail, it would fail earlier when checking the /system/info/public endpoint. Do you have any server logs from when that failure occurs? It's probably shortly after Kodi starts.

[Legogris]

Apart from the Database .kodi/userdata/Database/MyVideos107.db missing and ~/.kodi/userdata/Database/MyMusic60.db missing, the /Sessions/Capabilities/Full/ is the first error in logs after startup on the client side.

On the server side, if I enable Debug logs for all units, we have the following:

[09:48:14] [INF] [27] Microsoft.AspNetCore.Hosting.Diagnostics: Request starting HTTP/1.1 POST http://jellyfin-host/Sessions/Capabilities/Full application/json 451
[09:48:14] [DBG] [28] Jellyfin.Api.Auth.CustomAuthenticationHandler: AuthenticationScheme: CustomAuthentication was successfully authenticated.
[09:48:14] [DBG] [28] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: The request path  does not match the path filter
[09:48:14] [DBG] [28] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: The request path  does not match the path filter
[09:48:14] [DBG] [28] Microsoft.AspNetCore.Routing.Matching.DfaMatcher: No candidates found for the request path '/socket'
[09:48:14] [DBG] [28] Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware: Request did not match any endpoints
[09:48:14] [DBG] [28] Microsoft.AspNetCore.Cors.Infrastructure.CorsService: The request has an origin header: 'http://jellyfin-host:443'.
[09:48:14] [INF] [28] Microsoft.AspNetCore.Cors.Infrastructure.CorsService: CORS policy execution successful.
[09:48:14] [INF] [28] Emby.Server.Implementations.HttpServer.HttpListenerHost: WS ::ffff:192.168.1.42 request
[09:48:14] [DBG] [27] Jellyfin.Api.Auth.CustomAuthenticationHandler: AuthenticationScheme: CustomAuthentication was successfully authenticated.
[09:48:14] [DBG] [27] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: POST requests are not supported
[09:48:14] [DBG] [27] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: POST requests are not supported
[09:48:14] [DBG] [27] Microsoft.AspNetCore.Routing.Matching.DfaMatcher: 1 candidate(s) found for the request path '/Sessions/Capabilities/Full'
[09:48:14] [DBG] [27] Microsoft.AspNetCore.Routing.Matching.DfaMatcher: Endpoint 'Jellyfin.Api.Controllers.SessionController.PostFullCapabilities (Jellyfin.Api)' with route pattern 'Sessions/Capabilities/Full' is valid for the request path '/Sessions/Capabilities/Full'
[09:48:14] [DBG] [27] Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware: Request matched endpoint 'Jellyfin.Api.Controllers.SessionController.PostFullCapabilities (Jellyfin.Api)'
[09:48:14] [DBG] [27] Jellyfin.Api.Auth.CustomAuthenticationHandler: AuthenticationScheme: CustomAuthentication was successfully authenticated.
[09:48:14] [DBG] [23] Microsoft.AspNetCore.Server.Kestrel: Connection id "CONNID" accepted.
[09:48:14] [DBG] [11] Microsoft.AspNetCore.Server.Kestrel: Connection id "CONNID" started.
[09:48:14] [INF] [11] Microsoft.AspNetCore.Hosting.Diagnostics: Request starting HTTP/1.1 GET http://jellyfin-host/Users/USERID/Views application/json
[09:48:15] [DBG] [11] Jellyfin.Api.Auth.CustomAuthenticationHandler: AuthenticationScheme: CustomAuthentication was successfully authenticated.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: The request path  does not match the path filter
[09:48:15] [DBG] [11] Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware: The request path  does not match the path filter
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Routing.Matching.DfaMatcher: 1 candidate(s) found for the request path '/Users/USERID/Views'
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Routing.Matching.DfaMatcher: Endpoint 'Jellyfin.Api.Controllers.UserViewsController.GetUserViews (Jellyfin.Api)' with route pattern 'Users/{userId}/Views' is valid for the request path '/Users/USERID/Views'
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware: Request matched endpoint 'Jellyfin.Api.Controllers.UserViewsController.GetUserViews (Jellyfin.Api)'
[09:48:15] [INF] [11] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executing endpoint 'Jellyfin.Api.Controllers.UserViewsController.GetUserViews (Jellyfin.Api)'
[09:48:15] [INF] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Route matched with {action = "GetUserViews", controller = "UserViews"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.ActionResult`1[MediaBrowser.Model.Querying.QueryResult`1[MediaBrowser.Model.Dto.BaseItemDto]] GetUserViews(System.Guid, System.Nullable`1[System.Boolean], System.String, Boolean) on controller Jellyfin.Api.Controllers.UserViewsController (Jellyfin.Api).
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of authorization filters (in the following order): ["None"]
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of resource filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter"]
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of action filters (in the following order): ["Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)", "Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)"]
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of exception filters (in the following order): ["None"]
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of result filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter", "Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)", "Microsoft.AspNetCore.Mvc.ProducesAttribute (Order: 0)"]
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executing controller factory for controller Jellyfin.Api.Controllers.UserViewsController (Jellyfin.Api)
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executed controller factory for controller Jellyfin.Api.Controllers.UserViewsController (Jellyfin.Api)
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'userId' of type 'System.Guid' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Attempting to bind parameter 'userId' of type 'System.Guid' using the name 'userId' in request data ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'userId' of type 'System.Guid'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'userId' of type 'System.Guid'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'userId' of type 'System.Guid' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'userId' of type 'System.Guid'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'includeExternalContent' of type 'System.Nullable`1[System.Boolean]' ...
[09:48:15] [INF] [27] Microsoft.AspNetCore.Authorization.DefaultAuthorizationService: Authorization was successful.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'includeExternalContent' of type 'System.Nullable`1[System.Boolean]'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'includeExternalContent' of type 'System.Nullable`1[System.Boolean]'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'includeExternalContent' of type 'System.Nullable`1[System.Boolean]'.
[09:48:15] [INF] [27] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executing endpoint 'Jellyfin.Api.Controllers.SessionController.PostFullCapabilities (Jellyfin.Api)'
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'includeExternalContent' of type 'System.Nullable`1[System.Boolean]' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'includeExternalContent' of type 'System.Nullable`1[System.Boolean]'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'presetViews' of type 'System.String' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'presetViews' of type 'System.String'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'presetViews' of type 'System.String'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'presetViews' of type 'System.String'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'presetViews' of type 'System.String'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'presetViews' of type 'System.String' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'presetViews' of type 'System.String'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'includeHidden' of type 'System.Boolean' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'includeHidden' of type 'System.Boolean'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'includeHidden' of type 'System.Boolean'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'includeHidden' of type 'System.Boolean'.
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'includeHidden' of type 'System.Boolean' ...
[09:48:15] [DBG] [11] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'includeHidden' of type 'System.Boolean'.
[09:48:15] [INF] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Route matched with {action = "PostFullCapabilities", controller = "Session"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.ActionResult PostFullCapabilities(System.String, MediaBrowser.Model.Session.ClientCapabilities) on controller Jellyfin.Api.Controllers.SessionController (Jellyfin.Api).
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of authorization filters (in the following order): ["None"]
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of resource filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter"]
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of action filters (in the following order): ["Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)", "Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter (Order: -2000)"]
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of exception filters (in the following order): ["None"]
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Execution plan of result filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter", "Microsoft.AspNetCore.Mvc.Infrastructure.ClientErrorResultFilter (Order: -2000)", "Microsoft.AspNetCore.Mvc.ProducesAttribute (Order: 0)"]
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executing controller factory for controller Jellyfin.Api.Controllers.SessionController (Jellyfin.Api)
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executed controller factory for controller Jellyfin.Api.Controllers.SessionController (Jellyfin.Api)
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'id' of type 'System.String' ...
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'id' of type 'System.String'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'id' of type 'System.String'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'id' of type 'System.String'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'id' of type 'System.String' ...
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'id' of type 'System.String'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'capabilities' of type 'MediaBrowser.Model.Session.ClientCapabilities' ...
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder: Attempting to bind parameter 'capabilities' of type 'MediaBrowser.Model.Session.ClientCapabilities' using the name '' in request data ...
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder: Selected input formatter 'Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter' for content type 'application/json'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Server.Kestrel: Connection id "0HM2D8T1K3DBD", Request id "0HM2D8T1K3DBD:00000004": started reading request body.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Server.Kestrel: Connection id "0HM2D8T1K3DBD", Request id "0HM2D8T1K3DBD:00000004": done reading request body.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter: JSON input formatter threw an exception: The JSON value could not be converted to System.String[]. Path: $.SupportedCommands | LineNumber: 0 | BytePositionInLine: 413.
System.Text.Json.JsonException: The JSON value could not be converted to System.String[]. Path: $.SupportedCommands | LineNumber: 0 | BytePositionInLine: 413.
   at System.Text.Json.ThrowHelper.ThrowJsonException_DeserializeUnableToConvertValue(Type propertyType)
   at System.Text.Json.Serialization.Converters.IEnumerableDefaultConverter`2.OnTryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, TCollection& value)
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value)
   at System.Text.Json.JsonPropertyInfo`1.ReadJsonAndSetMember(Object obj, ReadStack& state, Utf8JsonReader& reader)
   at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value)
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCoreAsObject(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.JsonSerializer.ReadCore[TValue](JsonConverter jsonConverter, Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.JsonSerializer.ReadCore[TValue](JsonReaderState& readerState, Boolean isFinalBlock, ReadOnlySpan`1 buffer, JsonSerializerOptions options, ReadStack& state, JsonConverter converterBase)
   at System.Text.Json.JsonSerializer.ReadAsync[TValue](Stream utf8Json, Type returnType, JsonSerializerOptions options, CancellationToken cancellationToken)
   at Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonInputFormatter.ReadRequestBodyAsync(InputFormatterContext context, Encoding encoding)
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.BodyModelBinder: Done attempting to bind parameter 'capabilities' of type 'MediaBrowser.Model.Session.ClientCapabilities'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'capabilities' of type 'MediaBrowser.Model.Session.ClientCapabilities'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'capabilities' of type 'MediaBrowser.Model.Session.ClientCapabilities' ...
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'capabilities' of type 'MediaBrowser.Model.Session.ClientCapabilities'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter: The request has model state errors, returning an error response.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Request was short circuited at action filter 'Microsoft.AspNetCore.Mvc.Infrastructure.ModelStateInvalidFilter'.
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: List of registered output formatters, in the following order: ["Jellyfin.Server.Formatters.PascalCaseJsonProfileFormatter", "Jellyfin.Server.Formatters.CamelCaseJsonProfileFormatter", "Microsoft.AspNetCore.Mvc.Formatters.HttpNoContentOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StringOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StreamOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonOutputFormatter", "Jellyfin.Server.Formatters.CssOutputFormatter", "Jellyfin.Server.Formatters.XmlOutputFormatter"]
[09:48:15] [DBG] [27] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: No information found on request to perform content negotiation.

The /system/info/public seems to be fine though, confirmed by:

$ curl https://jellyfin-host/system/info/public
{"ServerName":"foo","Version":"10.7.0","ProductName":"Jellyfin Server","OperatingSystem":"Linux","Id":"deadbeef123"}

(Not actual values for ServerName and Id).

Only when trying to actually play a video does the server show something exceptional above Debug level, and that is the error on PlaybackInfo above.

[Legogris]

The deserialization error above is the following model: https://github.com/jellyfin/jellyfin/blob/master/MediaBrowser.Model/Session/ClientCapabilities.cs

Adding print(data) just before

jellyfin-kodi/jellyfin_kodi/jellyfin/api.py

Line 312 in 52bb733

return self.sessions("/Capabilities/Full", "POST", json=data)

:

{u'SupportsMediaControl': True, u'SupportedCommands': u'MoveUp,MoveDown,MoveLeft,MoveRight,Select,Back,ToggleContextMenu,ToggleFullscreen,ToggleOsdMenu,GoHome,PageUp,NextLetter,GoToSearch,GoToSettings,PageDown,PreviousLetter,TakeScreenshot,VolumeUp,VolumeDown,ToggleMute,SendString,DisplayMessage,SetAudioStreamIndex,SetSubtitleStreamIndex,SetRepeatMode,Mute,Unmute,SetVolume,Play,Playstate,PlayNext,PlayMediaSource', u'PlayableMediaTypes': u'Audio,Video'}

This looks to me like it's a bug in Jellyfin, not an issue with the plugin.

[Legogris]

Looks like this is fixed in current unstable already 🎉

Closing this.

[oddstr13]

So, my best guess on this issue is that the auth headers aren't properly passed along to the server.

Could you please try connecting directly, without the reverse proxy and see if the issue is still present then?

If it is also failing without reverse proxy, could you please note down the Jellyfin server and Jellyfin for Kodi versions you tested with?

jellyfin/jellyfin#3961 was also done client-side in the addon with #366, released in 0.5.9.