Замер времени выполнения кода — не редкая задача в разработке. Мы постоянно измеряем, сколько работает запрос к БД, сколько сортируется массив, сколько выполняется тяжёлый алгоритм. Казалось бы, что тут сложного? Написал System.currentTimeMillis() до и после — и готово.
Но на практике всё немного сложнее. В этой статье мы:
- Создадим готовое решение, которое можно сразу скопировать в проект
- Разберём, почему стандартные подходы плохи
- Напишем свой класс
MeasureTimeс нуля - Поймём, как правильно измерять время в разных сценариях
Почему System.currentTimeMillis() — это плохо?
Самый очевидный способ замера времени выглядит так:
|
1 2 3 4 |
long start = System.currentTimeMillis(); // ваш код long duration = System.currentTimeMillis() - start; System.out.println("Время: " + duration + " мс"); |
Проблема: currentTimeMillis() зависит от системных часов. Если во время замера операционная система скорректирует время (например, через NTP-синхронизацию), вы получите:
- Отрицательное время
- Резкий скачок в несколько секунд
- Некорректные результаты
Правильный инструмент: System.nanoTime()
Java предоставляет специальный метод для измерения интервалов — System.nanoTime(). Он:
- Не зависит от системных часов
- Имеет наносекундную точность (на практике — зависит от платформы)
- Монотонно увеличивается (не может идти назад)
Использовать его просто:
|
1 2 3 4 |
long start = System.nanoTime(); // ваш код long duration = System.nanoTime() - start; System.out.println("Время: " + duration / 1_000_000.0 + " мс"); |
Но каждый раз писать этот код — утомительно. Особенно когда нужно:
- Измерять несколько участков
- Получать время в разных единицах
- Красиво выводить результат
- Использовать в try-with-resources для автоматического замера
Создаём класс MeasureTime
Давайте напишем универсальный класс, который решит все эти задачи.
Шаг 1: Базовая структура
Начнём с простого: храним время старта и умеем его сбрасывать.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
public class MeasureTime { private long startPoint; public MeasureTime() { start(); } public void start() { this.startPoint = System.nanoTime(); } public long stop() { return System.nanoTime() - startPoint; } } |
Уже удобно:
|
1 2 3 |
MeasureTime timer = new MeasureTime(); // какой-то код System.out.println(timer.stop() + " нс"); |
Шаг 2: Добавляем кеширование результата
Если мы вызовем stop() дважды, получим два разных числа. Это не всегда удобно — иногда нужно зафиксировать результат и больше его не менять до следующего вызова start().
Добавим поле duration, которое запоминает результат после первого вызова stop():
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
public class MeasureTime { private long startPoint; private Long duration; // null, если таймер ещё не остановлен public MeasureTime() { start(); } public void start() { this.startPoint = System.nanoTime(); this.duration = null; } public long stop() { if (duration == null) { duration = System.nanoTime() - startPoint; } return duration; } } |
Теперь сколько раз не вызывай stop() — результат будет один.
Шаг 3: Разные единицы измерения
Наносекунды — это круто, но в реальности мы чаще работаем с миллисекундами. Добавим методы-геттеры:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
public long getDurationNanos() { return stop(); } public double getDurationMicros() { return stop() / 1_000.0; } public double getDurationMillis() { return stop() / 1_000_000.0; } public double getDurationSeconds() { return stop() / 1_000_000_000.0; } |
Теперь можно получить время в разных единицах времени, например в мс.:
|
1 |
System.out.println(timer.getDurationMillis() + " мс"); |
Шаг 4: Добавляем имя задачи
Чтобы понять, что именно мы измеряем, добавим поле taskName и будем выводить его в отчётах:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 |
public class MeasureTime { private static final String REPORT_STRING = "⏱ %s выполнено за %.3f мс"; private long startPoint; private Long duration; private final String taskName; public MeasureTime(String taskName) { this.taskName = taskName; start(); } public MeasureTime() { this("Задание"); } // Остальные методы... @Override public String toString() { return String.format(REPORT_STRING, taskName, getDurationMillis()); } } |
Шаг 5: Поддержка try-with-resources
Самый элегантный способ использования — автоматический замер при выходе из блока кода. Реализуем интерфейс AutoCloseable:
|
1 2 3 4 5 6 7 8 |
public class MeasureTime implements AutoCloseable { // ... все поля и методы ... @Override public void close() { System.out.println(this); // Выводим toString() } } |
Теперь можно писать так:
|
1 2 3 4 5 6 |
try (MeasureTime timer = new MeasureTime("Сохранение в БД")) { // Ваш код здесь connection.execute(query); } // При выходе из блока автоматически выведется: // ⏱ Сохранение в БД выполнено за 125.342 мс |
Финальный код класса
Соберём всё вместе:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 |
public class MeasureTime implements AutoCloseable { private static final String REPORT_STRING = "⏱ %s выполнено за %.3f мс"; private long startPoint; private Long duration; private final String taskName; /* Конструкторы */ public MeasureTime(String taskName) { this.taskName = taskName; start(); } public MeasureTime() { this("Задание"); } /* Фабричное создание объекта */ public static MeasureTime timer(String taskName) { return new MeasureTime(taskName); } public static MeasureTime start() { return new MeasureTime(); } public void start() { this.startPoint = System.nanoTime(); this.duration = null; } public long stop() { if (duration == null) { duration = System.nanoTime() - startPoint; } return duration; } /* Останов и разные единицы времени */ public long getDurationNanos() { return stop(); } public double getDurationMicros() { return stop() / 1_000.0; } public double getDurationMillis() { return stop() / 1_000_000.0; } public double getDurationSeconds() { return stop() / 1_000_000_000.0; } @Override public String toString() { return String.format(REPORT_STRING, taskName, getDurationMillis()); } @Override public void close() { System.out.println(this); } } |
Примеры использования
Базовый замер
|
1 2 3 4 |
MeasureTime timer = new MeasureTime(); int[] array = IntStream.range(0, 10000).toArray(); Arrays.sort(array); System.out.println(timer); |
Перезапуск таймера
|
1 2 3 4 5 6 7 8 |
MeasureTime timer = new MeasureTime(); // Таймер уже запущен. Thread.sleep(100); System.out.println(timer); // ~100 мс // Сброс таймера timer.start(); Thread.sleep(50); System.out.println(timer); // ~50 мс |
Не забудьте, что Thread.sleep требует обработки InterruptedException.
Try-with-resources (автоматический вывод)
|
1 2 3 4 5 |
try (MeasureTime ignored = new MeasureTime("Сохранение в БД")) { // Ваш код здесь Thread.sleep(150); } // При выходе из try в консоль будет выведен замер времени. |
Статические фабричные методы
|
1 2 3 4 |
try (MeasureTime timer = MeasureTime.timer()) { parseJson(largeFile); } // ⏱ Задание выполнено за 45.123 мс |
А почему не JMH?
Вообще, в JAVA есть готовый фреймворк для точного измерения времени — JMH (Java Microbenchmark Harness). Он позволяет честно вычислить производительность кода. Есть конечно же «НО».
JMH заметно усложняет код и процесс, делает это осознанно, чтобы дать взамен абсолютно достоверные результаты, которые класс MeasureTime дать не сможет. Это не «утяжеление ради утяжеления», а необходимость для борьбы с хитростями JVM.
Класс MeasureTime хорош для быстрого замера в продакшене, но он дает «сырые» данные. Проблема в том, что JVM — умная система :
- JIT-компиляция: JVM может оптимизировать ваш код во время выполнения. Первый запуск метода может быть медленным, а сотый — быстрым. Наш таймер этого не учитывает и может показать «среднюю температуру по больнице» .
- «Мертвый» код: JVM может понять, что результат метода нигде не используется, и просто не выполнить его. Наш таймер покажет очень маленькое время, не отражающее реальную работу.
JMH решает эти проблемы, но ценой усложнения: нужно настраивать отдельный проект, разбираться с аннотациями и понимать, как работают «прогрев» и «вилка».