Введение
Раздел Старый вопрос содержит первоначальный вопрос ( Дальнейшее расследование и Заключение были добавлены с тех пор, как).
Перейдите к разделу Дальнейшее расследование ниже для подробного сравнения различных методов синхронизации (rdtsc, clock_gettime и QueryThreadCycleTime).
Я полагаю, что ошибочное поведение CGT может быть связано либо с ошибочным ядром, либо с ошибочным процессором (см. Раздел Заключение ).
Код, используемый для тестирования, находится внизу этого вопроса (см. Раздел Приложение ).
Извинения за длину.
Старый вопрос
Короче : я использую clock_gettime для измерения времени выполнения многих сегментов кода.Я испытываю очень противоречивые измерения между отдельными прогонами.Этот метод имеет чрезвычайно высокое стандартное отклонение по сравнению с другими методами (см. Пояснение ниже).
Вопрос : Существует ли причина, по которой clock_gettime дает столь противоречивые измерения по сравнению с другимиметоды?Есть ли альтернативный метод с тем же разрешением, которое учитывает время простоя потока?
Объяснение : Я пытаюсь профилировать несколько небольших частей кода C.Время выполнения каждого из сегментов кода составляет не более пары микросекунд.За один прогон каждый из сегментов кода будет выполняться несколько сотен раз, что дает runs × hundreds измерений.
Мне также нужно измерять только время, которое поток фактически тратит на выполнение (вот почему rdtsc не подходит).Мне также нужно высокое разрешение (поэтому times не подходит).
Я пробовал следующие методы:
rdtsc (в Linuxи Windows),
clock_gettime (с 'CLOCK_THREAD_CPUTIME_ID'; в Linux) и
QueryThreadCycleTime (в Windows).
Методология : анализ был выполнен за 25 прогонов.При каждом запуске отдельные сегменты кода повторяются 101 раз.Поэтому у меня 2525 измерений.Затем я смотрю гистограмму измерений, а также вычисляю некоторые основные вещи (например, среднее значение, стандартное отклонение, медиана, мода, минимальное и максимальное значения).
Я не представляю, как я измерил«сходство» трех методов, но это просто связано с базовым сравнением доли времени, проведенного в каждом сегменте кода («пропорция» означает, что времена нормализованы).Затем я смотрю на чистые различия в этих пропорциях.Это сравнение показало, что все «rdtsc», «QTCT» и «CGT» измеряют одинаковые пропорции при усреднении по 25 прогонам.Тем не менее, приведенные ниже результаты показывают, что «CGT» имеет очень большое стандартное отклонение.Это делает его непригодным для использования в моем случае.
Результаты :
Сравнение clock_gettime с rdtsc для того же сегмента кода (25 прогонов из 101 измерения= 2525 показаний):
Обсуждение
rdtsc дает очень похожие результаты как для Linux, так и для Windows. Он имеет приемлемое стандартное отклонение - на самом деле он достаточно последовательный / стабильный. Однако это не учитывает время простоя потока. Поэтому переключение контекста делает измерения ошибочными (в Windows я наблюдал это довольно часто: сегмент кода со средним числом около 1000 тиков время от времени будет занимать ~ 30000 тиков - определенно из-за упреждения).
QueryThreadCycleTime дает очень непротиворечивые измерения - т.е. намного более низкое стандартное отклонение по сравнению с rdtsc. Когда переключение контекста не происходит, этот метод почти идентичен rdtsc.
clock_gettime, с другой стороны, дает крайне противоречивые результаты (не только между прогонами, но и между измерениями). Стандартные отклонения являются крайними (по сравнению с rdtsc).
Надеюсь, статистика в порядке. Но что может быть причиной такого расхождения в измерениях между двумя методами? Конечно, есть кеширование, миграция процессора / ядра и другие вещи. Но ничто из этого не должно отвечать за любые такие различия между 'rdtsc' и 'clock_gettime'. Что происходит?
Дальнейшее расследование
Я исследовал это немного дальше. Я сделал две вещи:
Измеряется накладные расходы, связанные с простым вызовом clock_gettime(CLOCK_THREAD_CPUTIME_ID, &t) (см. Код 1 в Приложении ) и
в простом цикле, называемом clock_gettime, и сохранили показания в массиве (см. Код 2 в Приложении ). Я измеряю delta times (разница в последовательных временах измерения, которая должна немного соответствовать служебной нагрузке вызова clock_gettime).
Я измерял это на двух разных компьютерах с двумя разными версиями ядра Linux:
ВКТ
Процессор : Core 2 Duo L9400 @ 1,86 ГГц
Ядро : Linux 2.6.40-4.fc15.i686 # 1 SMP пт 29 июля 18:54:39 UTC 2011 i686 i686 i386
Результаты :
- Расчетное
clock_gettime накладные расходы : между 690-710 нс
Дельта раз :
- Среднее: 815,22 нс
- Медиана: 713 нс
- Режим: 709 нс
- Мин: 698 нс
- Макс .: 23359 нс
Гистограмма (пропущенные диапазоны имеют частоты 0):
Range | Frequency
------------------+-----------
697 < x ≤ 800 -> 78111 <-- cached?
800 < x ≤ 1000 -> 16412
1000 < x ≤ 1500 -> 3
1500 < x ≤ 2000 -> 4836 <-- uncached?
2000 < x ≤ 3000 -> 305
3000 < x ≤ 5000 -> 161
5000 < x ≤ 10000 -> 105
10000 < x ≤ 15000 -> 53
15000 < x ≤ 20000 -> 8
20000 < x -> 5
ЦП : 4 × Двухъядерный процессор AMD Opteron 275
Ядро : Linux 2.6.26-2-amd64 # 1 SMP Sun 20 июня 20:16:30 UTC 2010 x86_64 GNU / Linux
Результаты
- Расчетное
clock_gettime накладные расходы : между 279-283 нс
Дельта раз :
- Среднее: 320,00
- Медиана: 1
- Режим: 1
- Мин .: 1
- Макс .: 3495529
Гистограмма (пропущенные диапазоны имеют частоты 0):
Range | Frequency
--------------------+-----------
x ≤ 1 -> 86738 <-- cached?
282 < x ≤ 300 -> 13118 <-- uncached?
300 < x ≤ 440 -> 78
2000 < x ≤ 5000 -> 52
5000 < x ≤ 30000 -> 5
3000000 < x -> 8
RDTSC
Связанный код rdtsc_delta.c и rdtsc_overhead.c.
Процессор : Core 2 Duo L9400 @ 1,86 ГГц
Ядро : Linux 2.6.40-4.fc15.i686 # 1 SMP пт 29 июля 18:54:39 UTC 2011 i686 i686 i386
Результаты
- Расчетные накладные расходы : между 39-42 тиками
Дельта раз :
- Средний: 52,46 тиков
- Медиана: 42 тика
- Режим: 42 тика
- Мин: 35 тиков
- Макс .: 28700 тиков
Гистограмма (пропущенные диапазоны имеют частоты 0):
Range | Frequency
------------------+-----------
34 < x ≤ 35 -> 16240 <-- cached?
41 < x ≤ 42 -> 63585 <-- uncached? (small difference)
48 < x ≤ 49 -> 19779 <-- uncached?
49 < x ≤ 120 -> 195
3125 < x ≤ 5000 -> 144
5000 < x ≤ 10000 -> 45
10000 < x ≤ 20000 -> 9
20000 < x -> 2
Процессор : 4 × Двухъядерный процессор AMD Opteron 275
Ядро : Linux 2.6.26-2-amd64 # 1 SMP Sun 20 июня 20:16:30 UTC 2010 x86_64 GNU / Linux
Результаты
- Расчетные накладные расходы : от 13,7 до 17,0 тиков
Дельта раз :
- Средний: 35,44 тиков
- Медиана: 16 тиков
- Режим: 16 тиков
- Мин: 14 тиков
- Макс .: 16372 тиков
Гистограмма (пропущенные диапазоны имеют частоты 0):
Range | Frequency
------------------+-----------
13 < x ≤ 14 -> 192
14 < x ≤ 21 -> 78172 <-- cached?
21 < x ≤ 50 -> 10818
50 < x ≤ 103 -> 10624 <-- uncached?
5825 < x ≤ 6500 -> 88
6500 < x ≤ 8000 -> 88
8000 < x ≤ 10000 -> 11
10000 < x ≤ 15000 -> 4
15000 < x ≤ 16372 -> 2
QTCT
Связанные коды qtct_delta.c и qtct_overhead.c.
CPU : Core 2 6700 @ 2,66 ГГц
Ядро : Windows 7 64-разрядная
Результаты
- Расчетные накладные расходы : от 890 до 940 тиков
Дельта раз :
- Средний: 1057,30 тиков
- Медиана: 890 тиков
- Режим: 890 тиков
- Мин: 880 тиков
- Макс .: 29400 тиков
Гистограмма (пропущенные диапазоны имеют частоты 0):
Range | Frequency
------------------+-----------
879 < x ≤ 890 -> 71347 <-- cached?
895 < x ≤ 1469 -> 844
1469 < x ≤ 1600 -> 27613 <-- uncached?
1600 < x ≤ 2000 -> 55
2000 < x ≤ 4000 -> 86
4000 < x ≤ 8000 -> 43
8000 < x ≤ 16000 -> 10
16000 < x -> 1
Заключение
Я полагаю, что ответом на мой вопрос будет ошибочная реализация на моей машине (с процессорами AMD со старым ядром Linux).
Результаты CGT на машине AMD со старым ядром показывают некоторые экстремальные значения. Если мы посмотрим на времена дельты, то увидим, что наиболее частая дельта равна 1 нс. Это означает, что вызов clock_gettime занял меньше наносекунды! Кроме того, он также произвел ряд необычайно больших дельт (более 3000000 нс)! Это кажется ошибочным поведением. (Может быть, неучтенные миграции ядра?)
Примечания:
Издержки CGT и QTCT довольно велики.
Также сложно учесть их издержки, потому что кеширование процессора, кажется, имеет большое значение.
Может быть, придерживаться RDTSC, привязать процесс к одному ядру и назначить приоритет в реальном времени - наиболее точный способ узнать, сколько циклов используется фрагмент кода ...
Приложение
Код 1 : clock_gettime_overhead.c
#include <time.h>
#include <stdio.h>
#include <stdint.h>
/* Compiled & executed with:
gcc clock_gettime_overhead.c -O0 -lrt -o clock_gettime_overhead
./clock_gettime_overhead 100000
*/
int main(int argc, char **args) {
struct timespec tstart, tend, dummy;
int n, N;
N = atoi(args[1]);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tstart);
for (n = 0; n < N; ++n) {
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &dummy);
}
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tend);
printf("Estimated overhead: %lld ns\n",
((int64_t) tend.tv_sec * 1000000000 + (int64_t) tend.tv_nsec
- ((int64_t) tstart.tv_sec * 1000000000
+ (int64_t) tstart.tv_nsec)) / N / 10);
return 0;
}
Код 2 : clock_gettime_delta.c
#include <time.h>
#include <stdio.h>
#include <stdint.h>
/* Compiled & executed with:
gcc clock_gettime_delta.c -O0 -lrt -o clock_gettime_delta
./clock_gettime_delta > results
*/
#define N 100000
int main(int argc, char **args) {
struct timespec sample, results[N];
int n;
for (n = 0; n < N; ++n) {
clock_gettime(CLOCK_THREAD_CPUTIME_ID, &sample);
results[n] = sample;
}
printf("%s\t%s\n", "Absolute time", "Delta");
for (n = 1; n < N; ++n) {
printf("%lld\t%lld\n",
(int64_t) results[n].tv_sec * 1000000000 +
(int64_t)results[n].tv_nsec,
(int64_t) results[n].tv_sec * 1000000000 +
(int64_t) results[n].tv_nsec -
((int64_t) results[n-1].tv_sec * 1000000000 +
(int64_t)results[n-1].tv_nsec));
}
return 0;
}
Код 3 : rdtsc.h
static uint64_t rdtsc() {
#if defined(__GNUC__)
# if defined(__i386__)
uint64_t x;
__asm__ volatile (".byte 0x0f, 0x31" : "=A" (x));
return x;
# elif defined(__x86_64__)
uint32_t hi, lo;
__asm__ __volatile__ ("rdtsc" : "=a"(lo), "=d"(hi));
return ((uint64_t)lo) | ((uint64_t)hi << 32);
# else
# error Unsupported architecture.
# endif
#elif defined(_MSC_VER)
return __rdtsc();
#else
# error Other compilers not supported...
#endif
}
Код 4 : rdtsc_delta.c
#include <stdio.h>
#include <stdint.h>
#include "rdtsc.h"
/* Compiled & executed with:
gcc rdtsc_delta.c -O0 -o rdtsc_delta
./rdtsc_delta > rdtsc_delta_results
Windows:
cl -Od rdtsc_delta.c
rdtsc_delta.exe > windows_rdtsc_delta_results
*/
#define N 100000
int main(int argc, char **args) {
uint64_t results[N];
int n;
for (n = 0; n < N; ++n) {
results[n] = rdtsc();
}
printf("%s\t%s\n", "Absolute time", "Delta");
for (n = 1; n < N; ++n) {
printf("%lld\t%lld\n", results[n], results[n] - results[n-1]);
}
return 0;
}
Код 5 : rdtsc_overhead.c
#include <time.h>
#include <stdio.h>
#include <stdint.h>
#include "rdtsc.h"
/* Compiled & executed with:
gcc rdtsc_overhead.c -O0 -lrt -o rdtsc_overhead
./rdtsc_overhead 1000000 > rdtsc_overhead_results
Windows:
cl -Od rdtsc_overhead.c
rdtsc_overhead.exe 1000000 > windows_rdtsc_overhead_results
*/
int main(int argc, char **args) {
uint64_t tstart, tend, dummy;
int n, N;
N = atoi(args[1]);
tstart = rdtsc();
for (n = 0; n < N; ++n) {
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
dummy = rdtsc();
}
tend = rdtsc();
printf("%G\n", (double)(tend - tstart)/N/10);
return 0;
}
Код 6 : qtct_delta.c
#include <stdio.h>
#include <stdint.h>
#include <Windows.h>
/* Compiled & executed with:
cl -Od qtct_delta.c
qtct_delta.exe > windows_qtct_delta_results
*/
#define N 100000
int main(int argc, char **args) {
uint64_t ticks, results[N];
int n;
for (n = 0; n < N; ++n) {
QueryThreadCycleTime(GetCurrentThread(), &ticks);
results[n] = ticks;
}
printf("%s\t%s\n", "Absolute time", "Delta");
for (n = 1; n < N; ++n) {
printf("%lld\t%lld\n", results[n], results[n] - results[n-1]);
}
return 0;
}
Код 7 : qtct_overhead.c
#include <stdio.h>
#include <stdint.h>
#include <Windows.h>
/* Compiled & executed with:
cl -Od qtct_overhead.c
qtct_overhead.exe 1000000
*/
int main(int argc, char **args) {
uint64_t tstart, tend, ticks;
int n, N;
N = atoi(args[1]);
QueryThreadCycleTime(GetCurrentThread(), &tstart);
for (n = 0; n < N; ++n) {
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
QueryThreadCycleTime(GetCurrentThread(), &ticks);
}
QueryThreadCycleTime(GetCurrentThread(), &tend);
printf("%G\n", (double)(tend - tstart)/N/10);
return 0;
}