CentOS 5.6およびCentOS 6.2

CentOS 5.6およびCentOS 6.2

私は尋ねた前の質問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つのスレッドは1msのスリープ時間のために2倍の時間がかかりましたが、8つのスレッドは今、各スレッドが約半分の時間を眠りに落ちたため、同じ時間がかかり、まだかなり良いです。)増加)。

ただし、RHEL 6では、4スレッドダブリングに必要な時間が予想ダブリングより約15%増加し、8スレッドの場合、予想小幅増加より約45%増加しました。 4スレッドケースの増加は、RHEL 6が実際に1ミリ秒間数マイクロ秒間休止しているのに対し、RHEL 5は約900usの間だけ休眠しているように見えますが、これは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;
}

いくつかのバージョンのOSを搭載した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から6.2よりも繰り返しごとのウォールクロック時間(gettimeofday)は異なりますが、CFSがプロセスに同じCPU時間を提供するのに優れているため、一貫した結果が得られるため、これは意味があります。 CentOS 6.2は、さまざまな省電力メカニズムでより正確で一貫した省電力時間を提供することも明らかです。 CentOS 5.6の場合はgettimeofday CentOS 6.2 gettimeofday

スレッド数が少ない6.2では、「ペナルティ」は確かに目立っていますが(gettimeofdayとユーザー時間グラフで見ることができます)、スレッド数が増えるにつれて減少しているように見えます(ユーザー時間の違いは単に会計上の問題かもしれません。測定のため当然受け入れられる)。

ユタイムCentOS 5.6 ユタイムCentOS 6.2

システム時間グラフは、省電力メカニズムが5.6より6.2でより多くのシステムを消費することを示しています。これは6.2で多くのCPUを消費しましたが、5.6ではそうでなかったselectを呼び出した前の50プロセスの簡単なテスト結果に対応します。それ以外の場合。

タイムセントOS 5.6 タイムセントOS 6.2

sched_yield() を使うと sleep メソッドと同じペナルティが発生しないという点に注目する価値があると思います。私の結論は、問題の原因はスケジューラ自体ではなく、スケジューラとスリープメソッドの相互作用であるということです。

Ubuntu 7.10とUbuntu 8.04-4

2つのカーネルバージョンの違いはCentOS 5.6と6.2よりも小さいですが、まだCFSが導入されている期間にわたっています。最初の興味深い結果は、selectとpollが8.04で「ペナルティが適用される」唯一の省電力メカニズムとして現れ、このペナルティはCentOS 6.2で見られるよりも高いスレッド数で持続することです。

Ubuntu 7.10時間取得 Ubuntu 8.04-4時間取得

Ubuntu 7.10の選択とポーリングとユーザー時間が低すぎるため、当時の種類の会計上の問題のようですが、現在の質問/議論とは関係がないと思います。

ウーテムUbuntu 7.10 ユタイムUbuntu 8.04-4

Ubuntu 8.04はUbuntu 7.10よりもシステム時間が長いようですが、CentOS 5.6と6.2と比較して、その違いははるかに明白ではありません。

時間Ubuntu 7.10 時間Ubuntu 8.04-4

Ubuntu 11.10およびUbuntu 12.04に関する注意事項

ここで最初に注目すべき点は、Ubuntu 12.04プロットは11.10プロットに似ているため、不要な重複を防ぐために表示されていないことです。

全体的に、Ubuntu 11.10のグラフはCentOS 6.2で観察されたのと同じ傾向を示しています(これは単純なRHEL問題ではなく一般的なカーネル問題であることを示唆しています)。唯一の例外はUbuntu 11.10のシステム時間がCentOS 6.2に比べてやや高いようですが、今回もこの測定の解像度は非常に自然なので「少し高いようだ」以外の結論は出ていないようです。薄い氷の上になければなりません。

BFSを使用したUbuntu 11.10およびUbuntu 11.10

UbuntuカーネルでBFSを使用するためのPPAは、次の場所にあります。https://launchpad.net/~chogydan/+archive/ppaこの比較を生成するためにインストールされました。 BFSを使用してCentOS 6.2を簡単に実行できる方法が見つからず、このように比較することになりましたが、Ubuntu 11.10の結果がCentOS 6.2と非常によく比較されたため、公正で意味のある比較だと思います。

Ubuntu 11.10時間取得 BFSを使用したUbuntu 11.10 gettimeofday

注目すべき重要な点は、BFSを使用すると、より低いスレッド番号ではselectとnanosleepだけが「ペナルティ」になりますが、より高いスレッド番号ではCFSに似た(それほど大きくはありませんが)「ペナルティ」が発生するようです。スレッド。

ユタイムUbuntu 11.10 utime Ubuntu 11.10とBFS

もう一つの興味深い点は、BFSのシステム時間がCFSよりも短いようです。繰り返しますが、これはデータの粗さのために薄い氷から始まりますが、わずかな違いがあるように見え、結果は単純な50プロセス選択ループテストと一致し、CFSよりBFSのCPU使用率が低くなります。

時間Ubuntu 11.10 Ubuntu 11.10とBFS

これら2つの点についての私の結論は、BFSが問題を解決することはできませんが、少なくともいくつかの点ではその影響を減らすようです。

結論として

前述のように、これはスケジューラ自体の問題ではなく、スリープメカニズムとスケジューラ間の相互作用に問題があると考えています。私は、CPUをほとんど使用せずに省電力モードにする必要があるプロセスのCPU使用率の増加が、CentOS 5.6の障害であり、イベントループやポーリングスタイルメカニズムを使用したいすべてのプログラムの主な障害と考えています。

問題をより詳細に診断するのに役立つように取得できる追加データまたは実行できるテストはありますか?

2012年6月29日更新

テストプログラムを少し簡素化した結果、次のことがわかりました。ここ(投稿が長さ制限を超え始めて移動するようになりました。)

ベストアンサー1

~によるとSLES 11 SP2 リリースノートこれはCFS実装方法の変更かもしれません。

SLES 11 SP2は現在SLESバージョンなので、この動作はまだ有効です(すべての3.xカーネルに対応しているようです)。

これらの変更は意図的なものですが、「望ましくない」副作用がある可能性があります。おそらく説明された解決策の1つが役に立ちます。

おすすめ記事