Either RESTEasy Reactive/REST Client Reactive swallow errors in some scenarios, very difficult to debug

[GavinRay97]

Describe the bug

The actual error being throw under the hood was:

com.fasterxml.jackson.databind.exc.MismatchedInputException: Cannot deserialize value of type `java.util.HashSet<org.acme.CurrentWeather>` from Object value (token `JsonToken.START_OBJECT`)
 at [Source: (ByteArrayInputStream); line: 1, column: 1]

But between the fact that Quarkus generates a lot of code, and the reactive/multithreaded bit, debugging this and trying to navigate the source + callstack was somewhat of a nightmare because:

• For a lot of the source, there's no file it would show in the IDE for the relevant code bits
• The chain of calls/indirection can be particularly deep

But with this code/endpoint:

@JsonIgnoreProperties(ignoreUnknown = true)
class CurrentWeather {
    public String description;
    public int temp;
    public int feels_like;
    public int wind_speed;
}

@RegisterRestClient(baseUri = "http://api.openweathermap.org/data/2.5")
interface WeatherService {

    enum MeasurementKind { standard, metric, imperial }

    // We can fake/pretend these are path params and it winds up a bit clearer
    @GET
    @Path("/weather?q={city},{country}&appid={apiKey}&units={units}")
    Set<CurrentWeather> getWeatherByCityAndCountry(String city,
                                                   String country,
                                                   String apiKey,
                                                   String units);
}

public class Thing {
    private static final Logger log = Logger.getLogger(SomePage.class);
    
    @RestClient WeatherService weatherApi;
    @Inject Configuration config;

    @GET
    @Path("/route")
    @Blocking
    public Set<CurrentWeather> getWeatherExample1() {
        log.info("called!!!");
        var results = weatherApi.getWeatherByCityAndCountry(
                "Miami", "US",
                config.openWeatherMapApiKey,
                WeatherService.MeasurementKind.imperial.name());
        log.info("results = ");
        log.info(results);
        return results;
    }
}

Nothing is ever logged past the initial called!!! 🙁
Very confusing

Expected behavior

No response

Actual behavior

No response

How to Reproduce?

Quarkus v2.1.2-final

plugins {
    java
    id("io.quarkus")
}

repositories {
    mavenCentral()
    mavenLocal()
}

val quarkusPlatformGroupId: String by project
val quarkusPlatformArtifactId: String by project
val quarkusPlatformVersion: String by project

dependencies {
    implementation(enforcedPlatform("${quarkusPlatformGroupId}:${quarkusPlatformArtifactId}:${quarkusPlatformVersion}"))
    implementation("io.quarkus:quarkus-arc")
    implementation("io.quarkus:quarkus-resteasy-reactive")
    implementation("io.quarkus:quarkus-resteasy-reactive-qute")
    implementation("io.quarkus:quarkus-resteasy-reactive-jackson")
    implementation("io.quarkus:quarkus-rest-client-reactive")
    implementation("io.quarkus:quarkus-rest-client-reactive-jackson")

    testImplementation("io.quarkus:quarkus-junit5")
    testImplementation("io.rest-assured:rest-assured")
}

group = "org.acme"
version = "1.0.0-SNAPSHOT"

java {
    sourceCompatibility = JavaVersion.VERSION_16
    targetCompatibility = JavaVersion.VERSION_16
}

tasks.withType<JavaCompile> {
    options.encoding = "UTF-8"
    options.compilerArgs.add("-parameters")
}

Output of uname -a or ver

No response

Output of java -version

No response

GraalVM version (if different from Java)

No response

Quarkus version or git rev

No response

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

No response

[quarkus-bot]

/cc @FroMage, @geoand, @michalszynkiewicz, @stuartwdouglas

[GavinRay97]

The solution to making the actual ENDPOINT work?

• https://stackoverflow.com/a/58544375

@Singleton
class MyObjectMapperCustomizer implements ObjectMapperCustomizer {
    public void customize(ObjectMapper mapper) {
        mapper.enable(DeserializationFeature.ACCEPT_SINGLE_VALUE_AS_ARRAY);
    }
}

I blame Jackson for the terrible error message, for starters... 😅

---

EDIT: Disregard everything I said above. I'm an idiot, the API doesn't even return an array of objects.
It's a single JSON object 🤦 There is no issue. Besides the one about the original error not being surfaced

And my comment about:

com.fasterxml.jackson.databind.exc.MismatchedInputException: Cannot deserialize value of type `T`
from Object value (token `JsonToken.START_OBJECT`)

Being a terrible error for saying Enable DeserializationFeature.ACCEPT_SINGLE_VALUE_AS_ARRAY in your ObjectMapper also stands ;^)

[geoand]

Yeah, it's sometimes hard to understand where the Jackson errors actually mean in practice.
That said, we could likely add some intelligence in Quarkus (perhaps only in dev-mode) to help users, but it would probably be very fragile...

[GavinRay97]

@geoand The main issue here was that the error mistakenly (I think) seemed to be "swallowed" -- no RESTeasy exception is ever thrown and it fails to "bubble up":

In the below image, called!!! is logged, and when the application errors, no exception is shown. It just "stops" and there's no further information you can get unless you attach a Java debugger and step through the stack:

No exception/error message -- the rest of the function just fails to execute

And the page response, empty, not the Quarkus exception page:

[stuartwdouglas]

Do you have a simple GH repo that reproduces the logging issue?

I could setup a new project and copy paste the classes above but a reproduce repo would make things a lot easier (It's not uncommon with these copy/paste reproducers for something to be missing so you spend the time setting it up and then it does not work anyway).

[geoand]

As Stuart mentions, if you have a small project we can use to reproduce what you are seeing, that would be great

[GavinRay97]

Yeah absolutely, I should have provided it in the first place.

I will feel quite an ass if it's user-error, but I will immediately put together a reproduction, that's no issue (it was a teaching app for showing Quarkus to a CS student anyways using OpenWeather API I wrote -- it's tiny and has 2 files.)

Will try to revert it back to the state that broke it and then post it here as a zip.
You Quarkus'ers/Redhatters are, as usual, just the best of people ❤️

[GavinRay97]

Here you go @geoand @stuartwdouglas:

quarkus-reactive-jackson-repro.zip

It runs on port 8081, only thing to note.
Run a gradle quarkusDev and then visit

• http://localhost:8081/weather/broken?city=Miami

For example, and watch the log output

Important pieces of the code (only 2 areas) have been tagged with FOR QUARKUS DEVS comments so you can Ctrl + F 👍

// FOR QUARKUS DEVS
@GET
@Path("/broken")
@Produces(MediaType.APPLICATION_JSON)
@Blocking
public Set<WeatherResponse> thisBreaksStuffs(@QueryParam("city") String city) {
    log.info("HERE, START OF thisBreaksStuffs()");
    Set<WeatherResponse> res = weatherApi.INCORRECT_BROKEN_GetWeatherByCityAndCountry(
            city, "USA",
            config.openWeatherMapApiKey, WeatherService.MeasurementKind.imperial
    );
    log.info("AFTER weatherApi.INCORRECT_BROKEN_GetWeatherByCityAndCountry, RETURNING RESPONSE");
    return res;
}

[stuartwdouglas]

This is because the 400 WebApplicationException from the client ends up being interpreted by the server. It's a known issue with both the client and the server using the same exception types, I have added a fix.

[GavinRay97]

Thank you, I really appreciate you all 🙏

[lorenzobenvenuti]

Hi,

I just came across the same issue in 2.16.3: if the REST client gets a 400 while serving a request, the application returns a 400 (while I think it should return a 500). I created a reproducer here: https://github.com/lorenzobenvenuti/rest-client-exception-bug

Thanks,

lorenzo

[geoand]

@lorenzobenvenuti the behavior you mention is expected.

If you really want to return 400 when the client gets that result, you can use Response or RestResponse as the return type of your client method and then check the response code.

[lorenzobenvenuti]

If you really want to return 400

Hi @geoand , actually the problem is that I don't want to return a 400: returning the same status code of a REST call performed by the request handler seems misleading to me. Since the underlying issue is that there was an unhandled exception on the server side, I think the default behavior should be returning a 500 (BTW this seems the same issue addressed by this MR, but either it doesn't work or there was a regression)

[geoand]

Oh sorry, I misread what you wrote. Please open a new issue and add the details you mentioned in the comment above.

Thanks

[lorenzobenvenuti]

Created #31326. Thanks!