Подсчёт времени выполнения метода через аннотацию
Во многих проектах требуется посчитать время, которое затратил тот или иной метод. Для этого можно вручную сохранять значение System.currentTimeMillis() и после метода вычислять затраченное время. Когда методов много это становится не очень удобным.
Поэтому я решил написать простенькую аннотацию, которая бы считала время выполнения метода. Попытавшись найти информацию в интернете, понял, что её по данной теме очень мало. Придётся как-то выкручиваться, собирая информацию по крупицам.
Наша аннотация будет помечать методы, для которых мы хотим посчитать время выполнения в миллисекундах или наносекундах и выводить результат через System.out.println.
Для начала создадим саму аннотацию:
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
@Target()
@Retention(RetentionPolicy.SOURCE)
public @ interface Time public enum TimeInterval < MILLISECOND, NANOSECOND >;
annotations.time.Time.TimeInterval interval() default annotations.time.Time.TimeInterval.MILLISECOND;
String format() default «Elapsed %s» ;
>
* This source code was highlighted with Source Code Highlighter .
Поле interval служит для указания интервала времени (миллисекунды или наносекунды), поле format задаёт формат вывода результата.
Теперь, чтобы данная аннотация сработала как надо, нужно создать класс-обработчик расширяющий AbstractProcessor. В данном классе добавляется сохранение времени перед кодом метода, сам код метода копируется в блок try-finally, а блоке finally вычисляется затраченное методом время и выводится в консоль:
import com.sun.tools.javac.code.Flags;
import com.sun.tools.javac.code.TypeTags;
import com.sun.tools.javac.model.JavacElements;
import com.sun.tools.javac.processing.JavacProcessingEnvironment;
import com.sun.tools.javac.tree.JCTree;
import com.sun.tools.javac.tree.JCTree.JCBlock;
import com.sun.tools.javac.tree.JCTree.JCCatch;
import com.sun.tools.javac.tree.JCTree.JCExpression;
import com.sun.tools.javac.tree.JCTree.JCExpressionStatement;
import com.sun.tools.javac.tree.JCTree.JCMethodDecl;
import com.sun.tools.javac.tree.JCTree.JCStatement;
import com.sun.tools.javac.tree.JCTree.JCVariableDecl;
import com.sun.tools.javac.tree.TreeMaker;
import com.sun.tools.javac.util. List ;
import java.util.Set;
import javax.annotation.processing.AbstractProcessor;
import javax.annotation.processing.ProcessingEnvironment;
import javax.annotation.processing.RoundEnvironment;
import javax.annotation.processing.SupportedAnnotationTypes;
import javax.annotation.processing.SupportedSourceVersion;
import javax.lang.model.SourceVersion;
import javax.lang.model.element.Element;
import javax.lang.model.element.TypeElement;
import javax.lang.model.util.Elements;
@SupportedAnnotationTypes( value = )
@SupportedSourceVersion(SourceVersion.RELEASE_6)
public class TimeAnnotationProcessor extends AbstractProcessor
public static final String ANNOTATION_TYPE = «annotations.time.Time» ;
private JavacProcessingEnvironment javacProcessingEnv;
private TreeMaker maker;
@Override
public void init(ProcessingEnvironment procEnv) super.init(procEnv);
this .javacProcessingEnv = (JavacProcessingEnvironment) procEnv;
this .maker = TreeMaker.instance(javacProcessingEnv.getContext());
>
@Override
public boolean process(Set annotations, RoundEnvironment roundEnv) if (annotations == null || annotations.isEmpty()) return false ;
>
final Elements elements = javacProcessingEnv.getElementUtils();
final TypeElement annotation = elements.getTypeElement(ANNOTATION_TYPE);
if (annotation != null ) // Выбираем все элементы, у которых стоит наша аннотация
final Set methods = roundEnv.getElementsAnnotatedWith(annotation);
JavacElements utils = javacProcessingEnv.getElementUtils();
for (final Element m : methods) Time time = m.getAnnotation(Time. class );
if (time != null ) JCTree blockNode = utils.getTree(m);
// Нам нужны только описания методов
if (blockNode instanceof JCMethodDecl) // Получаем содержимое метода
final List statements = ((JCMethodDecl) blockNode).body.stats;
// Новое тело метода
List newStatements = List .nil();
// Добавляем в начало метода сохранение текущего времени
JCVariableDecl var = makeTimeStartVar(maker, utils, time);
newStatements = newStatements.append( var );
// Создаём тело блока try, копируем в него оригинальное содержимое метода
List tryBlock = List .nil();
for (JCStatement statement : statements) tryBlock = tryBlock.append(statement);
>
// Создаём тело блока finally, добавляем в него вывод затраченного времени
JCBlock finalizer = makePrintBlock(maker, utils, time, var );
JCStatement stat = maker.Try(maker.Block(0, tryBlock), List .nil(), finalizer);
newStatements = newStatements.append(stat);
// Заменяем старый код метода на новый
((JCMethodDecl) blockNode).body.stats = newStatements;
>
>
>
private JCExpression makeCurrentTime(TreeMaker maker, JavacElements utils, Time time) // Создаём вызов System.nanoTime или System.currentTimeMillis
JCExpression exp = maker.Ident(utils.getName( «System» ));
String methodName;
switch (time.interval()) case NANOSECOND:
methodName = «nanoTime» ;
break ;
default :
methodName = «currentTimeMillis» ;
break ;
>
exp = maker.Select(exp, utils.getName(methodName));
return maker.Apply( List .nil(), exp, List .nil());
>
protected JCVariableDecl makeTimeStartVar(TreeMaker maker, JavacElements utils, Time time) // Создаём финальную переменную для хранения времени старта. Имя переменной в виде time_start_
JCExpression currentTime = makeCurrentTime(maker, utils, time);
String fieldName = fieldName = «time_start_» + ( int ) ( Math .random() * 10000);
return maker.VarDef(maker.Modifiers(Flags.FINAL), utils.getName(fieldName), maker.TypeIdent(TypeTags.LONG), currentTime);
>
protected JCBlock makePrintBlock(TreeMaker maker, JavacElements utils, Time time, JCVariableDecl var ) // Создаём вызов System.out.println
JCExpression printlnExpression = maker.Ident(utils.getName( «System» ));
printlnExpression = maker.Select(printlnExpression, utils.getName( «out» ));
printlnExpression = maker.Select(printlnExpression, utils.getName( «println» ));
// Создаём блок вычисления затраченного времени (currentTime — startTime)
JCExpression currentTime = makeCurrentTime(maker, utils, time);
JCExpression elapsedTime = maker.Binary(JCTree.MINUS, currentTime, maker.Ident( var .name));
// Форматируем результат
JCExpression formatExpression = maker.Ident(utils.getName( «String» ));
formatExpression = maker.Select(formatExpression, utils.getName( «format» ));
// Собираем все кусочки вместе
List formatArgs = List .nil();
formatArgs.append(maker.Literal(time.format()));
formatArgs.append(elapsedTime);
JCExpression format = maker.Apply( List .nil(), formatExpression, formatArgs);
List printlnArgs = List .nil();
printlnArgs.append(format);
JCExpression print = maker.Apply( List .nil(), printlnExpression, printlnArgs);
JCExpressionStatement stmt = maker.Exec(print);
List stmts = List .nil();
stmts.append(stmt);
return maker.Block(0, stmts);
>
>
* This source code was highlighted with Source Code Highlighter .
Для того чтобы компилятор java использовал наш управляющий класс, нужно создать файл META-INF/javax.annotation.processing.Processor, в котором должна быть прописана следующая строка:
annotations.time.TimeAnnotationProcessor
После этого собираем все наши файлы в annotations.jar и добавляем его в classpath к любому проекту.
Теперь, чтобы посчитать время выполнения метода, достаточно добавить к этому методу аннотацию Time и после его выполнения в консоль будет выведено затраченное методом время:
@Time(format= «method time: %s ms» )
public void start() Thread.sleep(1000);
>* This source code was highlighted with Source Code Highlighter .
В результате в консоли увидим:
method time: 1000 ms
UPD: добавил немного комментариев в код
UPD2: Так же можно переработать пример, чтобы он выводил время затраченное методом в System.err только если оно больше заданного в параметрах аннотации. Это могло бы быть полезно для production серверов, где пользоваться профайлером не всегда удобно.
Как замерить время выполнения
Зачастую требуется узнать, сколько времени выполняется тот или иной код. Иногда требуется замерить время выполнения метода или какой-то задачи. В данной статье мы расскажем вам принципы замера времени в Java и покажем лучшие практики для конкретных задач.
Замер времени с помощью currentTimeMills()
Это довольно простой способ измерить время. Метод System.currentTimeMillis() вернёт вам текущее время в миллисекундах. Его потребуется вызвать до выполнения нужной задачи и после, а затем вычислить разницу. В итоге мы узнаем время выполнения в миллисекундах:
long start = System.currentTimeMillis(); // выполнение какой-то логики Thread.sleep(1000); long finish = System.currentTimeMillis(); long elapsed = finish - start; System.out.println("Прошло времени, мс: " + elapsed); При работе с данным методом следует учитывать его специфику: System.currentTimeMillis() показывает текущее время, основываясь на системных часах и может выдавать некорректный результат.
Замер времени с помощью nanoTime()
Ещё один метод для получения текущего времени это System.nanoTime(). Как следует из названия, этот метод возвращает время с точностью до нансекунд. Также работа этого метода не зависит от системных часов.
Он используется аналогично:
long start = System.nanoTime(); // выполнение какой-то логики Thread.sleep(1000); long finish = System.nanoTime(); long elapsed = finish - start; System.out.println("Прошло времени, нс: " + elapsed); Для получения значения в миллисекундах результат можно разделить на 1000:
System.out.println("Прошло времени, мс: " + elapsed / 1000000); Важно: Хотя метод nanoTime() может возвращать время в наносекундах, он не гарантирует, что значения между его вызовами будут обновляться с точностью до наносекунд.
Но всё же это более приемлемый вариант, чем System.currentTimeMillis().
Замер времени с помощью Instant и Duration
В Java 8 добавили новый java.time API. В частности, ля измерения времени подойдут два новых класса – Instant и Duration. Оба эти класса иммутабельны.
Instant обозначает момент времени с начала эпохи Unix (1970-01-01T00:00:00Z). Для создания момента мы используем метод Instant.now(). После того, как мы создали два момент, вычислим разницу в миллисекундах:
Instant start = Instant.now(); // выполнение какой-то логики Thread.sleep(1000); Instant finish = Instant.now(); long elapsed = Duration.between(start, finish).toMillis(); System.out.println("Прошло времени, мс: " + elapsed); Рекомендуется использовать именно этот подход в Java 8 и выше.
Замер времени выполнения с помощью StopWatch
StopWatch – это класс из библиотеки Apache Commons Lang. Он работает как секундомер. Для его использования сначала требуется подключить библиотеку к проекту:
org.apache.commons commons-lang3 3.9
Теперь создадим экземпляр StopWatch. Затем начнём отсчёт с помощью метода start() и окончим отсчёт с помощью метода stop():
public static void stopWatch() throws InterruptedException < StopWatch stopWatch = new StopWatch(); stopWatch.start(); // выполнение какой-то логики Thread.sleep(1000); stopWatch.stop(); System.out.println("Прошло времени, мс: " + stopWatch.getTime()); > StopWatch удобно использовать тогда, когда в проекте уже подключена данная библиотека.
Исходный код
package ru.javalessons.time; import org.apache.commons.lang3.time.StopWatch; import java.time.Duration; import java.time.Instant; public class MeasureElapsedTime < public static void main(String[] args) throws InterruptedException < currentTimeMillis(); nanoTime(); instant(); stopWatch(); >public static void currentTimeMillis() throws InterruptedException < long start = System.currentTimeMillis(); // выполнение какой-то логики Thread.sleep(1000); long finish = System.currentTimeMillis(); long elapsed = finish - start; System.out.println("Прошло времени, мс: " + elapsed); >public static void nanoTime() throws InterruptedException < long start = System.nanoTime(); // выполнение какой-то логики Thread.sleep(1000); long finish = System.nanoTime(); long elapsed = finish - start; System.out.println("Прошло времени, нс: " + elapsed); >public static void instant() throws InterruptedException < Instant start = Instant.now(); // выполнение какой-то логики Thread.sleep(1000); Instant finish = Instant.now(); long elapsed = Duration.between(start, finish).toMillis(); System.out.println("Прошло времени, мс: " + elapsed); >public static void stopWatch() throws InterruptedException < StopWatch stopWatch = new StopWatch(); stopWatch.start(); // выполнение какой-то логики Thread.sleep(1000); stopWatch.stop(); System.out.println("Прошло времени, мс: " + stopWatch.getTime()); >> Заключение
В данной статье мы разобрали простые методы замера времени выполнения в Java. Для простых замеров можно использовать все вышеперечисленные методы, кроме currentTimeMillis (из-за того, что он зависит от системных часов).