Activities of "kfrancis@clinicalsupportsystems.com"

I would like to use a custom implementation of AbpStringLocalizerFactory, so that I can add metrics and watch what's going on. I suspect that localization isn't being cached correctly in my instance (for example, host admin is super fast but all tenant pages that contain lots of localization are slow), but to know what's going on, I need a custom implementation.

I have the following, but it's just not getting called.

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Threading;
using JetBrains.Annotations;
using Microsoft.Extensions.Localization;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Volo.Abp.DependencyInjection;
using Volo.Abp.Localization;
using Volo.Abp.Localization.External;

namespace CabMD.Localization
{
    /// <summary>
    /// A factory for creating <see cref="IStringLocalizer"/> instances that tracks performance metrics  for
    /// localization operations. This factory extends the functionality of <see cref="AbpStringLocalizerFactory"/>  by
    /// monitoring and logging the performance of string lookups and enumerations.
    /// </summary>
    /// <remarks>This factory wraps the created <see cref="IStringLocalizer"/> instances with a
    /// performance-tracking  implementation, enabling the measurement of slow localization operations. It is designed
    /// to help  identify and diagnose performance bottlenecks in localization processes.</remarks>
    [UsedImplicitly]
    [Dependency(ReplaceServices = true)]
    [ExposeServices(typeof(IStringLocalizerFactory), typeof(IAbpStringLocalizerFactory))]
    public class PerformanceTrackingStringLocalizerFactory : AbpStringLocalizerFactory
    {
        private readonly ILoggerFactory _loggerFactory;
        private readonly ILocalizationPerformanceMonitor _performanceMonitor;
        private const int SlowLookupThresholdMs =50;
        private const int SlowEnumerationThresholdMs =100;

        public PerformanceTrackingStringLocalizerFactory(
            ResourceManagerStringLocalizerFactory innerFactory,
            IOptions<AbpLocalizationOptions> abpLocalizationOptions,
            IServiceProvider serviceProvider,
            IExternalLocalizationStore externalLocalizationStore,
            ILocalizationPerformanceMonitor performanceMonitor,
            ILoggerFactory loggerFactory)
            : base(innerFactory, abpLocalizationOptions, serviceProvider, externalLocalizationStore)
        {
            _performanceMonitor = performanceMonitor;
            _loggerFactory = loggerFactory;
        }

        public override IStringLocalizer Create(Type resourceType)
        {
            var inner = base.Create(resourceType);
            return Wrap(inner, !string.IsNullOrEmpty(resourceType.Name) ? resourceType.Name : "Unknown");
        }

        public override IStringLocalizer Create(string baseName, string location)
        {
            var inner = base.Create(baseName, location);
            return Wrap(inner, $"{baseName}@{location}");
        }

        private PerformanceTrackingStringLocalizer Wrap(IStringLocalizer inner, string resourceName)
        {
            return new PerformanceTrackingStringLocalizer(
                inner,
                resourceName,
                _performanceMonitor,
                _loggerFactory.CreateLogger<PerformanceTrackingStringLocalizer>(),
                SlowLookupThresholdMs,
                SlowEnumerationThresholdMs);
        }
    }

    internal class PerformanceTrackingStringLocalizer : IStringLocalizer
    {
        private readonly IStringLocalizer _inner;
        private readonly string _resourceName;
        private readonly ILocalizationPerformanceMonitor _monitor;
        private readonly ILogger<PerformanceTrackingStringLocalizer> _logger;
        private readonly int _lookupThresholdMs;
        private readonly int _enumerationThresholdMs;

        public PerformanceTrackingStringLocalizer(
            IStringLocalizer inner,
            string resourceName,
            ILocalizationPerformanceMonitor monitor,
            ILogger<PerformanceTrackingStringLocalizer> logger,
            int lookupThresholdMs,
            int enumerationThresholdMs)
        {
            _inner = inner;
            _resourceName = resourceName;
            _monitor = monitor;
            _logger = logger;
            _lookupThresholdMs = lookupThresholdMs;
            _enumerationThresholdMs = enumerationThresholdMs;
        }

        public LocalizedString this[string name]
        {
            get
            {
                var sw = Stopwatch.StartNew();
                var culture = Thread.CurrentThread.CurrentUICulture.Name;
                try
                {
                    var result = _inner[name];
                    sw.Stop();
                    Record(name, sw.ElapsedMilliseconds, culture);
                    WarnSlow(sw.ElapsedMilliseconds, name, culture, false,0);
                    return result;
                }
                catch (Exception ex)
                {
                    sw.Stop();
                    _logger.LogError(ex, "Error localizing key '{Key}' in resource '{Resource}' for culture '{Culture}' after {ElapsedMs}ms", name, _resourceName, culture, sw.ElapsedMilliseconds);
                    throw;
                }
            }
        }

        public LocalizedString this[string name, params object[] arguments]
        {
            get
            {
                var sw = Stopwatch.StartNew();
                var culture = Thread.CurrentThread.CurrentUICulture.Name;
                try
                {
                    var result = _inner[name, arguments];
                    sw.Stop();
                    Record(name, sw.ElapsedMilliseconds, culture);
                    WarnSlow(sw.ElapsedMilliseconds, name, culture, true, arguments.Length);
                    return result;
                }
                catch (Exception ex)
                {
                    sw.Stop();
                    _logger.LogError(ex, "Error localizing key '{Key}' with arguments in resource '{Resource}' for culture '{Culture}' after {ElapsedMs}ms", name, _resourceName, culture, sw.ElapsedMilliseconds);
                    throw;
                }
            }
        }

        public IEnumerable<LocalizedString> GetAllStrings(bool includeParentCultures)
        {
            var sw = Stopwatch.StartNew();
            var culture = Thread.CurrentThread.CurrentUICulture.Name;
            try
            {
                var result = _inner.GetAllStrings(includeParentCultures);
                sw.Stop();
                if (sw.ElapsedMilliseconds > _enumerationThresholdMs)
                {
                    _logger.LogWarning("GetAllStrings for resource '{Resource}' and culture '{Culture}' took {ElapsedMs}ms", _resourceName, culture, sw.ElapsedMilliseconds);
                }
                return result;
            }
            catch (Exception ex)
            {
                sw.Stop();
                _logger.LogError(ex, "Error in GetAllStrings for resource '{Resource}' and culture '{Culture}' after {ElapsedMs}ms", _resourceName, culture, sw.ElapsedMilliseconds);
                throw;
            }
        }

        private void Record(string name, long elapsedMs, string culture)
        {
            var key = string.IsNullOrEmpty(_resourceName) ? name : $"{_resourceName}:{name}";
            _monitor.RecordMetric(key, elapsedMs, culture);
        }

        private void WarnSlow(long elapsedMs, string name, string culture, bool hasArgs, int argCount)
        {
            if (elapsedMs <= _lookupThresholdMs) return;
            if (hasArgs)
            {
                _logger.LogWarning("Slow localization with args: Resource='{Resource}', Key='{Key}', Culture='{Culture}', ArgCount={ArgCount}, Time={ElapsedMs}ms", _resourceName, name, culture, argCount, elapsedMs);
            }
            else
            {
                _logger.LogWarning("Slow localization: Resource='{Resource}', Key='{Key}', Culture='{Culture}', Time={ElapsedMs}ms", _resourceName, name, culture, elapsedMs);
            }
        }
    }
}

Do you have any suggestions?

Using: Tiered, MVC+SQL/EF with OpenIddict, ABP 9.3.2

I have the following hooked up to try and identify what's causing large and/or frequent delays:

/// <summary>
/// A debug implementation of the AbpClaimsPrincipalFactory that logs the resolution and contribution of claims
/// principal contributors.
/// </summary>
[Dependency(ReplaceServices = true)]
[ExposeServices(typeof(IAbpClaimsPrincipalFactory))]
public class DebugAbpClaimsPrincipalFactory : AbpClaimsPrincipalFactory
{
    private const int SlowThresholdMs = 500; // Log anything slower than 500ms
    private const string SlowMarker = "PERFORMANCE_BOTTLENECK";
    private readonly ILogger<DebugAbpClaimsPrincipalFactory> _logger;

    public DebugAbpClaimsPrincipalFactory(
        IServiceProvider serviceProvider,
        IOptions<AbpClaimsPrincipalFactoryOptions> abpClaimOptions,
        ILogger<DebugAbpClaimsPrincipalFactory> logger)
        : base(serviceProvider, abpClaimOptions)
    {
        _logger = logger;
    }

    /// <summary>
    ///     Creates a ClaimsPrincipal by contributing claims from registered contributors.
    /// </summary>
    /// <param name="options">
    ///     The options that define how claims are contributed to the ClaimsPrincipal.
    /// </param>
    /// <param name="existsClaimsPrincipal">
    ///     An existing ClaimsPrincipal to contribute to, or null to create a new one.
    /// </param>
    /// <param name="isDynamic">
    ///     If true, only dynamic contributors will be processed. If false, all contributors will be processed.
    /// </param>
    /// <returns>
    ///     A Task that represents the asynchronous operation, containing the created ClaimsPrincipal.
    /// </returns>
    public override async Task<ClaimsPrincipal> InternalCreateAsync(
        AbpClaimsPrincipalFactoryOptions options,
        ClaimsPrincipal? existsClaimsPrincipal = null,
        bool isDynamic = false)
    {
        var claimsPrincipal = existsClaimsPrincipal ?? new ClaimsPrincipal(new ClaimsIdentity(
            AuthenticationType,
            AbpClaimTypes.UserName,
            AbpClaimTypes.Role));

        var context = new AbpClaimsPrincipalContributorContext(claimsPrincipal, ServiceProvider);

        if (!isDynamic)
        {
            foreach (var contributorType in options.Contributors)
            {
                var stopwatch = Stopwatch.StartNew();

                var contributor =
                    (IAbpClaimsPrincipalContributor)ServiceProvider.GetRequiredService(contributorType);
                stopwatch.Stop();

                if (stopwatch.ElapsedMilliseconds > SlowThresholdMs)
                {
                    _logger.LogError(
                        "{SlowMarker} SLOW RESOLUTION: {ContributorType} took {ElapsedMs}ms to resolve",
                        SlowMarker, contributorType.Name, stopwatch.ElapsedMilliseconds);
                }

                var contributeStopwatch = Stopwatch.StartNew();
                await contributor.ContributeAsync(context);
                contributeStopwatch.Stop();

                if (contributeStopwatch.ElapsedMilliseconds > SlowThresholdMs)
                {
                    _logger.LogError(
                        "{SlowMarker} SLOW CONTRIBUTION: {ContributorType} took {ElapsedMs}ms to contribute",
                        SlowMarker, contributorType.Name, contributeStopwatch.ElapsedMilliseconds);
                }
            }
        }
        else
        {
            _logger.LogInformation("DYNAMIC_CLAIMS_START: Processing dynamic contributors...");

            foreach (var contributorType in options.DynamicContributors)
            {
                var stopwatch = Stopwatch.StartNew();

                var contributor =
                    (IAbpDynamicClaimsPrincipalContributor)ServiceProvider.GetRequiredService(contributorType);
                stopwatch.Stop();

                if (stopwatch.ElapsedMilliseconds > SlowThresholdMs)
                {
                    _logger.LogError(
                        "{SlowMarker} SLOW DYNAMIC RESOLUTION: {ContributorType} took {ElapsedMs}ms to resolve",
                        SlowMarker, contributorType.Name, stopwatch.ElapsedMilliseconds);
                }
                else
                {
                    _logger.LogInformation(
                        "FAST DYNAMIC RESOLUTION: {ContributorType} took {ElapsedMs}ms to resolve",
                        contributorType.Name, stopwatch.ElapsedMilliseconds);
                }

                var contributeStopwatch = Stopwatch.StartNew();
                await contributor.ContributeAsync(context);
                contributeStopwatch.Stop();

                if (contributeStopwatch.ElapsedMilliseconds > SlowThresholdMs)
                {
                    _logger.LogError(
                        "{SlowMarker} SLOW DYNAMIC CONTRIBUTION: {ContributorType} took {ElapsedMs}ms to contribute",
                        SlowMarker, contributorType.Name, contributeStopwatch.ElapsedMilliseconds);
                }
                else
                {
                    _logger.LogInformation(
                        "FAST DYNAMIC CONTRIBUTION: {ContributorType} took {ElapsedMs}ms to contribute",
                        contributorType.Name, contributeStopwatch.ElapsedMilliseconds);
                }
            }

            _logger.LogInformation("DYNAMIC_CLAIMS_END: Finished processing dynamic contributors");
        }

        return context.ClaimsPrincipal;
    }
}

I will very very often see slow contributions from the following:

  • IdentitySessionDynamicClaimsPrincipalContributor
  • EditionDynamicClaimsPrincipalContributor
[2025-09-03 17:38:17.935] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 793ms to contribute
[2025-09-03 17:38:18.935] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 1783ms to contribute
[2025-09-03 17:39:06.501] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentitySessionDynamicClaimsPrincipalContributor" took 798ms to contribute
[2025-09-03 17:40:23.994] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 1360ms to contribute
[2025-09-03 17:40:24.517] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 1878ms to contribute
[2025-09-03 17:40:41.697] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 585ms to contribute
[2025-09-03 17:40:42.651] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 1538ms to contribute
[2025-09-03 17:40:43.652] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 2537ms to contribute
[2025-09-03 17:40:44.170] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentitySessionDynamicClaimsPrincipalContributor" took 3059ms to contribute
[2025-09-03 17:40:44.171] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentitySessionDynamicClaimsPrincipalContributor" took 3059ms to contribute
[2025-09-03 17:40:45.169] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 998ms to contribute
[2025-09-03 17:43:14.784] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentitySessionDynamicClaimsPrincipalContributor" took 892ms to contribute
[2025-09-03 17:43:14.784] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 883ms to contribute
[2025-09-03 17:43:15.799] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 1897ms to contribute
[2025-09-03 17:43:16.815] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentityDynamicClaimsPrincipalContributor" took 2916ms to contribute
[2025-09-03 17:43:16.821] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentitySessionDynamicClaimsPrincipalContributor" took 2927ms to contribute
[2025-09-03 17:43:16.822] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 2037ms to contribute
[2025-09-03 17:43:17.374] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 552ms to contribute
[2025-09-03 17:43:18.353] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentitySessionDynamicClaimsPrincipalContributor" took 1537ms to contribute
[2025-09-03 17:44:31.660] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 650ms to contribute
[2025-09-03 17:44:31.660] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 651ms to contribute
[2025-09-03 17:44:31.660] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "EditionDynamicClaimsPrincipalContributor" took 651ms to contribute
[2025-09-03 17:44:31.661] [Error]  () <CabMD.Diagnostics.DebugAbpClaimsPrincipalFactory> "PERFORMANCE_BOTTLENECK" SLOW DYNAMIC CONTRIBUTION: "IdentityDynamicClaimsPrincipalContributor" took 642ms to contribute

How can I either speed these up or otherwise resolve?

Editions don't change (or change very, very infrequently), so I imagine there should be caching. For identity session, we're likely still doing things far too often - likely related to the session features.

I've never seen this before, but I'd check on this:

I started ABP Studio, then ABP Suite, and then was alerted.

Studio v1.0.2 (current)

My guess here is either a bad/hijacked dependency got pulled in or it's a false positive - but I'm going to need

Issue Description

I have an issue with my abp.io application (v9.1.0, .net 9.0) where my application service method is being called multiple times when a Kendo grid makes a single request to a page handler. The grid calls the page handler once, but the application service method (which takes some time to complete) gets called multiple times with different UnitOfWork IDs.

Sequence of Events

  1. Browser makes HTTP POST to PageHandler (/Files/Edt?handler=ReadRecords)
  2. Page Handler calls EdtFileAppService.GetListAsync()
  3. This method is then called multiple times, as shown in my logs

Attempted Solutions

  • Applied [UnitOfWork(IsDisabled = true)] to both PageHandler and AppService method, it's ignored (I suspected it might be UOW related, but thinking it's more the API layer now)
  • Confirmed I've added no retry policy using AddTransientHttpErrorPolicy in AbpHttpClientBuilderOptions > ProxyClientBuildActions
  • Set long timeout in AbpHttpClientBuilderOptions > ProxyClientActions
  • Created custom IProxyHttpClientFactory implementation with long timeout
  • Tried using GET instead of POST

Code Examples

Kendo Grid Definition (Simplified)

Html.Kendo().Grid<EdtFileViewModel>().Name("EdtFilesGrid")
    .DataSource(ds => ds.Custom().Type("aspnetmvc-ajax")
        .ServerFiltering(true)
        .ServerPaging(true)
        .ServerSorting(true)
        .Schema(s => s.Aggregates("aggregateResults").Data("data").Errors("errors").Total("total").Model(m=>
        {
            m.Id(x => x.Id);
            // Other field mappings...
        }))
        .Transport(t => t.Read(r => r.Url("/Files/Edt?handler=ReadRecords").Data("EdtFilesGrid_AdditionalData").Type(HttpVerbs.Post)))
        .PageSize(10))
    .Sortable()
    .Pageable()
    .Deferred()
    .Render(); 

Application Service Method

public override async Task<PagedResultDto<EdtFileDto>> GetListAsync(EdtFilePagedAndSortedResultRequestDto input)
{
    Logger.LogWarning("Method start: {FullName}.GetListAsync, Hash: {I}", GetType().FullName, GetHashCode());
    var isProxy = GetType().Namespace?.Contains("Castle.Proxies") == true;
    Logger.LogWarning("Is this object a proxy? {IsProxy}", isProxy);
    Logger.LogWarning("UOW ID: {Guid}, IsDisabled attribute: {IsDisabled}", 
        CurrentUnitOfWork?.Id, 
        GetType().GetMethod(nameof(GetListAsync)).GetCustomAttribute<UnitOfWorkAttribute>()?.IsDisabled);

    await Task.Delay(TimeSpan.FromSeconds(30)); // Added delay to demonstrate issue
    // Additional code...
}

Logs

[2025-05-15 14:47:04.371] [Warning] () <CabMD.Edt.EdtFileAppService> Method start: "CabMD.Edt.EdtFileAppService".GetListAsync, Hash: 26433642
[2025-05-15 14:47:04.371] [Warning] () <CabMD.Edt.EdtFileAppService> Is this object a proxy? False
[2025-05-15 14:47:04.371] [Warning] () <CabMD.Edt.EdtFileAppService> UOW ID: 63bfe718-a534-4c2a-b86b-57c783f71873, IsDisabled attribute: null
[2025-05-15 14:47:17.011] [Warning] () <CabMD.Edt.EdtFileAppService> Method start: "CabMD.Edt.EdtFileAppService".GetListAsync, Hash: 24543723
[2025-05-15 14:47:17.011] [Warning] () <CabMD.Edt.EdtFileAppService> Is this object a proxy? False
[2025-05-15 14:47:17.011] [Warning] () <CabMD.Edt.EdtFileAppService> UOW ID: e9cd7595-b92e-442b-b0fb-c1676a812e0b, IsDisabled attribute: null
[2025-05-15 14:47:29.429] [Warning] () <CabMD.Edt.EdtFileAppService> Method start: "CabMD.Edt.EdtFileAppService".GetListAsync, Hash: 26575601
[2025-05-15 14:47:29.429] [Warning] () <CabMD.Edt.EdtFileAppService> Is this object a proxy? False
[2025-05-15 14:47:29.429] [Warning] () <CabMD.Edt.EdtFileAppService> UOW ID: 3cdba2e4-04d2-4f0c-8039-0c06e913d793, IsDisabled attribute: null

Additional Information

Our implementation is fitting ABP on top of an existing DB (coming from ASP.NET 4.8), so our custom DB layer makes repositories that then make the underlying calls to the DB (usually using stored procedures) - all of that works fine.

Based on the sequence diagram I've attached (which shows the flow from Browser → Razor Page Handler → Static HTTP Proxy → API Controller → Application Service), I believe the issue might be related to the Static HTTP Proxy layer, but I'm unsure what mechanism is causing these duplicate calls.

I'm 100% certain the Kendo grid is not making multiple requests. The issue occurs between the HTTP Proxy and the application service. Can you please advise on how to prevent these duplicate calls or identify what's causing them? I don't want to lock the app service method up with a semaphore, as we want many requests to be responded to concurrently and this is all but one example.

Builds are suddenly failing; it looks like the https://nuget.abp.io server is acting up. Can't view it manually either, unlike usual operation.

  • ABP Framework version: v8.3.0
  • UI Type: MVC
  • Database System: EF Core (SQL Server)
  • Tiered (for MVC) or Auth Server Separated (for Angular): yes

We are getting this exception very often and it's causing the system to be unusable. We had a failed go-live because of this and we've not been successful at locating the reason:

2025-02-20 15:11:51.633] [Error] wn0mdwk000176 (77) <Volo.Abp.AspNetCore.Mvc.ExceptionHandling.AbpExceptionFilter> A task was canceled.
System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at Volo.Abp.Threading.SemaphoreSlimExtensions.LockAsync(SemaphoreSlim semaphoreSlim, CancellationToken cancellationToken)
   at Volo.Abp.Caching.DistributedCache`2.GetOrAddAsync(TCacheKey key, Func`1 factory, Func`1 optionsFactory, Nullable`1 hideErrors, Boolean considerUow, CancellationToken token)
   at Volo.Abp.LanguageManagement.DynamicResourceLocalizer.FillAsync(LocalizationResourceBase resource, String cultureName, Dictionary`2 dictionary)
   at Volo.Abp.Localization.LocalizationResourceContributorList.FillAsync(String cultureName, Dictionary`2 dictionary, Boolean includeDynamicContributors)
   at Volo.Abp.Localization.AbpDictionaryBasedStringLocalizer.GetAllStringsAsync(String cultureName, Boolean includeParentCultures, Boolean includeBaseLocalizers, Boolean includeDynamicContributors)
   at Volo.Abp.Localization.AbpDictionaryBasedStringLocalizer.GetAllStringsAsync(Boolean includeParentCultures, Boolean includeBaseLocalizers, Boolean includeDynamicContributors)
   at Volo.Abp.Localization.AbpStringLocalizerExtensions.GetAllStringsAsync(IStringLocalizer stringLocalizer, Boolean includeParentCultures, Boolean includeBaseLocalizers, Boolean includeDynamicContributors)
   at Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationLocalizationAppService.GetAsync(ApplicationLocalizationRequestDto input)
   at Castle.DynamicProxy.AsyncInterceptorBase.ProceedAsynchronous[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo)
   at Volo.Abp.Castle.DynamicProxy.CastleAbpMethodInvocationAdapterWithReturnValue`1.ProceedAsync()
   at Volo.Abp.GlobalFeatures.GlobalFeatureInterceptor.InterceptAsync(IAbpMethodInvocation invocation)
   at Volo.Abp.Castle.DynamicProxy.CastleAsyncAbpInterceptorAdapter`1.InterceptAsync[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo, Func`3 proceed)
   at Castle.DynamicProxy.AsyncInterceptorBase.ProceedAsynchronous[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo)
   at Volo.Abp.Castle.DynamicProxy.CastleAbpMethodInvocationAdapterWithReturnValue`1.ProceedAsync()
   at Volo.Abp.Auditing.AuditingInterceptor.ProceedByLoggingAsync(IAbpMethodInvocation invocation, AbpAuditingOptions options, IAuditingHelper auditingHelper, IAuditLogScope auditLogScope)
   at Volo.Abp.Auditing.AuditingInterceptor.ProcessWithNewAuditingScopeAsync(IAbpMethodInvocation invocation, AbpAuditingOptions options, ICurrentUser currentUser, IAuditingManager auditingManager, IAuditingHelper auditingHelper, IUnitOfWorkManager unitOfWorkManager)
   at Volo.Abp.Auditing.AuditingInterceptor.ProcessWithNewAuditingScopeAsync(IAbpMethodInvocation invocation, AbpAuditingOptions options, ICurrentUser currentUser, IAuditingManager auditingManager, IAuditingHelper auditingHelper, IUnitOfWorkManager unitOfWorkManager)
   at Volo.Abp.Auditing.AuditingInterceptor.InterceptAsync(IAbpMethodInvocation invocation)
   at Volo.Abp.Castle.DynamicProxy.CastleAsyncAbpInterceptorAdapter`1.InterceptAsync[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo, Func`3 proceed)
   at Castle.DynamicProxy.AsyncInterceptorBase.ProceedAsynchronous[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo)
   at Volo.Abp.Castle.DynamicProxy.CastleAbpMethodInvocationAdapterWithReturnValue`1.ProceedAsync()
   at Volo.Abp.Validation.ValidationInterceptor.InterceptAsync(IAbpMethodInvocation invocation)
   at Volo.Abp.Castle.DynamicProxy.CastleAsyncAbpInterceptorAdapter`1.InterceptAsync[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo, Func`3 proceed)
   at Castle.DynamicProxy.AsyncInterceptorBase.ProceedAsynchronous[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo)
   at Volo.Abp.Castle.DynamicProxy.CastleAbpMethodInvocationAdapterWithReturnValue`1.ProceedAsync()
   at Volo.Abp.Uow.UnitOfWorkInterceptor.InterceptAsync(IAbpMethodInvocation invocation)
   at Volo.Abp.Castle.DynamicProxy.CastleAsyncAbpInterceptorAdapter`1.InterceptAsync[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo, Func`3 proceed)
   at Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationLocalizationController.GetAsync(ApplicationLocalizationRequestDto input)
   at lambda_method3566(Closure, Object)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableObjectResultExecutor.Execute(ActionContext actionContext, IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Logged|12_1(ControllerActionInvoker invoker)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextExceptionFilterAsync>g__Awaited|26_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)

Pretty standard deploy: web, auth, API all pointing to the same redis instance at azure.

Redis health check is good:

Redis latency seems ok:

Help!

Hi,

We're finally in production, but I'm having a very hard time keeping the system in a healthy state. It appears like we're having issues with caching which is happening all the time.

  • ABP Framework version: v8.3.0
  • UI Type: Razor Pages
  • Database System: EF Core (SQL Server)
  • Tiered (for MVC) or Auth Server Separated (for Angular): Tiered, OpenIddict, yes

I've sent logs and the module classes to liming.ma@volosoft.com but let me know if I should send them somewhere else.

I'm seeing tons of these types of entries in the API logs:

[2025-01-14 00:03:03.768] [Warning] wn1ldwk0000OB (276) <Volo.Abp.Caching.DistributedCache> The operation was canceled.
System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAsync(String key, CancellationToken token)
   at Volo.Abp.Caching.DistributedCache`2.GetAsync(TCacheKey key, Nullable`1 hideErrors, Boolean considerUow, CancellationToken token)
[2025-01-14 00:03:03.770] [Error] wn1ldwk0000OB (276) <Microsoft.EntityFrameworkCore.Database.Connection> An error occurred using the connection to database '"(redacted)"' on server '"tcp:(redacted).database.windows.net,1433"'.

And

[2025-01-14 00:03:29.807] [Debug] wn1ldwk0000OB (277) <Volo.Abp.PermissionManagement.PermissionStore> PermissionStore.GetCacheItemAsync: pn:U,pk:de5c48e0-9804-4e05-b190-99304d28c0d8,n:CabMD.EDTAccount
[2025-01-14 00:03:29.811] [Warning] wn1ldwk0000OB (277) <Volo.Abp.Caching.DistributedCache> The operation was canceled.
System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.RefreshAsync(IDatabase cache, String key, Nullable`1 absExpr, Nullable`1 sldExpr, CancellationToken token)
   at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAndRefreshAsync(String key, Boolean getData, CancellationToken token)
   at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAsync(String key, CancellationToken token)
   at Volo.Abp.Caching.DistributedCache`2.GetAsync(TCacheKey key, Nullable`1 hideErrors, Boolean considerUow, CancellationToken token)
[2025-01-14 00:03:29.813] [Debug] wn1ldwk0000OB (277) <Volo.Abp.PermissionManagement.PermissionStore> Not found in the cache: pn:U,pk:de5c48e0-9804-4e05-b190-99304d28c0d8,n:CabMD.EDTAccount
[2025-01-14 00:03:29.813] [Debug] wn1ldwk0000OB (277) <Volo.Abp.PermissionManagement.PermissionStore> Getting all granted permissions from the repository for this provider name,key: U,de5c48e0-9804-4e05-b190-99304d28c0d8
[2025-01-14 00:03:29.814] [Warning] wn1ldwk0000OB (277) <Volo.Abp.Caching.DistributedCache> The operation was canceled.
System.OperationCanceledException: The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at Microsoft.Extensions.Caching.StackExchangeRedis.RedisCache.GetAsync(String key, CancellationToken token)
   at Volo.Abp.Caching.DistributedCache`2.GetAsync(TCacheKey key, Nullable`1 hideErrors, Boolean considerUow, CancellationToken token)
[2025-01-14 00:03:29.816] [Error] wn1ldwk0000OB (277) <Microsoft.EntityFrameworkCore.Database.Connection> An error occurred using the connection to database '"(redacted)"' on server '"tcp:(redacted).database.windows.net,1433"'.
[2025-01-14 00:03:29.825] [Error] wn1ldwk0000OB (277) <Volo.Abp.AspNetCore.Mvc.ExceptionHandling.AbpExceptionFilter> ---------- RemoteServiceErrorInfo ----------
{
  "code": null,
  "message": "An internal error occurred during your request!",
  "details": null,
  "data": {},
  "validationErrors": null
}

Testing went well, but now that this is live and we're getting lots of users - it's failing dramatically and the users are very frustrated.

I'm trying to understand:

  1. What the nature of this error is
  2. Why does it happen so often
  3. What solutions are there for resolving the issue

I'm using abp+hangfire using SQL, but it looks like there's an issue related to the RecurringJobId length and the general constraint that Hangfire has on the Key column (nvarchar 100).

  • ABP Framework version: v8.2
  • UI Type: MVC
  • Database System: EF Core (SQL Server)
  • Tiered (for MVC) or Auth Server Separated (for Angular): yes, tiered
  • Exception message and full stack trace: (below)
  • Steps to reproduce the issue:

[2024-07-04 15:21:31.520] [Fatal] DEV1-PC () <> Host terminated unexpectedly! Error: "An error occurred during the initialize Volo.Abp.Modularity.OnApplicationInitializationModuleLifecycleContributor phase of the module Volo.Abp.Identity.AbpIdentityProDomainModule, Volo.Abp.Identity.Pro.Domain, Version=8.2.0.0, Culture=neutral, PublicKeyToken=null: String or binary data would be truncated in table 'CabMD15.HangFire.Hash', column 'Key'. Truncated value: 'recurring-job:HangfirePeriodicBackgroundWorkerAdapter<IdentitySessionCleanupBackgroundWorker>.DoWork'.. See the inner exception for details." Volo.Abp.AbpInitializationException: An error occurred during the initialize Volo.Abp.Modularity.OnApplicationInitializationModuleLifecycleContributor phase of the module Volo.Abp.Identity.AbpIdentityProDomainModule, Volo.Abp.Identity.Pro.Domain, Version=8.2.0.0, Culture=neutral, PublicKeyToken=null: String or binary data would be truncated in table 'CabMD15.HangFire.Hash', column 'Key'. Truncated value: 'recurring-job:HangfirePeriodicBackgroundWorkerAdapter<IdentitySessionCleanupBackgroundWorker>.DoWork'.. See the inner exception for details. ---> Microsoft.Data.SqlClient.SqlException (0x80131904): String or binary data would be truncated in table 'CabMD15.HangFire.Hash', column 'Key'. Truncated value: 'recurring-job:HangfirePeriodicBackgroundWorkerAdapter<IdentitySessionCleanupBackgroundWorker>.DoWork'. at void Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, bool breakConnection, Action<Action> wrapCloseInAction) at void Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, bool breakConnection, Action<Action> wrapCloseInAction) at void Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, bool callerHasConnectionLock, bool asyncClose) at bool Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, out bool dataReady) at void Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, string resetOptionsString, bool isInternal, bool forDescribeParameterEncryption, bool shouldCacheForAlwaysEncrypted) at SqlDataReader Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, bool returnStream, bool isAsync, int timeout, out Task task, bool asyncWrite, bool inRetry, SqlDataReader ds, bool describeParameterEncryptionRequest) at SqlDataReader Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, bool returnStream, TaskCompletionSource<object> completion, int timeout, out Task task, out bool usedCache, bool asyncWrite, bool inRetry, string method) at Task Microsoft.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource<object> completion, bool sendToPipe, int timeout, out bool usedCache, bool asyncWrite, bool inRetry, string methodName) at int Microsoft.Data.SqlClient.SqlCommand.ExecuteNonQuery() at void Hangfire.SqlServer.SqlCommandBatch.ExecuteNonQuery() in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlCommandBatch.cs:line 122 at void Hangfire.SqlServer.SqlServerWriteOnlyTransaction.Commit()+(DbConnection connection, DbTransaction transaction) => { } in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerWriteOnlyTransaction.cs:line 100 at void Hangfire.SqlServer.SqlServerStorage.UseTransaction(DbConnection dedicatedConnection, Action<DbConnection, DbTransaction> action)+(DbConnection connection, DbTransaction transaction) => { } in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerStorage.cs:line 272 at void Hangfire.SqlServer.SqlServerStorage.UseTransaction(DbConnection dedicatedConnection, Action<DbConnection, DbTransaction> action)+(DbConnection connection) => { } in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerStorage.cs:line 319 at T Hangfire.SqlServer.SqlServerStorage.UseConnection<T>(DbConnection dedicatedConnection, Func<DbConnection, T> func) in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerStorage.cs:line 257 at T Hangfire.SqlServer.SqlServerStorage.UseTransaction<T>(DbConnection dedicatedConnection, Func<DbConnection, DbTransaction, T> func, IsolationLevel? isolationLevel) in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerStorage.cs:line 307 at void Hangfire.SqlServer.SqlServerStorage.UseTransaction(DbConnection dedicatedConnection, Action<DbConnection, DbTransaction> action) in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerStorage.cs:line 270 at void Hangfire.SqlServer.SqlServerWriteOnlyTransaction.Commit() in C:/projects/hangfire-525/src/Hangfire.SqlServer/SqlServerWriteOnlyTransaction.cs:line 69 at void Hangfire.RecurringJobManager.AddOrUpdate(string recurringJobId, Job job, string cronExpression, RecurringJobOptions options) in C:/projects/hangfire-525/src/Hangfire.Core/RecurringJobManager.cs:line 148 at void Hangfire.RecurringJobManagerExtensions.AddOrUpdate(IRecurringJobManager manager, string recurringJobId, Job job, string cronExpression, TimeZoneInfo timeZone, string queue) in C:/projects/hangfire-525/src/Hangfire.Core/RecurringJobManagerExtensions.cs:line 65 at void Hangfire.RecurringJob.AddOrUpdate(Expression<Func<Task>> methodCall, string cronExpression, TimeZoneInfo timeZone, string queue) in C:/projects/hangfire-525/src/Hangfire.Core/RecurringJob.cs:line 379 at async Task Volo.Abp.BackgroundWorkers.Hangfire.HangfireBackgroundWorkerManager.AddAsync(IBackgroundWorker worker, CancellationToken cancellationToken) at async Task Volo.Abp.Identity.AbpIdentityProDomainModule.OnApplicationInitializationAsync(ApplicationInitializationContext context) at void Nito.AsyncEx.Synchronous.TaskExtensions.WaitAndUnwrapException(Task task) at void Nito.AsyncEx.AsyncContext.Run(Action action)+(Task t) => { } at void Nito.AsyncEx.Synchronous.TaskExtensions.WaitAndUnwrapException(Task task) at void Nito.AsyncEx.AsyncContext.Run(Func<Task> action) at void Volo.Abp.Threading.AsyncHelper.RunSync(Func<Task> action) at void Volo.Abp.Identity.AbpIdentityProDomainModule.OnApplicationInitialization(ApplicationInitializationContext context) at void Volo.Abp.Modularity.OnApplicationInitializationModuleLifecycleContributor.Initialize(ApplicationInitializationContext context, IAbpModule module) at void Volo.Abp.Modularity.ModuleManager.InitializeModules(ApplicationInitializationContext context)

We're seeing an issue when multi-tenancy is enabled and when the tenancy picker has been removed (like as in https://community.abp.io/posts/hide-the-tenant-switch-of-the-login-page-4foaup7p), specifically when creating tenants and the tenant admin is created - the default is the same username making it difficult/impossible to use without having them login using email instead.

  • ABP Framework version: v8.1.3
  • UI Type: MVC
  • Database System: EF Core (SQL Server)
  • Tiered (for MVC) or Auth Server Separated (for Angular): yes, Tiered

To reproduce:

  1. Login as non-tenant admin
  2. Create tenant, specify email and password
  3. Logout
  4. Attempt to login using admin (since that's the default username, which isn't obvious to the user creating the tenancy) and the password specified in #2

Expected: Should be able to login Actual: Can't login

Now, it does make sense but what would be nice is:

  • Allow the user making the tenancy to create a unique username (since you already allow changing that in the tenancy "set password" modal.
  • Add a IdentityDataSeedContributor.AdminUsernamePropertyName property so we can modify (Project)TenantDatabaseMigrationHandler like:
// Seed data
using (var uow = _unitOfWorkManager.Begin(requiresNew: false, isTransactional: true))
{
    await _dataSeeder.SeedAsync(
        new DataSeedContext(tenantId)
            .WithProperty(IdentityDataSeedContributor.AdminUsernamePropertyName, adminUsername) // <-- NEW
            .WithProperty(IdentityDataSeedContributor.AdminEmailPropertyName, adminEmail)
            .WithProperty(IdentityDataSeedContributor.AdminPasswordPropertyName, adminPassword)
    );

    await uow.CompleteAsync();
}

Is that possible?

See https://support.abp.io/QA/Questions/6187/Lepton-Logo-Flashing, it's still happening on 8.1.1 today. I'd comment there, but it was closed.

Showing 1 to 10 of 32 entries
Boost Your Development
ABP Live Training
Packages
See Trainings
Mastering ABP Framework Book
The Official Guide
Mastering
ABP Framework
Learn More
Mastering ABP Framework Book
Made with ❤️ on ABP v10.1.0-preview. Updated on December 12, 2025, 10:36
1
ABP Assistant
🔐 You need to be logged in to use the chatbot. Please log in first.