StackOverflow2013

Note that there are some explanatory texts on larger screens.

plurals

POMaking sense of some dprof output
text
Body
copied!<p>Here is some dprofpp -I output, for almost the same program on different input sizes (program uses File:Tie to read input file and does some filtering of lines.</p> <p>The question is why is the elapsed time always double for this program?</p> <p>I am asking this because fixing this would make my program faster by 2x without any more magic - is it, perhaps, because of dprof? How do I find this out?</p> <p>Also confusing is the value of %Time in the last two sets:</p> <pre><code>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 </code></pre> <p>Here is the kind of code I am talking about : <a href="http://www.perlmonks.org/?node_id=763564" rel="nofollow noreferrer">http://www.perlmonks.org/?node_id=763564</a></p>

Querying!

Guidance

An individual column

Larger individual text columns get their own page to allow for proper reading.

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload