Enhancement to capture query execution metrics and integrate with micrometer

[ashu-walmart]

A candidate approach might be to create an instrumentation as described in graphql-java-kickstart/graphql-java-servlet#96

[oliemansm]

@ashu-walmart @apkrasny @kclaes
There's a PR in the works for this one, thanks to @senzzzi, see #141.

What kind of metrics would you like to have gathered and exposed to micrometer? So when you look at what TracingInstrumentation gathers for example, could you indicate what you would like to see as metrics? Below is an example tracing from TracingInstrumentation:

{
  "tracing": {
    "version": 1,
    "startTime": "2018-11-04T07:56:22.688Z",
    "endTime": "2018-11-04T07:56:22.708Z",
    "duration": 20854930,
    "parsing": {
      "startOffset": 13244060,
      "duration": 1601187
    },
    "validation": {
      "startOffset": 14140851,
      "duration": 858865
    },
    "execution": {
      "resolvers": [
        {
          "path": [
            "post"
          ],
          "parentType": "Query",
          "returnType": "Post",
          "fieldName": "post",
          "startOffset": 14452160,
          "duration": 579161
        },
        {
          "path": [
            "post",
            "text"
          ],
          "parentType": "Post",
          "returnType": "String",
          "fieldName": "text",
          "startOffset": 15252950,
          "duration": 43457
        },
        {
          "path": [
            "post",
            "comments"
          ],
          "parentType": "Post",
          "returnType": "[Comment!]!",
          "fieldName": "comments",
          "startOffset": 15453642,
          "duration": 280889
        }
      ]
    }
  }
}

[cgarrit-os]

Hi there! I work with @ashu-walmart. We're currently extending SimpleInstrumentation to wrap a Micrometer Timer around each field fetch and aggregating those on the back end. Our basic requirements were to understand how frequently specific elements were being requested, the result of that request (essentially whether or not a Throwable was present), and the timing of each. We didn't look at overall execution duration, validation, or parsing times, but we could see value in those metrics as well.

Additionally, we haven't looked at instrumenting error counts from the response's errors extension, but that would also be useful. Outwardly observable mechanisms like HTTP status code don't provide much resolution into response details.

Here's the instrumentation hook for resolvers.

public InstrumentationContext<Object> beginFieldFetch(InstrumentationFieldFetchParameters parameters) { Timer.Sample sample = Timer.start(registry); return SimpleInstrumentationContext.whenCompleted((result, throwable) -> { sample.stop(getTimer(parameters.getEnvironment(), throwable == null)); }); }

Having injectable behavior around the naming of timers to allow consumers to optimize for hierarchical or dimensional monitoring systems is probably preferable. We're currently using Graphite so we ended up imposing a naming convention to get the field hierarchy the way we wanted it.

[oliemansm]

Thanks for your input @cgarrit-os!

[oliemansm]

This has now been included for the next release, see #141