How to print server responses using LoggingFeature

2020-02-11 07:13发布

站内问答 / Java
1713 5 6

The following code results in JSON server responses being printed in Dropwizard 0.9.2 and 1.0.2:

return ClientBuilder
        .newBuilder()
        .build()
        .register(new LoggingFilter(Logger.getLogger(LoggingFilter.class.getName()), true))

For example:

Oct 21, 2016 7:57:42 AM org.glassfish.jersey.filter.LoggingFilter log
INFO: 1 * Client response received on thread main
1 < 401
1 < Connection: keep-alive
1 < Content-Length: 49
1 < Content-Type: text/plain
1 < Date: Fri, 21 Oct 2016 07:57:42 GMT
1 < Server: […]
1 < WWW-Authenticate: Basic realm="[…]"
Credentials are required to access this resource.

javax.ws.rs.NotAuthorizedException: HTTP 401 Unauthorized

However, LoggingFilter is deprecated in 1.0.2, and it's recommended to use LoggingFeature instead. In the documentation of LoggingFeature it says that the default verbosity is LoggingFeature.Verbosity.PAYLOAD_TEXT, so I was expecting the following code to still print JSON server responses in Dropwizard 1.0.2:

return ClientBuilder
        .newBuilder()
        .build()
        .register(new LoggingFeature(Logger.getLogger(getClass().getName())))

Instead the log contains just this:

javax.ws.rs.NotAuthorizedException: HTTP 401 Unauthorized

5条回答
爷、活的狠高调
2楼-- · 2020-02-11 07:34

so - I tested this. This may be an issue concerning your logger configuration and your feature configuration, not the actual feature. The hint I gave you does print what you want it to, and here is the proof: 

public class MainClientTest {

    public static void main(String[] args) {

        Client build = ClientBuilder.newBuilder().build();

        // Configure Logger to log it all
        Logger logger = Logger.getLogger("test");
        logger.setLevel(Level.ALL);
        logger.setUseParentHandlers(false);
        Handler[] handlers = logger.getHandlers();
        for(Handler h : handlers) logger.removeHandler(h);
        logger.addHandler(buildseh());
        logger.info("Logger");
        build = build.register(new LoggingFeature(logger, Level.ALL, Verbosity.PAYLOAD_ANY, null));

        build.target("https://www.google.com").request().get();
    }

    public static StreamHandler buildseh() {
        final StreamHandler seh = new StreamHandler(System.err, new JdkLoggerFormatter()) {
            @Override
            public synchronized void publish(final LogRecord record) {
                super.publish(record);
                flush();
            }
        };
        seh.setLevel(Level.ALL); // Default StdErr Setting
        return seh;
    }
}

This prints: 

1477055066111 I test Logger
1477055066397   test 1 * Sending client request on thread main
1 > GET https://www.google.com

1477055067350   test 1 * Client response received on thread main
1 < 200
1 < Accept-Ranges: none
1 < Alt-Svc: quic=":443"; ma=2592000; v="36,35,34,33,32"
1 < Cache-Control: private, max-age=0
1 < Content-Type: text/html; charset=ISO-8859-1
1 < Date: Fri, 21 Oct 2016 13:04:27 GMT
1 < Expires: -1
1 < P3P: CP="This is not a P3P policy! See https://www.google.com/support/accounts/answer/151657?hl=en for more info."
1 < Server: gws
1 < Set-Cookie: NID=89=YPr3UcI5rcA4qiaXfm9zkA0uAWrnSDEbxN3TcFuhZ9PkLNvkSHBCHHLcYeXa7tNpzpM_9p7AFAreYq3kR9awqqKrhv5W6pWavfx5bZM7Jjbt559a4aEv20exEPJRmS1N; expires=Sat, 22-Apr-2017 13:04:27 GMT; path=/; domain=.google.co.uk; HttpOnly
1 < Transfer-Encoding: chunked
1 < Vary: Accept-Encoding
1 < X-Frame-Options: SAMEORIGIN
1 < X-XSS-Protection: 1; mode=block
<!doctype html><html itemscope="" itemtype="http://schema.org/WebPage" lang="en-GB"><head><meta content="text/html; charset=UTF-8" http-equiv="Content-Type"><meta content="/images/branding/googleg/1x/googleg_standard_color_128dp.png" itemprop="image"><title>Google</title><script>(function(){window.google={kEI:'WxIKWJOeEcGwa_nDmNgC',kEXPI:'1351633,1351901,3700318,3700400,4029815,4031109,4032678,4036527,4038012,4039268,4043492,4045841,4048347,4052304,4062185,4063220,4065786,4066665,4068550,4068816,4069839,4069841,4070140,4070329,4071229,4072287,4072364,4072602,4072705,4072773,4073248,4073405,4073758,4073913,4073959,4074684,4074809,4076096,4076315,4076930,4076999,4077037,4077119,4077

So, here are the pitfalls:

Your feature MUST be configured with the right level. See:

new LoggingFeature(logger, Level.ALL, Verbosity.PAYLOAD_ANY, null)

The logger must be configured to log the right stuff. 

seh.setLevel(Level.ALL); // Default StdErr Setting
logger.setLevel(Level.ALL);

And the feature must have the right verbosity: Verbosity.PAYLOAD_ANY

And that is all you need to do.

Regards,

Artur

查看更多
0人赞 添加讨论(0) 举报
乱世女痞
3楼-- · 2020-02-11 07:37

This does the trick:

new LoggingFeature(Logger.getLogger(getClass().getName()), Level.OFF, LoggingFeature.Verbosity.PAYLOAD_TEXT, 8192)

I'm guessing the logging feature in the client acts like a filter, rather than as an include as expected.

查看更多
0人赞 添加讨论(0) 举报
Root（大扎）
4楼-- · 2020-02-11 07:42

A short example to illustrate a common issue which makes developers think that the logging feature is not working.

private static final LOG = Logger.getLogger(getClass().getName());

public void test() {
    Client client = ClientBuilder.newBuilder()
            .register(new LoggingFeature(LOG, Level.FINE, LoggingFeature.Verbosity.PAYLOAD_ALL, 8192))
            .build();
    // all requests and responses using this client will now be logged
    // with the log-level FINE to the logger LOG, but the logger
    // will simply ignore them, because it's default level is INFO
}

The created logger instance LOG uses the default log level, which is INFO. That means it will accept all log messages with an level of at least INFO or higher (WARNING, SEVERE, ...), but it will ignore all messages with a lower level, like FINE. (It will still pass the message to it's parent logger, if there is one)

Notice: The default log level for handlers is Level.ALL and they should not reject any log records, as long you don't modify their level.

So you will need either to raise the LoggingFeatures level or lower the loggers level to see the messages.

Solution 1: Increasing the level of the LoggingFeature:

new LoggingFeature(LOG, Level.INFO, LoggingFeature.Verbosity.PAYLOAD_ALL, 8192)

Solution 2: Decreasing the level of the Logger:

LOG.setLevel(Level.FINE)
查看更多
0人赞 添加讨论(0) 举报
倾城　Initia
5楼-- · 2020-02-11 07:47

For logging the custom logs for Server and Client request/response using the LoggingFeature, you need to create a custom class that extends LoggingFeature and implement ContainerRequestFilter, ContainerResponseFilter, ClientRequestFilter, ClientResponseFilter and WriterInterceptor.

You need to override the LoggingFeature method public boolean configure(FeatureContext context) and register your CustomLoggingFeature object with the context

@Override
public boolean configure(FeatureContext context) {
    context.register(this);
    return true;
}

ContainerRequestFilter and ContainerResponseFilter interface has methods used to log the Server request and response.

ClientRequestFilter and ContainerResponseFilter interface has methods used to log the Client request and response.

Also, you need to implement the WriterInterceptor to log the Client request and Server response body.

Finally registered your CustomLoggingFeature class with jersey.

environment.jersey().register(new CustomLoggingFeature(Logger.getLogger(getClass().getName()), Level.INFO, LoggingFeature.Verbosity.PAYLOAD_ANY, 8192));

I am using Dropwizard v1.3.5.

Here is my implementation.

public class CustomLoggingFeature extends LoggingFeature implements ContainerRequestFilter, ContainerResponseFilter,
    ClientRequestFilter, ClientResponseFilter, WriterInterceptor {

private static final boolean printEntity = true;
private static final int maxEntitySize = 8 * 1024;
private final Logger logger = Logger.getLogger("CustomLoggingFeature");
private static final String ENTITY_LOGGER_PROPERTY = CustomLoggingFeature.class.getName();
private static final String NOTIFICATION_PREFIX = "* ";
private static final String REQUEST_PREFIX = "> ";
private static final String RESPONSE_PREFIX = "< ";
private static final String AUTHORIZATION = "Authorization";
private static final String EQUAL = " = ";
private static final String HEADERS_SEPARATOR = ", ";
private static List<String> requestHeaders;

static {
    requestHeaders = new ArrayList<>();
    requestHeaders.add(AUTHORIZATION);
}

public CustomLoggingFeature(Logger logger, Level level, Verbosity verbosity, Integer maxEntitySize) {
    super(logger, level, verbosity, maxEntitySize);
}

@Override
public boolean configure(FeatureContext context) {
    context.register(this);
    return true;
}

@Override
public void filter(final ClientRequestContext context) {
    final StringBuilder b = new StringBuilder();
    printHeaders(b, context.getStringHeaders());
    printRequestLine(b, "Sending client request", context.getMethod(), context.getUri());

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

@Override
public void filter(final ClientRequestContext requestContext, final ClientResponseContext responseContext) throws IOException {
    final StringBuilder b = new StringBuilder();
    printResponseLine(b, "Client response received", responseContext.getStatus());

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

@Override
public void filter(final ContainerRequestContext context) throws IOException {
    final StringBuilder b = new StringBuilder();
    printHeaders(b, context.getHeaders());
    printRequestLine(b, "Server has received a request", context.getMethod(), context.getUriInfo().getRequestUri());

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

@Override
public void filter(final ContainerRequestContext requestContext, final ContainerResponseContext responseContext) {
    final StringBuilder b = new StringBuilder();
    printResponseLine(b, "Server responded with a response", responseContext.getStatus());

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

@Override
public void aroundWriteTo(final WriterInterceptorContext writerInterceptorContext) throws IOException, WebApplicationException {
    final LoggingStream stream = (LoggingStream) writerInterceptorContext.getProperty(ENTITY_LOGGER_PROPERTY);
    writerInterceptorContext.proceed();
    if (stream != null) {
        log(stream.getStringBuilder(MessageUtils.getCharset(writerInterceptorContext.getMediaType())));
    }
}

private static class LoggingStream extends FilterOutputStream {
    private final StringBuilder b;
    private final ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();

    LoggingStream(final StringBuilder b, final OutputStream inner) {
        super(inner);

        this.b = b;
    }

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

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

        return b;
    }

    public void write(final int i) throws IOException {
        if (byteArrayOutputStream.size() <= maxEntitySize) {
            byteArrayOutputStream.write(i);
        }
        out.write(i);
    }
}

private void printHeaders(StringBuilder b, MultivaluedMap<String, String> headers) {
    for (String header : requestHeaders) {
        if (Objects.nonNull(headers.get(header))) {
            b.append(header).append(EQUAL).append(headers.get(header)).append(HEADERS_SEPARATOR);
        }
    }
    int lastIndex = b.lastIndexOf(HEADERS_SEPARATOR);
    if (lastIndex != -1) {
        b.delete(lastIndex, lastIndex + HEADERS_SEPARATOR.length());
        b.append("\n");
    }
}

private void log(final StringBuilder b) {
    String message = Util.mask(b.toString());
    if (logger != null) {
        logger.info(message);
    }
}

private void printRequestLine(final StringBuilder b, final String note, final String method, final URI uri) {
    b.append(NOTIFICATION_PREFIX)
            .append(note)
            .append(" on thread ").append(Thread.currentThread().getId())
            .append(REQUEST_PREFIX).append(method).append(" ")
            .append(uri.toASCIIString()).append("\n");
}

private void printResponseLine(final StringBuilder b, final String note, final int status) {
    b.append(NOTIFICATION_PREFIX)
            .append(note)
            .append(" on thread ").append(Thread.currentThread().getId())
            .append(RESPONSE_PREFIX)
            .append(Integer.toString(status))
            .append("\n");
}

private InputStream logInboundEntity(final StringBuilder b, InputStream stream, final Charset charset) throws IOException {
    if (!stream.markSupported()) {
        stream = new BufferedInputStream(stream);
    }
    stream.mark(maxEntitySize + 1);
    final byte[] entity = new byte[maxEntitySize + 1];
    final int entitySize = stream.read(entity);
    b.append(new String(entity, 0, Math.min(entitySize, maxEntitySize), charset));
    if (entitySize > maxEntitySize) {
        b.append("...more...");
    }
    b.append('\n');
    stream.reset();
    return stream;
}
查看更多
0人赞 添加讨论(0) 举报
傲
6楼-- · 2020-02-11 07:49

For me, the solution by @l0b0 did log request/response payloads, but my access logs logged the requests and responses as errors. The following line worked correctly for me:

new LoggingFeature(Logger.getLogger(getClass().getName()), Level.INFO, LoggingFeature.Verbosity.PAYLOAD_TEXT, 8192)
查看更多
0人赞 添加讨论(0) 举报
登录 后发表回答
相关问题
查看全部
相关文章
查看全部
收藏的人(6)