Измерьте время выполнения метода, обрабатываемого bukkit.event.Listener

Мне нужно точно измерить в мс (#.### ms), сколько времени требуется для запуска метода void, чтобы измерение не влияло на результаты.

Обычно я бы просто сделал что-то вроде:

long startTime = System.nanoTime();
methodToTime();
long endTime = System.nanoTime();

long duration = (endTime - startTime);  //divide by 1000000 to get milliseconds.

Это не сработает, потому что мой код никогда не вызывает метод напрямую; это только определяет его.

import org.bukkit.event.Listener;
import org.bukkit.event.EventHandler;
import org.bukkit.event.EventPriority;

public class BlockListener implements Listener {

    @EventHandler(priority = EventPriority.LOWEST, ignoreCancelled = true)
    public void onPlace(BlockPlaceEvent event) {

    //...
    }
}

В контексте некоторых методов на этом сервере Minecraft Bukkit, над которым я работаю, 1 мс имеет большое значение, а это означает, что мне нужна высокая точность для измерения, а затем оптимизации чувствительных ко времени методов.

Итак, конечно, добавление любого кода внутри метода может повлиять на время выполнения метода?

Каков наилучший способ измерить это? Пожалуйста и спасибо вам

Running Paper/Spigot с ProtocolLib (1.16.5)


person DogeCode    schedule 18.04.2021    source источник


Ответы (1)


Измерение производительности всегда будет влиять на вашу производительность, поэтому я бы предложил сделать эту функцию переключаемой. Основываясь на этом ответе, вызов System.nanoTime() два раза для каждого метода займет примерно 200 тактов ЦП, что не является большой нагрузкой.

Но после измерения времени выполнения нужно его куда-то сохранить или распечатать лог. Обычно операции ввода/вывода являются самыми затратными, поэтому лучше избегать блокировки выходов в вашем методе. Для этой цели вы можете использовать java.util.concurrent.BlockingQueue или другие реализации потокобезопасных каналов (например, Disruptor). или JCTools) и протоколировать полученные результаты в отдельном потоке демона.

Предложение по реализации

public class ListenerPerformanceAuditor implements Listener {

    private final BlockingQueue<Long> executionTimeQueue;
    private final Listener auditedListener;

    public ListenerPerformanceAuditor(
            Listener auditedListener,
            BlockingQueue<Long> executionTimeQueue
    ) {
        this.auditedListener = auditedListener;
        this.executionTimeQueue = executionTimeQueue;
    }

    public void onPlace(BlockPlaceEvent event) {
        long startTime = System.nanoTime();
        auditedListener.onPlace(event);
        long endTime = System.nanoTime();

        long duration = (endTime - startTime);  //divide by 1000000 to get milliseconds.
        if(!executionTimeQueue.offer(duration)) {
            // if measuring each and every request isn't necessary,
            // this block can be eliminated, otherwise add error handling logic
        }
    }
}

person geobreze    schedule 18.04.2021
comment
Как насчет печати на стандартный вывод с помощью println()? Примерно сколько времени это занимает? Будет ли это так же незначительно, как с задержкой получения nanoTime внутри метода? - person DogeCode; 18.04.2021
comment
Производительность печати на консоль сравнима с производительностью ArrayBlockingQueue#offer в однопоточном приложении, но System.out.println — это синхронизированная операция, которая может привести к снижению производительности в многопоточной системе, когда несколько потоков пытаются выполнить запись в консоль. Кроме того, вы можете печатать непосредственно в ListenerPerformanceAuditor, но в пуле потоков, поэтому очередь не требуется, а производительность остается стабильной. - person geobreze; 18.04.2021