jellyfin icon indicating copy to clipboard operation
jellyfin copied to clipboard
Published 3 months ago • verified publisher icon jellyfin

Jellyfin slow after playing a file, thinks file is still playing

Open laxmanpradhan opened this issue 1 year ago • 5 comments

Description of the bug

  • Watching a file on Nvidia Shield, after playback is stopped the server is very slow.
  • The jellyfin admin dashboard thinks the file is still playing. Hitting the Stop or pause button on the dashboard does nothing. Nothing is playing on the shield, I'm at the jellyfin UI as it should be
  • Interestingly, the time stamp on the dashboard seems to jump around, it will be at 18m and then count up then jump to 40m then back to 30m ect even though nothing is playing
  • This happens with transcoding and direct play
  • does not happen every time, it is unpredictable.
  • CPU, memory and IO use does not seem to be anything excessive
  • At first I thought it was related to #12456 but I deleted jellystat a week ago and the issue persists.
  • Normally the UI is butter smooth (right after a server restart) as it runs on a ryzen 5950x with the config director on NVME storage
  • After this starts, opening the info page for a show or any UI request takes a long time and often times out:
[19:14:13] [DBG] [746] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 10073.9786ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,ParentIndexNumber,ProductionYear,OfficialRating,ForcedSortName,RunTimeTicks,Size,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,TotalBitrate,ExtraType,ExternalId,OwnerId,UserDatas.UserId,UserDatas.lastPlayedDate,UserDatas.playbackPositionTicks,UserDatas.playcount,UserDatas.isFavorite,UserDatas.played,UserDatas.rating from TypedBaseItems A left join UserDatas on UserDataKey=UserDatas.Key And (UserId=@UserId) where type=@type AND (ParentIndexNumber<>@ParentIndexNumberNotEquals or ParentIndexNumber is null) AND (played=@IsPlayed) AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey ORDER BY ParentIndexNumber DESC,IndexNumber DESC LIMIT 1

in the mean time, these messages keep popping up even though nothing is playing on the server (also note that it is direct playing, not transcoding):

[19:14:14] [DBG] [723] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:14] [DBG] [1458] Emby.Server.Implementations.Session.SessionWebSocketListener: Watching 2 WebSockets.
[19:14:15] [DBG] [1458] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:16] [DBG] [723] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:17] [DBG] [723] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:18] [DBG] [1458] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False

Reproduction steps

  1. Play file on Nvidia Shield
  2. Finish playing and exit by hitting the back button
  3. File seems to keep playing on the dashboard
  4. UI is now very slow on any device (browser, mobile app, shield) (I don't use other clients enough to know if this happens everywhere but I will try to see if I can trigger this in other clients, once it gets slow, all clients are slow)

What is the current bug behavior?

Slow UI after playback stopped

What is the expected correct behavior?

UI should run at normal speed

Jellyfin Server version

10.10.0+

Specify commit id

No response

Specify unstable release number

No response

Specify version number

No response

Specify the build version

10.10.6 (c335a3024)

Environment

- Ryzen 5950x with NVME ZFS storage for all docker config files
- Proxmox 8.2.7 -> Alpine 3.18.4 VM -> Docker Version 23.0.6
- Clients: Nvidia Shield
- Browser:
- FFmpeg Version:
- Playback Method:
- Hardware Acceleration: no, CPU only
- GPU Model:
- Plugins: LDAP authentication
- Reverse Proxy: traefik
- Base URL:
- Networking:
- Storage: NVME ZFS for server install, NAS NFS mount for media files.

Jellyfin logs

Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'percentPlayed' of type 'System.Nullable`1[System.Double]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'percentPlayed' of type 'System.Nullable`1[System.Double]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'percentPlayed' of type 'System.Nullable`1[System.Double]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Attempting to bind parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]' using the name '' in request data ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'unplayedCount' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'blur' of type 'System.Nullable`1[System.Int32]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Attempting to bind parameter 'blur' of type 'System.Nullable`1[System.Int32]' using the name '' in request data ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'blur' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'blur' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'blur' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'blur' of type 'System.Nullable`1[System.Int32]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'blur' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'backgroundColor' of type 'System.String' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Attempting to bind parameter 'backgroundColor' of type 'System.String' using the name '' in request data ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'backgroundColor' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'backgroundColor' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'backgroundColor' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'backgroundColor' of type 'System.String' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'backgroundColor' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'foregroundLayer' of type 'System.String' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Attempting to bind parameter 'foregroundLayer' of type 'System.String' using the name '' in request data ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'foregroundLayer' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'foregroundLayer' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'foregroundLayer' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'foregroundLayer' of type 'System.String' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'foregroundLayer' of type 'System.String'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to bind parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Attempting to bind parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]' using the name '' in request data ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Could not find a value in the request with name '' for binding parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.Binders.SimpleTypeModelBinder: Done attempting to bind parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to bind parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Attempting to validate the bound parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.ModelBinding.ParameterBinder: Done attempting to validate the bound parameter 'imageIndex' of type 'System.Nullable`1[System.Int32]'.
[19:14:08] [INF] [217] Microsoft.AspNetCore.Mvc.Infrastructure.PhysicalFileResultExecutor: Executing PhysicalFileResult, sending file '/config/cache/images/resized-images/b/b00abac0-3859-3425-c8b0-6960c77712cd.jpg' with download name '' ...
[19:14:08] [DBG] [217] Microsoft.AspNetCore.Mvc.Infrastructure.PhysicalFileResultExecutor: The file result has not been enabled for processing range requests. To enable it, set the EnableRangeProcessing property on the result to 'true'.
[19:14:08] [DBG] [217] Microsoft.AspNetCore.ResponseCompression.ResponseCompressionProvider: No response compression available for HTTPS requests. See ResponseCompressionOptions.EnableForHttps.
[19:14:08] [INF] [736] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executed action Jellyfin.Api.Controllers.ImageController.GetItemImage (Jellyfin.Api) in 2.514ms
[19:14:08] [INF] [736] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executed endpoint 'Jellyfin.Api.Controllers.ImageController.GetItemImage (Jellyfin.Api)'
[19:14:08] [DBG] [736] Microsoft.AspNetCore.Server.Kestrel.Connections: Connection id "0HNAH9P30I8SR" completed keep alive response.
[19:14:08] [INF] [736] Microsoft.AspNetCore.Hosting.Diagnostics: Request finished HTTP/1.1 GET https://jellyfin.example.com/Items/e77fc638-0dfc-e575-8e7b-2e7a697bf703/Images/Logo?maxWidth=600&tag=2eb4fa1c1c6b27ce5c118f41219adbe0 - 200 66229 image/jpeg 2.8174ms
[19:14:09] [DBG] [736] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:09] [DBG] [736] Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets: Connection id "0HNAH9P30I8SN" received FIN.
[19:14:09] [DBG] [1458] Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets: Connection id "0HNAH9P30I8SN" sending FIN because: "The Socket transport's send loop completed gracefully."
[19:14:09] [DBG] [1458] Microsoft.AspNetCore.Server.Kestrel.Connections: Connection id "0HNAH9P30I8SN" disconnecting.
[19:14:10] [DBG] [217] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:11] [DBG] [736] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:11] [DBG] [1458] Emby.Server.Implementations.HttpServer.WebSocketConnection: WS 192.168.37.57 received message: {"Data": null, "MessageType": "KeepAlive", "ServerId": null, "$type": "InboundWebSocketMessage`1"}
[19:14:12] [DBG] [1458] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:13] [DBG] [217] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:13] [DBG] [746] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 10073.9786ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,ParentIndexNumber,ProductionYear,OfficialRating,ForcedSortName,RunTimeTicks,Size,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,TotalBitrate,ExtraType,ExternalId,OwnerId,UserDatas.UserId,UserDatas.lastPlayedDate,UserDatas.playbackPositionTicks,UserDatas.playcount,UserDatas.isFavorite,UserDatas.played,UserDatas.rating from TypedBaseItems A left join UserDatas on UserDataKey=UserDatas.Key And (UserId=@UserId) where type=@type AND (ParentIndexNumber<>@ParentIndexNumberNotEquals or ParentIndexNumber is null) AND (played=@IsPlayed) AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey ORDER BY ParentIndexNumber DESC,IndexNumber DESC LIMIT 1
[19:14:13] [DBG] [1460] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 10076.3368ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,Overview,ParentIndexNumber,ProductionYear,OfficialRating,RunTimeTicks,Size,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,Images,TotalBitrate,ExtraType,ExternalId,OwnerId,UserDatas.UserId,UserDatas.lastPlayedDate,UserDatas.playbackPositionTicks,UserDatas.playcount,UserDatas.isFavorite,UserDatas.played,UserDatas.rating from TypedBaseItems A left join UserDatas on UserDataKey=UserDatas.Key And (UserId=@UserId) where type=@type AND ((ParentIndexNumber=@MinParentAndIndexNumberParent and IndexNumber>=@MinParentAndIndexNumberIndex) or ParentIndexNumber>@MinParentAndIndexNumberParent) AND (ParentIndexNumber<>@ParentIndexNumberNotEquals or ParentIndexNumber is null) AND (played is null or played=@IsPlayed) AND IsVirtualItem=@IsVirtualItem AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey ORDER BY ParentIndexNumber ASC,IndexNumber ASC LIMIT 1
[19:14:13] [DBG] [1061] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 5041.7463ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,ParentIndexNumber,ProductionYear,OfficialRating,RunTimeTicks,Size,DateCreated,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,Images,TotalBitrate,ExtraType,ExternalId,OwnerId,UserDatas.UserId,UserDatas.lastPlayedDate,UserDatas.playbackPositionTicks,UserDatas.playcount,UserDatas.isFavorite,UserDatas.played,UserDatas.rating from TypedBaseItems A left join UserDatas on UserDataKey=UserDatas.Key And (UserId=@UserId) where type=@type AND ParentIndexNumber=@ParentIndexNumber AND (played is null or played=@IsPlayed) AND IsVirtualItem=@IsVirtualItem AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey
[19:14:13] [DBG] [723] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 4880.1456ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,Overview,ParentIndexNumber,ProductionYear,OfficialRating,RunTimeTicks,Size,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,Images,TotalBitrate,ExtraType,ExternalId,OwnerId from TypedBaseItems A where type=@type AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey ORDER BY SortName ASC
[19:14:13] [DBG] [728] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 4886.3554ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,ParentIndexNumber,ProductionYear,OfficialRating,RunTimeTicks,Size,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,Images,TotalBitrate,ExtraType,ExternalId,OwnerId from TypedBaseItems A where type in ('MediaBrowser.Controller.Entities.TV.Episode','MediaBrowser.Controller.Entities.TV.Season') AND IsVirtualItem=@IsVirtualItem AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey ORDER BY SortName ASC
[19:14:13] [DBG] [723] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: List of registered output formatters, in the following order: ["Jellyfin.Api.Formatters.PascalCaseJsonProfileFormatter", "Jellyfin.Api.Formatters.CamelCaseJsonProfileFormatter", "Microsoft.AspNetCore.Mvc.Formatters.HttpNoContentOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StringOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StreamOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonOutputFormatter", "Jellyfin.Api.Formatters.CssOutputFormatter", "Jellyfin.Api.Formatters.XmlOutputFormatter"]
[19:14:13] [DBG] [723] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: Attempting to select an output formatter based on Accept header '["application/json", "application/octet-stream;q=0.9", "*/*;q=0.8"]' and explicitly specified content types '["application/json", "application/json; profile=\"CamelCase\"", "application/json; profile=\"PascalCase\""]'. The content types in the accept header must be a subset of the explicitly set content types.
[19:14:13] [DBG] [723] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: Selected output formatter 'Jellyfin.Api.Formatters.PascalCaseJsonProfileFormatter' and content type 'application/json' to write the response.
[19:14:13] [INF] [723] Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor: Executing ObjectResult, writing value of type 'MediaBrowser.Model.Querying.QueryResult`1[[MediaBrowser.Model.Dto.BaseItemDto, MediaBrowser.Model, Version=10.10.6.0, Culture=neutral, PublicKeyToken=null]]'.
[19:14:13] [DBG] [723] Microsoft.AspNetCore.ResponseCompression.ResponseCompressionProvider: No response compression available for HTTPS requests. See ResponseCompressionOptions.EnableForHttps.
[19:14:13] [DBG] [723] Jellyfin.Api.Middleware.ResponseTimeMiddleware: Slow HTTP Response from https://jellyfin.example.com/Items?startIndex=5&limit=20&parentId=a775ef26-0fa8-ae73-89a0-9d7f61c3d0f3&fields=PrimaryImageAspectRatio&fields=Overview&fields=ItemCounts&fields=DisplayPreferencesId&fields=ChildCount&includeItemTypes=Episode&enableTotalRecordCount=true&enableImages=true to 192.168.37.55 in 0:00:04.8838849 with Status Code 200
[19:14:13] [INF] [723] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executed action Jellyfin.Api.Controllers.ItemsController.GetItems (Jellyfin.Api) in 4883.6889ms
[19:14:13] [INF] [723] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executed endpoint 'Jellyfin.Api.Controllers.ItemsController.GetItems (Jellyfin.Api)'
[19:14:13] [DBG] [723] Microsoft.AspNetCore.Server.Kestrel.Connections: Connection id "0HNAH9P30I8SQ" completed keep alive response.
[19:14:13] [INF] [723] Microsoft.AspNetCore.Hosting.Diagnostics: Request finished HTTP/1.1 GET https://jellyfin.example.com/Items?startIndex=5&limit=20&parentId=a775ef26-0fa8-ae73-89a0-9d7f61c3d0f3&fields=PrimaryImageAspectRatio&fields=Overview&fields=ItemCounts&fields=DisplayPreferencesId&fields=ChildCount&includeItemTypes=Episode&enableTotalRecordCount=true&enableImages=true - 200 null application/json; charset=utf-8 4884.0622ms
[19:14:13] [DBG] [728] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: List of registered output formatters, in the following order: ["Jellyfin.Api.Formatters.PascalCaseJsonProfileFormatter", "Jellyfin.Api.Formatters.CamelCaseJsonProfileFormatter", "Microsoft.AspNetCore.Mvc.Formatters.HttpNoContentOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StringOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StreamOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.SystemTextJsonOutputFormatter", "Jellyfin.Api.Formatters.CssOutputFormatter", "Jellyfin.Api.Formatters.XmlOutputFormatter"]
[19:14:13] [DBG] [728] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: Attempting to select an output formatter based on Accept header '["application/json", "application/octet-stream;q=0.9", "*/*;q=0.8"]' and explicitly specified content types '["application/json", "application/json; profile=\"CamelCase\"", "application/json; profile=\"PascalCase\""]'. The content types in the accept header must be a subset of the explicitly set content types.
[19:14:13] [DBG] [728] Microsoft.AspNetCore.Mvc.Infrastructure.DefaultOutputFormatterSelector: Selected output formatter 'Jellyfin.Api.Formatters.PascalCaseJsonProfileFormatter' and content type 'application/json' to write the response.
[19:14:13] [INF] [728] Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor: Executing ObjectResult, writing value of type 'MediaBrowser.Model.Querying.QueryResult`1[[MediaBrowser.Model.Dto.BaseItemDto, MediaBrowser.Model, Version=10.10.6.0, Culture=neutral, PublicKeyToken=null]]'.
[19:14:13] [DBG] [728] Microsoft.AspNetCore.ResponseCompression.ResponseCompressionProvider: No response compression available for HTTPS requests. See ResponseCompressionOptions.EnableForHttps.
[19:14:13] [DBG] [728] Jellyfin.Api.Middleware.ResponseTimeMiddleware: Slow HTTP Response from https://jellyfin.example.com/Shows/e77fc638-0dfc-e575-8e7b-2e7a697bf703/Episodes?adjacentTo=798a1ed1-d762-d2b3-4642-2ac64f9a7e5d to 192.168.37.55 in 0:00:04.8879562 with Status Code 200
[19:14:13] [INF] [728] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Executed action Jellyfin.Api.Controllers.TvShowsController.GetEpisodes (Jellyfin.Api) in 4887.6078ms
[19:14:13] [INF] [728] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executed endpoint 'Jellyfin.Api.Controllers.TvShowsController.GetEpisodes (Jellyfin.Api)'
[19:14:13] [DBG] [728] Microsoft.AspNetCore.Server.Kestrel.Connections: Connection id "0HNAH9P30I8ST" completed keep alive response.
[19:14:13] [INF] [728] Microsoft.AspNetCore.Hosting.Diagnostics: Request finished HTTP/1.1 GET https://jellyfin.example.com/Shows/e77fc638-0dfc-e575-8e7b-2e7a697bf703/Episodes?adjacentTo=798a1ed1-d762-d2b3-4642-2ac64f9a7e5d - 200 null application/json; charset=utf-8 4888.0784ms
[19:14:13] [DBG] [723] Emby.Server.Implementations.HttpServer.WebSocketConnection: WS 192.168.37.55 received message: {"Data": null, "MessageType": "KeepAlive", "ServerId": null, "$type": "InboundWebSocketMessage`1"}
[19:14:14] [DBG] [723] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:14] [DBG] [1458] Emby.Server.Implementations.Session.SessionWebSocketListener: Watching 2 WebSockets.
[19:14:15] [DBG] [1458] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:16] [DBG] [723] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:17] [DBG] [723] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False
[19:14:18] [DBG] [1458] MediaBrowser.MediaEncoding.Transcoding.TranscodeManager: PingTranscodingJob PlaySessionId=68fa6403dbfa46e4bee8b5071fe0067e isUsedPaused: False

FFmpeg logs

Client / Browser logs

No response

Relevant screenshots or videos

No response

Additional information

No response

laxmanpradhan avatar Feb 21 '25 03:02 laxmanpradhan

the same

hwadong860 avatar Mar 03 '25 04:03 hwadong860

Note, this happens specifically when hitting the next episode button. To replicate, have a show playing, press the next episode button and it will create a lag in the server. Sometimes the next episode will actually start playing but all ui elements are slow and if you stop the play back the UI is near unresponsive.

If you restart the server, the next episode will playback without issue.

laxmanpradhan avatar May 05 '25 04:05 laxmanpradhan

Still happening in 10.10.7

[23:09:26] [DBG] [191] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 5030.2769ms. Query: select type,data,EndDate,ChannelId,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,ParentIndexNumber,ProductionYear,OfficialRating,RunTimeTicks,Size,DateCreated,DateModified,guid,ParentId,Audio,IsInMixedFolder,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,Images,TotalBitrate,ExtraType,ExternalId,OwnerId,UserDatas.UserId,UserDatas.lastPlayedDate,UserDatas.playbackPositionTicks,UserDatas.playcount,UserDatas.isFavorite,UserDatas.played,UserDatas.rating from TypedBaseItems A left join UserDatas on UserDataKey=UserDatas.Key And (UserId=@UserId) where type=@type AND ParentIndexNumber=@ParentIndexNumber AND (played is null or played=@IsPlayed) AND IsVirtualItem=@IsVirtualItem AND SeriesPresentationUniqueKey=@SeriesPresentationUniqueKey Group by PresentationUniqueKey

Happens when accessing via nvidia shield. Only remedy seems to be restarting the server.

laxmanpradhan avatar May 22 '25 06:05 laxmanpradhan

Are you using playback reporting plugin or jellystat?

felix920506 avatar May 22 '25 07:05 felix920506

Are you using playback reporting plugin or jellystat?

No, I deleted playback reporting and jellystat before posting this issue. The only plugin I installed is LDAP login.

laxmanpradhan avatar May 22 '25 15:05 laxmanpradhan

This issue has gone 120 days without an update and will be closed within 21 days if there is no new activity. To prevent this issue from being closed, please confirm the issue has not already been fixed by providing updated examples or logs.

If you have any questions you can use one of several ways to contact us.

jellyfin-bot avatar Oct 24 '25 02:10 jellyfin-bot

I suspect this has fixed itself with 10.11.0 as it seems to work well. I will close this issue and reopen with new logs if it crops up again.

laxmanpradhan avatar Oct 29 '25 05:10 laxmanpradhan