вторник, 4 июня 2013 г.

javasimon и метрики производительности

Производительность приложения, её тестирование и оценка. Многие наверняка слышали (если не слышали, то начать можно с wiki).
Так вот, если отвлечься от всяких методик и подходов и просто немного подумать. Есть приложение, для которого требуется оценить/проверить скорость работы, надёжность и пр. Ок, берём приложение, засовываем его в ящик, подаём на вход нагрузку, на выходе снимаем какие-то данные (время отклика на запрос, время фиксации транзакций в БД или чего-то там ещё), анализируем их, делаем выводы.
Хм, несложно и вроде эффективно. Хотя с эффективностью можно поспорить: для простого приложения, выполняющего несколько действий, такой способ может и подойдёт. Но для состоящего из большого числа компонентов, сложного по бизнес-логике приложения "чёрный" ящик ничего нового не сообщит. Ну, предположим, мы периодически наблюдаем увеличение времени отклика. За счёт чего это происходит, где возникают задержки и с чем они связаны? Вариантов может быть масса - переполнение очередей, тормоза на БД, долгий отклик внешних систем, дэдлоки, борьба за ресурсы и пр. и пр.
Можно добавить в код вывод отладочной информации по интересующим действиям. Но в таком логе легко "закопаться" (например, при многопоточной работе может оказаться нелёгким делом идентифицировать нужные события из общей массы). Да и само по себе работающее "на бою" приложение с отладочной печатью - mauvais tone.
И вот тут становится очевидным, что без метрик внутри приложения не обойтись. Чего хочется?
  • Иметь возможность "снимать" нужные статистические данные изнутри (а сколько объектов лежит в очереди? сколько времени занял очередной цикл или его часть?).
  • Задача по анализу должна быть отделена от основной логики.
  • Минимальный оверхэд и влияние на производительность приложения.
  • Простота и понятность, минимальное количество дополнительного кода. 
  • Что-то ещё?
Как часто бывает, кто-то об этом уже подумал. И даже разработал и предложил решения. Например, Java Application Monitor и Java Simple Monitoring API.

Java Application Monitor (JAMon). Страница проекта http://jamonapi.sourceforge.net/, последняя версия  на текущий момент 2.74. Поскольку в maven-репозиториях я её не нашёл, можно инсталлировать её в свой:
mvn install:install-file -Dfile=jamon-2.74.jar -Dpackaging=jar -DgroupId=monitoring -DartifactId=jamon -Dversion=2.74 -DgeneratePom=true
Ну, и в pom.xml проекта:
<!-- JAMon - Java Monitoring -->
<dependency>
    <groupId>monitoring</groupId>
    <artifactId>jamon</artifactId>
    <version>2.74</version>
</dependency>      
В базовом случае измерение можно провести так:
import com.jamonapi.*;

Monitor monitor = MonitorFactory.start("myFirstMonitor");
/* собственно, код ... */
monitor.stop();
System.out.println(monitor);
Если этот код выполнится несколько раз, класс Monitor соберёт все измерения, а затем предоставит дополнительную информацию в виде количества вызовов и среднего времени выполнения. Красиво и понятно!

Java Simple Monitoring API (javasimon). Страница проекта http://code.google.com/p/javasimon/. Имеется поддержка maven.
<dependencies>
    ...
    <dependency>
        <groupId>org.javasimon</groupId>
        <artifactId>javasimon-core</artifactId>
        <version>3.3.0</version>
    </dependency>
</dependencies>
Для работы требуется тоже не очень много:
import org.javasimon.*;

Stopwatch stopwatch = SimonManager.getStopwatch("stopwatch");
Split split = stopwatch.start();

/* полезные действия... */
split.stop();
System.out.println(stopwatch);
System.out.println(stopwatch.sample());
//дополнительная и подробная инфо

IMHO, особенной разницы не видно (как бы и сама задача, исходя из её нужного функционала, не предполагает богатства вариантов решения). А потому для подробного изучения, экспериментов и практического использования выбираем любую библиотеку. Я выбрал javasimon. Небольшой (но работающий!) пример в конце поста. А дальше - несколько выбранных особенностей.

1) Создавать новые simon-объекты (секундомеры и счётчики) можно через специальный менеджер org.javasimon.SimonManager (при желании можно сделать собственный менеджер, например, для какого-то распределённого приложения; но для большинства случаев рекомендуется именно этот класс). Фактически, это utility-подобный класс со статическими методами. Например, этот код создаст новый секундомер с заданным именем (либо вернёт уже существующий, если секундомер с таким же именем был создан ранее):
org.javasimon.Stopwatch stopwatchOne = SimonManager.getStopwatch(MyClass.class.getName() + ".one");
Далее созданный секундомер можно запустить (вызов создаст новый объект org.javasimon.Split) и остановить. Секундомер зафиксирует длительность работы, а при нескольких запусках - и другую статистическую информацию - общее время работы, количество запусков, минимальное / среднее / максимальное время и пр.

2) Отлично, создавать новые объекты просто. А как работать с ними работать, как "доставать" из них данные? Удобный способ - использовать интерфейс org.javasimon.Callback, чтобы получить возможность обработки различных событий, генерируемых javasimon. В общем-то, для многих задач реализовывать интерфейс целиком нет смысла - достаточно наследовать org.javasimon.CallbackSkeleton - весьма базовую реализацию интерфейса, ну, а далее уже перекрывать нужные методы. Именно такой подход реализован в примере - создаётся class StatCallback extends CallbackSkeleton, в котором вызывается public void onSimonCreated (Simon simon) для перехвата события создания нового simon-объекта.
Интересный пример - логирование статистических данных только в том случае, когда измеряемое событие длилось слишком долго (вернее, дольше некоторого заданного порога) - приведён тут [http://code.google.com/p/javasimon/wiki/Callbacks#Example_with_web_application]. Там реализуются методы public void stopwatchStart (Split split) и public void stopwatchStop (Split split) для перехвата событий запуска и остановки секундомера.

3) Показания счётчика / секундомера можно просто "получить" (sample) либо "получить-и-сбросить" (sampleAndReset). Что делать с полученной информацией, саму библиотеку не касается; можно логировать, сохранять в БД, передавать куда-то по сети и пр.
4) Имеется поддержка jmx. Примеры тут [http://javasimon.googlecode.com/svn/javadoc/api-3.3/org/javasimon/examples/jmx/package-frame.html].

5) Похоже, что работа и передача статистических данных происходят где-то "внутри" библиотеки: в одном месте работаем с секундомером, а в другом просто достаём его показания. Всё это хорошо, а вот если нужно передать какие-то свои, пользовательские данные? Что ж, тогда пишем свой собственный менеджер. Или используем атрибуты. Дело в том, что у simon-объектов есть атрибуты, которые можно установить, прочитать и удалить. Именно атрибуты могут быть использованы для передачи любых пользовательских объектов.
void setAttribute(String name, Object value)
Object getAttribute(String name)
void removeAttribute(String name)
6) Simon API является thread-safe, т. ч. разные потоки могут записывать события одновременно. Синхронизация скрыта внутри; например, секундомер org.javasimon.Stopwatch синхронизируется при старте и остановке.

Уф. Если постараться, то можно найти ещё и другие интересности. И озвученные вначале "хотелки" вполне реализованы. А в целом, javasimon - небольшая библиотека, удобная в применении и отлично решающая свою конкретную задачу.

http://www.2min2code.com/articles/simon_intro/overview Simon - 2 minute tutorial

P. S. Обещанный пример.
----------------------------------------------------------------------------------------------------
package by.father.examples.metrics;

import org.javasimon.Sample;
import org.javasimon.Simon;
import org.javasimon.SimonManager;
import org.javasimon.callback.CallbackSkeleton;

import java.util.Collection;
import java.util.LinkedList;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.TimeUnit;

/**
 * Здесь самое интересное - работа с метриками.
 * @author father [2013-05-22]
 */
public class MetricLogger implements Runnable {

    private final long metricLoggerLoopPeriodInSec;
    private final StatCallback statCallback;
    private final CopyOnWriteArrayList<IMetricStorage> newMetricEvents;

    public MetricLogger (long metricLoggerLoopPeriodInSec) {
        this.metricLoggerLoopPeriodInSec = metricLoggerLoopPeriodInSec;
        newMetricEvents = new CopyOnWriteArrayList<IMetricStorage>();
        newMetricEvents.add(new ConsoleMetricStorage());
        statCallback = new StatCallback();
        //регистрация колбэка через всё ту же статическую фабрику {@link SimonManager}
        SimonManager.callback().addCallback(statCallback);
    }

    @Override
    public void run() {
        long timeToStop = System.currentTimeMillis() + 20000;
        while (System.currentTimeMillis() < timeToStop) {
            loop();
        }
    }

    /**
     * Основной цикл - с заданным периодом опрашивать все секундомеры, а затем передавать данные обработчикам.
     */
    private void loop () {
        Collection<Sample> samples = statCallback.doLog();
        for (IMetricStorage newMetricEvent : newMetricEvents) {
            newMetricEvent.newStat(metricLoggerLoopPeriodInSec, samples);
        }

        try {
            TimeUnit.SECONDS.sleep(metricLoggerLoopPeriodInSec);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }

    /**
     * Интерфейс для обработчиков статистических данных.
     * <br/>Обработка может быть любой - простое логирование, агрегирование в памяти, сохранение в БД и пр.
     */
    public interface IMetricStorage {
        public void newStat (long periodSecond, Collection<Sample> samples);
    }

    /**
     * Реализация обработчика - простое логирование.
     */
    public class ConsoleMetricStorage implements IMetricStorage {
        public void newStat (long periodSecond, Collection<Sample> samples) {
            for (Sample sample : samples) {
                System.out.println(sample.toString());
            }
        }
    }

    /**
     * Создание колбэка - объекта, который позволит доставать из секундомеров результаты их работы.
     */
    public static class StatCallback extends CallbackSkeleton {
        /**
         * Список всех зарегистрированных секундомеров.
         */
        private CopyOnWriteArrayList<Simon> points;

        public StatCallback () {
            this.points = new CopyOnWriteArrayList<Simon>();
        }

        @Override
        public void initialize () {
            System.out.println("StatCallback initialize");
            super.initialize();
        }

        /**
         * Каждый раз, когда статическая фабрика {@link SimonManager} создаёт новый секундомер (или счётчик, или любой
         * другой объект, реализующий интерфейс {@link Simon}, вызывается обработчик этого события.
      * <br/>Здесь это событие перехватывается, созданный объект логируется и запоминается в списке {@link StatCallback#points}.
         * @param simon    новый объект для ведения статистики.
         */
        @Override
        public void onSimonCreated (Simon simon) {
            System.out.println("New simon was created: " + simon.getName());
            super.onSimonCreated(simon);
            this.points.add(simon);
        }

        /**
         * Извлечение данных из секундомеров.<br/>
         * По каждому объекту из списка {@link StatCallback#points} достаются сэмплы.
         * @return список всех сэмплов всех секундомеров.
         */
        public Collection<Sample> doLog () {
            LinkedList<Sample> ret = new LinkedList<Sample>();
            for (Simon simon : points) {
                //simon.sampleAndReset() - из объекта извлекаются и возвращаются текущие данные, а данные объекта очищаются
                ret.add(simon.sampleAndReset());
            }
            return ret;
        }
    }

}
----------------------------------------------------------------------------------------------------
package by.father.examples.metrics;

import org.javasimon.SimonManager;
import org.javasimon.Split;
import org.javasimon.Stopwatch;

/**
 * Имитатор полезных или важных дел - собственно, прикладной код, решающий поставленные задачи.
 * @author father [2013-05-22]
 */
public class ImportantAction {

    private final Stopwatch stopwatch;

    /**
     * Конструктор; создаётся экземпляр секундомера {@link Stopwatch} через статическую фабрику {@link SimonManager}.
     */
    public ImportantAction () {
        stopwatch = SimonManager.getStopwatch(ImportantAction.class.getName());
    }

    /**
     * Здесь мог бы быть ваш код :)
     */
    public void makeAnAction () {
        HelperAction helperAction = new HelperAction();
        Split split = null;

        for (int i = 0; i < 10; i++) {
            try {
                //имитация какого-то действия, длительность которого необходимо оценить и измерить
                long timeToSleep = (long)(Math.random() * 2000);
                System.out.println("ImportantAction: " + timeToSleep);

                //замеры делаются при запуске и остановке секундомера
                split = stopwatch.start();
                Thread.sleep(timeToSleep);
                split.stop();

                //вызов других нужных методов
                helperAction.makeSomeAdditionalActions();

            } catch (InterruptedException e) {
                //do nothing
            } finally {
                //завершение работы секундомера при сбоях
                if (split != null && split.isRunning()) {
                    split.stop();
                }
            }
        }
    }

}
 ----------------------------------------------------------------------------------------------------
package by.father.examples.metrics;

import org.javasimon.SimonManager;
import org.javasimon.Split;
import org.javasimon.Stopwatch;

/**
 * @author father [2013-05-22]
 */
public class HelperAction {

    private final Stopwatch stopwatchOne, stopwatchTwo;

    /**
     * Конструктор; создаются два экземпляра с помощью всё той же фабрики {@link SimonManager}.
     */
    public HelperAction () {
        stopwatchOne = SimonManager.getStopwatch(HelperAction.class.getName() + ".one");
        stopwatchTwo = SimonManager.getStopwatch(HelperAction.class.getName() + ".two");
    }

    /**
     * Что-то ещё дополнительное, чтобы было несколько действий и, соответственно, несколько секундомеров.
     * @throws InterruptedException
     */
    public void makeSomeAdditionalActions () throws InterruptedException {
        //действие номер раз
        long timeToSleepOne = (long)(Math.random() * 600);
        System.out.println("HelperAction.one: " + timeToSleepOne);
        Split splitOne = stopwatchOne.start();
        Thread.sleep(timeToSleepOne);
        splitOne.stop();

        //действие номер два
        long timeToSleepTwo = (long)(Math.random() * 400);
        System.out.println("HelperAction.two: " + timeToSleepTwo);
        Split splitTwo = stopwatchTwo.start();
        Thread.sleep(timeToSleepTwo);
        splitTwo.stop();
    }

}
----------------------------------------------------------------------------------------------------
package by.father.examples.metrics;

/**
 * @author father [2013-05-22]
 */
public class Starter {

    /**
     * Простой "запускатель". Сначала стартует {@link MetricLogger} в отдельном потоке, затем стартует имитатор полезных
     * / важных действий {@link ImportantAction}.
     * @param args    ничего не ожидается.
     */
    public static void main (String[] args) {
        final Long metricLoggerLoopPeriodInSec = 3L;
        MetricLogger metricLogger = new MetricLogger(metricLoggerLoopPeriodInSec);
        Thread metricLoggerThread = new Thread(metricLogger);
        metricLoggerThread.start();

        ImportantAction importantAction = new ImportantAction();
        importantAction.makeAnAction();
    }

}
----------------------------------------------------------------------------------------------------

Комментариев нет:

Отправить комментарий