Improve error handling of AbortExecutionException in smallrye-graphql extension

[roggenbrot]

Description

While playing around with quarkus, smallrye-graphql and spock I was running into problems while trying to execute a interaction based test case for a graphql endpoint with a mocked bean (Spock mock)

@PackageScope
@Inject
@GraphQLClient
DynamicGraphQLClient client

def "Assert that ......."() {
    given: "Mocked bean"
    QuarkusMock.installMockForType(Mock(Bean) {
        1 * get(_, "test",1) >> UUID.randomUUID()
        0 * _
    },Bean.class)
    when: "Action is performed that invokes a method that causes a org.spockframework.mock.TooManyInvocationsError (0 * _)"
    def response = client.executeSync(.....)
    then: "Test case fails with:  Unexpected response. Code=500, message=\"Internal Server Error\", body=\"null\""
    noExceptionThrown()
}

The test case always failed with an generic error message, giving me a hard time to detect the real cause of the failing test:

Expected no exception to be thrown, but got 'io.smallrye.graphql.client.InvalidResponseException'

	at spock.lang.Specification.noExceptionThrown(Specification.java:118)
	at xxxxxxxxxxxxxxxxxxx.Assert that ..................................(xxxxxxxxxxxxxxxxxxxxxxxxxxxx.groovy:558)
Caused by: io.smallrye.graphql.client.InvalidResponseException: Unexpected response. Code=500, message="Internal Server Error", body="null"
	at io.smallrye.graphql.client.impl.ResponseReader.readFrom(ResponseReader.java:64)
	at io.smallrye.graphql.client.vertx.dynamic.VertxDynamicGraphQLClient.lambda$executeSingleResultOperationOverHttp$7(VertxDynamicGraphQLClient.java:338)
	at io.smallrye.context.impl.wrappers.SlowContextualFunction.apply(SlowContextualFunction.java:21)
	at io.smallrye.mutiny.operators.uni.UniOnItemTransform$UniOnItemTransformProcessor.onItem(UniOnItemTransform.java:36)
	at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forwardResult(UniCreateFromCompletionStage.java:63)
	at io.smallrye.context.impl.wrappers.SlowContextualBiConsumer.accept(SlowContextualBiConsumer.java:21)

After some debugging I found out that the exception is thrown in smallrye-graphql and then catched by the quarkus graphql extension in

quarkus/extensions/smallrye-graphql/runtime/src/main/java/io/quarkus/smallrye/graphql/runtime/spi/datafetcher/QuarkusDefaultDataFetcher.java

Lines 89 to 92 in 6014d34

	} catch (Error e) {
	resultBuilder.clearErrors().data(null).error(new AbortExecutionException(e));
	return (T) resultBuilder.build();
	} catch (Throwable ex) {

and finally handled in

quarkus/extensions/smallrye-graphql/runtime/src/main/java/io/quarkus/smallrye/graphql/runtime/SmallRyeGraphQLExecutionHandler.java

Lines 324 to 327 in 6014d34

	if (shouldFail(er)) {
	response.setStatusCode(500)
	.end();
	} else {

So the exception/cause of the problem gets swallowed -> No log message

Since such errors are bypassing all ExceptionHandler, ErroCodes .... mechanism, it's also not possible to make such exceptions appear in the logs by customization

Implementation ideas

A simple log entry would help a lot.

[quarkus-bot]

/cc @Ladicek(smallrye), @jmartisk(graphql,smallrye), @phillip-kruger(graphql,smallrye), @radcortez(smallrye)

[jmartisk]

Agreed, an error that causes a 500 response should probably be logged as a WARN. I'll send a PR

[gsmet]

Why a WARN? A 500 should be logged as an error? At least that's what we do in REST.

[jmartisk]

Ok, I'll make it ERROR then :)