Initial query call is taking unusually huge time ~24secs (Performance Issue)

[chandsalam1108]

Is there an existing issue for this?

• [X] I have searched the existing issues

Describe the bug

We're using following HotChocolate libraries for GraphQL server & Federated Schema (pub/sub). It's taking unusually huge time for initial query at times ~24 secs.

<PackageReference Include="HotChocolate.Data.EntityFramework" Version="11.3.3" />
<PackageReference Include="HotChocolate.Stitching" Version="11.3.3" />
<PackageReference Include="HotChocolate.AspNetCore.Authorization" Version="11.3.3" />
<PackageReference Include="HotChocolate.Stitching.Redis" Version="11.3.3" />

We're also using appropriate DataLoaders (Group & Batch) as explained in Chili Cream documentation.

Please help us on improving performance.

Product

Hot Chocolate

Version

11.3.3

[PascalSenn]

@chandsalam1108 This is because the schema is built on the first request. In the newest version this is already a lot faster and we will continually improve this. Can you give feedback how the performance is in v12? The easiest way to work around this in v11.3.3 is to set IntitializeOnStartup on the schema builder.

[michaelstaib]

24 seconds sounds rather high :)

But just from the message we cannot help. My suggestion would also to upgrade to 12-rc.5 and try if it is better ... if not we can have a look together what it might be in your case.

[michaelstaib]

Also you can use the InitializeOnStartup configuration to move the schema building to startup.

[michaelstaib]

Just as an info.... I looked at our initialization benchmarks.

A large schema (18.850 Types and 91.883 Fields) takes around 9 seconds in version 11.3 to initialize. The same schema takes 3 seconds in version 12.

so a 24 second initialization seems quite heavy. But try out 12 and opt-into InitializeOnStartup and report back where you are with initialization then.

If you cannot get it down we can have a discussion on slack to see where the issue lies with your schema.

http://slack.chillicream.com

[michaelstaib]

@chandsalam1108 do you guys have any feedback?

[chandsalam1108]

@michaelstaib @PascalSenn - Thank you so much for the swift response. I'll try your recommendations and get back to you with the details.

[chandsalam1108]

Already using "InitializeOnStartup" in domain services. Also using Federated Schema pub sub for hot reload.

services
                .AddSingleton(ConnectionMultiplexer.Connect(Configuration.GetConnectionString("FederatedSchemaRedisXXXX")))
                .AddGraphQLServer()
                .AddHttpRequestInterceptor<HttpRequestInterceptor>()
                .AddAuthorization()
                .AddQueryType<Query>()
                .AddDataLoader<EnrollmentsByStatusCodeDataloader>()
                .AddDataLoader<EnrollmentByRequestNumberDataLoader>()
                .AddProjections()
                .AddFiltering()
                .AddSorting()
                // We initialize the schema on startup so it is published to the redis as soon as possible
                .InitializeOnStartup()
                // We configure the publish definition
                .PublishSchemaDefinition(c => c
                    // The name of the schema. This name should be unique
                    .SetName("EnrollmentXXX")
                    .IgnoreRootTypes()
                    .AddTypeExtensionsFromFile("./Stitching.graphql")
                    .PublishToRedis("NaraakomFederatedSchema", sp => sp.GetRequiredService<ConnectionMultiplexer>()))
                .ModifyRequestOptions(opt => opt.IncludeExceptionDetails = true);

Here, we're using projections so no N+1 issue still 10 secs for initial call

I'll upgrade to version 12 & update on initial load time.

Thank you!

[chandsalam1108]

HI @michaelstaib @PascalSenn ,

After upgrading to v12 getting follow error. Please help.

Thank you!

 Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
      An unhandled exception has occurred while executing the request.
      HotChocolate.SchemaException: For more details look at the `Errors` property.

      1. Unable to resolve type reference `None: Uuid`. (HotChocolate.Types.ObjectType)

         at HotChocolate.Configuration.RegisteredType.GetType[T](ITypeReference typeRef)
         at HotChocolate.Types.OutputFieldBase`1.OnCompleteField(ITypeCompletionContext context, ITypeSystemMember declaringMember, TDefinition definition)
         at HotChocolate.Types.ObjectField.OnCompleteField(ITypeCompletionContext context, ITypeSystemMember declaringMember, ObjectFieldDefinition definition)
         at HotChocolate.Types.FieldBase`1.CompleteField(ITypeCompletionContext context, ITypeSystemMember declaringMember)
         at HotChocolate.Types.FieldBase`1.HotChocolate.Types.Helpers.IFieldCompletion.CompleteField(ITypeCompletionContext context, ITypeSystemMember declaringMember)
         at HotChocolate.Internal.FieldInitHelper.CompleteFieldsInternal[TField](ITypeCompletionContext context, ITypeSystemMember declaringMember, TField[] fields)
         at HotChocolate.Internal.FieldInitHelper.CompleteFieldsInternal[TFieldDefinition,TField](ITypeCompletionContext context, ITypeSystemMember declaringMember, IEnumerable`1 fieldDefinitions, Func`3 fieldFactory, Int32 fieldCount)
         at HotChocolate.Internal.FieldInitHelper.CompleteFields[TFieldDefinition,TField](ITypeCompletionContext context, ITypeSystemMember declaringMember, IReadOnlyList`1 fieldDefs, Func`3 fieldFactory)
         at HotChocolate.Types.ObjectType.OnCompleteFields(ITypeCompletionContext context, ObjectTypeDefinition definition)
         at HotChocolate.Types.ObjectType.OnCompleteType(ITypeCompletionContext context, ObjectTypeDefinition definition)
         at HotChocolate.Types.TypeSystemObjectBase`1.CompleteType(ITypeCompletionContext context)
         at HotChocolate.Configuration.TypeInitializer.<CompleteTypes>g__CompleteType|23_0(RegisteredType registeredType)
         at HotChocolate.Configuration.TypeInitializer.ProcessTypes(TypeDependencyKind kind, Func`2 action)
         at HotChocolate.Configuration.TypeInitializer.CompleteTypes()
         at HotChocolate.Configuration.TypeInitializer.Initialize(Func`1 schemaResolver, IReadOnlySchemaOptions options)         at HotChocolate.SchemaBuilder.Setup.InitializeTypes(SchemaBuilder builder, IDescriptorContext context, IReadOnlyList`1 types, LazySchema lazySchema)
         at HotChocolate.SchemaBuilder.Setup.Create(SchemaBuilder builder, LazySchema lazySchema, IDescriptorContext context)
         at HotChocolate.SchemaBuilder.Create(IDescriptorContext context)
         at HotChocolate.SchemaBuilder.HotChocolate.ISchemaBuilder.Create(IDescriptorContext context)
         at HotChocolate.Execution.RequestExecutorResolver.CreateSchemaAsync(NameString schemaName, RequestExecutorSetup options, RequestExecutorOptions executorOptions, IServiceProvider serviceProvider, TypeModuleChangeMonitor typeModuleChangeMonitor, CancellationToken cancellationToken)
         at HotChocolate.Execution.RequestExecutorResolver.CreateSchemaServicesAsync(NameString schemaName, RequestExecutorSetup options, CancellationToken cancellationToken)
         at HotChocolate.Execution.RequestExecutorResolver.GetRequestExecutorNoLockAsync(NameString schemaName, CancellationToken cancellationToken)
         at Microsoft.Extensions.DependencyInjection.HotChocolateStitchingRequestExecutorExtensions.<>c__DisplayClass5_0.<<AddRemoteSchema>b__2>d.MoveNext()
      --- End of stack trace from previous location ---
         at HotChocolate.Execution.RequestExecutorResolver.CreateSchemaAsync(NameString schemaName, RequestExecutorSetup options, RequestExecutorOptions executorOptions, IServiceProvider serviceProvider, TypeModuleChangeMonitor typeModuleChangeMonitor, CancellationToken cancellationToken)
         at HotChocolate.Execution.RequestExecutorResolver.CreateSchemaServicesAsync(NameString schemaName, RequestExecutorSetup options, CancellationToken cancellationToken)
         at HotChocolate.Execution.RequestExecutorResolver.GetRequestExecutorNoLockAsync(NameString schemaName, CancellationToken cancellationToken)
         at HotChocolate.Execution.RequestExecutorResolver.GetRequestExecutorAsync(NameString schemaName, CancellationToken cancellationToken)
         at HotChocolate.Execution.RequestExecutorProxy.GetRequestExecutorAsync(CancellationToken cancellationToken)
         at HotChocolate.AspNetCore.HttpPostMiddleware.HandleRequestAsync(HttpContext context, AllowedContentType contentType)
         at HotChocolate.AspNetCore.HttpPostMiddleware.InvokeAsync(HttpContext context)
         at HotChocolate.AspNetCore.WebSocketSubscriptionMiddleware.InvokeAsync(HttpContext context)
         at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
         at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
         at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)

[michaelstaib]

Have you looked at the migration guide?

[chandsalam1108]

I'll try adding following middleware at our domain services where we're using UUID fields.

services
    .AddGraphQLServer()
    .AddType(() => new UuidType("Uuid", defaultFormat: 'N'));

[michaelstaib]

Have you also added this to the stitching server?

[chandsalam1108]

added at domain service and federated schema (gateway) service still getting same error:

Domain Service:

services
                .AddSingleton(ConnectionMultiplexer.Connect(Configuration.GetConnectionString("FederatedSchemaRedis")))
                .AddGraphQLServer()
                //.AddType(() => new UuidType("Uuid", defaultFormat: 'N'))
                .AddType(() => new UuidType("Uuid"))
                .AddHttpRequestInterceptor<HttpRequestInterceptor>()
                .AddAuthorization()
                .AddQueryType<Query>()
                .AddDataLoader<EnrollmentsByStatusCodeDataloader>()
                .AddDataLoader<EnrollmentByRequestNumberDataLoader>()
                .AddProjections()
                .AddFiltering()
                .AddSorting()
                // We initialize the schema on startup so it is published to the redis as soon as possible
                .InitializeOnStartup()
                // We configure the publish definition
                .PublishSchemaDefinition(c => c
                    // The name of the schema. This name should be unique
                    .SetName("EnrollmentWAx")
                    .IgnoreRootTypes()
                    .AddTypeExtensionsFromFile("./Stitching.graphql")
                    .PublishToRedis("NaraakomFederatedSchema", sp => sp.GetRequiredService<ConnectionMultiplexer>()))
                .ModifyRequestOptions(opt => opt.IncludeExceptionDetails = true);

Stiching (Gateway) Service:

 services
                // This is the connection multiplexer that redis will use
                .AddSingleton(ConnectionMultiplexer.Connect(Configuration.GetConnectionString("FederatedSchemaRedisConnectionString")))
                .AddGraphQLServer()
                .AddQueryType(d => d.Name("Query"))
                //.AddType(() => new UuidType("Uuid", defaultFormat: 'N'))
                .AddType(() => new UuidType("Uuid"))
                .AddRemoteSchemasFromRedis("NaraakomFederatedSchema", sp => sp.GetRequiredService<ConnectionMultiplexer>())
                .ModifyRequestOptions(opt => opt.IncludeExceptionDetails = true);

Error:

  HotChocolate.SchemaException: For more details look at the `Errors` property.

      1. Unable to resolve type reference `None: Uuid`. (HotChocolate.Types.ObjectType)

PS: Tried both ways but same error.

1) .AddType(() => new UuidType("Uuid", defaultFormat: 'N'));

2) .AddType(() => new UuidType("Uuid"))

[chandsalam1108]

Hi @michaelstaib @PascalSenn ,

We are primary health care corporation in the state of Qatar, we are currently working on an ambitious graphql project and implemented the server implementation using HotChocolate

We've implemented GraphQL domain services, along with federated schema (pub/sub model) for stitching & other best practices as per the documentation (https://chillicream.com/docs/hotchocolate)

Upon your suggestion, I've upgraded to v12 but, still noticing an unusually hug time of ~24-30 secs for the initial query.

However, subsequent query calls are taking <1-2 secs but if I call after 3-4hrs finding the same performance issue with unusually huge time ~24-30 secs.

Please find the screenshots for our reference and seeking your help in resolving this performance issue.

Thank you!

Domain service startup calls service config:

public void ConfigureServices(IServiceCollection services)
        {

            services.AddControllers();

            services.AddHttpContextAccessor();

            services.AddAuthorization();

            services.AddPooledDbContextFactory<AppDBContext>(opt => opt.UseSqlServer(Configuration.GetConnectionString("SqlConnectionString")));

            services
                .AddSingleton(ConnectionMultiplexer.Connect(Configuration.GetConnectionString("FederatedSchemaRedisConnectionString")))
                .AddGraphQLServer()
                .AddHttpRequestInterceptor<HttpRequestInterceptor>()
                .AddAuthorization()
                .AddQueryType<Query>()
                .AddDataLoader<StatusByCodeDataLoader>()
                .AddProjections()
                .AddFiltering()
                .AddSorting()
                // We initialize the schema on startup so it is published to the redis as soon as possible
                .InitializeOnStartup()
                // We configure the publish definition
                .PublishSchemaDefinition(c => c
                    // The name of the schema. This name should be unique
                    .SetName("NaraakomGenericWAx")
                    .IgnoreRootTypes()
                    .AddTypeExtensionsFromFile("./Stitching.graphql")
                    .PublishToRedis("NaraakomFederatedSchema", sp => sp.GetRequiredService<ConnectionMultiplexer>()))
                .ModifyRequestOptions(opt => opt.IncludeExceptionDetails = true);
        }

Gateway service startup calls service config:

public void ConfigureServices(IServiceCollection services)
        {
            services.AddControllers();

            services.AddHttpContextAccessor();

            services.AddHeaderPropagation(options =>
            {
                // forward the 'Authorization' if present.
                options.Headers.Add("Authorization");

                // forward the 'x-is-nas-auth-required' if present.
                options.Headers.Add("x-is-auth-required");
            });            

            DomainServices = Configuration.GetSection("DomainServices").GetChildren()
                .ToDictionary(x => x.Key, x => x.Value);

            foreach (var item in DomainServices)
            {
                services.AddHttpClient(item.Key, c => c.BaseAddress = new Uri(item.Value)).AddHeaderPropagation();
            }

            services
                // This is the connection multiplexer that redis will use
                .AddSingleton(ConnectionMultiplexer.Connect(Configuration.GetConnectionString("FederatedSchemaRedisConnectionString")))
                .AddGraphQLServer()
                .AddQueryType(d => d.Name("Query"))
                //.AddType(() => new UuidType("Uuid", defaultFormat: 'N'))                
                //.AddType(() => new UuidType("Uuid"))
                //.AddType(new UuidType('D'))
                .AddType(() => new UuidType(defaultFormat: 'N'))
                .AddRemoteSchemasFromRedis("NaraakomFederatedSchema", sp => sp.GetRequiredService<ConnectionMultiplexer>())
                .ModifyRequestOptions(opt => opt.IncludeExceptionDetails = true);

        }

[michaelstaib]

I would say there is something wrong in the setup :) the calls should be in the milliseconds.... even 1 second calls are slow. But to find an issue in your setup we would need to really look at the code and have a look at what component is causing the load times. One thing that is clear now is that it's not schema building that is causing this.

[michaelstaib]

Are you guys on slack?

http://slack.chillicream.com

[chandsalam1108]

I would say there is something wrong in the setup :) the calls should be in the milliseconds.... even 1 second calls are slow. But to find an issue in your setup we would need to really look at the code and have a look at what component is causing the load times. One thing that is clear now is that it's not schema building that is causing this.

Hi @michaelstaib , I can arrange a code walkthrough. Let me know if we have MS Teams call for that.

[chandsalam1108]

Are you guys on slack?

http://slack.chillicream.com

Yes I've recently joined but not using effectively as it's blocked by our CORP network.

[chandsalam1108]

Hi @michaelstaib , Can you help us on this performance issue. I've also posted this issue on slack as well!

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.