Смысл некоторого вывода dprof - PullRequest
1 голос
/ 19 мая 2009

Вот некоторый вывод dprofpp -I для почти одной и той же программы с разными размерами ввода (программа использует File: Tie для чтения входного файла и выполняет некоторую фильтрацию строк.

Вопрос в том, почему истекшее время для этой программы всегда удваивается?

Я спрашиваю об этом, потому что исправление этого сделало бы мою программу быстрее в 2 раза без какой-либо магии - возможно, из-за dprof? Как мне это выяснить?

Также сбивает с толку значение% Time в последних двух наборах:

Total Elapsed Time = 456.5656 Seconds
  User+System Time = 206.2156 Seconds
Inclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 87.6   25.71 180.65 157920   0.0000 0.0001  Tie::File::FETCH
 75.1   28.96 154.93 157920   0.0000 0.0001  Tie::File::_fetch
 26.0   14.77 53.769 839753   0.0000 0.0001  Tie::File::Cache::insert
 20.2   41.73 41.732 167950   0.0000 0.0000  Tie::File::_read_record
 18.9   11.54 38.998 839753   0.0000 0.0000  Tie::File::Heap::insert
 17.2   21.16 35.610 157920   0.0000 0.0000  Tie::File::Cache::lookup
 12.4   0.566 25.571  14503   0.0000 0.0018  Tie::File::FETCHSIZE
 11.9   6.701 24.732      1   6.7008 24.731  Tie::File::_fill_offsets
 11.5   10.57 23.874 839753   0.0000 0.0000  Tie::File::Heap::_insert_new
 7.00   4.756 14.444 739447   0.0000 0.0000  Tie::File::Heap::lookup
 6.25   11.62 12.893 839755   0.0000 0.0000  Tie::File::_seek
 5.33   10.99 10.991 839753   0.0000 0.0000  Tie::File::Cache::_heap_move
 4.70   6.796  9.688 739447   0.0000 0.0000  Tie::File::Heap::promote
 3.14   6.474  6.474 157920   0.0000 0.0000  Tie::File::Heap::_nseq
 1.12   2.311  2.311 839753   0.0000 0.0000  Tie::File::Heap::_nelts_inc

Total Elapsed Time = 1029.736 Seconds
  User+System Time = 562.5560 Seconds
Inclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 119.   58.01 671.82 304761   0.0000 0.0002  Tie::File::FETCH
 109.   62.95 613.81 304761   0.0000 0.0002  Tie::File::_fetch
 68.6   30.71 385.95 154266   0.0000 0.0003  Tie::File::Cache::insert
 47.2   4.344 265.93 536190   0.0000 0.0005  Tie::File::Cache::flush
 46.5   7.502 261.58 536190   0.0000 0.0005  Tie::File::Cache::reduce_size_to
 45.1   4.131 254.08 636473   0.0000 0.0004  Tie::File::Heap::popheap
 44.4   148.4 249.95 636473   0.0002 0.0004  Tie::File::Heap::remove
 21.7   122.5 122.50 142968   0.0000 0.0000  Tie::File::Cache::_heap_move
 15.9   48.97 89.786 304761   0.0000 0.0000  Tie::File::Cache::lookup
 15.8   25.25 89.314 154266   0.0000 0.0001  Tie::File::Heap::insert
 14.2   80.39 80.394 308533   0.0000 0.0000  Tie::File::_read_record
 10.0   26.06 56.595 154266   0.0000 0.0000  Tie::File::Heap::_insert_new
 9.13   16.15 51.384      1   16.157 51.384  Tie::File::_fill_offsets
 9.13       - 51.384      1        - 51.384  Tie::File::FETCHSIZE
 7.26   15.52 40.815 150494   0.0000 0.0000  Tie::File::Heap::lookup

Total Elapsed Time = 556.7212 Seconds
  User+System Time = 290.2512 Seconds
Inclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 115.   51.05 336.00 335279   0.0000 0.0001  Tie::File::FETCH
 98.1   50.85 284.95 335279   0.0000 0.0001  Tie::File::_fetch
 35.4   45.84 102.90 335279   0.0000 0.0000  Tie::File::Cache::lookup
 29.0   18.79 84.176 107247   0.0000 0.0001  Tie::File::Cache::insert
 22.5   17.16 65.380 107247   0.0000 0.0001  Tie::File::Heap::insert
 19.6   21.19 57.056 228032   0.0000 0.0000  Tie::File::Heap::lookup
 17.2   50.07 50.077 214494   0.0000 0.0000  Tie::File::_read_record
 14.9   16.68 43.486 107247   0.0000 0.0000  Tie::File::Heap::_insert_new
 12.3   25.18 35.862 228032   0.0000 0.0000  Tie::File::Heap::promote
 10.8   9.213 31.547      1   9.2133 31.546  Tie::File::_fill_offsets
 10.8       - 31.546      1        - 31.546  Tie::File::FETCHSIZE
 7.90   22.92 22.923 107247   0.0000 0.0000  Tie::File::Cache::_heap_move
 6.64   15.98 19.280 107247   0.0000 0.0000  Tie::File::_seek
 5.31   15.41 15.411 335279   0.0000 0.0000  Tie::File::Heap::_nseq
 1.34   3.883  3.883 107247   0.0000 0.0000  Tie::File::Heap::_nelts_inc

Вот код, о котором я говорю: http://www.perlmonks.org/?node_id=763564

Ответы [ 2 ]

4 голосов
/ 19 мая 2009
  1. Tie :: File говорит вам, что ваше узкое место читает с диска. Итак, ваша оптимизация окончена. Если, конечно, вы можете найти более умный способ , а не чтения с диска.

  2. Используйте Devel :: NYTProf , это намного более полно.

0 голосов
/ 10 июля 2010

Вопрос в том, почему истекшее время для этой программы всегда удваивается?

Насколько я понимаю, это потому, что половина времени уходит на ввод / вывод [я могу ошибаться здесь]

Но, чтобы получить лучшее представление о том, где фактическое время тратится, используйте

$> dprofpp -I -r 

ИЛИ

$>dprofpp -I -r -A
Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...