Я задал предыдущий вопрос, чтобы попытаться изолировать источник увеличения загрузки ЦП при перемещении приложения из RHEL 5 в RHEL 6. Анализ, который я сделал для этого, по-видимому, указывает на то, что это вызвано CFS в ядре. Я написал тестовое приложение, чтобы попытаться проверить, так ли это (оригинальное тестовое приложение удалено, чтобы соответствовать ограничению размера, но все еще доступно в git repo .
Я скомпилировал его с помощью следующей команды на RHEL 5:
cc test_select_work.c -O2 -DSLEEP_TYPE=0 -Wall -Wextra -lm -lpthread -o test_select_work
Затем я играл с параметрами, пока время выполнения на одну итерацию не составило около 1 мс на Dell Precision m6500.
Я получил следующий результат на RHEL 5:
./test_select_work 1000 10000 300 4
time_per_iteration: min: 911.5 us avg: 913.7 us max: 917.1 us stddev: 2.4 us
./test_select_work 1000 10000 300 8
time_per_iteration: min: 1802.6 us avg: 1803.9 us max: 1809.1 us stddev: 2.1 us
./test_select_work 1000 10000 300 40
time_per_iteration: min: 7580.4 us avg: 8567.3 us max: 9022.0 us stddev: 299.6 us
И следующее на RHEL 6:
./test_select_work 1000 10000 300 4
time_per_iteration: min: 914.6 us avg: 975.7 us max: 1034.5 us stddev: 50.0 us
./test_select_work 1000 10000 300 8
time_per_iteration: min: 1683.9 us avg: 1771.8 us max: 1810.8 us stddev: 43.4 us
./test_select_work 1000 10000 300 40
time_per_iteration: min: 7997.1 us avg: 8709.1 us max: 9061.8 us stddev: 310.0 us
В обеих версиях эти результаты были примерно такими, как я ожидал, со средним количеством времени на итерацию, масштабируемым относительно линейно. Затем я перекомпилировал -DSLEEP_TYPE=1и получил следующие результаты на RHEL 5:
./test_select_work 1000 10000 300 4
time_per_iteration: min: 1803.3 us avg: 1902.8 us max: 2001.5 us stddev: 113.8 us
./test_select_work 1000 10000 300 8
time_per_iteration: min: 1997.1 us avg: 2002.0 us max: 2010.8 us stddev: 5.0 us
./test_select_work 1000 10000 300 40
time_per_iteration: min: 6958.4 us avg: 8397.9 us max: 9423.7 us stddev: 619.7 us
И следующие результаты по RHEL 6:
./test_select_work 1000 10000 300 4
time_per_iteration: min: 2107.1 us avg: 2143.1 us max: 2177.7 us stddev: 30.3 us
./test_select_work 1000 10000 300 8
time_per_iteration: min: 2903.3 us avg: 2903.8 us max: 2904.3 us stddev: 0.3 us
./test_select_work 1000 10000 300 40
time_per_iteration: min: 8877.7.1 us avg: 9016.3 us max: 9112.6 us stddev: 62.9 us
На RHEL 5 результаты были примерно такими, как я ожидал (4 потока занимали вдвое больше времени из-за 1 мс сна, но 8 потоков занимали одинаковое количество времени, так как каждый поток теперь спит около половины времени, и все еще довольно линейное увеличение).
Однако с RHEL 6 время, затрачиваемое на 4 потока, увеличилось примерно на 15% больше, чем ожидаемое удвоение, а случай с 8 потоками увеличился примерно на 45% больше, чем ожидаемое небольшое увеличение. Увеличение в случае с 4-мя потоками, по-видимому, заключается в том, что RHEL 6 фактически спит в течение нескольких микросекунд более 1 мс, в то время как RHEL 5 только спит около 900 мкс, но это не объясняет неожиданно большое увеличение 8 и 40. футляры
Я видел похожие типы поведения со всеми значениями 3 -DSLEEP_TYPE. Я также попытался поиграть с параметрами планировщика в sysctl, но ничто не оказало существенного влияния на результаты. Любые идеи о том, как я могу дополнительно диагностировать эту проблему?
ОБНОВЛЕНИЕ: 2012-05-07
Я добавил измерения использования процессора пользователем и системой из / proc / stat // tasks // stat в качестве результата теста, чтобы попытаться получить другую точку наблюдения. Я также обнаружил проблему со способом обновления среднего и стандартного отклонения, который появился, когда я добавил внешний цикл итерации, поэтому я добавлю новые графики, которые имеют исправленные измерения среднего и стандартного отклонения. Я включил обновленную программу. Я также сделал git-репо для отслеживания кода, и он доступен здесь.
#include <limits.h>
#include <math.h>
#include <poll.h>
#include <pthread.h>
#include <sched.h>
#include <stdio.h>
#include <stdlib.h>
#include <time.h>
#include <unistd.h>
#include <sys/select.h>
#include <sys/syscall.h>
#include <sys/time.h>
// Apparently GLIBC doesn't provide a wrapper for this function so provide it here
#ifndef HAS_GETTID
pid_t gettid(void)
{
return syscall(SYS_gettid);
}
#endif
// The different type of sleep that are supported
enum sleep_type {
SLEEP_TYPE_NONE,
SLEEP_TYPE_SELECT,
SLEEP_TYPE_POLL,
SLEEP_TYPE_USLEEP,
SLEEP_TYPE_YIELD,
SLEEP_TYPE_PTHREAD_COND,
SLEEP_TYPE_NANOSLEEP,
};
// Information returned by the processing thread
struct thread_res {
long long clock;
long long user;
long long sys;
};
// Function type for doing work with a sleep
typedef struct thread_res *(*work_func)(const int pid, const int sleep_time, const int num_iterations, const int work_size);
// Information passed to the thread
struct thread_info {
pid_t pid;
int sleep_time;
int num_iterations;
int work_size;
work_func func;
};
inline void get_thread_times(pid_t pid, pid_t tid, unsigned long long *utime, unsigned long long *stime)
{
char filename[FILENAME_MAX];
FILE *f;
sprintf(filename, "/proc/%d/task/%d/stat", pid, tid);
f = fopen(filename, "r");
if (f == NULL) {
*utime = 0;
*stime = 0;
return;
}
fscanf(f, "%*d %*s %*c %*d %*d %*d %*d %*d %*u %*u %*u %*u %*u %Lu %Lu", utime, stime);
fclose(f);
}
// In order to make SLEEP_TYPE a run-time parameter function pointers are used.
// The function pointer could have been to the sleep function being used, but
// then that would mean an extra function call inside of the "work loop" and I
// wanted to keep the measurements as tight as possible and the extra work being
// done to be as small/controlled as possible so instead the work is declared as
// a seriees of macros that are called in all of the sleep functions. The code
// is a bit uglier this way, but I believe it results in a more accurate test.
// Fill in a buffer with random numbers (taken from latt.c by Jens Axboe <jens.axboe@oracle.com>)
#define DECLARE_FUNC(NAME) struct thread_res *do_work_##NAME(const int pid, const int sleep_time, const int num_iterations, const int work_size)
#define DECLARE_WORK() \
int *buf; \
int pseed; \
int inum, bnum; \
pid_t tid; \
struct timeval clock_before, clock_after; \
unsigned long long user_before, user_after; \
unsigned long long sys_before, sys_after; \
struct thread_res *diff; \
tid = gettid(); \
buf = malloc(work_size * sizeof(*buf)); \
diff = malloc(sizeof(*diff)); \
get_thread_times(pid, tid, &user_before, &sys_before); \
gettimeofday(&clock_before, NULL)
#define DO_WORK(SLEEP_FUNC) \
for (inum=0; inum<num_iterations; ++inum) { \
SLEEP_FUNC \
\
pseed = 1; \
for (bnum=0; bnum<work_size; ++bnum) { \
pseed = pseed * 1103515245 + 12345; \
buf[bnum] = (pseed / 65536) % 32768; \
} \
} \
#define FINISH_WORK() \
gettimeofday(&clock_after, NULL); \
get_thread_times(pid, tid, &user_after, &sys_after); \
diff->clock = 1000000LL * (clock_after.tv_sec - clock_before.tv_sec); \
diff->clock += clock_after.tv_usec - clock_before.tv_usec; \
diff->user = user_after - user_before; \
diff->sys = sys_after - sys_before; \
free(buf); \
return diff
DECLARE_FUNC(nosleep)
{
DECLARE_WORK();
// Let the compiler know that sleep_time isn't used in this function
(void)sleep_time;
DO_WORK();
FINISH_WORK();
}
DECLARE_FUNC(select)
{
struct timeval ts;
DECLARE_WORK();
DO_WORK(
ts.tv_sec = 0;
ts.tv_usec = sleep_time;
select(0, 0, 0, 0, &ts);
);
FINISH_WORK();
}
DECLARE_FUNC(poll)
{
struct pollfd pfd;
const int sleep_time_ms = sleep_time / 1000;
DECLARE_WORK();
pfd.fd = 0;
pfd.events = 0;
DO_WORK(
poll(&pfd, 1, sleep_time_ms);
);
FINISH_WORK();
}
DECLARE_FUNC(usleep)
{
DECLARE_WORK();
DO_WORK(
usleep(sleep_time);
);
FINISH_WORK();
}
DECLARE_FUNC(yield)
{
DECLARE_WORK();
// Let the compiler know that sleep_time isn't used in this function
(void)sleep_time;
DO_WORK(
sched_yield();
);
FINISH_WORK();
}
DECLARE_FUNC(pthread_cond)
{
pthread_cond_t cond = PTHREAD_COND_INITIALIZER;
pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;
struct timespec ts;
const int sleep_time_ns = sleep_time * 1000;
DECLARE_WORK();
pthread_mutex_lock(&mutex);
DO_WORK(
clock_gettime(CLOCK_REALTIME, &ts);
ts.tv_nsec += sleep_time_ns;
if (ts.tv_nsec >= 1000000000) {
ts.tv_sec += 1;
ts.tv_nsec -= 1000000000;
}
pthread_cond_timedwait(&cond, &mutex, &ts);
);
pthread_mutex_unlock(&mutex);
pthread_cond_destroy(&cond);
pthread_mutex_destroy(&mutex);
FINISH_WORK();
}
DECLARE_FUNC(nanosleep)
{
struct timespec req, rem;
const int sleep_time_ns = sleep_time * 1000;
DECLARE_WORK();
DO_WORK(
req.tv_sec = 0;
req.tv_nsec = sleep_time_ns;
nanosleep(&req, &rem);
);
FINISH_WORK();
}
void *do_test(void *arg)
{
const struct thread_info *tinfo = (struct thread_info *)arg;
// Call the function to do the work
return (*tinfo->func)(tinfo->pid, tinfo->sleep_time, tinfo->num_iterations, tinfo->work_size);
}
struct thread_res_stats {
double min;
double max;
double avg;
double stddev;
double prev_avg;
};
#ifdef LLONG_MAX
#define THREAD_RES_STATS_INITIALIZER {LLONG_MAX, LLONG_MIN, 0, 0, 0}
#else
#define THREAD_RES_STATS_INITIALIZER {LONG_MAX, LONG_MIN, 0, 0, 0}
#endif
void update_stats(struct thread_res_stats *stats, long long value, int num_samples, int num_iterations, double scale_to_usecs)
{
// Calculate the average time per iteration
double value_per_iteration = value * scale_to_usecs / num_iterations;
// Update the max and min
if (value_per_iteration < stats->min)
stats->min = value_per_iteration;
if (value_per_iteration > stats->max)
stats->max = value_per_iteration;
// Update the average
stats->avg += (value_per_iteration - stats->avg) / (double)(num_samples);
// Update the standard deviation
stats->stddev += (value_per_iteration - stats->prev_avg) * (value_per_iteration - stats->avg);
// And record the current average for use in the next update
stats->prev_avg= stats->avg;
}
void print_stats(const char *name, const struct thread_res_stats *stats)
{
printf("%s: min: %.1f us avg: %.1f us max: %.1f us stddev: %.1f us\n",
name,
stats->min,
stats->avg,
stats->max,
stats->stddev);
}
int main(int argc, char **argv)
{
if (argc <= 6) {
printf("Usage: %s <sleep_time> <outer_iterations> <inner_iterations> <work_size> <num_threads> <sleep_type>\n", argv[0]);
printf(" outer_iterations: Number of iterations for each thread (used to calculate statistics)\n");
printf(" inner_iterations: Number of work/sleep cycles performed in each thread (used to improve consistency/observability))\n");
printf(" work_size: Number of array elements (in kb) that are filled with psuedo-random numbers\n");
printf(" num_threads: Number of threads to spawn and perform work/sleep cycles in\n");
printf(" sleep_type: 0=none 1=select 2=poll 3=usleep 4=yield 5=pthread_cond 6=nanosleep\n");
return -1;
}
struct thread_info tinfo;
int outer_iterations;
int sleep_type;
int s, inum, tnum, num_samples, num_threads;
pthread_attr_t attr;
pthread_t *threads;
struct thread_res *res;
struct thread_res **times;
// Track the stats for each of the measurements
struct thread_res_stats stats_clock = THREAD_RES_STATS_INITIALIZER;
struct thread_res_stats stats_user = THREAD_RES_STATS_INITIALIZER;
struct thread_res_stats stats_sys = THREAD_RES_STATS_INITIALIZER;
// Calculate the conversion factor from clock_t to seconds
const long clocks_per_sec = sysconf(_SC_CLK_TCK);
const double clocks_to_usec = 1000000 / (double)clocks_per_sec;
// Get the parameters
tinfo.pid = getpid();
tinfo.sleep_time = atoi(argv[1]);
outer_iterations = atoi(argv[2]);
tinfo.num_iterations = atoi(argv[3]);
tinfo.work_size = atoi(argv[4]) * 1024;
num_threads = atoi(argv[5]);
sleep_type = atoi(argv[6]);
switch (sleep_type) {
case SLEEP_TYPE_NONE: tinfo.func = &do_work_nosleep; break;
case SLEEP_TYPE_SELECT: tinfo.func = &do_work_select; break;
case SLEEP_TYPE_POLL: tinfo.func = &do_work_poll; break;
case SLEEP_TYPE_USLEEP: tinfo.func = &do_work_usleep; break;
case SLEEP_TYPE_YIELD: tinfo.func = &do_work_yield; break;
case SLEEP_TYPE_PTHREAD_COND: tinfo.func = &do_work_pthread_cond; break;
case SLEEP_TYPE_NANOSLEEP: tinfo.func = &do_work_nanosleep; break;
default:
printf("Invalid sleep type: %d\n", sleep_type);
return -7;
}
// Initialize the thread creation attributes
s = pthread_attr_init(&attr);
if (s != 0) {
printf("Error initializing thread attributes\n");
return -2;
}
// Allocate the memory to track the threads
threads = calloc(num_threads, sizeof(*threads));
times = calloc(num_threads, sizeof(*times));
if (threads == NULL) {
printf("Error allocating memory to track threads\n");
return -3;
}
// Initialize the number of samples
num_samples = 0;
// Perform the requested number of outer iterations
for (inum=0; inum<outer_iterations; ++inum) {
// Start all of the threads
for (tnum=0; tnum<num_threads; ++tnum) {
s = pthread_create(&threads[tnum], &attr, &do_test, &tinfo);
if (s != 0) {
printf("Error starting thread\n");
return -4;
}
}
// Wait for all the threads to finish
for (tnum=0; tnum<num_threads; ++tnum) {
s = pthread_join(threads[tnum], (void **)(&res));
if (s != 0) {
printf("Error waiting for thread\n");
return -6;
}
// Save the result for processing when they're all done
times[tnum] = res;
}
// For each of the threads
for (tnum=0; tnum<num_threads; ++tnum) {
// Increment the number of samples in the statistics
++num_samples;
// Update the statistics with this measurement
update_stats(&stats_clock, times[tnum]->clock, num_samples, tinfo.num_iterations, 1);
update_stats(&stats_user, times[tnum]->user, num_samples, tinfo.num_iterations, clocks_to_usec);
update_stats(&stats_sys, times[tnum]->sys, num_samples, tinfo.num_iterations, clocks_to_usec);
// And clean it up
free(times[tnum]);
}
}
// Clean up the thread creation attributes
s = pthread_attr_destroy(&attr);
if (s != 0) {
printf("Error cleaning up thread attributes\n");
return -5;
}
// Finish the calculation of the standard deviation
stats_clock.stddev = sqrtf(stats_clock.stddev / (num_samples - 1));
stats_user.stddev = sqrtf(stats_user.stddev / (num_samples - 1));
stats_sys.stddev = sqrtf(stats_sys.stddev / (num_samples - 1));
// Print out the statistics of the times
print_stats("gettimeofday_per_iteration", &stats_clock);
print_stats("utime_per_iteration", &stats_user);
print_stats("stime_per_iteration", &stats_sys);
// Clean up the allocated threads and times
free(threads);
free(times);
return 0;
}
Я перезапустил тесты на Dell Vostro 200 (двухъядерный процессор) с несколькими различными версиями ОС. Я понимаю, что к некоторым из них будут применены различные патчи, и они не будут "чистым кодом ядра", но это был самый простой способ, которым я мог запустить тесты на разных версиях ядра и получить сравнения. Я создал графики с помощью gnuplot и включил версию из bugzilla об этой проблеме .
Все эти тесты были выполнены с помощью следующей команды со следующим сценарием и этой командой ./run_test 1000 10 1000 250 8 6 <os_name>.
#!/bin/bash
if [ $# -ne 7 ]; then
echo "Usage: `basename $0` <sleep_time> <outer_iterations> <inner_iterations> <work_size> <max_num_threads> <max_sleep_type> <test_name>"
echo " max_num_threads: The highest value used for num_threads in the results"
echo " max_sleep_type: The highest value used for sleep_type in the results"
echo " test_name: The name of the directory where the results will be stored"
exit -1
fi
sleep_time=$1
outer_iterations=$2
inner_iterations=$3
work_size=$4
max_num_threads=$5
max_sleep_type=$6
test_name=$7
# Make sure this results directory doesn't already exist
if [ -e $test_name ]; then
echo "$test_name already exists";
exit -1;
fi
# Create the directory to put the results in
mkdir $test_name
# Run through the requested number of SLEEP_TYPE values
for i in $(seq 0 $max_sleep_type)
do
# Run through the requested number of threads
for j in $(seq 1 $max_num_threads)
do
# Print which settings are about to be run
echo "sleep_type: $i num_threads: $j"
# Run the test and save it to the results file
./test_sleep $sleep_time $outer_iterations $inner_iterations $work_size $j $i >> "$test_name/results_$i.txt"
done
done
Вот краткое изложение того, что я наблюдал. На этот раз я буду сравнивать их попарно, потому что думаю, что это немного более информативно.
CentOS 5.6 против CentOS 6.2
Время настенных часов (gettimeofday) на итерацию в CentOS 5.6 более разнообразно, чем в 6.2, но это имеет смысл, так как CFS должен лучше справляться с предоставлением процессам равного времени ЦП, что приводит к более согласованным результатам. Также совершенно очевидно, что CentOS 6.2 более точен и согласован по времени, в течение которого он спит с различными механизмами сна.
«Штраф» определенно очевиден в 6.2 с небольшим числом потоков (видимым на графиках gettimeofday и user time), но, по-видимому, он уменьшается при большем количестве потоков (разница во времени пользователя может быть просто проблемой учета, поскольку пользовательские измерения времени таковы).
График системного времени показывает, что механизмы сна в 6.2 потребляют больше системы, чем в 5.6, что соответствует предыдущим результатам простого теста 50 процессов, просто вызывающего select, потребляющего нетривиальное количество ЦП на 6.2, но не 5.6 ,
Я считаю, что стоит отметить, что использование sched_yield () не влечет за собой то же наказание, что и методы sleep. Из этого я заключаю, что источником проблемы является не сам планировщик, а проблема взаимодействия методов сна с планировщиком.
Ubuntu 7.10 против Ubuntu 8.04-4
Разница в версии ядра между этими двумя версиями меньше, чем в CentOS 5.6 и 6.2, но они все еще охватывают период времени, когда был введен CFS. Первый интересный результат заключается в том, что select и poll, кажется, являются единственными механизмами ожидания, которые имеют «штраф» на 8.04, и этот штраф продолжается для большего числа потоков, чем было замечено в CentOS 6.2.
Время пользователя для выбора и опроса и Ubuntu 7.10 неоправданно мало, так что, похоже, это была какая-то проблема учета, существовавшая тогда, но я считаю, что она не имеет отношения к текущей проблеме / обсуждению.
Похоже, что системное время в Ubuntu 8.04 выше, чем в Ubuntu 7.10, но эта разница на порядок меньше, чем в CentOS 5.6 против 6.2.
Примечания по Ubuntu 11.10 и Ubuntu 12.04
Первое, что следует здесь отметить, это то, что графики для Ubuntu 12.04 были сопоставимы с графиками из 11.10, поэтому они не показывают, чтобы предотвратить ненужную избыточность.
В целом графики для Ubuntu 11.10 показывают ту же тенденцию, что и в CentOS 6.2 (что указывает на то, что это проблема ядра в целом, а не только проблема RHEL). Единственное исключение состоит в том, что системное время кажется немного выше в Ubuntu 11.10, чем в CentOS 6.2, но, опять же, разрешение этого измерения очень естественное, поэтому я думаю, что любой вывод, отличный от «, кажется, немного выше». "будет наступать на тонкий лед.
Ubuntu 11.10 против Ubuntu 11.10 с BFS
PPA, который использует BFS с ядром Ubuntu, можно найти по адресу https://launchpad.net/~chogydan/+archive/ppa, и он был установлен для создания этого сравнения. Я не смог найти простой способ запустить CentOS 6.2 с BFS, поэтому я побежал с этим сравнением, и, поскольку результаты Ubuntu 11.10 так хорошо сравниваются с CentOS 6.2, я считаю, что это справедливое и содержательное сравнение.
Важным моментом является то, что при BFS только select и nanosleep вызывают «штраф» при небольшом количестве потоков, но, похоже, он вызывает такой же «штраф» (если не больший), как при CFS для более высокого уровня. количество потоков.
Другим интересным моментом является то, что системное время оказывается ниже с BFS, чем с CFS. Еще раз, это начинает наступать на тонкий лед из-за грубости данных, но некоторая разница, кажется, присутствует, и этот результат действительно совпадает с простым тестом с циклом выбора процесса из 50, который показал меньшее использование CPU с BFS, чем с CFS ,
Вывод, который я делаю из этих двух моментов, заключается в том, что BFS не решает проблему, но, по крайней мере, похоже, уменьшает ее влияние в некоторых областях.
Вывод
Как уже говорилось ранее, я не считаю, что это проблема самого планировщика, а взаимодействия между спящими механизмами и планировщиком. Я считаю, что повышенное использование ЦП в процессах, которые должны быть спящими и практически не использующими ЦП, является регрессом из CentOS 5.6 и основным препятствием для любой программы, которая хочет использовать цикл обработки событий или стиль опроса.
Есть ли какие-либо другие данные, которые я могу получить или тесты, которые я могу выполнить, чтобы помочь дальнейшей диагностике проблемы?
Обновление от 29 июня 2012 г.
Я немного упростил программу тестирования и ее можно найти здесь (пост начинал превышать ограничение длины, поэтому пришлось его перемещать).
источник
Ответы:
В соответствии с примечаниями к выпуску SLES 11 SP2 это может быть изменение, внесенное в способ реализации CFS.
Поскольку SLES 11 SP2 является текущей версией SLES, это поведение остается в силе (как это кажется для всех 3.x-ядер).
Это изменение было задумано, но может иметь «плохие» побочные эффекты. Возможно, один из описанных обходных путей поможет вам ...
источник