Что именно измеряет профилирование C ++ (google cpu perf tools)? - PullRequest
Новая
       72

Что именно измеряет профилирование C ++ (google cpu perf tools)?

8 голосов
/ 16 июня 2009

Я пытаюсь начать работу с Google Perf Tools для профилирования некоторых приложений, интенсивно использующих процессор. Это статистический расчет, который выводит каждый шаг в файл, используя `ofstream '. Я не эксперт по С ++, поэтому мне трудно найти узкое место. Мой первый проход дает результаты: 

Total: 857 samples
     357  41.7%  41.7%      357  41.7% _write$UNIX2003
     134  15.6%  57.3%      134  15.6% _exp$fenv_access_off
     109  12.7%  70.0%      276  32.2% scythe::dnorm
     103  12.0%  82.0%      103  12.0% _log$fenv_access_off
      58   6.8%  88.8%       58   6.8% scythe::const_matrix_forward_iterator::operator*
      37   4.3%  93.1%       37   4.3% scythe::matrix_forward_iterator::operator*
      15   1.8%  94.9%       47   5.5% std::transform
      13   1.5%  96.4%      486  56.7% SliceStep::DoStep
      10   1.2%  97.5%       10   1.2% 0x0002726c
       5   0.6%  98.1%        5   0.6% 0x000271c7
       5   0.6%  98.7%        5   0.6% _write$NOCANCEL$UNIX2003

Это удивительно, так как все реальные вычисления происходят в SliceStep :: DoStep. «_Write $ UNIX2003» (где я могу узнать, что это такое?), Похоже, происходит от записи выходного файла. Что меня смущает, так это то, что если я закомментирую все операторы outfile << "text" и запущу pprof, 95% будет в SliceStep::DoStep и `_write $ UNIX2003 'исчезнет. Однако, мое приложение не ускоряется, как измеряется общим временем. Все это ускоряется менее чем на 1 процент.

Что мне не хватает?

Добавлено: Вывод pprof без операторов outfile <<: 

Total: 790 samples
     205  25.9%  25.9%      205  25.9% _exp$fenv_access_off
     170  21.5%  47.5%      170  21.5% _log$fenv_access_off
     162  20.5%  68.0%      437  55.3% scythe::dnorm
      83  10.5%  78.5%       83  10.5% scythe::const_matrix_forward_iterator::operator*
      70   8.9%  87.3%       70   8.9% scythe::matrix_forward_iterator::operator*
      28   3.5%  90.9%       78   9.9% std::transform
      26   3.3%  94.2%       26   3.3% 0x00027262
      12   1.5%  95.7%       12   1.5% _write$NOCANCEL$UNIX2003
      11   1.4%  97.1%      764  96.7% SliceStep::DoStep
       9   1.1%  98.2%        9   1.1% 0x00027253
       6   0.8%  99.0%        6   0.8% 0x000274a6

Это похоже на то, что я ожидал, за исключением того, что я не вижу видимого увеличения производительности (0,1 секунды при 10-секундном расчете). Код по существу: 

ofstream outfile("out.txt");
for loop:
  SliceStep::DoStep()
  outfile << 'result'
outfile.close()

Обновление: я определяю время, используя boost :: timer, начиная с начала профилировщика и заканчивая там, где заканчивается. Я не использую темы или что-нибудь необычное.

Ответы [ 3 ]

3 голосов
/ 17 июня 2009

Из моих комментариев:

Цифры, которые вы получаете от своего профилировщика, говорят о том, что программа должна быть примерно на 40% быстрее без операторов печати. ​​

Однако время выполнения практически не меняется.

Очевидно, что одно из измерений должно быть неправильным. Это означает, что вам нужно делать больше и лучшие измерения.

Сначала я предлагаю начать с другого простого инструмента: команды времени. Это должно дать вам приблизительное представление о том, где вы проводите время.

Если результаты все еще не убедительны, вам нужен лучший тестовый пример:

  • Используйте большую проблему
  • Сделайте разминку перед измерением. Сделайте несколько циклов и начните любое измерение впоследствии (в том же процессе).

Тиристан: Это все в пользовании. То, что я делаю, довольно просто, я думаю ... Означает ли факт, что файл открыт все время, что-нибудь значит?

Это означает, что профилировщик неверен.

Печать 100000 строк на консоли с использованием Python приводит к чему-то вроде: 

for i in xrange(100000):
    print i

На консоль: 

time python print.py
[...]
real    0m2.370s
user    0m0.156s
sys     0m0.232s

Versus: 

time python test.py > /dev/null

real    0m0.133s
user    0m0.116s
sys     0m0.008s

Моя точка зрения: Ваши внутренние измерения и времени показывают, что вы ничего не получите от отключения выхода. Google Perf Tools говорит, что вы должны. Кто не прав?

1 голос
/ 18 июня 2009

Google perftools собирает образцы стека вызовов, так что вам нужно, чтобы получить некоторую наглядность в них.

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

1 голос
/ 16 июня 2009

_write $ UNIX2003, вероятно, относится к системному вызову write POSIX, который выводит на терминал. Ввод / вывод очень медленный по сравнению с чем-либо еще, поэтому имеет смысл, что ваша программа тратит там много времени, если вы пишете немало информации.

Я не уверен, почему ваша программа не будет ускоряться, когда вы удаляете вывод, но я не могу точно догадаться только о той информации, которую вы предоставили. Было бы неплохо увидеть некоторый код или даже вывод perftools после удаления оператора cout.

...