Configure GraphQL-java's DataFetcherExceptionHandler to reduce log noise

[tatu-at-datastax]

(note: see graphql-java/graphql-java#2564 for the issue on grapql-java side)

Currently failures to fetch data for GraphQL query will get both indicated to caller and automatically logged (possibly multiple times). In case of automated logging at WARN level we will also always get a (lengthy) stack trace. Unfortunately this logging is done by graphql-java default handler, SimpleDataFetcherExceptionHandler and cannot be easily changed -- while it's not a big class and we could copy-paste, it seems better to try to use and configure default handler here, if possible.

An example of output (somewhat truncated):

Step #4 - "cassandra-4.0": WARN  [main] 2021-09-27 15:37:41,533 SimpleDataFetcherExceptionHandler.java:25 - Exception while fetching data (/m1) : graphql.GraphQLException: options can only de defined once in an @atomic mutation selection
Step #4 - "cassandra-4.0": java.util.concurrent.CompletionException: graphql.GraphQLException: options can only de defined once in an @atomic mutation selection
Step #4 - "cassandra-4.0": 	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
Step #4 - "cassandra-4.0": 	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
Step #4 - "cassandra-4.0": 	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
Step #4 - "cassandra-4.0": 	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
Step #4 - "cassandra-4.0": 	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
Step #4 - "cassandra-4.0": 	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
Step #4 - "cassandra-4.0": 	at io.stargate.graphql.web.StargateGraphqlContext$BatchContext.setExecutionResult(StargateGraphqlContext.java:135)
Step #4 - "cassandra-4.0": 	at io.stargate.graphql.schema.cqlfirst.dml.fetchers.MutationFetcher.executeAsPartOfBatch(MutationFetcher.java:92)
Step #4 - "cassandra-4.0": 	at io.stargate.graphql.schema.cqlfirst.dml.fetchers.MutationFetcher.get(MutationFetcher.java:56)
Step #4 - "cassandra-4.0": 	at io.stargate.graphql.schema.cqlfirst.dml.fetchers.MutationFetcher.get(MutationFetcher.java:31)
Step #4 - "cassandra-4.0": 	at io.stargate.graphql.schema.CassandraFetcher.get(CassandraFetcher.java:33)
Step #4 - "cassandra-4.0": 	at graphql.execution.instrumentation.dataloader.DataLoaderDispatcherInstrumentation.lambda$instrumentDataFetcher$0(DataLoaderDispatcherInstrume
...

This happens about ~70 times during our CI tests but also affects products logging (depending on how many failures of these types are triggered by clients).

[olim7t]

Do you mean configuring SLF4J to skip the notprivacysafe.* categories?

Note that #1238 introduces a custom exception handler (that currently extends the default one). If needed we could indeed duplicate the code instead, it's just 4 lines if we don't log.

[tatu-at-datastax]

@olim7t yes, it's not tons of code so maybe this is one case where we could just change it. I filed the graphql-java issue just in case; we could just use that later on.

As to change, I was thinking of changing actual call to do some of:

1. Reduce WARN to INFO
2. Drop logging of stack trace either always, or by looking at underlying exception (cause) -- looks like there are different sources.

Our test run gets about 73 of these failures and all so far seem ones where message itself has all the pertinent information.
But it'd probably make sense to try to leave stack trace in for NPEs and such -- so trim it out for known types like IllegalArgumentException, for some of CompletionException and so on.

[tatu-at-datastax]

@olim7t Forgot to mention that #1238 helps here so could copy handling there from the base implementation. So I think this should wait until it gets merged.

[tatu-at-datastax]

Quick note: graphql-java will have this improvement in release 18.0 (not yet released as of 04-Oct-2021):

graphql-java/graphql-java#2569

(fixes graphql-java/graphql-java#2564)

in which a new overridable method has been added:

protected void logException(ExceptionWhileDataFetching error, Throwable exception) { 
    logNotSafe.warn(error.getMessage(), exception);
}

allowing for changing the behavior

[tatu-at-datastax]

Alas, there's STILL no new release with the fix to use.... 17.3 from September 2021 is the latest:

https://mvnrepository.com/artifact/com.graphql-java/graphql-java

[tatu-at-datastax]

But now 18.0 and 18.1 are out, see https://mvnrepository.com/artifact/com.graphql-java/graphql-java !

[tatu-at-datastax]

Fix waiting for CR.