Slow response time for /api/abp/application-configuration during login #10565

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

The timing shows GetAuthConfigAsync alone takes 3474ms — and looking at the timestamps, there's a 3-second gap BEFORE the BulkPermissionStore cache hits. This means the bottleneck is somewhere inside GetAuthConfigAsync before it even reaches the permission check.

I've updated OptimizedAppConfigurationAppService.cs with detailed step-by-step timing. Please replace the file and make two requests (first login + one page refresh), then share the logs. We'll see exactly which step is slow:

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Authorization;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations;
using Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.ObjectExtending;
using Volo.Abp.Authorization;
using Volo.Abp.Authorization.Permissions;
using Volo.Abp.DependencyInjection;
using Volo.Abp.Features;
using Volo.Abp.Localization;
using Volo.Abp.MultiTenancy;
using Volo.Abp.Settings;
using Volo.Abp.Timing;
using Volo.Abp.Users;

[Dependency(ReplaceServices = true)]
[ExposeServices(typeof(IAbpApplicationConfigurationAppService))]
public class OptimizedAppConfigurationAppService : AbpApplicationConfigurationAppService
{
    public OptimizedAppConfigurationAppService(
        IOptions<AbpLocalizationOptions> localizationOptions,
        IOptions<AbpMultiTenancyOptions> multiTenancyOptions,
        IServiceProvider serviceProvider,
        IAbpAuthorizationPolicyProvider abpAuthorizationPolicyProvider,
        IPermissionDefinitionManager permissionDefinitionManager,
        DefaultAuthorizationPolicyProvider defaultAuthorizationPolicyProvider,
        IPermissionChecker permissionChecker,
        IAuthorizationService authorizationService,
        ICurrentUser currentUser,
        ISettingProvider settingProvider,
        ISettingDefinitionManager settingDefinitionManager,
        IFeatureDefinitionManager featureDefinitionManager,
        ILanguageProvider languageProvider,
        ITimezoneProvider timezoneProvider,
        IOptions<AbpClockOptions> abpClockOptions,
        ICachedObjectExtensionsDtoService cachedObjectExtensionsDtoService,
        IOptions<AbpApplicationConfigurationOptions> options)
        : base(localizationOptions, multiTenancyOptions, serviceProvider,
            abpAuthorizationPolicyProvider, permissionDefinitionManager,
            defaultAuthorizationPolicyProvider, permissionChecker,
            authorizationService, currentUser, settingProvider,
            settingDefinitionManager, featureDefinitionManager,
            languageProvider, timezoneProvider, abpClockOptions,
            cachedObjectExtensionsDtoService, options)
    {
    }

    protected override async Task<ApplicationAuthConfigurationDto> GetAuthConfigAsync()
    {
        var totalSw = Stopwatch.StartNew();
        var sw = Stopwatch.StartNew();

        var authConfig = new ApplicationAuthConfigurationDto();

        var abpAuthorizationPolicyProvider = LazyServiceProvider
            .LazyGetRequiredService<IAbpAuthorizationPolicyProvider>();
        var permissionDefinitionManager = LazyServiceProvider
            .LazyGetRequiredService<IPermissionDefinitionManager>();
        var defaultAuthorizationPolicyProvider = LazyServiceProvider
            .LazyGetRequiredService<DefaultAuthorizationPolicyProvider>();
        var permissionChecker = LazyServiceProvider
            .LazyGetRequiredService<IPermissionChecker>();
        var authorizationService = LazyServiceProvider
            .LazyGetRequiredService<IAuthorizationService>();

        // Step 1: Get all policy names
        var policyNames = await abpAuthorizationPolicyProvider.GetPoliciesNamesAsync();
        Logger.LogInformation(
            "OptimizedAppConfig [Step1] GetPoliciesNamesAsync: {Elapsed}ms, count: {Count}",
            sw.ElapsedMilliseconds, policyNames.Count);

        // Step 2: Load all permission definitions into HashSet
        sw.Restart();
        var permissionNameSet = new HashSet<string>(
            (await permissionDefinitionManager.GetPermissionsAsync()).Select(p => p.Name),
            StringComparer.Ordinal);
        Logger.LogInformation(
            "OptimizedAppConfig [Step2] GetPermissionsAsync+HashSet: {Elapsed}ms, count: {Count}",
            sw.ElapsedMilliseconds, permissionNameSet.Count);

        // Step 3: Classify policy names (ABP permissions vs other policies)
        sw.Restart();
        var abpPolicyNames = new List<string>();
        var otherPolicyNames = new List<string>();

        foreach (var policyName in policyNames)
        {
            if (await defaultAuthorizationPolicyProvider.GetPolicyAsync(policyName) == null &&
                permissionNameSet.Contains(policyName))
            {
                abpPolicyNames.Add(policyName);
            }
            else
            {
                otherPolicyNames.Add(policyName);
            }
        }
        Logger.LogInformation(
            "OptimizedAppConfig [Step3] ClassifyPolicies loop: {Elapsed}ms, abp: {AbpCount}, other: {OtherCount}",
            sw.ElapsedMilliseconds, abpPolicyNames.Count, otherPolicyNames.Count);

        // Step 4: Check other (non-ABP) policies
        sw.Restart();
        foreach (var policyName in otherPolicyNames)
        {
            if (await authorizationService.IsGrantedAsync(policyName))
            {
                authConfig.GrantedPolicies[policyName] = true;
            }
        }
        Logger.LogInformation(
            "OptimizedAppConfig [Step4] OtherPolicies check: {Elapsed}ms",
            sw.ElapsedMilliseconds);

        // Step 5: Batch permission check (goes through OptimizedPermissionChecker -> BulkPermissionStore)
        sw.Restart();
        var result = await permissionChecker.IsGrantedAsync(abpPolicyNames.ToArray());
        foreach (var item in result.Result)
        {
            if (item.Value == PermissionGrantResult.Granted)
            {
                authConfig.GrantedPolicies[item.Key] = true;
            }
        }
        Logger.LogInformation(
            "OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: {Elapsed}ms, granted: {Count}",
            sw.ElapsedMilliseconds, authConfig.GrantedPolicies.Count);

        Logger.LogInformation(
            "OptimizedAppConfig GetAuthConfigAsync total: {Elapsed}ms",
            totalSw.ElapsedMilliseconds);

        return authConfig;
    }

    protected override async Task<ApplicationFeatureConfigurationDto> GetFeaturesConfigAsync()
    {
        var sw = Stopwatch.StartNew();
        var result = await base.GetFeaturesConfigAsync();
        Logger.LogInformation("OptimizedAppConfig: GetFeaturesConfigAsync took {Elapsed}ms", sw.ElapsedMilliseconds);
        return result;
    }

    protected override async Task<ApplicationLocalizationConfigurationDto> GetLocalizationConfigAsync(
        ApplicationConfigurationRequestOptions options)
    {
        var sw = Stopwatch.StartNew();
        var result = await base.GetLocalizationConfigAsync(options);
        Logger.LogInformation("OptimizedAppConfig: GetLocalizationConfigAsync took {Elapsed}ms", sw.ElapsedMilliseconds);
        return result;
    }

    protected override async Task<TimingDto> GetTimingConfigAsync()
    {
        var sw = Stopwatch.StartNew();
        var result = await base.GetTimingConfigAsync();
        Logger.LogInformation("OptimizedAppConfig: GetTimingConfigAsync took {Elapsed}ms", sw.ElapsedMilliseconds);
        return result;
    }
}

The logs will show something like:

OptimizedAppConfig [Step1] GetPoliciesNamesAsync: XXms, count: XXX
OptimizedAppConfig [Step2] GetPermissionsAsync+HashSet: XXms, count: XXX
OptimizedAppConfig [Step3] ClassifyPolicies loop: XXms, abp: XXX, other: XXX
OptimizedAppConfig [Step4] OtherPolicies check: XXms
OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: XXms, granted: XXX
OptimizedAppConfig GetAuthConfigAsync total: XXms

This will tell us exactly which step is consuming the 3474ms. Please share logs for both the first request (cold) and second request (warm).

Thanks

0

vkelwan created 5 months ago

Hello

This is first request (cold) logs

1:46:49 LOG [06:16:33 DBG] Executing AbpApplicationConfigurationAppService.GetAsync()... 11:46:49 LOG [06:16:33 INF] OptimizedAppConfig [Step1] GetPoliciesNamesAsync: 6ms, count: 4358 11:46:49 LOG [06:16:33 INF] OptimizedAppConfig [Step2] GetPermissionsAsync+HashSet: 3ms, count: 4358 11:46:49 LOG [06:16:33 INF] OptimizedAppConfig [Step3] ClassifyPolicies loop: 0ms, abp: 4358, other: 0 11:46:49 LOG [06:16:33 INF] OptimizedAppConfig [Step4] OtherPolicies check: 0ms 11:46:49 LOG [06:16:35 INF] OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: 1867ms, granted: 0 11:46:49 LOG [06:16:35 INF] OptimizedAppConfig GetAuthConfigAsync total: 1877ms 11:46:49 LOG [06:16:35 INF] OptimizedAppConfig: GetFeaturesConfigAsync took 16ms 11:46:49 LOG [06:16:35 INF] OptimizedAppConfig: GetLocalizationConfigAsync took 0ms 11:46:49 LOG [06:16:35 INF] OptimizedAppConfig: GetTimingConfigAsync took 1ms 11:46:49 LOG [06:16:35 DBG] Executed AbpApplicationConfigurationAppService.GetAsync(). 11:46:49 LOG [06:16:35 INF] Executing ObjectResult, writing value of type 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.ApplicationConfigurationDto'. 11:46:49 LOG [06:16:35 INF] Executed action Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc) in 1908.0486ms 11:46:49 LOG [06:16:35 INF] Executed endpoint 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc)' 11:46:49 LOG [06:16:35 INF] Request finished HTTP/1.1 GET http://adminserver/api/abp/application-configuration?includeLocalizationResources=false - 200 null application/json; charset=utf-8 1911.3843ms 11:46:49 LOG [06:16:35 INF] Request starting HTTP/1.1 GET http://adminserver/api/abp/application-localization?cultureName=en&onlyDynamics=false - null null

This is second request (warm) logs

11:37:54 LOG [06:07:10 DBG] Executing AbpApplicationConfigurationAppService.GetAsync()... 11:37:54 LOG [06:07:10 INF] OptimizedAppConfig [Step1] GetPoliciesNamesAsync: 6ms, count: 4358 11:37:54 LOG [06:07:10 INF] OptimizedAppConfig [Step2] GetPermissionsAsync+HashSet: 3ms, count: 4358 11:37:54 LOG [06:07:10 INF] OptimizedAppConfig [Step3] ClassifyPolicies loop: 0ms, abp: 4358, other: 0 11:37:54 LOG [06:07:10 INF] OptimizedAppConfig [Step4] OtherPolicies check: 0ms 11:37:54 LOG [06:07:13 DBG] BulkPermissionStore: cache hit for U:8e19f3c2-3cca-01a5-c78a-3a1fd5abe6b6. 11:37:54 LOG [06:07:13 DBG] BulkPermissionStore: cache hit for R:admin. 11:37:54 LOG [06:07:13 DBG] BulkPermissionStore: cache hit for C:Angular. 11:37:54 LOG [06:07:13 INF] OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: 3462ms, granted: 1822 11:37:54 LOG [06:07:13 INF] OptimizedAppConfig GetAuthConfigAsync total: 3473ms 11:37:54 LOG [06:07:13 INF] OptimizedAppConfig: GetFeaturesConfigAsync took 30ms 11:37:54 LOG [06:07:13 INF] OptimizedAppConfig: GetLocalizationConfigAsync took 0ms 11:37:54 LOG [06:07:13 INF] OptimizedAppConfig: GetTimingConfigAsync took 1ms 11:37:54 LOG [06:07:13 DBG] Executed AbpApplicationConfigurationAppService.GetAsync(). 11:37:54 LOG [06:07:13 INF] Executing ObjectResult, writing value of type 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.ApplicationConfigurationDto'. 11:37:54 LOG [06:07:13 INF] Executed action Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc) in 3517.73ms 11:37:54 LOG [06:07:13 INF] Executed endpoint 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc)' 11:37:54 LOG [06:07:13 INF] Request finished HTTP/1.1 GET http://adminserver/api/abp/application-configuration?includeLocalizationResources=false - 200 null application/json; charset=utf-8 3523.7173ms 11:37:54 LOG [06:07:14 INF] Request starting HTTP/1.1 GET http://adminserver/api/abp/application-localization?cultureName=en&onlyDynamics=false - null null

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

Great, the timing logs pinpoint the issue perfectly:

Step1: 6ms    ✅ fast
Step2: 3ms    ✅ fast  
Step3: 0ms    ✅ fast
Step4: 0ms    ✅ fast
Step5: 3462ms ← all the time is here

Step 5 (PermissionChecker.IsGrantedAsync) is taking 3462ms. This strongly suggests the OptimizedPermissionChecker is not being picked up by DI in this environment. Without it, the original PermissionChecker calls GetOrNullAsync + StateCheckerManager.IsEnabledAsync individually for each of the 4358 permissions — that's ~8700 async operations with semaphore locks and DI scope creation, which explains the 3.4 seconds.

Please replace both files with these updated versions. They include diagnostic logging that will confirm whether OptimizedPermissionChecker is active and show exactly where time is spent.

File 1: OptimizedPermissionChecker.cs (replace existing)

using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Security.Claims;
using System.Threading.Tasks;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;
using Volo.Abp;
using Volo.Abp.Authorization.Permissions;
using Volo.Abp.DependencyInjection;
using Volo.Abp.MultiTenancy;
using Volo.Abp.Security.Claims;
using Volo.Abp.SimpleStateChecking;

[Dependency(ReplaceServices = true)]
[ExposeServices(typeof(IPermissionChecker))]
public class OptimizedPermissionChecker : IPermissionChecker, ITransientDependency
{
    public ILogger<OptimizedPermissionChecker> Logger { get; set; }

    protected IPermissionDefinitionManager PermissionDefinitionManager { get; }
    protected ICurrentPrincipalAccessor PrincipalAccessor { get; }
    protected ICurrentTenant CurrentTenant { get; }
    protected IPermissionValueProviderManager PermissionValueProviderManager { get; }
    protected ISimpleStateCheckerManager<PermissionDefinition> StateCheckerManager { get; }

    public OptimizedPermissionChecker(
        ICurrentPrincipalAccessor principalAccessor,
        IPermissionDefinitionManager permissionDefinitionManager,
        ICurrentTenant currentTenant,
        IPermissionValueProviderManager permissionValueProviderManager,
        ISimpleStateCheckerManager<PermissionDefinition> stateCheckerManager)
    {
        PrincipalAccessor = principalAccessor;
        PermissionDefinitionManager = permissionDefinitionManager;
        CurrentTenant = currentTenant;
        PermissionValueProviderManager = permissionValueProviderManager;
        StateCheckerManager = stateCheckerManager;
        Logger = NullLogger<OptimizedPermissionChecker>.Instance;
    }

    public virtual async Task<bool> IsGrantedAsync(string name)
    {
        return await IsGrantedAsync(PrincipalAccessor.Principal, name);
    }

    public virtual async Task<bool> IsGrantedAsync(ClaimsPrincipal? claimsPrincipal, string name)
    {
        Check.NotNull(name, nameof(name));

        var permission = await PermissionDefinitionManager.GetOrNullAsync(name);
        if (permission == null)
        {
            return false;
        }

        if (!permission.IsEnabled)
        {
            return false;
        }

        if (!await StateCheckerManager.IsEnabledAsync(permission))
        {
            return false;
        }

        var multiTenancySide = CurrentTenant.GetMultiTenancySide();

        if (!permission.MultiTenancySide.HasFlag(multiTenancySide))
        {
            return false;
        }

        var isGranted = false;
        var context = new PermissionValueCheckContext(permission, claimsPrincipal);
        foreach (var provider in PermissionValueProviderManager.ValueProviders)
        {
            if (context.Permission.Providers.Any() &&
                !context.Permission.Providers.Contains(provider.Name))
            {
                continue;
            }

            var result = await provider.CheckAsync(context);

            if (result == PermissionGrantResult.Granted)
            {
                isGranted = true;
            }
            else if (result == PermissionGrantResult.Prohibited)
            {
                return false;
            }
        }

        return isGranted;
    }

    public virtual async Task<MultiplePermissionGrantResult> IsGrantedAsync(string[] names)
    {
        return await IsGrantedAsync(PrincipalAccessor.Principal, names);
    }

    public virtual async Task<MultiplePermissionGrantResult> IsGrantedAsync(
        ClaimsPrincipal? claimsPrincipal, string[] names)
    {
        Check.NotNull(names, nameof(names));

        Logger.LogInformation("OptimizedPermissionChecker.IsGrantedAsync called with {Count} permissions", names.Length);

        var totalSw = Stopwatch.StartNew();
        var sw = Stopwatch.StartNew();

        var result = new MultiplePermissionGrantResult();
        if (!names.Any())
        {
            return result;
        }

        var multiTenancySide = CurrentTenant.GetMultiTenancySide();

        // Step A: Pre-load all permission definitions at once
        var allPermissions = (await PermissionDefinitionManager.GetPermissionsAsync())
            .ToDictionary(p => p.Name);
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepA] GetPermissionsAsync: {Elapsed}ms, count: {Count}",
            sw.ElapsedMilliseconds, allPermissions.Count);

        sw.Restart();
        var pendingStateCheck = new List<PermissionDefinition>();
        var permissionDefinitions = new List<PermissionDefinition>();

        foreach (var name in names)
        {
            if (!allPermissions.TryGetValue(name, out var permission))
            {
                result.Result.Add(name, PermissionGrantResult.Prohibited);
                continue;
            }

            result.Result.Add(name, PermissionGrantResult.Undefined);

            if (!permission.IsEnabled || !permission.MultiTenancySide.HasFlag(multiTenancySide))
            {
                continue;
            }

            if (permission.StateCheckers.Any())
            {
                pendingStateCheck.Add(permission);
            }
            else
            {
                permissionDefinitions.Add(permission);
            }
        }
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepB] Filter: {Elapsed}ms, needStateCheck: {StateCount}, noStateCheck: {NoStateCount}",
            sw.ElapsedMilliseconds, pendingStateCheck.Count, permissionDefinitions.Count);

        // Step C: Batch state check
        sw.Restart();
        if (pendingStateCheck.Any())
        {
            var stateCheckResult = await StateCheckerManager.IsEnabledAsync(
                pendingStateCheck.ToArray());
            foreach (var item in stateCheckResult)
            {
                if (item.Value)
                {
                    permissionDefinitions.Add(item.Key);
                }
            }
        }
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepC] StateCheckerManager: {Elapsed}ms",
            sw.ElapsedMilliseconds);

        // Step D: Provider checking
        sw.Restart();
        foreach (var provider in PermissionValueProviderManager.ValueProviders)
        {
            var permissions = permissionDefinitions
                .Where(x => !x.Providers.Any() || x.Providers.Contains(provider.Name))
                .ToList();

            if (permissions.IsNullOrEmpty())
            {
                continue;
            }

            var context = new PermissionValuesCheckContext(permissions, claimsPrincipal);
            var multipleResult = await provider.CheckAsync(context);

            foreach (var grantResult in multipleResult.Result.Where(x => result.Result.ContainsKey(x.Key)))
            {
                switch (grantResult.Value)
                {
                    case PermissionGrantResult.Granted:
                    {
                        if (result.Result[grantResult.Key] != PermissionGrantResult.Prohibited)
                        {
                            result.Result[grantResult.Key] = PermissionGrantResult.Granted;
                        }
                        break;
                    }
                    case PermissionGrantResult.Prohibited:
                        result.Result[grantResult.Key] = PermissionGrantResult.Prohibited;
                        permissionDefinitions.RemoveAll(x => x.Name == grantResult.Key);
                        break;
                }
            }

            if (result.AllProhibited)
            {
                break;
            }
        }
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepD] Providers: {Elapsed}ms",
            sw.ElapsedMilliseconds);

        Logger.LogInformation(
            "OptimizedPermissionChecker total: {Elapsed}ms",
            totalSw.ElapsedMilliseconds);

        return result;
    }
}

File 2: OptimizedAppConfigurationAppService.cs (replace existing — same as before but now logs the PermissionChecker type)

The key new log line in this file is:

OptimizedAppConfig [Step5] PermissionChecker type: {Type}

If it shows OptimizedPermissionChecker, the checker is active. If it shows Volo.Abp.Authorization.Permissions.PermissionChecker, it means the replacement didn't work.

Please deploy both files, make two requests (first login + page refresh), and share the full logs. We expect to see:

OptimizedAppConfig [Step5] PermissionChecker type: OptimizedPermissionChecker
OptimizedPermissionChecker.IsGrantedAsync called with 4358 permissions
OptimizedPermissionChecker [StepA] GetPermissionsAsync: Xms, count: XXX
OptimizedPermissionChecker [StepB] Filter: Xms, ...
OptimizedPermissionChecker [StepC] StateCheckerManager: Xms
OptimizedPermissionChecker [StepD] Providers: Xms

If you DON'T see the OptimizedPermissionChecker logs, then the file is not being registered properly — make sure it's included in the admin service project and the project compiles without errors.

Thanks

0

vkelwan created 5 months ago

This is first request (cold) logs

12:22:15 LOG [06:51:54 DBG] Executing AbpApplicationConfigurationAppService.GetAsync()... 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig [Step1] GetPoliciesNamesAsync: 4ms, count: 4358 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig [Step2] GetPermissionsAsync+HashSet: 2ms, count: 4358 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig [Step3] ClassifyPolicies loop: 0ms, abp: 4358, other: 0 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig [Step4] OtherPolicies check: 0ms 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig [Step5] PermissionChecker type: TMSMS.AdministrationService.OptimizedPermissionChecker 12:22:15 LOG [06:51:54 INF] OptimizedPermissionChecker.IsGrantedAsync called with 4358 permissions 12:22:15 LOG [06:51:54 INF] OptimizedPermissionChecker [StepA] GetPermissionsAsync: 2ms, count: 4358 12:22:15 LOG [06:51:54 INF] OptimizedPermissionChecker [StepB] Filter: 2ms, needStateCheck: 4050, noStateCheck: 305 12:22:15 LOG [06:51:54 INF] OptimizedPermissionChecker [StepC] StateCheckerManager: 322ms 12:22:15 LOG [06:51:54 INF] OptimizedPermissionChecker [StepD] Providers: 21ms 12:22:15 LOG [06:51:54 INF] OptimizedPermissionChecker total: 349ms 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: 352ms, granted: 0 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig GetAuthConfigAsync total: 360ms 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig: GetFeaturesConfigAsync took 1ms 12:22:15 LOG [06:51:54 INF] OptimizedAppConfig: GetLocalizationConfigAsync took 10ms 12:22:15 LOG [06:51:55 INF] OptimizedAppConfig: GetTimingConfigAsync took 4ms 12:22:15 LOG [06:51:55 DBG] Executed AbpApplicationConfigurationAppService.GetAsync(). 12:22:15 LOG [06:51:55 INF] Executing ObjectResult, writing value of type 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.ApplicationConfigurationDto'. 12:22:15 LOG [06:51:55 INF] Executed action Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc) in 602.8061ms 12:22:15 LOG [06:51:55 INF] Executed endpoint 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc)' 12:22:15 LOG [06:51:55 INF] Request finished HTTP/1.1 GET http://adminserver/api/abp/application-configuration?includeLocalizationResources=false - 200 null application/json; charset=utf-8 970.523ms 12:22:15 LOG [06:51:55 INF] Request starting HTTP/1.1 GET http://adminserver/api/abp/application-localization?cultureName=en&onlyDynamics=false - null null

This is second request (warm) logs

12:23:11 LOG [06:52:59 INF] OptimizedPermissionChecker [StepC] StateCheckerManager: 3519ms 12:23:11 LOG [06:52:59 DBG] BulkPermissionStore: cache hit for U:8e19f3c2-3cca-01a5-c78a-3a1fd5abe6b6. 12:23:11 LOG [06:52:59 DBG] BulkPermissionStore: cache hit for R:admin. 12:23:11 LOG [06:52:59 DBG] BulkPermissionStore: cache hit for C:Angular. 12:23:11 LOG [06:52:59 INF] OptimizedPermissionChecker [StepD] Providers: 29ms 12:23:11 LOG [06:52:59 INF] OptimizedPermissionChecker total: 3573ms 12:23:11 LOG [06:52:59 INF] OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: 3578ms, granted: 1822 12:23:11 LOG [06:52:59 INF] OptimizedAppConfig GetAuthConfigAsync total: 3603ms 12:23:11 LOG [06:52:59 INF] OptimizedAppConfig: GetFeaturesConfigAsync took 33ms 12:23:11 LOG [06:52:59 INF] OptimizedAppConfig: GetLocalizationConfigAsync took 0ms 12:23:11 LOG [06:52:59 INF] OptimizedAppConfig: GetTimingConfigAsync took 2ms 12:23:11 LOG [06:52:59 DBG] Executed AbpApplicationConfigurationAppService.GetAsync(). 12:23:11 LOG [06:52:59 INF] Executing ObjectResult, writing value of type 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.ApplicationConfigurationDto'. 12:23:11 LOG [06:52:59 INF] Executed action Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc) in 3651.1354ms 12:23:11 LOG [06:52:59 INF] Executed endpoint 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc)' 12:23:11 LOG [06:52:59 INF] Request finished HTTP/1.1 GET http://adminserver/api/abp/application-configuration?includeLocalizationResources=false - 200 null application/json; charset=utf-8 3657.251ms 12:23:11 LOG [06:53:00 INF] Request starting HTTP/1.1 GET http://adminserver/api/abp/application-localization?cultureName=en&onlyDynamics=false - null null

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

We found the root cause. Your timing logs showed that StepC (StateCheckerManager) takes 3519ms — 4050 of your 4358 permissions have feature-based state checkers. Each state checker calls IFeatureChecker.IsEnabledAsync which does a Redis GET per call. That's 4050+ individual Redis calls just for feature checking.

The fix: pre-load all unique feature values once (~30-50 Redis calls), then check all 4050 permissions against in-memory data (0 Redis calls). This should reduce StepC from ~3500ms to under 100ms.

Please replace OptimizedPermissionChecker.cs with the version below. The other files stay the same.

OptimizedPermissionChecker.cs (replace existing):

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Security.Claims;
using System.Threading.Tasks;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Extensions.Options;
using Volo.Abp;
using Volo.Abp.Authorization.Permissions;
using Volo.Abp.DependencyInjection;
using Volo.Abp.Features;
using Volo.Abp.GlobalFeatures;
using Volo.Abp.MultiTenancy;
using Volo.Abp.Security.Claims;
using Volo.Abp.SimpleStateChecking;
using Volo.Abp.Users;

[Dependency(ReplaceServices = true)]
[ExposeServices(typeof(IPermissionChecker))]
public class OptimizedPermissionChecker : IPermissionChecker, ITransientDependency
{
    public ILogger<OptimizedPermissionChecker> Logger { get; set; }

    protected IPermissionDefinitionManager PermissionDefinitionManager { get; }
    protected ICurrentPrincipalAccessor PrincipalAccessor { get; }
    protected ICurrentTenant CurrentTenant { get; }
    protected IPermissionValueProviderManager PermissionValueProviderManager { get; }
    protected ISimpleStateCheckerManager<PermissionDefinition> StateCheckerManager { get; }
    protected IServiceProvider ServiceProvider { get; }
    protected AbpSimpleStateCheckerOptions<PermissionDefinition> StateCheckerOptions { get; }

    public OptimizedPermissionChecker(
        ICurrentPrincipalAccessor principalAccessor,
        IPermissionDefinitionManager permissionDefinitionManager,
        ICurrentTenant currentTenant,
        IPermissionValueProviderManager permissionValueProviderManager,
        ISimpleStateCheckerManager<PermissionDefinition> stateCheckerManager,
        IServiceProvider serviceProvider,
        IOptions<AbpSimpleStateCheckerOptions<PermissionDefinition>> stateCheckerOptions)
    {
        PrincipalAccessor = principalAccessor;
        PermissionDefinitionManager = permissionDefinitionManager;
        CurrentTenant = currentTenant;
        PermissionValueProviderManager = permissionValueProviderManager;
        StateCheckerManager = stateCheckerManager;
        ServiceProvider = serviceProvider;
        StateCheckerOptions = stateCheckerOptions.Value;
        Logger = NullLogger<OptimizedPermissionChecker>.Instance;
    }

    public virtual async Task<bool> IsGrantedAsync(string name)
    {
        return await IsGrantedAsync(PrincipalAccessor.Principal, name);
    }

    public virtual async Task<bool> IsGrantedAsync(ClaimsPrincipal? claimsPrincipal, string name)
    {
        Check.NotNull(name, nameof(name));

        var permission = await PermissionDefinitionManager.GetOrNullAsync(name);
        if (permission == null)
        {
            return false;
        }

        if (!permission.IsEnabled)
        {
            return false;
        }

        if (!await StateCheckerManager.IsEnabledAsync(permission))
        {
            return false;
        }

        var multiTenancySide = CurrentTenant.GetMultiTenancySide();

        if (!permission.MultiTenancySide.HasFlag(multiTenancySide))
        {
            return false;
        }

        var isGranted = false;
        var context = new PermissionValueCheckContext(permission, claimsPrincipal);
        foreach (var provider in PermissionValueProviderManager.ValueProviders)
        {
            if (context.Permission.Providers.Any() &&
                !context.Permission.Providers.Contains(provider.Name))
            {
                continue;
            }

            var result = await provider.CheckAsync(context);

            if (result == PermissionGrantResult.Granted)
            {
                isGranted = true;
            }
            else if (result == PermissionGrantResult.Prohibited)
            {
                return false;
            }
        }

        return isGranted;
    }

    public virtual async Task<MultiplePermissionGrantResult> IsGrantedAsync(string[] names)
    {
        return await IsGrantedAsync(PrincipalAccessor.Principal, names);
    }

    public virtual async Task<MultiplePermissionGrantResult> IsGrantedAsync(
        ClaimsPrincipal? claimsPrincipal, string[] names)
    {
        Check.NotNull(names, nameof(names));

        Logger.LogInformation("OptimizedPermissionChecker.IsGrantedAsync called with {Count} permissions", names.Length);

        var totalSw = Stopwatch.StartNew();
        var sw = Stopwatch.StartNew();

        var result = new MultiplePermissionGrantResult();
        if (!names.Any())
        {
            return result;
        }

        var multiTenancySide = CurrentTenant.GetMultiTenancySide();

        var allPermissions = (await PermissionDefinitionManager.GetPermissionsAsync())
            .ToDictionary(p => p.Name);
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepA] GetPermissionsAsync: {Elapsed}ms, count: {Count}",
            sw.ElapsedMilliseconds, allPermissions.Count);

        sw.Restart();
        var pendingStateCheck = new List<PermissionDefinition>();
        var permissionDefinitions = new List<PermissionDefinition>();

        foreach (var name in names)
        {
            if (!allPermissions.TryGetValue(name, out var permission))
            {
                result.Result.Add(name, PermissionGrantResult.Prohibited);
                continue;
            }

            result.Result.Add(name, PermissionGrantResult.Undefined);

            if (!permission.IsEnabled || !permission.MultiTenancySide.HasFlag(multiTenancySide))
            {
                continue;
            }

            if (permission.StateCheckers.Any())
            {
                pendingStateCheck.Add(permission);
            }
            else
            {
                permissionDefinitions.Add(permission);
            }
        }
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepB] Filter: {Elapsed}ms, needStateCheck: {StateCount}, noStateCheck: {NoStateCount}",
            sw.ElapsedMilliseconds, pendingStateCheck.Count, permissionDefinitions.Count);

        sw.Restart();
        if (pendingStateCheck.Any())
        {
            await CheckStatesInSingleScopeAsync(pendingStateCheck, permissionDefinitions);
        }
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepC] StateCheck: {Elapsed}ms, passed: {Count}",
            sw.ElapsedMilliseconds, permissionDefinitions.Count);

        sw.Restart();
        foreach (var provider in PermissionValueProviderManager.ValueProviders)
        {
            var permissions = permissionDefinitions
                .Where(x => !x.Providers.Any() || x.Providers.Contains(provider.Name))
                .ToList();

            if (permissions.IsNullOrEmpty())
            {
                continue;
            }

            var context = new PermissionValuesCheckContext(permissions, claimsPrincipal);
            var multipleResult = await provider.CheckAsync(context);

            foreach (var grantResult in multipleResult.Result.Where(x => result.Result.ContainsKey(x.Key)))
            {
                switch (grantResult.Value)
                {
                    case PermissionGrantResult.Granted:
                    {
                        if (result.Result[grantResult.Key] != PermissionGrantResult.Prohibited)
                        {
                            result.Result[grantResult.Key] = PermissionGrantResult.Granted;
                        }
                        break;
                    }
                    case PermissionGrantResult.Prohibited:
                        result.Result[grantResult.Key] = PermissionGrantResult.Prohibited;
                        permissionDefinitions.RemoveAll(x => x.Name == grantResult.Key);
                        break;
                }
            }

            if (result.AllProhibited)
            {
                break;
            }
        }
        Logger.LogInformation(
            "OptimizedPermissionChecker [StepD] Providers: {Elapsed}ms",
            sw.ElapsedMilliseconds);

        Logger.LogInformation(
            "OptimizedPermissionChecker total: {Elapsed}ms",
            totalSw.ElapsedMilliseconds);

        return result;
    }

    protected virtual async Task CheckStatesInSingleScopeAsync(
        List<PermissionDefinition> pendingStateCheck,
        List<PermissionDefinition> permissionDefinitions)
    {
        using (var scope = ServiceProvider.CreateScope())
        {
            var cachedServiceProvider = scope.ServiceProvider.GetRequiredService<ICachedServiceProvider>();

            // 1. Handle batch state checkers
            var batchStateCheckers = pendingStateCheck
                .SelectMany(x => x.StateCheckers)
                .Where(x => x is ISimpleBatchStateChecker<PermissionDefinition>)
                .Cast<ISimpleBatchStateChecker<PermissionDefinition>>()
                .GroupBy(x => x)
                .Select(x => x.Key);

            var batchDisabledSet = new HashSet<string>();

            foreach (var stateChecker in batchStateCheckers)
            {
                var relevantStates = pendingStateCheck
                    .Where(x => x.StateCheckers.Contains(stateChecker))
                    .ToArray();
                var context = new SimpleBatchStateCheckerContext<PermissionDefinition>(
                    cachedServiceProvider, relevantStates);

                foreach (var item in await stateChecker.IsEnabledAsync(context))
                {
                    if (!item.Value)
                    {
                        batchDisabledSet.Add(item.Key.Name);
                    }
                }
            }

            // 2. Handle global batch state checkers
            foreach (ISimpleBatchStateChecker<PermissionDefinition> globalChecker in StateCheckerOptions
                .GlobalStateCheckers
                .Where(x => typeof(ISimpleBatchStateChecker<PermissionDefinition>).IsAssignableFrom(x))
                .Select(x => scope.ServiceProvider.GetRequiredService(x)))
            {
                var relevantStates = pendingStateCheck
                    .Where(x => !batchDisabledSet.Contains(x.Name))
                    .ToArray();
                if (!relevantStates.Any())
                {
                    break;
                }

                var context = new SimpleBatchStateCheckerContext<PermissionDefinition>(
                    cachedServiceProvider, relevantStates);

                foreach (var item in await globalChecker.IsEnabledAsync(context))
                {
                    if (!item.Value)
                    {
                        batchDisabledSet.Add(item.Key.Name);
                    }
                }
            }

            // 3. Pre-load feature values (key optimization!)
            //    Instead of 4000+ individual Redis GETs, we load ~30-50 unique features once.
            var featureChecker = scope.ServiceProvider.GetRequiredService<IFeatureChecker>();
            var isAuthenticated = scope.ServiceProvider.GetRequiredService<ICurrentUser>().IsAuthenticated;

            var uniqueFeatureNames = pendingStateCheck
                .SelectMany(p => p.StateCheckers)
                .OfType<RequireFeaturesSimpleStateChecker<PermissionDefinition>>()
                .SelectMany(c => c.FeatureNames)
                .Distinct()
                .ToList();

            var featureEnabledCache = new Dictionary<string, bool>();
            foreach (var featureName in uniqueFeatureNames)
            {
                featureEnabledCache[featureName] = await featureChecker.IsEnabledAsync(featureName);
            }

            Logger.LogInformation(
                "OptimizedPermissionChecker: Pre-loaded {Count} unique feature values",
                uniqueFeatureNames.Count);

            // 4. Evaluate state checkers against in-memory data (0 Redis calls)
            var globalNonBatchCheckerTypes = StateCheckerOptions.GlobalStateCheckers
                .Where(x => !typeof(ISimpleBatchStateChecker<PermissionDefinition>).IsAssignableFrom(x))
                .ToList();

            var resolvedGlobalCheckers = globalNonBatchCheckerTypes
                .Select(x => (ISimpleStateChecker<PermissionDefinition>)scope.ServiceProvider.GetRequiredService(x))
                .ToList();

            foreach (var permission in pendingStateCheck)
            {
                if (batchDisabledSet.Contains(permission.Name))
                {
                    continue;
                }

                var isEnabled = true;

                foreach (var checker in permission.StateCheckers
                    .Where(x => x is not ISimpleBatchStateChecker<PermissionDefinition>))
                {
                    if (checker is RequireFeaturesSimpleStateChecker<PermissionDefinition> fc)
                    {
                        isEnabled = fc.RequiresAll
                            ? fc.FeatureNames.All(f => featureEnabledCache.GetValueOrDefault(f))
                            : fc.FeatureNames.Any(f => featureEnabledCache.GetValueOrDefault(f));
                    }
                    else if (checker is RequireGlobalFeaturesSimpleStateChecker<PermissionDefinition> gfc)
                    {
                        isEnabled = gfc.RequiresAll
                            ? gfc.GlobalFeatureNames.All(x => GlobalFeatureManager.Instance.IsEnabled(x))
                            : gfc.GlobalFeatureNames.Any(x => GlobalFeatureManager.Instance.IsEnabled(x));
                    }
                    else if (checker is RequireAuthenticatedSimpleStateChecker<PermissionDefinition>)
                    {
                        isEnabled = isAuthenticated;
                    }
                    else
                    {
                        var context = new SimpleStateCheckerContext<PermissionDefinition>(
                            cachedServiceProvider, permission);
                        isEnabled = await checker.IsEnabledAsync(context);
                    }

                    if (!isEnabled)
                    {
                        break;
                    }
                }

                if (isEnabled && resolvedGlobalCheckers.Any())
                {
                    var context = new SimpleStateCheckerContext<PermissionDefinition>(
                        cachedServiceProvider, permission);
                    foreach (var globalChecker in resolvedGlobalCheckers)
                    {
                        if (!await globalChecker.IsEnabledAsync(context))
                        {
                            isEnabled = false;
                            break;
                        }
                    }
                }

                if (isEnabled)
                {
                    permissionDefinitions.Add(permission);
                }
            }
        }
    }
}

After deploying, please make two requests and share the logs. The key log to look for:

OptimizedPermissionChecker: Pre-loaded XX unique feature values
OptimizedPermissionChecker [StepC] StateCheck: XXms

We expect StepC to drop from ~3500ms to well under 100ms.

Thanks

0

vkelwan created 5 months ago

Hello this is warm logs

13:45:36 LOG [08:15:24 DBG] Executing AbpApplicationConfigurationAppService.GetAsync()... 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig [Step1] GetPoliciesNamesAsync: 6ms, count: 4358 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig [Step2] GetPermissionsAsync+HashSet: 4ms, count: 4358 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig [Step3] ClassifyPolicies loop: 0ms, abp: 4358, other: 0 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig [Step4] OtherPolicies check: 0ms 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig [Step5] PermissionChecker type: TMSMS.AdministrationService.OptimizedPermissionChecker 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker.IsGrantedAsync called with 4358 permissions 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker [StepA] GetPermissionsAsync: 3ms, count: 4358 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker [StepB] Filter: 17ms, needStateCheck: 4047, noStateCheck: 275 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker: Pre-loaded 31 unique feature values 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker [StepC] StateCheck: 41ms, passed: 1827 13:45:36 LOG [08:15:24 DBG] BulkPermissionStore: cache hit for U:8e19f3c2-3cca-01a5-c78a-3a1fd5abe6b6. 13:45:36 LOG [08:15:24 DBG] BulkPermissionStore: cache hit for R:admin. 13:45:36 LOG [08:15:24 DBG] BulkPermissionStore: cache hit for C:Angular. 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker [StepD] Providers: 35ms 13:45:36 LOG [08:15:24 INF] OptimizedPermissionChecker total: 99ms 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig [Step5] PermissionChecker.IsGrantedAsync: 100ms, granted: 1822 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig GetAuthConfigAsync total: 112ms 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig: GetFeaturesConfigAsync took 40ms 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig: GetLocalizationConfigAsync took 0ms 13:45:36 LOG [08:15:24 INF] OptimizedAppConfig: GetTimingConfigAsync took 1ms 13:45:36 LOG [08:15:24 DBG] Executed AbpApplicationConfigurationAppService.GetAsync(). 13:45:36 LOG [08:15:24 INF] Executing ObjectResult, writing value of type 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.ApplicationConfigurationDto'. 13:45:36 LOG [08:15:24 INF] Executed action Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc) in 167.8399ms 13:45:36 LOG [08:15:24 INF] Executed endpoint 'Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationController.GetAsync (Volo.Abp.AspNetCore.Mvc)' 13:45:36 LOG [08:15:24 INF] Request finished HTTP/1.1 GET http://adminserver/api/abp/application-configuration?includeLocalizationResources=false - 200 null application/json; charset=utf-8 173.8023ms 13:45:36 LOG [08:15:25 INF] Request starting HTTP/1.1 GET http://adminserver/api/abp/application-localization?cultureName=en&onlyDynamics=false - null null

And these newtork's tabs, I want to ask you, without this, did anything happen in this API or not?

Like, why is the network server response time 457 ms and in logs 167.8399 ms?

and why this open-configuration takes 1 sec

?

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

The optimization is working perfectly:

StepC (StateChecker): 3519ms → 41ms
Total server-side:    3651ms → 167ms

The key line Pre-loaded 31 unique feature values confirms that instead of 4047 individual Redis calls, we only made 31 and checked everything else in memory.

"Without this, did anything happen in this API or not?"

No, there are no other changes to this API. The improvement is entirely from the patch files we provided. The API code itself in ABP hasn't changed — our patch files just replace the internal services with optimized versions.

About the timing difference (browser 848ms vs server logs 167ms):

Looking at your DevTools Timing tab:

Waiting (TTFB): 457ms = ~290ms network round-trip + 167ms server processing
Content Download: 137ms (transferring the 93.6 kB JSON response)
Total in Timing: 738ms

The 848ms total in the network tab includes additional time for connection setup, queueing, or browser-level overhead before the request was sent.

The server processes the request in 167ms — the rest is network latency and response transfer, which depends on the distance between your users and the server.

"Why does open-configuration take 1 sec?"

The first request after login (or after the application restarts) is slower because it needs to populate caches that are empty:

Loading permission definitions from the database
Loading feature values from Redis/database for the first time
Building internal caches

Once these caches are populated, subsequent requests are fast (167ms as you can see). This is expected behavior — the first request warms up the caches, and all following requests benefit from them.

Thanks

0

vkelwan created 5 months ago

So now do I need to remove all logs and this final optimized code update in all three of my productions?

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

Yes, please deploy the latest version of all 5 files to all three production environments. The diagnostic logs (timing info) are lightweight and won't affect performance, so you can keep them if you want to monitor things — but feel free to remove them if you prefer cleaner logs.

To summarize, these are the 5 files you should have in each admin service project:

PermissionGrantBulkCacheItem.cs
BulkPermissionStore.cs
PermissionGrantBulkCacheItemInvalidator.cs
OptimizedPermissionChecker.cs (the latest version with feature pre-loading)
OptimizedAppConfigurationAppService.cs

Make sure the OptimizedPermissionChecker.cs is the latest version — the one that shows Pre-loaded XX unique feature values in the logs. That's the version that brought StepC from 3519ms down to 41ms.

Once you upgrade to ABP 10.3.1 or later, you can remove all 5 files.

Thanks

0

vkelwan created 5 months ago

OKay Thank you so much. i will deploy this in all my production environments and test it and if there are any further issues, I will let you know

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

You're welcome! Glad we got it resolved. Just a quick summary for your reference:

The problem: With 4000+ permissions, /api/abp/application-configuration was taking 10+ seconds due to multiple performance bottlenecks stacking up.

What the 5 files do:

| File | What it fixes | Impact | |------|--------------|--------| | PermissionGrantBulkCacheItem.cs | Bulk cache data structure | — | | BulkPermissionStore.cs | 12,000+ individual Redis calls → 3 bulk lookups | 10s → ~1s | | PermissionGrantBulkCacheItemInvalidator.cs | Keeps bulk cache in sync when permissions change | — | | OptimizedPermissionChecker.cs | Pre-loads permission definitions + feature values, avoids thousands of DI scope creations | ~3.5s → 41ms | | OptimizedAppConfigurationAppService.cs | Replaces per-permission async lookups with a single batch load | ~800ms → 10ms |

Final result: 10s+ → 167ms server-side

These optimizations will be included in ABP 10.3.1. After upgrading, you can remove all 5 files.

Feel free to reach out if you run into any issues after deploying to your other environments.

Thanks

0

vkelwan created 5 months ago

one more thing. Suppose I have 20 microservices module wise in that in one production I just use only 1 module and with your ABP, all common microservices so when i make new production environment, ABP makes my default admin role with all permissions. then in this we have features like this or not that, whatever feature is assigned as module to that production that only permission goes in admin and fetch also that only

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

ABP actually already handles this through the Feature system.

When permissions are defined in a module, they're typically linked to a feature using RequireFeatures. The permission management UI filters permissions through these feature checks — so if a module's feature is disabled, its permissions won't show up in the UI, and "Grant all permissions" won't grant them either.

So in your scenario with 20 microservices:

If you only enable the Hotel module's feature in a production environment, the permission UI will only show Hotel module permissions + common permissions
"Grant all" will only grant those visible permissions
Permissions from other disabled modules won't appear

The reason you're seeing 4000+ permissions is likely because all module features are currently enabled in your environments (or were enabled when "Grant all" was clicked). The old grants for disabled features stay in the database but are ignored at runtime.

If you want to keep things clean for a new production that only uses 1 module:

Disable the features for modules you don't use (through the Feature Management UI or settings)
Then set up the admin role permissions — only the relevant module's permissions will be available

Thanks

0

vkelwan created 5 months ago

but in my last production, where 4 seconds take place in that only hotel active, then you also see that it's showing tour and all in permission UI.

You see, the tour is not given in feaure

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

Looking at your screenshots, the TourModule feature is disabled in the Feature Management UI, but TourService permissions still show up. Let me explain why.

ABP has two separate feature systems, and they work differently with permissions:

1. Features (RequireFeatures) — per-tenant, managed in Feature Management UI

This is what your Feature Management UI controls. To make permissions respect this, each permission must explicitly call .RequireFeatures() in its definition:

public class TourServicePermissionDefinitionProvider : PermissionDefinitionProvider
{
    public override void Define(IPermissionDefinitionContext context)
    {
        var group = context.AddGroup("TourService");

        group.AddPermission("TourService.Tours")
            .RequireFeatures("TourServiceModule");  // ← links to tenant feature

        group.AddPermission("TourService.Tours.Create")
            .RequireFeatures("TourServiceModule");  // ← each permission needs this
    }
}

If .RequireFeatures("TourServiceModule") is missing from the permission definition, disabling the feature in the UI won't filter out that permission.

2. Global Features (RequireGlobalFeatures) — application-level, configured in code

This is a different system — it's enabled/disabled at the application level (not per-tenant), and the Feature Management UI does NOT control it. It looks like this:

group.AddPermission("CmsKit.Comments")
    .RequireGlobalFeatures(typeof(CommentsFeature));

What's happening in your case:

Your TourService permissions most likely don't have .RequireFeatures("TourServiceModule") in their permission definition code. So even though you disabled TourServiceModule in the Feature Management UI, the permission system doesn't know they're linked — it shows them regardless.

To fix this, you need to add .RequireFeatures("TourServiceModule") to each TourService permission in your TourServicePermissionDefinitionProvider. Same for other modules — each module's permissions should reference their module feature.

After adding this, when the feature is disabled:

The permissions won't show in the admin permission UI
"Grant all" won't grant them
Runtime permission checks will return false for them

Thanks

0

vkelwan created 5 months ago

We checked our TourService backend. All permissions already have .RequireFeatures() configured:

TMSMSFeature.cs:

public const string GroupName = "TourModule"; public const string Tour = GroupName + ".TourService"; // = "TourModule.TourService"

FeatureProvider.cs:

myGroup. AddFeature(TMSMSFeature.Tour, defaultValue: "false", ...);

TourServicePermissionDefinitionProvider.cs:

Every permission already has .RequireFeatures(TMSMSFeature.Tour)—for example:

myGroup.AddPermission(TourServicePermissions.TourCategories.Default, ...) .RequireFeatures(TMSMSFeature.Tour); tourCategoryPermission.AddChild(TourServicePermissions.TourCategories.Create, ...) .RequireFeatures(TMSMSFeature.Tour);

All permissions in the file follow this pattern. So the issue is not missing .RequireFeatures() — it's already there on every permission. Despite disabling the feature in the Feature Management UI, permissions still appear. Could this be a framework-level issue with permission UI not respecting RequireFeatures when listing?

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

The performance issue is resolved now. The feature filtering question is a separate topic — could you please create a new support question for it?

To help us investigate quickly, please include the following in the new question:

The full feature definition code (TMSMSFeature.cs and your FeatureDefinitionProvider.cs)
A few permission definitions from TourServicePermissionDefinitionProvider.cs showing the .RequireFeatures() usage
Screenshot of the Feature Management UI with TourModule disabled — and please note whether you're viewing it as Host or as a specific Tenant
The feature values from the database:

SELECT * FROM AbpFeatureValues 
WHERE Name LIKE '%TourModule%' OR Name LIKE '%TourService%'
ORDER BY ProviderName, ProviderKey;

Which ABP version you're using for this environment

Thanks

0

vkelwan created 5 months ago

Screenshot of the Feature Management UI with TourModule disabled — and please note whether you're viewing it as Host or as a specific Tenant

see feature only able to see in host under saas of tenants tabs, okay?

and permission I am seeing under tenant login and roles section

The feature values from the database:

no record in tenant

Which ABP version you're using for this environment

ABP Commercial v9.2.0 with .NET 9.0

0

maliming created 5 months ago

Support Team Fullstack Developer

Hi,

The performance issue is resolved. This feature filtering question is a different topic — please create a new support question so we can track it separately.

Based on the code, ABP checks feature values in this order: Tenant (T) → Edition (E) → Configuration (C) → Default (D). The first non-null value wins. Your feature has defaultValue: "false", so if no other provider returns a value, the feature should be disabled and permissions should not show.

Since the permissions are still showing, some provider must be returning a value that enables the feature. To find out which one, please run this SQL on your SaaS/Administration service database (in microservices, AbpFeatureValues is typically NOT in the tenant database):

SELECT * FROM AbpFeatureValues 
WHERE Name LIKE '%TourModule%' OR Name LIKE '%TourService%'
ORDER BY ProviderName, ProviderKey;

Please share the result in the new question, along with:

Whether the tenant is assigned to an Edition
The feature definition and permission definition code you mentioned earlier

Thanks

0

vkelwan created 5 months ago

Hello i have created another query please reply in that

0

maliming created 5 months ago

Support Team Fullstack Developer

Thanks, we will check your new question.

Framework

Tools

Mobile

Startup Templates

UI

Modules

71 Answer(s)

ABP Live Training
Packages

Mastering
ABP Framework

Framework

Tools

Mobile

Startup Templates

UI

Modules

More

More

More

More

Slow response time for /api/abp/application-configuration during login #10565

71 Answer(s)

ABP Live TrainingPackages

MasteringABP Framework

ABP Live Training
Packages

Mastering
ABP Framework