8.7.1 eProf — встраиваемый профилировщик

Во время разработки программы вы часто хотите узнать время, которое требуется функции для выполнения, или время, необходимое, чтобы добраться из одной точки программы в другую. На этом этапе вам не нужен полномасштабный профилировщик. Вы можете написать свой собственный профилировщик (который авторы называют eProf), чтобы помочь себе в случае потребности малого профилирования. eProf представляет собой профилировщик на базе функций. Предоставляемые интерфейсы могут быть встроены в программу для измерения задержки исполнения между любыми двумя точками в программе. eProf предоставляет несколько экземпляров профилировщика, каждый экземпляр которого способен измерять время в различных программных областях в одно и то же время. Предоставляемые интерфейсы перечислены в Таблице 8.3.

Таблица 8.3 Функции eProf

Давайте сначала рассмотрим использование этих интерфейсов, а потом их реализацию. В Распечатке 8.9 мы профилируем две функции, которые выполняются параллельно. Запустите программу из Распечатки 8.9, чтобы получить результаты профилирования.

# gcc –o prof prof.c eprof.c -lpthread

# ./prof

eProf Result:

ID name           calls     usec/call

---------------------------------------------------

0: func1             1       10018200

1: func2            10         501894

eprof_print печатает данные профилирования всех экземпляров. Выходные данные показывают:

▪Идентификатор экземпляра профилировщика

▪Имя экземпляра профилировщика

▪Количество раз вызова экземпляра (то есть, сколько раз была вызвана пара eprof_start и eprof_stop)

▪Среднее время выполнения кода в микросекундах от вызова eprof_start до eprof_stop

Реализация eProf

В этом разделе мы рассмотрим реализацию eProf.

/*** eprof.c ***/

#include <stdio.h>

#include <sys/time.h>

MAX_INSTANCE определяет общее количество экземпляров профилировщика, поддерживаемое eProf. Вы можете изменить это значение для поддержки большего числа экземпляров профилировщика.

#define MAX_INSTANCE 5

Структуры данных eProf включают поле eprof_curr, которое содержит текущую метку времени и заполняется функцией eprof_start. eprof_diff хранит разницу в метках времени, записанных eprof_stop и eprof_start. eprof_calls хранит число, сколько раз для данного экземпляра была вызвана пара eprof_start - eprof_stop. Наконец, eprof_label хранит метку экземпляра. Оно заполняется функцией eprof_alloc.

/* Хранит текущую метку времени. Заполняется в eprof_start */

long long int eprof_curr[MAX_INSTANCE] ;

/*

 * timestamp(eprof_stop) – timestamp(eprof_start).

 * Заполняется в eprof_stop

 */

long long int eprof_diff[MAX_INSTANCE] ;

/*

 * Сколько раз была вызвана пара {eprof_start,eprof_stop}

 */

long eprof_calls[MAX_INSTANCE] ;

/* Метка экземпляра */

char * eprof_label[MAX_INSTANCE] ;

get_curr_time является ядром eProf. Она записывает текущее время. Для достижения высокой точности результатов профилирования необходимо, что эта функция была реализована с использованием источника времени высокого разрешения. Некоторые из вариантов:

▪Использование аппаратных счётчиков, таких как Time Stamp Counter (TSC) на Pentium. get_curr_time может быть реализована с использованием TSC, как показано ниже.
 
static unsigned long long get_curr_time()
{
 unsigned long long int x;
 __asm__ volatile("rdtsc" : "=A"(x));
 
 /* convert x to microseconds */
 
 return x;
}

▪Использование таймеров высокого разрешения POSIX (High-Resolution POSIX Timers, HRT), если они доступны. Для получения информации об их использовании обратитесь к Главе 7.

▪Если ваша целевая платформа обеспечивает поддержку аппаратных таймеров высокого разрешения, то они могли бы быть использованы. Обычно интерфейсы для доступа к аппаратным таймерам недоступны в пространстве пользователя. Для экспорта таких интерфейсов в пространство пользователя вы можете использовать драйвер kapi, описанный в Главе 6.

▪Наконец, если нет аппаратного источника времени, для получения текущего времени можно использовать gettimeofday.Точность gettimeofday определяется системными часами. Так, если значение HZ равно 100, точность составляет 10 мс. Если значение HZ равно 1000, точность составляет 1 мс.
 
/* Возвращаем текущее время */
static unsigned long long get_curr_time(){
 struct timeval tv;
 gettimeofday(&tv,NULL);
 return tv.tv_sec*1000000 + tv.tv_usec;
}

Различные структуры данных инициализирует eprof_init.

/* Инициализация */

void eprof_init () {

  int i;

  for (i=0; i<MAX_INSTANCE; i++) {

    eprof_diff[i] = 0;

    eprof_curr[i] = 0;

    eprof_calls[i] = 0;

    eprof_label[i] = NULL;

  }

}

eprof_alloc создаёт экземпляр профилировщика. Она проверяет число ненулевых записей в eprof_label и возвращает соответствующий индекс.

int eprof_alloc(char *label) {

  int id;

  for (id = 0; id < MAX_INSTANCE &&

                    eprof_label[id] != NULL; id++)

    ;

  if (id == MAX_INSTANCE)

    return -1;

  /* Store the label and return index */

  eprof_label[id] = label;

  return id;

}

eprof_start записывает в eprof_curr текущее время.

void eprof_start(int id) {

  if (id >= 0 && id < MAX_INSTANCE)

    eprof_curr[id] = get_curr_time();

}

eprof_stop сохраняет в eprof_diff разницу времени между моментом вызова себя и временем в eprof_curr. Напомним, что eprof_curr заполняется в eprof_start. Она также отслеживает в eprof_calls, сколько раз был вызван данный экземпляр профилировщика.

void eprof_stop(int id) {

  if (id >= 0 && id < MAX_INSTANCE) {

    eprof_diff[id] += get_curr_time() - eprof_curr[id];

    eprof_calls[id]++;

  }

}

eprof_free освобождает запись в eprof_label.

void eprof_free(char *label){

  int id;

  for (id = 0; id < MAX_INSTANCE &&

                  strcmp(label,eprof_label[id]) != 0; id++)

    ;

  if (id < MAX_INSTANCE)

    eprof_label[id] = NULL;

}

eprof_print в большей степени является функцией форматирования. Она печатает данные профилирования всех экземпляров профилировщика.

void eprof_print () {

  int i;

  printf ("\neProf Result:\n\n"

          "%s %.15s %20s %10s\n"

  "---------------------------------------------------\n",

          "ID", "name", "calls", "usec/call");

  for (i=0; i<MAX_INSTANCE; i++) {

    if (eprof_label[i]) {

      printf ("%d: %.15s %20d", i, eprof_label[i],

                                  eprof_calls[i]);

      if (eprof_calls[i])

        printf(" %15lld", eprof_diff[i] / eprof_calls[i]);

      printf ("\n");

    }

  }

}