Как регистрировать время обработки запроса в фильтре JAX-RS - PullRequest
Новая
       4

Как регистрировать время обработки запроса в фильтре JAX-RS

1 голос
/ 05 мая 2020

У меня есть веб-приложение JAX-RS, и я хочу регистрировать время от получения запроса до ответа. Это было легко в Spring Boot с фильтрами сервлетов. Но фильтр в моем приложении не работает должным образом: 

@Provider
public class RequestLogFilter implements ContainerRequestFilter, ContainerResponseFilter {

    private long requestStartTime;

    @Override
    public void filter(ContainerRequestContext requestContext) {
        requestStartTime = System.currentTimeMillis();
    }

    @Override
    public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext) {
        long requestFinishTime = System.currentTimeMillis();
        System.out.println(requestFinishTime - requestStartTime);
    }

}

Он отлично работает в первом методе, где текущие временные метки записываются в requestStartTime. Но похоже, что у второго метода есть собственная копия переменной requestStartTime, потому что во втором методе она всегда равна нулю. Поэтому я не могу вычислить разницу между переменными. Что я могу сделать вместо этого, чтобы регистрировать время обработки запроса?

Ответы [ 2 ]

2 голосов
/ 06 мая 2020

На самом деле нечто подобное встроено в Quarkus благодаря API MicroProfile Metrics:

  1. Добавьте расширение SmallRye Metrics (quarkus-smallrye-metrics) в свой пом. xml

  2. Это должно быть включено по умолчанию, но вы можете явно включить регистрацию метрик RestEasy / JAX-RS, добавив в application.properties следующее :

    quarkus.smallrye-metrics.extensions.enabled = true

Метрики (# вызовов, время, проведенное в каждом) будут добавлены к конечной точке / metrics. Показатели появятся после вызова конечной точки.

1 голос
/ 06 мая 2020

Поскольку вы реализуете как ContainerRequestFilter, так и ContainerResponseFilter в одном классе, создается впечатление, что создаются 2 разных экземпляра, поэтому переменная requestStartTime различается между двумя экземплярами.

Эта проблема сообщалось о проекте Eclipse Jersey и считалось ошибкой, которая была решена, см. https://github.com/eclipse-ee4j/jersey/issues/3796.

Здесь все обсуждение: https://github.com/eclipse-ee4j/jaxrs-api/issues/605.

Аргументом было то, что такое поведение не соответствует спецификации JAX-RS (раздел 4.1):

По умолчанию для каждого приложения JAX-RS создается отдельный экземпляр каждого класса провайдера.

Но Quarkus использует RESTEasy, поэтому я предполагаю, что он не содержит этого исправления.

В любом случае, даже если был создан единственный экземпляр (например, с использованием аннотации @Singleton ), вам по-прежнему не следует использовать переменную экземпляра для сохранения времени начала, поскольку одновременные запросы будут переопределять его (спасибо @areus за указание на это).

Вместо этого вы можете сохранить время запуска в свойствах ContainerRequestContext на ContainerRequestFilter.filter(), а затем получить его и использовать на ContainerResponseFilter.filter(): 

@Provider
public class RequestLogFilter implements ContainerRequestFilter, ContainerResponseFilter {

    @Override
    public void filter(ContainerRequestContext requestContext) {
        long requestStartTime = System.nanoTime();
        requestContext.setProperty("requestStartTime", requestStartTime);
    }

    @Override
    public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext) {
        long requestStartTime = (long) requestContext.getProperty("requestStartTime");
        long requestFinishTime = System.nanoTime();
        long duration = requestFinishTime - requestStartTime;
        System.out.println("duration: " + TimeUnit.NANOSECONDS.toMillis(duration) + " ms");
    }
}
...