Существует множество фреймворков для работы с метриками Java-приложений (например Micrometer, который, к тому же, еще и включён в новые версии Spring Boot). Но когда дело доходит до мониторинга времени выполнения асинхронных запросов у некоторых (у меня!) сразу возникает множество проблем.
Передо мной стояла задача настроить JMX-мониторинг для отслеживания асинхронных вызовов в Mono фреймворка Java Reactor. Меня интересовали всего два параметра – общее количество вызовов и среднее время их выполнения.
Spring Boot позволяет создать и зарегистрировать JMX-бин, указав всего пару аннотаций. Вот так в итоге выглядел мой класс:
@ManagedResource(description = "JMX Metrics MBean")
@Component
public class MyMBean {
private volatile long avgQueryTime = 1;
private volatile long queryQty = 0;
@ManagedAttribute(description = "Average time of async call")
public long getAvgQueryTime() {
return avgQueryTime;
}
public synchronized void addQueryTime(long newTime) {
this.avgQueryTime = (avgQueryTime + newTime) / 2;
}
@ManagedAttribute(description = "Quantity of queries being called")
public long getQueryQty() {
return queryQty;
}
public synchronized void incQty() {
queryQty++;
}
}
Аннотация @ManagedResource устанавливается на уровне класса и регистрирует наш компонент в качестве JMX-бина, а при помощи @ManagedAttribute обозначаются поля, которые должны быть доступны для мониторинга. Я добавил аннотацию @Component для регистрации класса в качестве компонента Spring, для удобства.
Прошу не судить меня строго за реализацию методов подсчёта среднего времени и количества вызовов, это пример.
По окончании обработки каждого Mono нам необходимо обновлять атрибуты MyMBean, чтобы клиенты могли увидеть свежую статистику. Как получить время выполнения асинхронного метода?
Непосредственно перед возвратом Mono сделаем временную “засечку”:
final long start = System.nanoTime()
А в монаду Mono добавим метод doFinally(), который выполняется по событию завершения Mono (это может быть отмена, завершение или ошибка):
.doFinally(end -> {
long elapsed = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start);
myMBean.incQty();
myMBean.addQueryTime(elapsed);
})
Примечание: myMBean – @Autowired экземпляр класса MyMBean.
Выглядит просто, реализуется быстро, даёт хоть какой-то результат. Посмотреть статистику JMX-бина можно в JConsole (есть в поставке JDK).
Реализация с применением metrics()
После прочёсывания мануалов оказалось, что класс Mono содержит метод metrics(), который публикует обширную JMX-статистику по использованию асинхронных вызовов. Достаточно добавить вызов этого метода в монаду Mono (примечание: статистика публикуется только если Mono был задействован хотя бы один раз).
Запускаем приложение, активируем интересующий нас Mono хотя бы один раз, подключаемся к процессу через JConsole и ищем ветку metrics -> ReactorFlowDuration.exception.flow.reactor.status.completed.type.Mono. Здесь находится довольно обширная статистика асинхронных вызовов:
