CentOS 5.6 与 CentOS 6.2

Question

我问了一个上一个问题当将应用程序从 RHEL 5 移动到 RHEL 6 时，尝试隔离 CPU 使用率增加的根源。我为此所做的分析似乎表明这是由内核中的 CFS 引起的。我编写了一个测试应用程序来尝试验证是否是这种情况（原始测试应用程序已删除以适应大小限制，但仍然可用git 仓库。

我在 RHEL 5 上使用以下命令编译它：

cc test_select_work.c -O2 -DSLEEP_TYPE=0 -Wall -Wextra -lm -lpthread -o test_select_work

然后我调整这些参数，直到 Dell Precision m6500 上每次迭代的执行时间约为 1 毫秒。

我在 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

在这两个版本中，这些结果都与我的预期一致，每次迭代的平均时间相对线性地缩放。然后我在 RHEL 5 上重新编译-DSLEEP_TYPE=1并得到以下结果：

./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 us，但这并不能解释 8 和 40 线程中意外的大幅增加线程案例。

我看到所有 3 个 -DSLEEP_TYPE 值都有类似的行为类型。我还尝试使用 sysctl 中的调度程序参数，但似乎没有什么对结果产生重大影响。关于如何进一步诊断这个问题有什么想法吗？

更新：2012-05-07

我从 /proc/stat//tasks//stat 添加了对用户和系统 CPU 使用情况的测量作为测试的输出，以尝试获得另一个观察点。我还发现了在添加外部迭代循环时引入的平均值和标准差更新方式的问题，因此我将添加具有校正后的平均值和标准差测量值的新图。我已经包含了更新的程序。我还制作了一个 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 <[email protected]>)
#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（双核 CPU）上重新运行了测试。我意识到其中几个将应用不同的补丁，并且不会是“纯内核代码”，但这是我可以在不同版本的内核上运行测试并进行比较的最简单方法。我用 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

CentOS 5.6 上每次迭代的挂钟时间 (gettimeofday) 比 6.2 变化更大，但这是有道理的，因为 CFS 应该能更好地为进程提供相等的 CPU 时间，从而获得更一致的结果。同样很明显的是，CentOS 6.2 在不同的休眠机制下，其休眠时间更准确、更一致。

在线程数量较少的 6.2 上，“惩罚”绝对是显而易见的（在 gettimeofday 和用户时间图上可见），但随着线程数量的增加，它似乎会减少（用户时间的差异可能只是一个会计问题，因为用户时间测量是理所当然的）。

系统时间图显示 6.2 中的睡眠机制比 5.6 中消耗更多的系统，这与之前对 50 个进程进行简单测试的结果相对应，这些进程仅调用 select 在 6.2 上消耗大量 CPU，但在 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 中看到的线程数量更高的情况。

select 和 poll 以及 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 与使用 BFS 的 Ubuntu 11.10

可以在以下位置找到在 Ubuntu 内核中使用 BFS 的 PPA：https://launchpad.net/~chogydan/+archive/ppa安装它是为了生成此比较。我找不到使用 BFS 运行 CentOS 6.2 的简单方法，因此我进行了此比较，由于 Ubuntu 11.10 的结果与 CentOS 6.2 的比较非常好，我相信这是一个公平且有意义的比较。

值得注意的主要一点是，对于 BFS，仅 select 和 nanosleep 在线程数量较少时会引发“惩罚”，但它似乎会引发与 CFS 较高线程数量时类似的“惩罚”（如果不是更大的话）。线程数。

另一个有趣的点是，BFS 的系统时间似乎比 CFS 低。再一次，由于数据的粗糙度，这开始如履薄冰，但似乎确实存在一些差异，并且该结果确实与简单的 50 个进程选择循环测试相匹配，并且确实显示 BFS 的 CPU 使用率比 CFS 低。

我从这两点得出的结论是，BFS 并没有解决问题，但至少在某些方面似乎减少了它的影响。

结论

如前所述，我不认为这是调度程序本身的问题，而是睡眠机制和调度程序之间的交互的问题。我认为本应睡眠且几乎不使用 CPU 的进程中 CPU 使用率的增加是 CentOS 5.6 的倒退，也是任何想要使用事件循环或轮询风格机制的程序的主要障碍。

我可以获取任何其他数据或可以运行测试来帮助进一步诊断问题吗？

2012 年 6 月 29 日更新

我把测试程序稍微简化了一下，可以发现这里（该帖子开始超出长度限制，因此必须移动它）。

Answer 1

根据SLES 11 SP2 发行说明这可能是对 CFS 实施方式的改变。

由于 SLES 11 SP2 是当前的 SLES 版本，因此此行为仍然有效（对于所有 3.x 内核似乎都是如此）。

此更改是有意为之的 - 但可能会产生“不良”副作用。也许所描述的解决方法之一对您有帮助......