Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Performance Regression from 7.5.12 -> 7.6.3 Microsoft.AspNetCore.OData #2745

Closed
stack111 opened this issue Jan 12, 2023 · 4 comments · Fixed by #2769
Closed

Performance Regression from 7.5.12 -> 7.6.3 Microsoft.AspNetCore.OData #2745

stack111 opened this issue Jan 12, 2023 · 4 comments · Fixed by #2769
Assignees

Comments

@stack111
Copy link

Short summary (3-5 sentences) describing the issue.

We have a AspNetCore service running OData

image

Assemblies affected

*Which assemblies and versions are known to be affected e.g. OData WebApi lib 6.1.0
7.6.3

Reproduce steps

The simplest set of steps to reproduce the issue. If possible, reference a commit that demonstrates the issue.

            app.UseEndpoints(endpoints =>
            {
                endpoints.EnableDependencyInjection();
                endpoints.Select().Filter().OrderBy().Count().MaxTop(ModelConstants.MaxTopCount).SkipToken();
                endpoints.MapODataRoute(odata, odata, container =>
                {
                    container.AddService(OData.ServiceLifetime.Singleton, sp => GetEdmModel());
                    container.AddService<ODataPayloadValueConverter, ExtendedODataConverter>(OData.ServiceLifetime.Singleton);
                    container.AddService(OData.ServiceLifetime.Singleton, _ => app.ApplicationServices.GetRequiredService<ODataUriResolver>());
                    container.AddService<IEnumerable<IODataRoutingConvention>>(OData.ServiceLifetime.Singleton,
                        sp => ODataRoutingConventions.CreateDefaultWithAttributeRouting(odata, endpoints.ServiceProvider));
                    container.AddService<SkipTokenHandler, CosmosDbSkipTokenHandler>(OData.ServiceLifetime.Singleton);
                });
                endpoints.MapControllers();
            });
        private static ActionConfiguration EdmModelHelper<T>(ODataConventionModelBuilder odataBuilder, string baseKey, string[] keys)
             where T : class
        {
            odataBuilder.EntitySet<T>(baseKey);
            var accountScopedQuery = odataBuilder.Action(baseKey + "ScopeQuery");
            foreach (var key in keys)
            {
                accountScopedQuery.Parameter<string>(key).Optional();
            }

            accountScopedQuery.ReturnsCollectionFromEntitySet<T>(baseKey);
            return accountScopedQuery;
        }

        private static IEdmModel GetEdmModel()
        {
            const string partitionKey = "partitionKey";

            var odataBuilder = new ODataConventionModelBuilder();
            odataBuilder.EnableLowerCamelCase();
            EdmModelHelper<DocumentAccount>(odataBuilder, "Accounts", new string[] { partitionKey, ModelConstants.ResourceGroup, ModelConstants.ResourceName, ModelConstants.ClientId, ModelConstants.ParentId });
            var accountModel = odataBuilder.EntitySet<DocumentAccount>(partitionKey);
            accountModel.EntityType.CollectionProperty(l => l.LinkedResources).IsOptional();

            var repeatedSet = new string[] { partitionKey, ModelConstants.ResourceName, ModelConstants.Id, ModelConstants.ParentId };
            EdmModelHelper<DocumentCreatorResource>(odataBuilder, "Creators", repeatedSet);
            EdmModelHelper<DocumentEventGridFilter>(odataBuilder, "EventGridFilters", new string[] { partitionKey, ModelConstants.ResourceName, ModelConstants.Id, ModelConstants.ParentId });
            EdmModelHelper<DocumentSubscription>(odataBuilder, "Subscriptions", new string[] { partitionKey, ModelConstants.Id });
            odataBuilder.EntitySet<ManagedIdentityDocument>("msi");
            var model = odataBuilder.GetEdmModel();
            return model;
        }

Perf affected controller

namespace Microsoft.Azure.LocationServices.IdentityService.Controllers
{
    using System;
    using System.Collections.Generic;
    using System.Threading.Tasks;
    using Microsoft.AspNet.OData;
    using Microsoft.AspNet.OData.Query;
    using Microsoft.AspNet.OData.Routing;
    using Microsoft.AspNetCore.Authorization;
    using Microsoft.AspNetCore.Mvc;
    using Microsoft.Azure.LocationServices.IdentityService.CosmosDb;

    [Route("odata/accounts")]
    [ODataRoutePrefix("accounts")]
    [ApiController]
    [Authorize]
    public class AccountsODataController : ODataController
    {
        private readonly IResourceRepository accountRepository;

        public AccountsODataController(IResourceRepository accountRepository)
        {
            this.accountRepository = accountRepository;
        }

        [HttpGet("")]
        [EnableQuery(
            AllowedQueryOptions =
            AllowedQueryOptions.Select |
            AllowedQueryOptions.Count |
            AllowedQueryOptions.Filter |
            AllowedQueryOptions.OrderBy |
            AllowedQueryOptions.Top |
            AllowedQueryOptions.Skip |
            AllowedQueryOptions.SkipToken)]
        [ApiVersion(ApiVersions.V1)]
        public async Task<IEnumerable<DocumentAccount>> QueryAccounts(ODataQueryOptions queryOptions)
        {
            if (!queryOptions.TryExtractFilter(nameof(ModelConstants.PartitionKey), out string partitionKey))
            {
                queryOptions.TryExtractFilter(ModelConstants.SubscriptionId, out partitionKey);
            }

            ScopeQuery query = new ScopeQuery()
            {
                PartitionKey = partitionKey,
                ResourceType = ModelConstants.AccountResourceType
            };

            var result = await accountRepository.QueryPagedResourceTypeAsync<DocumentAccount>(query, queryOptions, HttpContext.RequestAborted);
            return result.FormattedResponse(Request);
        }
    }
}

Expected result

In our test environment we would not have seen a 100ms 99th percentile increase in latency from the nuget package upgrade from 7.5.12 -> 7.6.3.

Actual result

With a very vacuum controlled steady flow of requests (test environment) we observed requests increase significantly (seconds) after isolating the only change to the NuGet upgrade. We reverted the NuGet upgrade and the latency recovered back to expected behavior.

Additional detail

Example OData queries which are affected follow

/odata/accounts?$filter=partitionKey eq 'e58ec759-cdd4-42d9-af7b-807214f4a456' and (state eq 'Activated' or state eq 'Locked')

@ElizabethOkerio
Copy link
Contributor

@stack111 could you do some profiling to determine what is triggering the issue or where the issue is.

@stack111
Copy link
Author

OData 7-6-3.zip

I performed a 20 sec sample using visual studio 2022 cpu performance profiler. This is my first time using VS2022 profiler, but I believe I found some useful insights into the modules. Hopefully this helps.

Name Total CPU [unit, %] Self CPU [unit, %]
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.WriteResourceAsync() 36248 (92.27%) 1 (0.00%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.WriteComplexPropertiesAsync() 36076 (91.83%) 0 (0.00%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.WriteComplexPropertiesAsync(Microsoft.AspNet.OData.Formatter.Serialization.SelectExpandNode, Microsoft.AspNet.OData.ResourceContext, Microsoft.OData.ODataWriter) 36076 (91.83%) 0 (0.00%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.GetPropertiesToWrite() 35922 (91.44%) 0 (0.00%)
 - Microsoft.AspNet.OData.Formatter.EdmLibHelpers.GetClrType(Microsoft.OData.Edm.IEdmTypeReference, Microsoft.OData.Edm.IEdmModel, Microsoft.AspNet.OData.Interfaces.IWebApiAssembliesResolver) 35898 (91.38%) 1 (0.00%)
 - Microsoft.AspNet.OData.Formatter.EdmLibHelpers.GetClrType(Microsoft.OData.Edm.IEdmType, Microsoft.OData.Edm.IEdmModel, Microsoft.AspNet.OData.Interfaces.IWebApiAssembliesResolver) 35884 (91.34%) 1 (0.00%)
 - Microsoft.AspNet.OData.TypeHelper.GetLoadedTypes() 25222 (64.20%) 498 (1.27%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.WriteResourceAsync(object, Microsoft.OData.ODataWriter, Microsoft.AspNet.OData.Formatter.Serialization.ODataSerializerContext, Microsoft.OData.Edm.IEdmTypeReference) 16628 (42.33%) 0 (0.00%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.WriteComplexAndExpandedNavigationPropertyAsync() 16417 (41.79%) 2 (0.01%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSerializer.WriteComplexAndExpandedNavigationPropertyAsync(Microsoft.OData.Edm.IEdmProperty, Microsoft.OData.UriParser.SelectItem, Microsoft.AspNet.OData.ResourceContext, Microsoft.OData.ODataWriter) 16417 (41.79%) 0 (0.00%)
 - Microsoft.AspNet.OData.Formatter.EdmLibHelpers.GetMatchingTypes.AnonymousMethod__0(System.Type) 10503 (26.73%) 216 (0.55%)
 - Microsoft.AspNet.OData.Formatter.EdmLibHelpers.EdmFullName(System.Type) 10287 (26.18%) 142 (0.36%)
 - Microsoft.AspNet.OData.Formatter.EdmLibHelpers.MangleClrTypeName(System.Type) 1741 (4.43%) 274 (0.70%)
 - Microsoft.AspNet.OData.Formatter.Serialization.ODataResourceSetSerializer.WriteResourceSetAsync() 458 (1.17%) 1 (0.00%)
 - Microsoft.AspNet.OData.Adapters.WebApiAssembliesResolver.get_Assemblies() 144 (0.37%) 144 (0.37%)

@habbes habbes removed their assignment Feb 14, 2023
@owerkop
Copy link

owerkop commented Feb 22, 2023

As a more detailed reference - I'm attaching profiler's output:

I've executed the same request to my application for two Microsoft.AspNet.OData versions.

Microsoft.AspNet.OData 7.5.14:
image

Microsoft.AspNet.OData 7.6.1:
image

Problem occurs only for OData entity having computed collection property.

We see WriteComplexProperties method in 7.6.1 became very slow despite it's called exactly the same number of times.
I suppose this is related to changes introduced i #2697

UPDATE:
There is called method:
GetMatchingTypes(string edmFullName, IWebApiAssembliesResolver assembliesResolver).
(WebApiAssembliesResolver.Assemblies in my application returns 390 assemblies)

Effectively for every loaded assembly and every (public) Type is executed EdmLibHelpers.EdmFullName() method.

That all is repeated for every returned OData response record!

Profiler's output showing described situation:
image

@shdim
Copy link

shdim commented Mar 22, 2023

In IEnumerable<KeyValuePair<IEdmStructuralProperty, PathSelectItem>> GetPropertiesToWrite(SelectExpandNode selectExpandNode, ResourceContext resourceContext)

                    if (type != null && resourceContext.EdmModel != null)
                    {
                        Type clrType = EdmLibHelpers.GetClrType(type.AsStructured(), resourceContext.EdmModel);

                        if (clrType != null && clrType == typeof(ODataIdContainer))
                        {
                            continue;
                        }
                    }

If a property is a complex type collection then type is not a IEdmStructuredTypeReference and AsStructured returns BadEntityTypeReference which causes reflecting over all assemblies.

Something like if (type != null && type.IsStructured() && resourceContext.EdmModel != null) should fix it, I think.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants