Skip to content
This repository has been archived by the owner on Jul 31, 2024. It is now read-only.

Poor query performance in IdentityServer4 3.1.4 #4672

Closed
martinmine opened this issue Jul 21, 2020 · 21 comments
Closed

Poor query performance in IdentityServer4 3.1.4 #4672

martinmine opened this issue Jul 21, 2020 · 21 comments
Assignees

Comments

@martinmine
Copy link

martinmine commented Jul 21, 2020

Comparing the performance on IdentityServer4 2.1.1 and 3.1.4 towards Microsoft SQL Server I have noticed that the query performance is significantly worse. With 2.1.1 we get 1.217ms avg. query time. With 3.1.4 the query time is up in 153ms. We can therefore not use this version in production. Looking at the logs, I can see that it runs a large set of queries torwards the Clients table:

SELECT TOP(1) [t].[Id], [t].[AbsoluteRefreshTokenLifetime], [t].[AccessTokenLifetime], [t].[AccessTokenType], [t].[AllowAccessTokensViaBrowser], [t].[AllowOfflineAccess], [t].[AllowPlainTextPkce], [t].[AllowRememberConsent], [t].[AlwaysIncludeUserClaimsInIdToken], [t].[AlwaysSendClientClaims], [t].[AuthorizationCodeLifetime], [t].[BackChannelLogoutSessionRequired], [t].[BackChannelLogoutUri], [t].[ClientClaimsPrefix], [t].[ClientId], [t].[ClientName], [t].[ClientUri], [t].[ConsentLifetime], [t].[Created], [t].[Description], [t].[DeviceCodeLifetime], [t].[EnableLocalLogin], [t].[Enabled], [t].[FrontChannelLogoutSessionRequired], [t].[FrontChannelLogoutUri], [t].[IdentityTokenLifetime], [t].[IncludeJwtId], [t].[LastAccessed], [t].[LogoUri], [t].[NonEditable], [t].[PairWiseSubjectSalt], [t].[ProtocolType], [t].[RefreshTokenExpiration], [t].[RefreshTokenUsage], [t].[RequireClientSecret], [t].[RequireConsent], [t].[RequirePkce], [t].[SlidingRefreshTokenLifetime], [t].[UpdateAccessTokenClaimsOnRefresh], [t].[Updated], [t].[UserCodeType], [t].[UserSsoLifetime]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]
SELECT [c0].[Id], [c0].[ClientId], [c0].[Origin]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientCorsOrigins] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[GrantType]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientGrantTypes] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[Scope]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientScopes] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[Type], [c0].[Value]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientClaims] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[Created], [c0].[Description], [c0].[Expiration], [c0].[Type], [c0].[Value]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientSecrets] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[Provider]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientIdPRestrictions] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[PostLogoutRedirectUri]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientPostLogoutRedirectUris] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[Key], [c0].[Value]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientProperties] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [c0].[Id], [c0].[ClientId], [c0].[RedirectUri]FROM (    SELECT [c].[Id], [c].[AbsoluteRefreshTokenLifetime], [c].[AccessTokenLifetime], [c].[AccessTokenType], [c].[AllowAccessTokensViaBrowser], [c].[AllowOfflineAccess], [c].[AllowPlainTextPkce], [c].[AllowRememberConsent], [c].[AlwaysIncludeUserClaimsInIdToken], [c].[AlwaysSendClientClaims], [c].[AuthorizationCodeLifetime], [c].[BackChannelLogoutSessionRequired], [c].[BackChannelLogoutUri], [c].[ClientClaimsPrefix], [c].[ClientId], [c].[ClientName], [c].[ClientUri], [c].[ConsentLifetime], [c].[Created], [c].[Description], [c].[DeviceCodeLifetime], [c].[EnableLocalLogin], [c].[Enabled], [c].[FrontChannelLogoutSessionRequired], [c].[FrontChannelLogoutUri], [c].[IdentityTokenLifetime], [c].[IncludeJwtId], [c].[LastAccessed], [c].[LogoUri], [c].[NonEditable], [c].[PairWiseSubjectSalt], [c].[ProtocolType], [c].[RefreshTokenExpiration], [c].[RefreshTokenUsage], [c].[RequireClientSecret], [c].[RequireConsent], [c].[RequirePkce], [c].[SlidingRefreshTokenLifetime], [c].[UpdateAccessTokenClaimsOnRefresh], [c].[Updated], [c].[UserCodeType], [c].[UserSsoLifetime]    FROM [Clients] AS [c]    WHERE [c].[ClientId] = 'myservice') AS [t]INNER JOIN [ClientRedirectUris] AS [c0] ON [t].[Id] = [c0].[ClientId]
SELECT [i].[Id], [i].[Created], [i].[Description], [i].[DisplayName], [i].[Emphasize], [i].[Enabled], [i].[Name], [i].[NonEditable], [i].[Required], [i].[ShowInDiscoveryDocument], [i].[Updated], [i0].[Id], [i0].[IdentityResourceId], [i0].[Type], [i1].[Id], [i1].[IdentityResourceId], [i1].[Key], [i1].[Value]FROM [IdentityResources] AS [i]LEFT JOIN [IdentityClaims] AS [i0] ON [i].[Id] = [i0].[IdentityResourceId]LEFT JOIN [IdentityProperties] AS [i1] ON [i].[Id] = [i1].[IdentityResourceId]WHERE [i].[Name] IN (N'scopes')ORDER BY [i].[Id], [i0].[Id], [i1].[Id]

SELECT 
    [a].[Id], [a].[Created], [a].[Description], [a].[DisplayName], [a].[Enabled], 
    [a].[LastAccessed], [a].[Name], [a].[NonEditable], [a].[Updated], 
    [a0].[Id], [a0].[ApiResourceId], [a0].[Created], [a0].[Description], 
    [a0].[Expiration], [a0].[Type], [a0].[Value], 
    [t].[Id], [t].[ApiResourceId], [t].[Description], [t].[DisplayName], [t].[Emphasize],
    [t].[Name], [t].[Required], [t].[ShowInDiscoveryDocument], [t].[Id0], [t].[ApiScopeId],
    [t].[Type],
    [a3].[Id], [a3].[ApiResourceId], [a3].[Type],
    [a4].[Id], [a4].[ApiResourceId], [a4].[Key], [a4].[Value]
    FROM [ApiResources] AS [a]
    LEFT JOIN [ApiSecrets] AS [a0] ON [a].[Id] = [a0].[ApiResourceId]
    LEFT JOIN (
            SELECT
                [a1].[Id], [a1].[ApiResourceId], [a1].[Description], [a1].[DisplayName],
                [a1].[Emphasize], [a1].[Name], [a1].[Required], [a1].[ShowInDiscoveryDocument],
                [a2].[Id] AS [Id0], [a2].[ApiScopeId], [a2].[Type]
                        FROM [ApiScopes] AS [a1]
                        LEFT JOIN [ApiScopeClaims] AS [a2] ON [a1].[Id] = [a2].[ApiScopeId]) AS [t] ON [a].[Id] = [t].[ApiResourceId]
    LEFT JOIN [ApiClaims] AS [a3] ON [a].[Id] = [a3].[ApiResourceId]
    LEFT JOIN [ApiProperties] AS [a4] ON [a].[Id] = [a4].[ApiResourceId]
    WHERE EXISTS (
        SELECT 1 FROM [ApiScopes] AS [a5]
        WHERE ([a].[Id] = [a5].[ApiResourceId])
        AND [a5].[Name] IN 
        (N'scopes'))
    ORDER BY [a].[Id], [a0].[Id], [t].[Id], [t].[Id0], [a3].[Id], [a4].[Id]
SELECT [i].[Id], [i].[Created], [i].[Description], [i].[DisplayName], [i].[Emphasize], [i].[Enabled], [i].[Name], [i].[NonEditable], [i].[Required], [i].[ShowInDiscoveryDocument], [i].[Updated], [i0].[Id], [i0].[IdentityResourceId], [i0].[Type], [i1].[Id], [i1].[IdentityResourceId], [i1].[Key], [i1].[Value]FROM [IdentityResources] AS [i]LEFT JOIN [IdentityClaims] AS [i0] ON [i].[Id] = [i0].[IdentityResourceId]LEFT JOIN [IdentityProperties] AS [i1] ON [i].[Id] = [i1].[IdentityResourceId]WHERE [i].[Name] IN (N'scopes')ORDER BY [i].[Id], [i0].[Id], [i1].[Id]
SELECT [a].[Id], [a].[Created], [a].[Description], [a].[DisplayName], [a].[Enabled], [a].[LastAccessed], [a].[Name], [a].[NonEditable], [a].[Updated], [a0].[Id], [a0].[ApiResourceId], [a0].[Created], [a0].[Description], [a0].[Expiration], [a0].[Type], [a0].[Value], [t].[Id], [t].[ApiResourceId], [t].[Description], [t].[DisplayName], [t].[Emphasize], [t].[Name], [t].[Required], [t].[ShowInDiscoveryDocument], [t].[Id0], [t].[ApiScopeId], [t].[Type], [a3].[Id], [a3].[ApiResourceId], [a3].[Type], [a4].[Id], [a4].[ApiResourceId], [a4].[Key], [a4].[Value]FROM [ApiResources] AS [a]LEFT JOIN [ApiSecrets] AS [a0] ON [a].[Id] = [a0].[ApiResourceId]LEFT JOIN (    SELECT [a1].[Id], [a1].[ApiResourceId], [a1].[Description], [a1].[DisplayName], [a1].[Emphasize], [a1].[Name], [a1].[Required], [a1].[ShowInDiscoveryDocument], [a2].[Id] AS [Id0], [a2].[ApiScopeId], [a2].[Type]    FROM [ApiScopes] AS [a1]    LEFT JOIN [ApiScopeClaims] AS [a2] ON [a1].[Id] = [a2].[ApiScopeId]) AS [t] ON [a].[Id] = [t].[ApiResourceId]LEFT JOIN [ApiClaims] AS [a3] ON [a].[Id] = [a3].[ApiResourceId]LEFT JOIN [ApiProperties] AS [a4] ON [a].[Id] = [a4].[ApiResourceId]WHERE EXISTS (    SELECT 1    FROM [ApiScopes] AS [a5]    WHERE ([a].[Id] = [a5].[ApiResourceId]) AND [a5].[Name] IN (N'scopes'))ORDER BY [a].[Id], [a0].[Id], [t].[Id], [t].[Id0], [a3].[Id], [a4].[Id]

After looking at the ClientStore class (https://github.com/IdentityServer/IdentityServer4/blob/3.1.4/src/EntityFramework.Storage/src/Stores/ClientStore.cs), I noticed that it is split up into many queries. By reverting the change added by c2dd330 (raised by #3718), I managed to a comparable performance benchmarks I got from 2.1.1 with 2.383ms avg. query time (the additional query time is however compensated with faster request/response time, where the new version with the custom FindClientByIdAsync has an average request time on 24ms, down from 41ms). I ended up with the following implementation of FindClientByIdAsync:

public override async Task<Client> FindClientByIdAsync(string clientId)
{
    var client = await Context.Clients
        .Include(x => x.AllowedGrantTypes)
        .Include(x => x.RedirectUris)
        .Include(x => x.PostLogoutRedirectUris)
        .Include(x => x.AllowedScopes)
        .Include(x => x.ClientSecrets)
        .Include(x => x.Claims)
        .Include(x => x.IdentityProviderRestrictions)
        .Include(x => x.AllowedCorsOrigins)
        .Include(x => x.Properties)
        .FirstOrDefaultAsync(x => x.ClientId == clientId);
    var model = client?.ToModel();

    Logger.LogDebug("{clientId} found in database: {clientIdFound}", clientId, model != null);

    return model;
}
@martinmine martinmine changed the title Poor query performance in IdentityServer 4 3.1.4 Poor query performance in IdentityServer4 3.1.4 Jul 21, 2020
@brockallen
Copy link
Member

Did you revert the change and test it with our v4.0.x? That's where we'd consider making this change. Also, can you share anything on how you did the testing (test scripts, etc)? I'd like to be able to run the same tests locally to confirm. I am a bit boggled -- the reason for the prior change was to address the per issues introduced by changes in EFCore for 3.x. So now you're suggesting we revert those. So I'm trying to figure out which code style w/ EF is the real perf problem. Thanks.

@martinmine
Copy link
Author

I haven't tested it on v4.0.x as it introduced a lot of breaking changes that will be expensive for me to move over for now. The implementation I pasted is running on IdentityServer4 3.1.4 towards a Microsoft SQL Server 2016 SP2. The issue in #3718 is in combination with Postgres, it might be that Postgres caches data differently compared to Microsoft SQL. I am not suggesting we should revert the change, but rather investigate why we are seeing this difference between Postgres and Microsoft SQL. Just because the code I posted above works better for my scenario doesn't mean it works for everyone.
I am using Artillery for running this performance test towards IdentityServer4:

config:
  target: "http://identityserver.example.com"
  http:
    pool: 200
  phases:
    - name: "Warmup"
      duration: 30
      arrivalRate: 10
      rampTo: 10
    - name: "Stress test"
      duration: 1200
      arrivalRate: 35
      maxVusers: 200
scenarios:
  - name: "tokens" 
    weight: 8
    flow:
      - post:
          name: "Generate token with extra data"
          url: "/connect/token"
          auth:
            user: "referencetokenservice"
            password: "secret"
          form:
            grant_type: "client_credentials"
            scope: "scope1 scope2 scope3 scope4 scope5"
            ext:foo: "bar"
            ext:id: "2b8ae4b6-a9d9-423b-9620-01341b244f86"
            ext:traceId: "8c6489fa-5633-496c-82f3-148eaebed3fc"
            ext:resourceId: "c406a9c7-b090-450e-3ae9-08d7fd683c77"
          capture:
            - json: "$.access_token"
              as: "token"
      - post:
          name: "Introspect token"
          url: "/connect/introspect"
          auth:
            user: "introspectionservice"
            password: "secret"
          form: 
            token: "{{token}}"
  - name: "Reference service token"
    weight: 1
    flow:
    - post:
        name: "Generate service reference token"
        url: "/connect/token"
        auth:
          user: "referencetokenservice"
          password: "secret"
        form: 
          grant_type: "client_credentials"
          scope: "myscope1 myscope2"
        capture:
          - json: "$.access_token"
            as: "token"
    - post:
        name: "Introspect service reference token"
        url: "/connect/introspect"
        auth:
          user: "introspectionservice"
          password: "secret"
        form: 
          token: "{{token}}"
  - name: "Generate JWT token"
    weight: 1
    flow:
      - post:
          name: "Generate service JWT token"
          url: "/connect/token"
          auth:
            user: "jwtservice"
            password: "secret"
          form: 
            grant_type: "client_credentials"
            scope: "myscope1 myscope2"

@martinmine
Copy link
Author

I did some more testing with the different changes that has been made to the ClientStore (for example without async, moving null checks, and so on) in order to isolate error sources. It all points to that splitting it up into multiple queries leads to a significant negative impact request throughput. I can also see that with the version I posted above, the CPU usage is much lower compared to the original ClientStore. In my case, the stress test runs towards two machines running IdentityServer4, with a third machine hosting the database. The additional network overhead could also be a factor in the increased latency I experience with the new ClientStore class.

@brockallen
Copy link
Member

Would you be willing to try Postgres to see how that compares?

@martinmine
Copy link
Author

I will do some investigation and see if I can replicate that behavior with Postgresql.

@martinmine
Copy link
Author

martinmine commented Jul 22, 2020

I've set up a local SQL server with MSSQL and Postgresql and ran the Artillery script I have above (without the introspection requests), that resulted in the following results:
MSSQL:
Average request time optimized: 17.5ms
Average request time unoptimized: 21ms

Postgresql:
Average request time optimized: 13ms
Average request time unoptimized: 16.2ms

By unoptimized I mean the code that IdentityServer4 comes with out of the box, while optimized is with the change I have commented with in this issue. In other words, the change actually decreases performance for both Postgresql and MSSQL.

@brockallen
Copy link
Member

Ok, thanks for that research. We'll figure out what to do next.

@martinmine
Copy link
Author

I managed to replicate the issue in #3718 with more data in my configuration tables. As the issue they experienced was due to the cartesian product, I got the following results towards MSSQL by adding 40 ClientRedirectUris to the client that I have:
Optimized: 150ms, 213ms
Unoptimized: 21ms, 21.6ms

Will do some more digging and see if I can find a way to optimize this that benefits both use-cases. What is most interesting is how the response time jumped up from the old IdentityServer 2.1.1 to 3.x even with running the queries separately.

@martinmine
Copy link
Author

I ended up with the following implementation of FindClientByIdAsync.FindClientByIdAsync:

public override async Task<Client> FindClientByIdAsync(string clientId)
{
    var baseQuery = Context.Clients.Where(x => x.ClientId == clientId);

    var client = await baseQuery.FirstOrDefaultAsync();

    await baseQuery.SelectMany(x => x.AllowedCorsOrigins).LoadAsync();
    await baseQuery.SelectMany(x => x.AllowedGrantTypes).LoadAsync();
    await baseQuery.SelectMany(x => x.AllowedScopes).LoadAsync();
    await baseQuery.SelectMany(x => x.Claims).LoadAsync();
    await baseQuery.SelectMany(x => x.ClientSecrets).LoadAsync();
    await baseQuery.SelectMany(x => x.IdentityProviderRestrictions).LoadAsync();
    await baseQuery.SelectMany(x => x.PostLogoutRedirectUris).LoadAsync();
    await baseQuery.SelectMany(x => x.Properties).LoadAsync();
    await baseQuery.SelectMany(x => x.RedirectUris).LoadAsync();

    var model = client?.ToModel();

    Logger.LogDebug("{clientId} found in database: {clientIdFound}", clientId, model != null);

    return model;
}

This nearly halfed the response times from a baseline on 118ms. Unfortunately I wasn't able to reproduce the high response times as my friends had done maintenance on the database server while I was on vacation. However, I have noticed that with this change I get more or less identical performance as with the 2.x of IdentityServer4. Comparing the queries, I see that FirstOrDefaultAsync produces a TOP (1) query which is the same as previously. So I think it would be wise to use FirstOrDefaultAsync over SingleOrDefault. The code I ended up with is also a bit more cleaner, but I am not sure if or why it would impact performance. It does however follow what is suggested here: dotnet/efcore#18017 (comment)

@martinmine
Copy link
Author

I have completed performing benchmarks with async vs. non-async and found that using async APIs caused a very unstable response times around 60-100. With non-async APIs I got a stable 30ms response time which is faster than 2.x.

@brockallen
Copy link
Member

I have completed performing benchmarks with async vs. non-async and found that using async APIs caused a very unstable response times around 60-100. With non-async APIs I got a stable 30ms response time which is faster than 2.x.

@ajcvickers any ideas (perhaps on this whole thread)?

@martinmine
Copy link
Author

From what I gather, with async the API will basically queue up work for the database to process, as the API will start processing next request once it is waiting for the SQL server to do IO. What I am seeing is that the database is struggling with keeping up with processing the queries generated by the API. This discussion is related to #2067.

I also found several queries that can be optimized and fine-tuned in the stores. For example, getting an entry from PersistedGrants is using a regular .Where, which runs a .ToArrayAsync and then it runs a .SingleOrDefault with the same predicate as in the .Where:

var persistedGrant = (await Context.PersistedGrants.AsNoTracking().Where(x => x.Key == key).ToArrayAsync())
    .SingleOrDefault(x => x.Key == key);

This can be simplified to:

var persistedGrant = await Context.PersistedGrants
    .AsNoTracking()
    .FirstOrDefaultAsync(x => x.Key == key);

The same can be seen in StoreAsync when grants are stored, but this can also be refactored using AnyAsync and then fetch the grant from the database if it exists (the second select will be quite fast due to caching, but this path should not be the one that occurs most frequently the way I see it)

@martinmine
Copy link
Author

Did some digging today and found that the following stack trace occurred several times in the process dumps I took under heavy load:

 	[Managed to Native Transition]	
>	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParserStateObjectNative.ReadSyncOverAsync(int timeoutRemaining, out uint error)	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParserStateObject.TryReadByte(out byte value)	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParser.TryRun(Microsoft.Data.SqlClient.RunBehavior runBehavior, Microsoft.Data.SqlClient.SqlCommand cmdHandler, Microsoft.Data.SqlClient.SqlDataReader dataStream, Microsoft.Data.SqlClient.BulkCopySimpleResultSet bulkCopyHandler, Microsoft.Data.SqlClient.TdsParserStateObject stateObj, out bool dataReady)	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParser.Run(Microsoft.Data.SqlClient.RunBehavior runBehavior, Microsoft.Data.SqlClient.SqlCommand cmdHandler, Microsoft.Data.SqlClient.SqlDataReader dataStream, Microsoft.Data.SqlClient.BulkCopySimpleResultSet bulkCopyHandler, Microsoft.Data.SqlClient.TdsParserStateObject stateObj)	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(byte[] buffer, Microsoft.Data.SqlClient.TdsEnums.TransactionManagerRequestType request, string transactionName, Microsoft.Data.SqlClient.TdsEnums.TransactionManagerIsolationLevel isoLevel, int timeout, Microsoft.Data.SqlClient.SqlInternalTransaction transaction, Microsoft.Data.SqlClient.TdsParserStateObject stateObj, bool isDelegateControlRequest)	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(Microsoft.Data.SqlClient.SqlInternalConnection.TransactionRequest transactionRequest, string transactionName, System.Data.IsolationLevel iso, Microsoft.Data.SqlClient.SqlInternalTransaction internalTransaction, bool isDelegateControlRequest)	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlInternalTransaction.Commit()	Unknown
 	Microsoft.Data.SqlClient.dll!Microsoft.Data.SqlClient.SqlTransaction.Commit()	Unknown
 	Microsoft.EntityFrameworkCore.Relational.dll!Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Commit() Line 104	C#
 	Microsoft.EntityFrameworkCore.Relational.dll!Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(System.Collections.Generic.IEnumerable<Microsoft.EntityFrameworkCore.Update.ModificationCommandBatch> commandBatches, Microsoft.EntityFrameworkCore.Storage.IRelationalConnection connection, System.Threading.CancellationToken cancellationToken) Line 145	C#
 	[Resuming Async Method]	
 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 172	C#
 	System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder<int>.AsyncStateMachineBox<Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.<ExecuteAsync>d__8>.MoveNext(System.Threading.Thread threadPoolThread) Line 617	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox box, bool allowInlining) Line 794	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3320	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task<System.Threading.Tasks.VoidTaskResult>.TrySetResult(System.Threading.Tasks.VoidTaskResult result) Line 419	C#
 	Microsoft.EntityFrameworkCore.Relational.dll!Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.ExecuteAsync(Microsoft.EntityFrameworkCore.Storage.IRelationalConnection connection, System.Threading.CancellationToken cancellationToken) Line 296	C#
 	Microsoft.EntityFrameworkCore.Relational.dll!Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.ExecuteAsync(Microsoft.EntityFrameworkCore.Storage.IRelationalConnection connection, System.Threading.CancellationToken cancellationToken) Line 296	C#
 	[Resuming Async Method]	
 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 172	C#
 	System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder<System.Threading.Tasks.VoidTaskResult>.AsyncStateMachineBox<Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.<ExecuteAsync>d__29>.MoveNext(System.Threading.Thread threadPoolThread) Line 617	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox box, bool allowInlining) Line 794	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3320	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task<System.__Canon>.TrySetResult(System.__Canon result) Line 419	C#
 	Microsoft.EntityFrameworkCore.Relational.dll!Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(Microsoft.EntityFrameworkCore.Storage.RelationalCommandParameterObject parameterObject, System.Threading.CancellationToken cancellationToken) Line 560	C#
 	Microsoft.EntityFrameworkCore.Relational.dll!Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(Microsoft.EntityFrameworkCore.Storage.RelationalCommandParameterObject parameterObject, System.Threading.CancellationToken cancellationToken) Line 560	C#
 	[Resuming Async Method]	
 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 172	C#
 	System.Private.CoreLib.dll!System.Runtime.CompilerServices.AsyncTaskMethodBuilder<Microsoft.EntityFrameworkCore.Storage.RelationalDataReader>.AsyncStateMachineBox<Microsoft.EntityFrameworkCore.Storage.RelationalCommand.<ExecuteReaderAsync>d__17>.MoveNext(System.Threading.Thread threadPoolThread) Line 617	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.AwaitTaskContinuation.RunOrScheduleAction(System.Runtime.CompilerServices.IAsyncStateMachineBox box, bool allowInlining) Line 794	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3320	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2049	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.ExecuteWithThreadLocal(ref System.Threading.Tasks.Task currentTaskSlot, System.Threading.Thread threadPoolThread) Line 2402	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.ThreadPoolTaskScheduler.TryExecuteTaskInline(System.Threading.Tasks.Task task, bool taskWasPreviouslyQueued) Line 77	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.TaskScheduler.TryRunInline(System.Threading.Tasks.Task task, bool taskWasPreviouslyQueued) Line 201	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.TaskContinuation.InlineIfPossibleOrElseQueue(System.Threading.Tasks.Task task, bool needsProtection) Line 236	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3332	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task<System.__Canon>.TrySetResult(System.__Canon result) Line 419	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.UnwrapPromise<Microsoft.Data.SqlClient.SqlDataReader>.TrySetFromTask(System.Threading.Tasks.Task task, bool lookForOce) Line 6697	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.UnwrapPromise<System.__Canon>.ProcessInnerTask(System.Threading.Tasks.Task task) Line 6721	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.RunContinuations(object continuationObject) Line 3338	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.FinishSlow(bool userDelegateExecute) Line 2049	C#
 	System.Private.CoreLib.dll!System.Threading.Tasks.Task.ExecuteWithThreadLocal(ref System.Threading.Tasks.Task currentTaskSlot, System.Threading.Thread threadPoolThread) Line 2402	C#
 	System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch() Line 663	C#
 	[Async Call Stack]	
 	[External Code]	

To me, this looks like a synchronous API-call inside EF-Core internals towards the Microsoft.Data.SqlClient using its own synchronous Commit: https://github.com/dotnet/efcore/blob/v3.1.6/src/EFCore.Relational/Update/Internal/BatchExecutor.cs#L145

This looks like have been fixed by a later commit: dotnet/efcore@1e977ae#diff-c5e724774bdd22fa0e9f3c2143e74d1b

I will go ahead and create an issue on their gh regarding this.

@ajcvickers
Copy link

/cc @roji since we have been discussing cases like this.

@roji
Copy link

roji commented Jul 31, 2020

Some comments:

@martinmine
Copy link
Author

I have ended up mitigating this issue by using the in-memory cache for ClientStore and ResourceStore for now. This will effectively eliminate almost all SELECT queries (except for the ones towards PersistedGrants). For my case it seems that the performance issues I experience is a combination of periodically slow SQL server together with excessive use of async and possibly blocking APIs. I have not been able to reproduce the perf issues with pgsql so far.

@roji
Copy link

roji commented Aug 3, 2020

@martinmine thanks for the additional details. AFAIK with Npgsql/PostgreSQL, all async calls are indeed async all the way down, so there shouldn't be any sort of TP starvation issue as with SqlClient in dotnet/efcore#21818 - that may be why PG works OK (but the periodically slow SQL Server sounds like something to investigate as well).

@stann1
Copy link

stann1 commented Aug 15, 2020

I have ended up mitigating this issue by using the in-memory cache for ClientStore and ResourceStore for now.

@martinmine Can you share how you managed to override them? I'm using IdentityServer4 (3.1.2) as a nuget package, so I do not see a way to do that.

@brockallen
Copy link
Member

So where do we stand here? I think there's no change to be made in IdentityServer, correct?

@brockallen brockallen added this to the 4.0.5 milestone Sep 7, 2020
@brockallen brockallen self-assigned this Sep 7, 2020
@brockallen
Copy link
Member

Closing. If you still have issues, feel free to reopen.

@brockallen brockallen removed this from the 4.1.0 milestone Sep 9, 2020
@github-actions
Copy link

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Nov 26, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

5 participants