Аномалии времени доступа к кешу / памяти процессора - PullRequest
2 голосов
/ 15 марта 2019

Мы пытаемся оптимизировать тяжелые операции с памятью в Java и столкнулись с некоторыми аномалиями. Исходя из наших данных, мы заключили гипотезу о том, что блок массива / памяти может быть загружен в кэш ЦП из-за большого количества обращений, но после многократного клонирования этого массива кэш заполняется и перемещает исходный массив обратно в ОЗУ.

Чтобы проверить это, мы настроили тест. Это делает следующее:

  1. Создать массив с заданным размером
  2. Запишите некоторые данные в поля
  3. Чтение / повторение миллион раз (для помещения в кэш процессора)
  4. Клонировать его один раз в новый массив
  5. Клонировать новый массив в новый массив и использовать новый в следующий раз указанное количество раз

Кроме того, после каждого из этих шагов массив повторяется три раза, и для каждой итерации измеряется необходимое время. Вот код:

private static long[] read(byte[] array, int count, boolean logTimes) {
    long[] times = null;
    if (logTimes) {
        times = new long[count];
    }
    int sum = 0;
    for (int n = 0; n < count; n++) {
        long start = System.nanoTime();
        for (int i = 0; i < array.length; i++) {
            sum += array[i];
        }
        if (logTimes) {
            long time = System.nanoTime() - start;
            times[n] = time;
        }
    }
    System.out.println(sum);
    return times;
}

public static void main(String[] args) {
    int arraySize = Integer.parseInt(args[0]);
    int clones = Integer.parseInt(args[1]);
    byte[] array = new byte[arraySize];
    long[] initialReadTimes = read(array, 3, true);
    // Fill with some non-zero content
    for (int i = 0; i < array.length; i++) {
        array[i] = (byte) i;
    }
    long[] afterWriteTimes = read(array, 3, true);

    // Make this array important, so it lands in CPU Cache
    read(array, 1_000_000, false);
    long[] afterReadTimes = read(array, 3, true);

    long[] afterFirstCloneReadTimes = null;
    byte[] copy = new byte[array.length];
    System.arraycopy(array, 0, copy, 0, array.length);
    for (int i = 1; i <= clones; i++) {
        byte[] copy2 = new byte[copy.length];
        System.arraycopy(copy, 0, copy2, 0, copy.length);
        copy = copy2;
        if (i == 1) {
            afterFirstCloneReadTimes = read(array, 3, true);
        }
    }

    long[] afterAllClonesReadTimes = read(array, 3, true);

    // Write to CSV
    ...
    System.out.println("Finished.");
}

Мы выполнили этот тест с размером массива = 10 000 и клонами = 10 000 000 на i5 второго поколения с 16 ГБ ОЗУ: enter image description here

Было довольно много вариаций, однако, у 2-го и 3-го прогонов иногда было разное время или были пики во 2-м и 3-м прогонах последнего теста чтения.

Эти результаты кажутся довольно запутанными. Я думаю, что это может показать, что при инициализации массива он не сразу загружается в кэш процессора, поскольку начальное время чтения относительно велико. После написания ничего не изменилось. Только после многократной итерации время доступа становится быстрее, а первый запуск всегда медленнее (из-за накладных расходов на измерение, которые выполняются между показаниями?). Кроме того, клонирование / заполнение памяти новыми массивами, похоже, совсем не влияет. Может ли кто-нибудь объяснить эти результаты?

Мы предполагали, что это может быть связано с управлением памятью в java, поэтому мы пытались переопределить эталонный тест в C ++:

void read(unsigned char array[], int length, int count, std::vector<long int> & logTimes) {
    for (int c = 0; c < count; c++) {
        int sum = 0;
        std::chrono::high_resolution_clock::time_point t1;
        if (count <= 3) {
            t1 = std::chrono::high_resolution_clock::now();
        }
        for (int i = 0; i < length; i++) {
            sum += array[i];
        }
        if (count <= 3) {
            std::chrono::high_resolution_clock::time_point t2 = std::chrono::high_resolution_clock::now();
            long int duration = std::chrono::duration_cast<std::chrono::nanoseconds>(t2 - t1).count();
            std::cout << duration << " ns\n";
            logTimes.push_back(duration);
        }
    }
}

int main(int argc, char ** args)
{
    int ARRAYSIZE = 10000;
    int CLONES = 10000000;
    std::vector<long int> initialTimes, afterWritingTimes, afterReadTimes, afterFirstCloneTimes, afterCloneTimes, null;
    unsigned char array[ARRAYSIZE];
    read(array, ARRAYSIZE, 3, initialTimes);
    for (long long i = 0; i < ARRAYSIZE; i++) {
        array[i] = i;
    }
    std::cout << "Reads after writing:\n";
    read(array, ARRAYSIZE, 3, afterWritingTimes);

    read(array, ARRAYSIZE, 1000000, null);
    std::cout << "Reads after 1M Reads:\n";
    read(array, ARRAYSIZE, 3, afterReadTimes);

    unsigned char copy[ARRAYSIZE];
    unsigned char * ptr_copy = copy;
    std::memcpy(ptr_copy, array, ARRAYSIZE);
    for (long long i = 0; i < CLONES; i++) {
        unsigned char copy2[ARRAYSIZE];
        std::memcpy(copy2, ptr_copy, ARRAYSIZE);
        ptr_copy = copy2;
        if (i == 0) {
            read(array, ARRAYSIZE, 3, afterFirstCloneTimes);
        }
    }
    std::cout << "Reads after cloning:\n";
    read(array, ARRAYSIZE, 3, afterCloneTimes);

    writeTimesToCSV(initialTimes, afterWritingTimes, afterReadTimes, afterFirstCloneTimes, afterCloneTimes);
    std::cout << "Finished.\n";
}

Используя те же параметры, мы получили следующие результаты:

enter image description here

Так что в C ++ времена довольно похожи друг на друга, с некоторыми странными пиками во 2-й серии. Это, кажется, показывает, что вышеупомянутые более быстрые тайминги были вызваны оптимизацией Java (или, скорее, неоптимальной обработкой в ​​первых чтениях). Значит ли это, что кеш процессора вообще не задействован?

...