Pull to refresh

Поиск причин странной производительности

Reading time 5 min
Views 20K

Введение


Наконец-то полез детально изучать Java-байткод, и почти сразу же в голове возник интересный вопрос. Есть там инструкция NOP, которая не делает ничего. Так вот, а как это «ничего» сказывается на производительности? Собственно, процесс изучения этого и описан в посте.

Дисклеймер


Сам рассказ, в первую очередь, не о том, как оно реально работает, а о том, каких ошибок стоит опасаться при измерениях производительности.

Инструменты


Начнем с главного: как проводились все измерения. Для генерации кода использовалась библиотека ASM, для создания самого бенчмарка — JMH.

Чтобы не использовать reflection, был создан маленький интерфейс:
public interface Getter {
    int get();
}


Дальше, генерировался класс, реализующий метод get:
  public get()I
    NOP
    ...
    NOP
    LDC 20
    IRETURN

Можно вставить произвольное количество нопов.

Полный код генератора
public class SimpleGetterClassLoader extends ClassLoader {

    private static final String GENERATED_CLASS_NAME = "other.GeneratedClass";

    private static final ClassLoader myClassLoader = new SimpleGetterClassLoader();

    @SuppressWarnings("unchecked")
    public static Getter newInstanceWithNOPs(int nopCount) throws Exception {
        Class<?> clazz = Class.forName(GENERATED_CLASS_NAME + "_" + nopCount, false, myClassLoader);
        return (Getter) clazz.newInstance();
    }

    @NotNull
    @Override
    protected Class<?> findClass(@NotNull String name) throws ClassNotFoundException {
        if (!name.startsWith(GENERATED_CLASS_NAME))
            throw new ClassNotFoundException(name);

        int nopCount = Integer.parseInt(name.substring(GENERATED_CLASS_NAME.length() + 1));

        ClassWriter cw = new ClassWriter(0);
        cw.visit(V1_5, ACC_PUBLIC, name.replace('.', '/'), null, getInternalName(Object.class), new String[]{getInternalName(Getter.class)});
        {
            MethodVisitor mv = cw.visitMethod(ACC_PUBLIC, "<init>", "()V", null, null);
            mv.visitCode();
            mv.visitVarInsn(ALOAD, 0);
            mv.visitMethodInsn(INVOKESPECIAL, getInternalName(Object.class), "<init>", "()V");
            mv.visitInsn(RETURN);
            mv.visitMaxs(1, 1);
            mv.visitEnd();
        }
        {
            MethodVisitor mv = cw.visitMethod(ACC_PUBLIC, "get", "()I", null, null);
            mv.visitCode();
            for (int i = 0; i < nopCount; i++) {
                mv.visitInsn(NOP);
            }
            mv.visitLdcInsn(20);
            mv.visitInsn(IRETURN);
            mv.visitMaxs(1, 1);
            mv.visitEnd();
        }
        cw.visitEnd();

        byte[] bytes = cw.toByteArray();

        return defineClass(name, bytes, 0, bytes.length);
    }
}


Бенчмарк
@State(Scope.Benchmark)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
public class Bench {

    private Getter nop_0;
    private Getter nop_10;
    ...

    @Setup
    public void setup() throws Exception {
        nop_0 = newInstanceWithNOPs(0);
        nop_10 = newInstanceWithNOPs(10);
        ...
    }

    @GenerateMicroBenchmark
    public int nop_0() {
        return nop_0.get();
    }

    @GenerateMicroBenchmark
    public int nop_10() {
        return nop_10.get();
    }

   ...



Поиск истины


Сначала были запущены 2 теста: без нопов и с 2000.

Benchmark            Mode   Samples         Mean   Mean error    Units
b.Bench.nop_0       thrpt         5      838,753       48,962   ops/us
b.Bench.nop_2000    thrpt         5      298,428        7,965   ops/us

И сразу же я сделал очень мощный вывод: «Глупый JIT не вырезает нопы, а транслирует их в машинные.»
Вопрос знатокам:
Если бы это было правдой, то результат измерения был бы похож? Или было бы что-то совершенно другое?

Но это, все-таки, была гипотеза, и очень хотелось ее проверить. Сначала убедился что эти методы действительно компилируются JIT`ом, затем посмотрел во что. Естественно, полученный ассемблер был полностью идентичным. И вот тут я понял что чего-то не понимаю. Исполняемый код полностью совпадает, а производительность отличается в 2,5 раза. Странно.

Дальше очень захотелось посмотреть на вид зависимости.
Benchmark             Mode   Samples         Mean   Mean error    Units
b.Bench.nop_0        thrpt         5      813,010       71,510   ops/us
b.Bench.nop_2000     thrpt         5      302,589       12,360   ops/us
b.Bench.nop_10000    thrpt         5        0,268        0,017   ops/us

Скрытое знание
Это измерение вообще шикарное. 3 точки, и все из разных последовательностей.

Здесь стоит отдельно отметить, что для новой точки ни происходит ли компиляция, ни что получается на выходе, я вообще не смотрел. Автоматически предположил, что все так же, как при 0/2к. Что было ошибкой.

Посмотрел я на это, и сделал следующий далеко идущий вывод: «Зависимость очень сильно нелинейная.». Но, что гораздо важнее, в этом месте я начал подозревать, что реально дело тут не в самих нопах, а в размере метода.

Следующая мысль заключалась в том, что методы у нас виртуальные, значит они хранятся в таблице виртуальных методов. Может быть сама таблица чувствительна к размеру? Для проверки просто перенес код в статические методы, и, естественно, не изменилось вообще ничего.
Вопрос знатокам 2
Эта мысль являлась полной глупостью? Или же что-то здравое в ней все же было?


Дальше, от непонимания, полез искать при чем тут размер метода. Ответ был найден в исходниках openjdk:
  develop(intx, HugeMethodLimit,  8000,                                     \
          "Don't compile methods larger than this if "                      \
          "+DontCompileHugeMethods")      

Интересно, как раз между 2к и 10к. Посчитаем размер моего метода: 3 байта на «return 20», остается 7997.
Benchmark             Mode   Samples         Mean   Mean error    Units
b.Bench.nop_0        thrpt         5      797,376       12,998   ops/us
b.Bench.nop_2000     thrpt         5      306,795        0,243   ops/us
b.Bench.nop_7997     thrpt         5      303,314        7,161   ops/us
b.Bench.nop_7998     thrpt         5        0,335        0,001   ops/us
b.Bench.nop_10000    thrpt         5        0,269        0,000   ops/us

Угадали, эта граница понятна. Осталось понять что происходит до 8000 байт. Добавим точек:
Benchmark             Mode   Samples         Mean   Mean error    Units
b.Bench.nop_0        thrpt         5      853,499       61,847   ops/us
b.Bench.nop_10       thrpt         5      845,861      112,504   ops/us
b.Bench.nop_100      thrpt         5      867,068       20,681   ops/us
b.Bench.nop_500      thrpt         5      304,116        1,665   ops/us
b.Bench.nop_1000     thrpt         5      299,295        8,745   ops/us
b.Bench.nop_2000     thrpt         5      306,495        0,578   ops/us
b.Bench.nop_7997     thrpt         5      301,322        7,992   ops/us
b.Bench.nop_7998     thrpt         5        0,335        0,005   ops/us
b.Bench.nop_10000    thrpt         5        0,269        0,004   ops/us
b.Bench.nop_25000    thrpt         5        0,105        0,007   ops/us
b.Bench.nop_50000    thrpt         5        0,053        0,001   ops/us

Первое, что нас здесь радует — после того, как jit отключился, очень хорошо видна линейная зависимость. Что в точности совпадает с нашим ожиданием, т.к. каждый NOP надо явно обработать.

Следующее, на что падает глаз — есть сильное ощущение что до 8к не одна какая-то зависимость, а просто 2 константы. Еще 5 минут ручного бинарного поиска, и граница найдена.
Benchmark             Mode   Samples         Mean   Mean error    Units
b.Bench.nop_0        thrpt         5      805,466       10,074   ops/us
b.Bench.nop_10       thrpt         5      862,027        4,756   ops/us
b.Bench.nop_100      thrpt         5      861,462        9,881   ops/us
b.Bench.nop_322      thrpt         5      863,176       22,385   ops/us
b.Bench.nop_323      thrpt         5      303,677        5,130   ops/us
b.Bench.nop_500      thrpt         5      299,368       11,143   ops/us
b.Bench.nop_1000     thrpt         5      302,884        3,373   ops/us
b.Bench.nop_2000     thrpt         5      306,682        3,598   ops/us
b.Bench.nop_7997     thrpt         5      301,457        4,209   ops/us
b.Bench.nop_7998     thrpt         5        0,337        0,001   ops/us
b.Bench.nop_10000    thrpt         5        0,268        0,004   ops/us
b.Bench.nop_25000    thrpt         5        0,107        0,002   ops/us
b.Bench.nop_50000    thrpt         5        0,053        0,000   ops/us

Почти все, осталось понять что же это за граница. Посчитаем: 3 + 322 == 325. Ищем что же это за магическое 325, и находим некий ключик -XX:FreqInlineSize
FreqInlineSize is 325 on modern 64bit Linux

и его описание из доки:
Integer specifying maximum number of bytecode instructions in a frequently executed method which gets inlined.


Ура! Наконец-то все со всем сошлось. Итого, мы нашли зависимость производительности от размера метода (естественно, «при прочих равных»).
1. JIT + inline
2. JIT
3. честная интерпретация

Заключение


Как я уже говорил в начале, главное, на что стоит обратить внимание — это не реальное поведение. Оно оказалось достаточно тривиальным, и, уверен, описано в доке (не читал, не знаю). Основной мой посыл в том, что очень важно доверять здравому смыслу, и если результаты измерений хоть чуть-чуть с ним расходятся, или же просто кажутся непонятными, то обязательно надо все проверять и перепроверять.

Надеюсь, кому-нибудь этот пост показался интересным.

P.S.


Я все время считал и 8000, и 325 в байтах включительно. Похоже, надо было это делать в инструкциях невключительно.

Вопрос знатокам 3
Почему именно 325 и 8000? Это случайные числа, или же за ними что-то стоит?
Tags:
Hubs:
+49
Comments 30
Comments Comments 30

Articles