feature/time-tracker-boost: Add total time or duration methods that log despite error

[anticipasean]

Add measurement functional type and base set of time-elapsed measurement on action methods to TimeTracer that log total time or duration even when error occurs

Pull request checklist

• [x] Please read our contributor guide
• [x] Consider creating a discussion on the discussion forum first
• [x] Make sure the PR doesn't introduce backward compatibility issues
• [x] Make sure to have sufficient test cases

Pull Request type

• [ ] Bugfix
• [ ] Feature
• [x] Refactoring (no functional changes, no api changes)
• [ ] Build related changes
• [ ] Other (please describe):

Changes in this PR

• Add measurement functional type and base set of time-elapsed measurement on action methods to TimeTracer that log total time or duration even when error occurs
• Create unit tests for new measurement and logger extension functions on TimeTracer

Describe the new behavior from this PR, and why it's needed

Issue # NA

No migration of existing calls to the com.netflix.graphql.dgs.internal.utils.TimeTracer#logTime function were done as part of this PR, so no change in behavior of the application should be observed at compile time or runtime (provided that, of course, my local testing environment has the expected configuration for this repo). I will leave it to the repo owners to decide whether to migrate those function calls to make use of one of the new functions on this TimeTracer singleton.

I observed that the com.netflix.graphql.dgs.internal.utils.TimeTracer#logTime function does not log the total time when an error within one of its various referenced action blocks occurs and think it will be helpful to others if it still did log those times, especially if that duration takes suspiciously long in the case of an error but is otherwise quick in the success case.

I also think the new syntax is a little cleaner in Kotlin when function calls like that one, com.netflix.graphql.dgs.internal.utils.TimeTracer#logTime, have their one function input parameter at the end of their parameter sets so the block can hang off the end of the function call and in some cases, with extension functions, the Logger parameter can become implied through a receiver function call.

(I am working on a functional feature engineering pipeline in my repo funcify-feature-eng and am considering using DGS for at least part of it but need to flesh out certain other functional typing and pipelining constructs before I get to the GraphQL piece. So, that's how I came across this timing component)

Alternatives considered

• Since these changes only affect a very specific class within the com.netflix.graphql.dgs.internal package, it seemed to be more fun to present the more extensive solution first, one with some syntactic sugar examples, before posting a basic but possibly preferred (depending on the repo-owners) simple try { ... } catch { ... } block around the action.invoke() piece in the existing com.netflix.graphql.dgs.internal.utils.TimeTracer#logTime

Describe alternative implementation you have considered

• A simple try { ... } catch { ... } block around the action.invoke() piece in the existing com.netflix.graphql.dgs.internal.utils.TimeTracer#logTime

[berngp]

Hi @anticipasean, did you looked at graphql-dgs-spring-boot-micrometer? To provide measurements we are leveraging Micrometer, checkout our Metrics Out of the Box

[anticipasean]

Hey @berngp, thanks for the reference! I am just getting started with a new project that I am considering using DGS for, at least one of its components. I am still exploring all of the configuration options, possible dependencies, etc. for this use case. The graphql-dgs-spring-boot-micrometer module definitely appears to cover the more important metrics I want to capture and track: the query and mutation times.

With that said, the graphql-dfs and graphql-dgs-spring-webmvc modules are still using com.netflix.graphql.dgs.internal.utils.TimeTracer#logTime method to log several some action times:

• DgsRestController-L182
• DgsRestController-L207
• DefaultDgsGraphQLContextBuilder-L36

If you do plan to still log those times and/or others that fall outside the scope of micrometer tagging or GraphQL instrumentation specs e.g. how long it takes to build the dgs graphql context in the context builder, then it wouldn't hurt to use this measurement code in TimeTracer since it's only in the internal package / API and helpful for measuring any synchronous but potentially delayed actions (The asynchronous ones obviously require a bit more finesse to measure properly).

Is the plan to have micrometer eventually cover these other use cases as well i.e. start-up schema wiring, context creation, context updates, etc.?

[anticipasean]

Just curious, which team works on this repo at Netflix? Lots of the examples feature entities like shows and reviews---Netflix's customer-facing company product types---but I would figure creating data pipelines that do feature engineering for machine learning models and business statistics like what I've been working on---entities like transunion_credit_report and transunion_tradeline_features with fields like adj_rev_spend_idx_1y (adjusted revolving spend index over past year)---would be a pretty cool use case and feature set for DGS. The current set of opensource tools out there require a lot of stitchwork to pull together: Apache Spark, Apache Druid, Apache Beam, Hasura, Spotify Scio, etc. and house under one GraphQL schema roof (or federated set of GraphQL schemata).

[srinivasankavitha]

The examples are based on product types because the DGS framework primarily started as solving for Netflix's Studio API. Most of our DGSs are in that space, with a few more coming up for internal usages. We haven't yet come across any business use case for adopting this for data pipelines for machine learning. We do have an examples section in our docs with contributions from the community, so if you have ideas there, we would welcome any additional examples for such new use cases. https://netflix.github.io/dgs/examples/#community-contributions

On Tue, Apr 5, 2022 at 12:21 PM Sean @.***> wrote:

Just curious, which team works on this repo at Netflix? Lots of the examples feature entities like shows and reviews---Netflix's customer-facing company product types---but I would figure creating data pipelines that do feature engineering for machine learning models and business statistics like what I've been working on---entities like transunion_credit_report and transunion_tradeline_features with fields like adj_rev_spend_idx_1y (adjusted revolving spend index over past year)---would be a pretty cool use case and feature set for DGS. The current set of opensource tools out there require a lot of stitchwork to pull together: Apache Spark, Apache Druid, Apache Beam, Hasura, Spotify Scio, etc. and house under one GraphQL schema roof (or federated set of GraphQL schemata).

— Reply to this email directly, view it on GitHub https://github.com/Netflix/dgs-framework/pull/954#issuecomment-1089222641, or unsubscribe https://github.com/notifications/unsubscribe-auth/AJ5JPXJ5P6MXNTSCKFPXEM3VDSHDDANCNFSM5SGXEIZQ . You are receiving this because you are subscribed to this thread.Message ID: @.***>

[berngp]

I think that logging is not really a scalable way to express measurements. So, to answer your question, I think that we should replace them. I do see value on abstracting the observations of actions in such a manner that they can be easily leveraged for metrics via Micrometer,or other use cases, such as tracing via Brave/Zipkin.

PS there is a Micrometer Meter Registry that logs measurements to a file.

[github-actions[bot]]

This pull request has been marked as stale because it has been open 1 year with no activity. Remove stale label or comment or this will be closed in 7 days