11 hours ago
(This post was last modified: 8 hours ago by moniker. Edited 6 times in total.
Edit Reason: Updating to add one slow function.
)
Hi,
I followed the steps to upgrade to 10.11.0 and everything seemed alright migration-wise, no errors. I have a large movies library of ~20k youtube videos that I have re scanned a few times now. When loading the main page it will take about 30-50 seconds to load recent additions, the library, etc on the page, and when attempting to browse to the library it has not loaded after 30 minutes.
Previously with 10.10.7 these would load in <500ms. It also pins a core now whenever someone attempts to load one of these pages.
To debug I have attempted to remove the problem library, upgrade from 10.10.7 to 10.11.0, then re-add a new library manually. However this doesn't help with the issue. In this library embedded image extractor, screen grabber, real time monitoring and Prefer embedded titles over filenames are enabled.
After looking through the logs a bit more I've found a 100x slowdown for the main page to be in GetLatestMediaLegacy. In 10.10 for the problem library it took 263.497ms, while in 10.11 it took 25609.8359ms.
Log for 10.10:
Log for 10.11:
For loading the library itself in 10.11 here is (logs of the thread? that handles) the request that never returns/finishes after 50 minutes:
Please let me know if there are any other logs that are needed. Thanks!
I followed the steps to upgrade to 10.11.0 and everything seemed alright migration-wise, no errors. I have a large movies library of ~20k youtube videos that I have re scanned a few times now. When loading the main page it will take about 30-50 seconds to load recent additions, the library, etc on the page, and when attempting to browse to the library it has not loaded after 30 minutes.
Previously with 10.10.7 these would load in <500ms. It also pins a core now whenever someone attempts to load one of these pages.
To debug I have attempted to remove the problem library, upgrade from 10.10.7 to 10.11.0, then re-add a new library manually. However this doesn't help with the issue. In this library embedded image extractor, screen grabber, real time monitoring and Prefer embedded titles over filenames are enabled.
After looking through the logs a bit more I've found a 100x slowdown for the main page to be in GetLatestMediaLegacy. In 10.10 for the problem library it took 263.497ms, while in 10.11 it took 25609.8359ms.
Log for 10.10:
[01:26:23] [DBG] [23] Emby.Server.Implementations.Data.SqliteItemRepository: GetItemList query time (slow): 250.3336ms. Query: select type,data,StartDate,EndDate,ChannelId,IsMovie,IsSeries,EpisodeTitle,IsRepeat,CommunityRating,IndexNumber,Width,Height,Name,Path,PremiereDate,ParentIndexNumber,ProductionYear,OfficialRating,RunTimeTicks,Size,DateModified,guid,ParentId,Audio,ExternalServiceId,IsInMixedFolder,Tags,TrailerTypes,PrimaryVersionId,Album,LUFS,NormalizationGain,CriticRating,IsVirtualItem,SeriesName,SeasonName,SeasonId,SeriesId,ProviderIds,Images,TotalBitrate,ExtraType,Artists,AlbumArtists,ExternalId,ShowId,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 IsFolder=@IsFolder AND (played is null or played=@IsPlayed) AND IsVirtualItem=@IsVirtualItem AND MediaType=@MediaTypes AND (TopParentId=@TopParentId) Group by PresentationUniqueKey ORDER BY DateCreated DESC,SortName DESC,ProductionYear DESC LIMIT 80
Log for 10.11:
[02:52:40] [INF] [24] Microsoft.EntityFrameworkCore.Database.Command: Executed DbCommand (25,385ms) [Parameters=[@__filter_IsFolder_0='?' (DbType = Boolean), @__filter_User_Id_1='?' (DbType = Guid), @__filter_IsPlayed_2='?' (DbType = Boolean), @__isVirtualItem_Value_3='?' (DbType = Boolean), @__p_4='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
SELECT "b6"."Id", "b6"."Album", "b6"."AlbumArtists", "b6"."Artists", "b6"."Audio", "b6"."ChannelId", "b6"."CleanName", "b6"."CommunityRating", "b6"."CriticRating", "b6"."CustomRating", "b6"."Data", "b6"."DateCreated", "b6"."DateLastMediaAdded", "b6"."DateLastRefreshed", "b6"."DateLastSaved", "b6"."DateModified", "b6"."EndDate", "b6"."EpisodeTitle", "b6"."ExternalId", "b6"."ExternalSeriesId", "b6"."ExternalServiceId", "b6"."ExtraIds", "b6"."ExtraType", "b6"."ForcedSortName", "b6"."Genres", "b6"."Height", "b6"."IndexNumber", "b6"."InheritedParentalRatingSubValue", "b6"."InheritedParentalRatingValue", "b6"."IsFolder", "b6"."IsInMixedFolder", "b6"."IsLocked", "b6"."IsMovie", "b6"."IsRepeat", "b6"."IsSeries", "b6"."IsVirtualItem", "b6"."LUFS", "b6"."MediaType", "b6"."Name", "b6"."NormalizationGain", "b6"."OfficialRating", "b6"."OriginalTitle", "b6"."Overview", "b6"."OwnerId", "b6"."ParentId", "b6"."ParentIndexNumber", "b6"."Path", "b6"."PreferredMetadataCountryCode", "b6"."PreferredMetadataLanguage", "b6"."PremiereDate", "b6"."PresentationUniqueKey", "b6"."PrimaryVersionId", "b6"."ProductionLocations", "b6"."ProductionYear", "b6"."RunTimeTicks", "b6"."SeasonId", "b6"."SeasonName", "b6"."SeriesId", "b6"."SeriesName", "b6"."SeriesPresentationUniqueKey", "b6"."ShowId", "b6"."Size", "b6"."SortName", "b6"."StartDate", "b6"."Studios", "b6"."Tagline", "b6"."Tags", "b6"."TopParentId", "b6"."TotalBitrate", "b6"."Type", "b6"."UnratedType", "b6"."Width", "b2"."Id", "b2"."ItemId", "b3"."ItemId", "b3"."ProviderId", "b3"."ProviderValue", "b4"."Id", "b4"."ItemId", "u1"."ItemId", "u1"."UserId", "u1"."CustomDataKey", "u1"."AudioStreamIndex", "u1"."IsFavorite", "u1"."LastPlayedDate", "u1"."Likes", "u1"."PlayCount", "u1"."PlaybackPositionTicks", "u1"."Played", "u1"."Rating", "u1"."RetentionDate", "u1"."SubtitleStreamIndex", "b5"."Id", "b5"."Blurhash", "b5"."DateModified", "b5"."Height", "b5"."ImageType", "b5"."ItemId", "b5"."Path", "b5"."Width"
FROM (
SELECT "b"."Id", "b"."Album", "b"."AlbumArtists", "b"."Artists", "b"."Audio", "b"."ChannelId", "b"."CleanName", "b"."CommunityRating", "b"."CriticRating", "b"."CustomRating", "b"."Data", "b"."DateCreated", "b"."DateLastMediaAdded", "b"."DateLastRefreshed", "b"."DateLastSaved", "b"."DateModified", "b"."EndDate", "b"."EpisodeTitle", "b"."ExternalId", "b"."ExternalSeriesId", "b"."ExternalServiceId", "b"."ExtraIds", "b"."ExtraType", "b"."ForcedSortName", "b"."Genres", "b"."Height", "b"."IndexNumber", "b"."InheritedParentalRatingSubValue", "b"."InheritedParentalRatingValue", "b"."IsFolder", "b"."IsInMixedFolder", "b"."IsLocked", "b"."IsMovie", "b"."IsRepeat", "b"."IsSeries", "b"."IsVirtualItem", "b"."LUFS", "b"."MediaType", "b"."Name", "b"."NormalizationGain", "b"."OfficialRating", "b"."OriginalTitle", "b"."Overview", "b"."OwnerId", "b"."ParentId", "b"."ParentIndexNumber", "b"."Path", "b"."PreferredMetadataCountryCode", "b"."PreferredMetadataLanguage", "b"."PremiereDate", "b"."PresentationUniqueKey", "b"."PrimaryVersionId", "b"."ProductionLocations", "b"."ProductionYear", "b"."RunTimeTicks", "b"."SeasonId", "b"."SeasonName", "b"."SeriesId", "b"."SeriesName", "b"."SeriesPresentationUniqueKey", "b"."ShowId", "b"."Size", "b"."SortName", "b"."StartDate", "b"."Studios", "b"."Tagline", "b"."Tags", "b"."TopParentId", "b"."TotalBitrate", "b"."Type", "b"."UnratedType", "b"."Width"
FROM "BaseItems" AS "b"
WHERE "b"."Id" IN (
SELECT (
SELECT "b1"."Id"
FROM "BaseItems" AS "b1"
WHERE "b1"."IsFolder" = @__filter_IsFolder_0 AND COALESCE((
SELECT "u0"."Played"
FROM "UserData" AS "u0"
WHERE "b1"."Id" = "u0"."ItemId" AND "u0"."UserId" = @__filter_User_Id_1
LIMIT 1), 0) = @__filter_IsPlayed_2 AND "b1"."IsVirtualItem" = @__isVirtualItem_Value_3 AND "b1"."MediaType" = 'Video' AND "b1"."TopParentId" = '65E0C354-8C9D-74AC-4214-5F90423A863A' AND ("b0"."PresentationUniqueKey" = "b1"."PresentationUniqueKey" OR ("b0"."PresentationUniqueKey" IS NULL AND "b1"."PresentationUniqueKey" IS NULL))
LIMIT 1)
FROM "BaseItems" AS "b0"
WHERE "b0"."IsFolder" = @__filter_IsFolder_0 AND COALESCE((
SELECT "u"."Played"
FROM "UserData" AS "u"
WHERE "b0"."Id" = "u"."ItemId" AND "u"."UserId" = @__filter_User_Id_1
LIMIT 1), 0) = @__filter_IsPlayed_2 AND "b0"."IsVirtualItem" = @__isVirtualItem_Value_3 AND "b0"."MediaType" = 'Video' AND "b0"."TopParentId" = '65E0C354-8C9D-74AC-4214-5F90423A863A'
GROUP BY "b0"."PresentationUniqueKey"
)
ORDER BY "b"."DateCreated" DESC, "b"."SortName" DESC, "b"."ProductionYear" DESC
LIMIT @__p_4
) AS "b6"
LEFT JOIN "BaseItemTrailerTypes" AS "b2" ON "b6"."Id" = "b2"."ItemId"
LEFT JOIN "BaseItemProviders" AS "b3" ON "b6"."Id" = "b3"."ItemId"
LEFT JOIN "BaseItemMetadataFields" AS "b4" ON "b6"."Id" = "b4"."ItemId"
LEFT JOIN "UserData" AS "u1" ON "b6"."Id" = "u1"."ItemId"
LEFT JOIN "BaseItemImageInfos" AS "b5" ON "b6"."Id" = "b5"."ItemId"
ORDER BY "b6"."DateCreated" DESC, "b6"."SortName" DESC, "b6"."ProductionYear" DESC, "b6"."Id", "b2"."Id", "b2"."ItemId", "b3"."ItemId", "b3"."ProviderId", "b4"."Id", "b4"."ItemId", "u1"."ItemId", "u1"."UserId", "u1"."CustomDataKey"
[02:52:40] [INF] [24] Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor: Executing OkResult2[[System.Tuple2[[MediaBrowser.Controller.Entities.BaseItem, MediaBrowser.Controller, Version=10.11.0.0, Culture=neutral, PublicKeyToken=null],[System.Collections.Generic.List1[[MediaBrowser.Controller.Entities.BaseItem, MediaBrowser.Controller, Version=10.11.0.0, Culture=neutral, PublicKeyToken=null]], System.Private.CoreLib, Version=9.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], System.Private.CoreLib, Version=9.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[MediaBrowser.Model.Dto.BaseItemDto, MediaBrowser.Model, Version=10.11.0.0, Culture=neutral, PublicKeyToken=null]]'.
[02:52:40] [INF] [24] Microsoft.EntityFrameworkCore.Database.Command: Executed DbCommand (1ms) [Parameters=[@__id_0='?' (DbType = Guid)], CommandType='Text', CommandTimeout='30']
SELECT "b4"."Id", "b4"."Album", "b4"."AlbumArtists", "b4"."Artists", "b4"."Audio", "b4"."ChannelId", "b4"."CleanName", "b4"."CommunityRating", "b4"."CriticRating", "b4"."CustomRating", "b4"."Data", "b4"."DateCreated", "b4"."DateLastMediaAdded", "b4"."DateLastRefreshed", "b4"."DateLastSaved", "b4"."DateModified", "b4"."EndDate", "b4"."EpisodeTitle", "b4"."ExternalId", "b4"."ExternalSeriesId", "b4"."ExternalServiceId", "b4"."ExtraIds", "b4"."ExtraType", "b4"."ForcedSortName", "b4"."Genres", "b4"."Height", "b4"."IndexNumber", "b4"."InheritedParentalRatingSubValue", "b4"."InheritedParentalRatingValue", "b4"."IsFolder", "b4"."IsInMixedFolder", "b4"."IsLocked", "b4"."IsMovie", "b4"."IsRepeat", "b4"."IsSeries", "b4"."IsVirtualItem", "b4"."LUFS", "b4"."MediaType", "b4"."Name", "b4"."NormalizationGain", "b4"."OfficialRating", "b4"."OriginalTitle", "b4"."Overview", "b4"."OwnerId", "b4"."ParentId", "b4"."ParentIndexNumber", "b4"."Path", "b4"."PreferredMetadataCountryCode", "b4"."PreferredMetadataLanguage", "b4"."PremiereDate", "b4"."PresentationUniqueKey", "b4"."PrimaryVersionId", "b4"."ProductionLocations", "b4"."ProductionYear", "b4"."RunTimeTicks", "b4"."SeasonId", "b4"."SeasonName", "b4"."SeriesId", "b4"."SeriesName", "b4"."SeriesPresentationUniqueKey", "b4"."ShowId", "b4"."Size", "b4"."SortName", "b4"."StartDate", "b4"."Studios", "b4"."Tagline", "b4"."Tags", "b4"."TopParentId", "b4"."TotalBitrate", "b4"."Type", "b4"."UnratedType", "b4"."Width", "b0"."Id", "b0"."ItemId", "b1"."ItemId", "b1"."ProviderId", "b1"."ProviderValue", "b2"."Id", "b2"."ItemId", "u"."ItemId", "u"."UserId", "u"."CustomDataKey", "u"."AudioStreamIndex", "u"."IsFavorite", "u"."LastPlayedDate", "u"."Likes", "u"."PlayCount", "u"."PlaybackPositionTicks", "u"."Played", "u"."Rating", "u"."RetentionDate", "u"."SubtitleStreamIndex", "b3"."Id", "b3"."Blurhash", "b3"."DateModified", "b3"."Height", "b3"."ImageType", "b3"."ItemId", "b3"."Path", "b3"."Width"
FROM (
SELECT "b"."Id", "b"."Album", "b"."AlbumArtists", "b"."Artists", "b"."Audio", "b"."ChannelId", "b"."CleanName", "b"."CommunityRating", "b"."CriticRating", "b"."CustomRating", "b"."Data", "b"."DateCreated", "b"."DateLastMediaAdded", "b"."DateLastRefreshed", "b"."DateLastSaved", "b"."DateModified", "b"."EndDate", "b"."EpisodeTitle", "b"."ExternalId", "b"."ExternalSeriesId", "b"."ExternalServiceId", "b"."ExtraIds", "b"."ExtraType", "b"."ForcedSortName", "b"."Genres", "b"."Height", "b"."IndexNumber", "b"."InheritedParentalRatingSubValue", "b"."InheritedParentalRatingValue", "b"."IsFolder", "b"."IsInMixedFolder", "b"."IsLocked", "b"."IsMovie", "b"."IsRepeat", "b"."IsSeries", "b"."IsVirtualItem", "b"."LUFS", "b"."MediaType", "b"."Name", "b"."NormalizationGain", "b"."OfficialRating", "b"."OriginalTitle", "b"."Overview", "b"."OwnerId", "b"."ParentId", "b"."ParentIndexNumber", "b"."Path", "b"."PreferredMetadataCountryCode", "b"."PreferredMetadataLanguage", "b"."PremiereDate", "b"."PresentationUniqueKey", "b"."PrimaryVersionId", "b"."ProductionLocations", "b"."ProductionYear", "b"."RunTimeTicks", "b"."SeasonId", "b"."SeasonName", "b"."SeriesId", "b"."SeriesName", "b"."SeriesPresentationUniqueKey", "b"."ShowId", "b"."Size", "b"."SortName", "b"."StartDate", "b"."Studios", "b"."Tagline", "b"."Tags", "b"."TopParentId", "b"."TotalBitrate", "b"."Type", "b"."UnratedType", "b"."Width"
FROM "BaseItems" AS "b"
WHERE "b"."Id" = @__id_0
LIMIT 1
) AS "b4"
LEFT JOIN "BaseItemTrailerTypes" AS "b0" ON "b4"."Id" = "b0"."ItemId"
LEFT JOIN "BaseItemProviders" AS "b1" ON "b4"."Id" = "b1"."ItemId"
LEFT JOIN "BaseItemMetadataFields" AS "b2" ON "b4"."Id" = "b2"."ItemId"
LEFT JOIN "UserData" AS "u" ON "b4"."Id" = "u"."ItemId"
LEFT JOIN "BaseItemImageInfos" AS "b3" ON "b4"."Id" = "b3"."ItemId"
ORDER BY "b4"."Id", "b0"."Id", "b0"."ItemId", "b1"."ItemId", "b1"."ProviderId", "b2"."Id", "b2"."ItemId", "u"."ItemId", "u"."UserId", "u"."CustomDataKey"
For loading the library itself in 10.11 here is (logs of the thread? that handles) the request that never returns/finishes after 50 minutes:
[02:24:30] [INF] [19] Emby.Server.Implementations.IO.LibraryMonitor: Watching directory /media/tube
[02:53:21] [INF] [19] Microsoft.AspNetCore.Hosting.Diagnostics: Request starting HTTP/1.0 GET http://jellyfin.local/Users/3746f94ab209...&Limit=100 - null null
[02:53:21] [INF] [19] Microsoft.AspNetCore.Routing.EndpointMiddleware: Executing endpoint 'Jellyfin.Api.Controllers.ItemsController.GetItemsByUserIdLegacy (Jellyfin.Api)'
[02:53:21] [INF] [19] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker: Route matched with {action = "GetItemsByUserIdLegacy", controller = "Items"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.ActionResult1[MediaBrowser.Model.Dto.BaseItemDto]] GetItemsByUserIdLegacy(System.Guid, System.String, System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Guid], System.Nullable1[System.Int32], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], MediaBrowser.Model.Entities.LocationType[], MediaBrowser.Model.Entities.LocationType[], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Double], System.Nullable1[System.Double], System.Nullable1[System.DateTime], System.Nullable1[System.DateTime], System.Nullable1[System.DateTime], System.Nullable1[System.DateTime], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Guid[], System.Nullable1[System.Int32], System.Nullable1[System.Int32], System.Nullable1[System.Boolean], System.String, Jellyfin.Database.Implementations.Enums.SortOrder[], System.Nullable1[System.Guid], MediaBrowser.Model.Querying.ItemFields[], Jellyfin.Data.Enums.BaseItemKind[], Jellyfin.Data.Enums.BaseItemKind[], MediaBrowser.Model.Querying.ItemFilter[], System.Nullable1[System.Boolean], Jellyfin.Data.Enums.MediaType[], MediaBrowser.Model.Entities.ImageType[], Jellyfin.Data.Enums.ItemSortBy[], System.Nullable1[System.Boolean], System.String[], System.String[], System.String[], Int32[], System.Nullable1[System.Boolean], System.Nullable1[System.Int32], MediaBrowser.Model.Entities.ImageType[], System.String, System.Guid[], System.String[], System.String[], System.String[], System.Guid[], System.Guid[], System.Guid[], System.Guid[], System.String[], System.Guid[], System.Guid[], MediaBrowser.Model.Entities.VideoType[], System.String, System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Boolean], System.Nullable1[System.Int32], System.Nullable1[System.Int32], System.Nullable1[System.Int32], System.Nullable1[System.Int32], System.Nullable1[System.Boolean], MediaBrowser.Model.Entities.SeriesStatus[], System.String, System.String, System.String, System.Guid[], System.Guid[], Boolean, System.Nullable1[System.Boolean]) on controller Jellyfin.Api.Controllers.ItemsController (Jellyfin.Api).Please let me know if there are any other logs that are needed. Thanks!