Легко измерить прошедшее время - PullRequest
258 голосов
/ 11 мая 2010

Я пытаюсь использовать time () для измерения различных точек моей программы.

Что я не понимаю, так это то, почему значения до и после одинаковы?Я понимаю, что это не лучший способ для профилирования моей программы, я просто хочу посмотреть, как долго что-то займет.

printf("**MyProgram::before time= %ld\n", time(NULL));

doSomthing();
doSomthingLong();

printf("**MyProgram::after time= %ld\n", time(NULL));

Я пытался:

struct timeval diff, startTV, endTV;

gettimeofday(&startTV, NULL); 

doSomething();
doSomethingLong();

gettimeofday(&endTV, NULL); 

timersub(&endTV, &startTV, &diff);

printf("**time taken = %ld %ld\n", diff.tv_sec, diff.tv_usec);

Как мне прочитать результат **time taken = 0 26339?Означает ли это, что 26339 наносекунд = 26,3 мсек?

Как насчет **time taken = 4 45025, это значит 4 секунды и 25 мсек?

Ответы [ 23 ]

7 голосов
/ 03 декабря 2016
#include <ctime>
#include <cstdio>
#include <iostream>
#include <chrono>
#include <sys/time.h>
using namespace std;
using namespace std::chrono;

void f1()
{
  high_resolution_clock::time_point t1 = high_resolution_clock::now();
  high_resolution_clock::time_point t2 = high_resolution_clock::now();
  double dif = duration_cast<nanoseconds>( t2 - t1 ).count();
  printf ("Elasped time is %lf nanoseconds.\n", dif );
}

void f2()
{
  timespec ts1,ts2;
  clock_gettime(CLOCK_REALTIME, &ts1);
  clock_gettime(CLOCK_REALTIME, &ts2);
  double dif = double( ts2.tv_nsec - ts1.tv_nsec );
  printf ("Elasped time is %lf nanoseconds.\n", dif );
}

void f3()
{
  struct timeval t1,t0;
  gettimeofday(&t0, 0);
  gettimeofday(&t1, 0);
  double dif = double( (t1.tv_usec-t0.tv_usec)*1000);
  printf ("Elasped time is %lf nanoseconds.\n", dif );
}
void f4()
{
  high_resolution_clock::time_point t1 , t2;
  double diff = 0;
  t1 = high_resolution_clock::now() ;
  for(int i = 1; i <= 10 ; i++)
  {
    t2 = high_resolution_clock::now() ;
    diff+= duration_cast<nanoseconds>( t2 - t1 ).count();
    t1 = t2;
  }
  printf ("high_resolution_clock:: Elasped time is %lf nanoseconds.\n", diff/10 );
}

void f5()
{
  timespec ts1,ts2;
  double diff = 0;
  clock_gettime(CLOCK_REALTIME, &ts1);
  for(int i = 1; i <= 10 ; i++)
  {
    clock_gettime(CLOCK_REALTIME, &ts2);
    diff+= double( ts2.tv_nsec - ts1.tv_nsec );
    ts1 = ts2;
  }
  printf ("clock_gettime:: Elasped time is %lf nanoseconds.\n", diff/10 );
}

void f6()
{
  struct timeval t1,t2;
  double diff = 0;
  gettimeofday(&t1, 0);
  for(int i = 1; i <= 10 ; i++)
  {
    gettimeofday(&t2, 0);
    diff+= double( (t2.tv_usec-t1.tv_usec)*1000);
    t1 = t2;
  }
  printf ("gettimeofday:: Elasped time is %lf nanoseconds.\n", diff/10 );
}

int main()
{
  //  f1();
  //  f2();
  //  f3();
  f6();
  f4();
  f5();
  return 0;
}
4 голосов
/ 12 марта 2018

C ++ std :: chrono имеет явное преимущество кроссплатформенности. Однако это также приводит к значительным накладным расходам по сравнению с POSIX clock_gettime (). На моем Linux-компьютере все std::chrono::xxx_clock::now() версии работают примерно одинаково:

std::chrono::system_clock::now()
std::chrono::steady_clock::now()
std::chrono::high_resolution_clock::now()

Хотя POSIX clock_gettime(CLOCK_MONOTONIC, &time) должен быть таким же, как steady_clock::now(), но он более чем в 3 раза быстрее!

Вот мой тест на полноту.

#include <stdio.h>
#include <chrono>
#include <ctime>

void print_timediff(const char* prefix, const struct timespec& start, const 
struct timespec& end)
{
    double milliseconds = end.tv_nsec >= start.tv_nsec
                        ? (end.tv_nsec - start.tv_nsec) / 1e6 + (end.tv_sec - start.tv_sec) * 1e3
                        : (start.tv_nsec - end.tv_nsec) / 1e6 + (end.tv_sec - start.tv_sec - 1) * 1e3;
    printf("%s: %lf milliseconds\n", prefix, milliseconds);
}

int main()
{
    int i, n = 1000000;
    struct timespec start, end;

    // Test stopwatch
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i) {
        struct timespec dummy;
        clock_gettime(CLOCK_MONOTONIC, &dummy);
    }
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("clock_gettime", start, end);

    // Test chrono system_clock
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i)
        auto dummy = std::chrono::system_clock::now();
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("chrono::system_clock::now", start, end);

    // Test chrono steady_clock
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i)
        auto dummy = std::chrono::steady_clock::now();
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("chrono::steady_clock::now", start, end);

    // Test chrono high_resolution_clock
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i)
        auto dummy = std::chrono::high_resolution_clock::now();
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("chrono::high_resolution_clock::now", start, end);

    return 0;
}

И это вывод, который я получаю при компиляции с gcc7.2 -O3:

clock_gettime: 24.484926 milliseconds
chrono::system_clock::now: 85.142108 milliseconds
chrono::steady_clock::now: 87.295347 milliseconds
chrono::high_resolution_clock::now: 84.437838 milliseconds
3 голосов
/ 11 мая 2010

Функциональный вызов time(NULL) вернет количество секунд, прошедшее с момента epoc: 1 января 1970 года. Возможно, вам нужно взять разницу между двумя временными метками:

size_t start = time(NULL);
doSomthing();
doSomthingLong();

printf ("**MyProgram::time elapsed= %lds\n", time(NULL) - start);
2 голосов
/ 23 сентября 2015

В linux clock_gettime () - один из лучших вариантов. Вы должны связать библиотеку в реальном времени (-lrt).

#include <stdio.h>
#include <unistd.h>
#include <stdlib.h>
#include <time.h>

#define BILLION  1000000000L;

int main( int argc, char **argv )
  {
    struct timespec start, stop;
    double accum;

    if( clock_gettime( CLOCK_REALTIME, &start) == -1 ) {
      perror( "clock gettime" );
      exit( EXIT_FAILURE );
    }

    system( argv[1] );

    if( clock_gettime( CLOCK_REALTIME, &stop) == -1 ) {
      perror( "clock gettime" );
      exit( EXIT_FAILURE );
    }

    accum = ( stop.tv_sec - start.tv_sec )
          + ( stop.tv_nsec - start.tv_nsec )
            / BILLION;
    printf( "%lf\n", accum );
    return( EXIT_SUCCESS );
  }
2 голосов
/ 26 января 2015

Из того, что видно, tv_sec хранит прошедшие секунды, а tv_usec - отдельно хранящиеся микросекунды. И они не являются обращением друг друга. Следовательно, они должны быть изменены на соответствующую единицу и добавлены, чтобы получить общее время, прошедшее.

struct timeval startTV, endTV;

gettimeofday(&startTV, NULL); 

doSomething();
doSomethingLong();

gettimeofday(&endTV, NULL); 

printf("**time taken in microseconds = %ld\n",
    (endTV.tv_sec * 1e6 + endTV.tv_usec - (startTV.tv_sec * 1e6 + startTV.tv_usec))
    );
2 голосов
/ 11 мая 2010

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

2 голосов
/ 10 февраля 2018

Как уже отмечали другие, функция time () в стандартной библиотеке C не имеет разрешения лучше, чем одна секунда. Похоже, единственной полностью переносимой функцией C, которая может обеспечить лучшее разрешение, является clock (), но она измеряет время процессора, а не время настенных часов. Если кто-то хочет ограничиться платформой POSIX (например, Linux), то функция clock_gettime () - хороший выбор.

Начиная с C ++ 11, есть гораздо лучшие средства синхронизации , которые предлагают лучшее разрешение в форме, которая должна быть очень переносимой для различных компиляторов и операционных систем. Точно так же библиотека boost :: datetime предоставляет хорошие классы синхронизации высокого разрешения, которые должны быть легко переносимыми.

Одной из проблем при использовании любого из этих средств является задержка, вызванная запросом системных часов. Из экспериментов с clock_gettime (), boost :: datetime и std :: chrono эта задержка может легко составлять несколько микросекунд. Таким образом, при измерении длительности любой части вашего кода вы должны учитывать наличие ошибки измерения около этого размера или пытаться каким-то образом исправить эту нулевую ошибку. В идеале может потребоваться собрать несколько измерений времени, затраченного вашей функцией, и вычислить среднее или максимальное / минимальное время, затраченное на несколько прогонов.

Чтобы решить все эти проблемы переносимости и сбора статистики, я разрабатывал библиотеку cxx-rtimers, доступную в Github , которая пытается предоставить простой API для блоков синхронизации кода C ++, вычисляя ноль ошибки и отчеты о статистике от нескольких таймеров, встроенных в ваш код. Если у вас есть компилятор C ++ 11, вы просто #include <rtimers/cxx11.hpp> и используете что-то вроде:

void expensiveFunction() {
    static rtimers::cxx11::DefaultTimer timer("expensiveFunc");
    auto scopedStartStop = timer.scopedStart();
    // Do something costly...
}

При выходе из программы вы получите сводную статистику по времени, записанную в std :: cerr, такую ​​как:

Timer(expensiveFunc): <t> = 6.65289us, std = 3.91685us, 3.842us <= t <= 63.257us (n=731)

, который показывает среднее время, его стандартное отклонение, верхний и нижний пределы и количество раз, когда эта функция была вызвана.

Если вы хотите использовать специфичные для Linux функции синхронизации, вы можете #include <rtimers/posix.hpp> или, если у вас есть библиотеки Boost, но более старый компилятор C ++, вы можете #include <rtimers/boost.hpp>. Существуют также версии этих классов таймеров, которые могут собирать статистическую информацию о времени из разных потоков. Существуют также методы, позволяющие оценить нулевую ошибку, связанную с двумя непосредственно последовательными запросами системных часов.

1 голос
/ 15 февраля 2016

Я обычно использую следующее:

#include <chrono>
#include <type_traits>

using perf_clock = std::conditional<
    std::chrono::high_resolution_clock::is_steady,
    std::chrono::high_resolution_clock,
    std::chrono::steady_clock
>::type;

using floating_seconds = std::chrono::duration<double>;

template<class F, class... Args>
floating_seconds run_test(Func&& func, Args&&... args)
{
   const auto t0 = perf_clock::now();
   std::forward<Func>(func)(std::forward<Args>(args)...);
   return floating_seconds(perf_clock::now() - t0);
} 

Это то же самое, что предложил @ nikos-athanasiou, за исключением того, что я избегаю использования неустойчивых часов и использую плавающее число секунд в качестве продолжительности.

1 голос
/ 11 мая 2010

Причина, по которой оба значения одинаковы, заключается в том, что ваша длинная процедура не занимает столько времени - меньше одной секунды. Вы можете попробовать просто добавить длинный цикл (for (int i = 0; i <100000000; i ++);) в конце функции, чтобы убедиться, что это проблема, тогда мы можем пойти дальше ... </p>

В случае, если вышеприведенное окажется верным, вам нужно будет найти другую системную функцию (я понимаю, вы работаете над linux, поэтому я не могу помочь вам с именем функции), чтобы более точно измерять время. Я уверен, что есть функция, похожая на GetTickCount () в Linux, вам просто нужно ее найти.

1 голос
/ 11 мая 2010

Они одинаковы, потому что ваша функция doSomething происходит быстрее, чем гранулярность таймера. Попробуйте:

printf ("**MyProgram::before time= %ld\n", time(NULL));

for(i = 0; i < 1000; ++i) {
    doSomthing();
    doSomthingLong();
}

printf ("**MyProgram::after time= %ld\n", time(NULL));
...