How do I debug a Quarkus/SmallRye client request

Question

I have a request that looks like this:

@Path("/v1")
@RegisterRestClient
@Produces("application/json")
public interface VaultClient {
    @POST
    @Path("/auth/jwt/login")
    @Consumes("application/json")
    String getVaultToken(LoginPayload loginPayload);
}

LoginPayload it just a simple POJO:

public class LoginPayload {
    private String jwt;
    final private String role = "some-service";

    public void setJwt(String _jwt) {
        this.jwt = _jwt;
    }
}

When I attempt to call this endpoint via a service:

public String getServiceJwt() {
    String loginJwt = getLoginJwt();
    LoginPayload loginPayload = new LoginPayload();
    loginPayload.setJwt(loginJwt);
    try {
        System.out.println(loginPayload.toString());
        String tokenResponse = vaultClient.getVaultToken(loginPayload);
        System.out.println("##################");
        System.out.println(tokenResponse);
    } catch (Exception e) {
        System.out.println(e);
    }
    return vaultJwt;
}

I get a 400:

javax.ws.rs.WebApplicationException: Unknown error, status code 400
java.lang.RuntimeException: method call not supported

I'm at a loss at how to troubleshoot this however. I can perform this same request via PostMan/Insomnia and it returns a response just fine. Is there a way I can get better introspection into what the outgoing response looks like? Maybe it didn't serialize the POJO to JSON properly? I have no way of knowing.

***Update I threw a node server on the other end of this request and logged out the body. It was empty. So something is not serializing the POJO and sending it with the POST request. This isn't a great debugging story though. Is there any way I could have gotten this without logging at the other end of this request?

Also, why wouldn't the POJO serialize? It's following all the documentation pretty closely.

Answer 1

I used a Filter and Interceptor as an Exception Handler to solve this problem:

A Filter to print logs:

import lombok.extern.java.Log;
import org.glassfish.jersey.message.MessageUtils;

import javax.ws.rs.WebApplicationException;
import javax.ws.rs.client.ClientRequestContext;
import javax.ws.rs.client.ClientRequestFilter;
import javax.ws.rs.client.ClientResponseContext;
import javax.ws.rs.client.ClientResponseFilter;
import javax.ws.rs.container.ContainerRequestContext;
import javax.ws.rs.container.ContainerRequestFilter;
import javax.ws.rs.container.ContainerResponseContext;
import javax.ws.rs.container.ContainerResponseFilter;
import javax.ws.rs.core.MultivaluedMap;
import javax.ws.rs.ext.WriterInterceptor;
import javax.ws.rs.ext.WriterInterceptorContext;
import java.io.BufferedInputStream;
import java.io.ByteArrayOutputStream;
import java.io.FilterOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.net.URI;
import java.nio.charset.Charset;
import java.util.Comparator;
import java.util.List;
import java.util.Map;
import java.util.Set;
import java.util.TreeSet;
import java.util.concurrent.atomic.AtomicLong;

/**
 * Based on org.glassfish.jersey.filter.LoggingFilter
 */
@Log
public class LoggingFilter implements ContainerRequestFilter, ClientRequestFilter, ContainerResponseFilter,
                                      ClientResponseFilter, WriterInterceptor {

    private static final String NOTIFICATION_PREFIX = "* ";

    private static final String REQUEST_PREFIX = "> ";

    private static final String RESPONSE_PREFIX = "< ";

    private static final String ENTITY_LOGGER_PROPERTY = LoggingFilter.class.getName() + ".entityLogger";

    private static final String LOGGING_ID_PROPERTY = LoggingFilter.class.getName() + ".id";

    private static final Comparator<Map.Entry<String, List<String>>> COMPARATOR = (o1, o2) -> o1.getKey().compareToIgnoreCase(o2.getKey());

    private static final int DEFAULT_MAX_ENTITY_SIZE = 8 * 1024;

    private final AtomicLong _id = new AtomicLong(0);

    private final int maxEntitySize;

    public LoggingFilter() {

        this.maxEntitySize = LoggingFilter.DEFAULT_MAX_ENTITY_SIZE;
    }


    private void log(final StringBuilder b) {

        LoggingFilter.log.info(b.toString());
    }

    private StringBuilder prefixId(final StringBuilder b, final long id) {

        b.append(id).append(" ");
        return b;
    }

    private void printRequestLine(final StringBuilder b, final String note, final long id, final String method, final URI uri) {

        this.prefixId(b, id).append(LoggingFilter.NOTIFICATION_PREFIX)
                .append(note)
                .append(" on thread ").append(Thread.currentThread().getName())
                .append("\n");
        this.prefixId(b, id).append(LoggingFilter.REQUEST_PREFIX).append(method).append(" ")
                .append(uri.toASCIIString()).append("\n");
    }

    private void printResponseLine(final StringBuilder b, final String note, final long id, final int status) {

        this.prefixId(b, id).append(LoggingFilter.NOTIFICATION_PREFIX)
                .append(note)
                .append(" on thread ").append(Thread.currentThread().getName()).append("\n");
        this.prefixId(b, id).append(LoggingFilter.RESPONSE_PREFIX)
                .append(status)
                .append("\n");
    }

    private void printPrefixedHeaders(final StringBuilder b,
                                      final long id,
                                      final String prefix,
                                      final MultivaluedMap<String, String> headers) {

        for (final Map.Entry<String, List<String>> headerEntry : this.getSortedHeaders(headers.entrySet())) {
            final List<?> val = headerEntry.getValue();
            final String header = headerEntry.getKey();

            if(val.size() == 1) {
                this.prefixId(b, id).append(prefix).append(header).append(": ").append(val.get(0)).append("\n");
            }
            else {
                final StringBuilder sb = new StringBuilder();
                boolean add = false;
                for (final Object s : val) {
                    if(add) {
                        sb.append(',');
                    }
                    add = true;
                    sb.append(s);
                }
                this.prefixId(b, id).append(prefix).append(header).append(": ").append(sb.toString()).append("\n");
            }
        }
    }

    private Set<Map.Entry<String, List<String>>> getSortedHeaders(final Set<Map.Entry<String, List<String>>> headers) {

        final TreeSet<Map.Entry<String, List<String>>> sortedHeaders = new TreeSet<>(LoggingFilter.COMPARATOR);
        sortedHeaders.addAll(headers);
        return sortedHeaders;
    }

    private InputStream logInboundEntity(final StringBuilder b, InputStream stream, final Charset charset) throws IOException {

        if(!stream.markSupported()) {
            stream = new BufferedInputStream(stream);
        }
        stream.mark(this.maxEntitySize + 1);
        final byte[] entity = new byte[this.maxEntitySize + 1];
        final int entitySize = stream.read(entity);
        b.append(new String(entity, 0, Math.min(entitySize, this.maxEntitySize), charset));
        if(entitySize > this.maxEntitySize) {
            b.append("...more...");
        }
        b.append('\n');
        stream.reset();
        return stream;
    }

    @Override
    public void filter(final ClientRequestContext context) throws IOException {

        final long id = this._id.incrementAndGet();
        context.setProperty(LoggingFilter.LOGGING_ID_PROPERTY, id);

        final StringBuilder b = new StringBuilder();

        this.printRequestLine(b, "Sending client request", id, context.getMethod(), context.getUri());
        this.printPrefixedHeaders(b, id, LoggingFilter.REQUEST_PREFIX, context.getStringHeaders());

        if(context.hasEntity()) {
            final OutputStream stream = new LoggingFilter.LoggingStream(b, context.getEntityStream());
            context.setEntityStream(stream);
            context.setProperty(LoggingFilter.ENTITY_LOGGER_PROPERTY, stream);
            // not calling log(b) here - it will be called by the interceptor
        }
        else {
            this.log(b);
        }
    }

    @Override
    public void filter(final ClientRequestContext requestContext, final ClientResponseContext responseContext)
    throws IOException {

        final Object requestId = requestContext.getProperty(LoggingFilter.LOGGING_ID_PROPERTY);
        final long id = requestId != null ? (Long) requestId : this._id.incrementAndGet();

        final StringBuilder b = new StringBuilder();

        this.printResponseLine(b, "Client response received", id, responseContext.getStatus());
        this.printPrefixedHeaders(b, id, LoggingFilter.RESPONSE_PREFIX, responseContext.getHeaders());

        if(responseContext.hasEntity()) {
            responseContext.setEntityStream(this.logInboundEntity(b, responseContext.getEntityStream(),
                    MessageUtils.getCharset(responseContext.getMediaType())));
        }

        this.log(b);
    }

    @Override
    public void filter(final ContainerRequestContext context) throws IOException {

        final long id = this._id.incrementAndGet();
        context.setProperty(LoggingFilter.LOGGING_ID_PROPERTY, id);

        final StringBuilder b = new StringBuilder();

        this.printRequestLine(b, "Server has received a request", id, context.getMethod(), context.getUriInfo().getRequestUri());
        this.printPrefixedHeaders(b, id, LoggingFilter.REQUEST_PREFIX, context.getHeaders());

        if(context.hasEntity()) {
            context.setEntityStream(
                    this.logInboundEntity(b, context.getEntityStream(), MessageUtils.getCharset(context.getMediaType())));
        }

        this.log(b);
    }

    @Override
    public void filter(final ContainerRequestContext requestContext, final ContainerResponseContext responseContext)
    throws IOException {

        final Object requestId = requestContext.getProperty(LoggingFilter.LOGGING_ID_PROPERTY);
        final long id = requestId != null ? (Long) requestId : this._id.incrementAndGet();

        final StringBuilder b = new StringBuilder();

        this.printResponseLine(b, "Server responded with a response", id, responseContext.getStatus());
        this.printPrefixedHeaders(b, id, LoggingFilter.RESPONSE_PREFIX, responseContext.getStringHeaders());

        if(responseContext.hasEntity()) {
            final OutputStream stream = new LoggingFilter.LoggingStream(b, responseContext.getEntityStream());
            responseContext.setEntityStream(stream);
            requestContext.setProperty(LoggingFilter.ENTITY_LOGGER_PROPERTY, stream);
            // not calling log(b) here - it will be called by the interceptor
        }
        else {
            this.log(b);
        }
    }

    @Override
    public void aroundWriteTo(final WriterInterceptorContext writerInterceptorContext)
    throws IOException, WebApplicationException {

        final LoggingFilter.LoggingStream stream = (LoggingFilter.LoggingStream) writerInterceptorContext.getProperty(LoggingFilter.ENTITY_LOGGER_PROPERTY);
        writerInterceptorContext.proceed();
        if(stream != null) {
            this.log(stream.getStringBuilder(MessageUtils.getCharset(writerInterceptorContext.getMediaType())));
        }
    }

    private class LoggingStream extends FilterOutputStream {

        private final StringBuilder b;

        private final ByteArrayOutputStream baos = new ByteArrayOutputStream();

        LoggingStream(final StringBuilder b, final OutputStream inner) {

            super(inner);

            this.b = b;
        }

        StringBuilder getStringBuilder(final Charset charset) {
            // write entity to the builder
            final byte[] entity = this.baos.toByteArray();

            this.b.append(new String(entity, 0, Math.min(entity.length, LoggingFilter.this.maxEntitySize), charset));
            if(entity.length > LoggingFilter.this.maxEntitySize) {
                this.b.append("...more...");
            }
            this.b.append('\n');

            return this.b;
        }

        @Override
        public void write(final int i) throws IOException {

            if(this.baos.size() <= LoggingFilter.this.maxEntitySize) {
                this.baos.write(i);
            }
            this.out.write(i);
        }

    }

}

Using the filter in the rest client interface:

@Path("/")
@Produces(MediaType.APPLICATION_JSON)
@Consumes(MediaType.APPLICATION_JSON)
@RegisterRestClient
@RegisterProvider(LoggingFilter.class)
public interface Api {

    @GET
    @Path("/foo/bar")
    FooBar getFoorBar();

Now the request and response payload is printed in log.

After that, an interceptor to handle exceptions:

Qualifier:

@InterceptorBinding
@Target({TYPE, METHOD})
@Retention(RUNTIME)
public @interface ExceptionHandler {

}

Interceptor:

@Interceptor
@ExceptionHandler
public class ExceptionHandlerInterceptor  {

    @AroundInvoke
    public Object processRequest(final InvocationContext invocationContext) {

        try {
            return invocationContext.proceed();

        }
        catch (final WebApplicationException e) {

            final int status = e.getResponse().getStatus();
            final String errorJson = e.getResponse().readEntity(String.class);

            final Jsonb jsonb = JsonbBuilder.create();

            //"ErrorMessageDTO" is waited when a error occurs
            ErrorMessage errorMessage = jsonb.fromJson(errorJson, ErrorMessage.class);

            //isValid method verifies if the conversion was successful
            if(errorMessage.isValid()) {
                return Response
                        .status(status)
                        .entity(errorMessage)
                        .build();
            }

            errorMessage = ErrorMessage
                    .builder()
                    .statusCode(status)
                    .statusMessage(e.getMessage())
                    .success(false)
                    .build();

            return Response
                    .status(status)
                    .entity(errorMessage)
                    .build();
        }
        catch (final Exception e) {

            e.printStackTrace();

            return Response
                    .status(Status.INTERNAL_SERVER_ERROR)
                    .entity(ErrorMessage
                            .builder()
                            .statusCode(Status.INTERNAL_SERVER_ERROR.getStatusCode())
                            .statusMessage(e.getMessage())
                            .success(false)
                            .build())
                    .build();
        }
    }

}

Using the interceptor:

@Path("/resource")
@Produces(MediaType.APPLICATION_JSON)
@Consumes(MediaType.APPLICATION_JSON)
@ExceptionHandler
@Traced
@Log
public class ResourceEndpoint {

    @Inject
    @RestClient
    Api api;

    @GET
    @Path("/latest")
    public Response getFooBarLatest() {

        return Response.ok(this.api.getFoorBar()).build();
    }

ErrorMessage bean:

@RegisterForReflection
@Getter
@Setter
@AllArgsConstructor
@NoArgsConstructor
@Data
@Builder
public class ErrorMessage  {

    @JsonbProperty("status_message")
    private String statusMessage;

    @JsonbProperty("status_code")
    private Integer statusCode;

    @JsonbProperty("success")
    private boolean success = true;

    @JsonbTransient
    public boolean isValid() {

        return this.statusMessage != null && !this.statusMessage.isEmpty() && this.statusCode != null;
    }

}

PS: Using Lombok!