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

Instrumentation reporting low numbers when using DataLoader #859

Closed
patrik-j-nilsson opened this issue Oct 15, 2018 · 9 comments
Closed
Labels
bug Something isn't working

Comments

@patrik-j-nilsson
Copy link

I suspect instrumentation only reports time to fetch from cache, not the actual data fetch.

@joemcbride
Copy link
Member

It would report how long the particular resolver took. If you're using a cache, it would only reflect the actual data fetch when not pulling the data from the cache.

@joemcbride joemcbride added the question Developer asks to help him deal with some problem label Oct 15, 2018
@patrik-j-nilsson
Copy link
Author

Sorry, I meant the data loader's cache.
To me it looks like only LoadAsync is instrumented (fetch from data loader cache).

@joemcbride
Copy link
Member

I'm not aware of any metrics captured specific to using a DataLoader. The main metrics being captured are on a per-field (resolver) basis. If that field uses a DataLoader then the time it takes to fetch could be different if pulling from the DataLoader's cache vs. the first time it fetches.

Here's the docs for metrics: https://graphql-dotnet.github.io/docs/getting-started/metrics

And the implementation of InstrumentFieldsMiddleware:

public class InstrumentFieldsMiddleware
{
public Task<object> Resolve(ResolveFieldContext context, FieldMiddlewareDelegate next)
{
var metadata = new Dictionary<string, object>
{
{"typeName", context.ParentType.Name},
{"fieldName", context.FieldName},
{"returnTypeName", SchemaPrinter.ResolveName(context.ReturnType)},
{"path", context.Path},
};
using (context.Metrics.Subject("field", context.FieldName, metadata))
{
return next(context);
}
}
}

@johnrutherford
Copy link
Member

It looks to me like the next delegate needs to be awaited in InstrumentFieldsMiddleware for accurate timing with an async resolver.

@joemcbride
Copy link
Member

@johnrutherford Ha, duh - yes that would do it.

@joemcbride joemcbride added bug Something isn't working and removed question Developer asks to help him deal with some problem labels Oct 16, 2018
joemcbride added a commit that referenced this issue Oct 16, 2018
joemcbride added a commit that referenced this issue Oct 16, 2018
@RehanSaeed
Copy link
Contributor

@joemcbride There seems to be an implementation of InstrumentFieldsMiddleware built in here which has not been updated yet with an await. Also, is this something that is enabled by default in the server project, I can't quite figure it out?

@joemcbride
Copy link
Member

@RehanSaeed Yes, I'm updating that with async/await. Metrics are not enabled by default in the server project. You would need to create your own class that inherits from DefaultGraphQLExecuter<T> so you can add the InstrumentFieldsMiddleware to the ExecutionOptions.

@patrik-j-nilsson
Copy link
Author

Thanks for this!

@joemcbride
Copy link
Member

This is published in 2.3.0 (along with a few other things)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

4 participants