← Index
NYTProf Performance Profile   « block view • line view • sub view »
For ./testnewboardincnply
  Run on Mon Jan 12 21:52:27 2015
Reported on Mon Jan 12 22:01:18 2015

Filename/homes/dcw/src/perl/coloroids_solver/NewSolveGame.pm
StatementsExecuted 475 statements in 9.75ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
1112.94ms58.1smain::::solve_gamemain::solve_game
11114µs14µsmain::::BEGIN@5main::BEGIN@5
1115µs90µsmain::::BEGIN@6main::BEGIN@6
1115µs28µsmain::::BEGIN@5.8main::BEGIN@5.8
1115µs20µsmain::::BEGIN@7.9main::BEGIN@7.9
1115µs20µsmain::::BEGIN@10.11main::BEGIN@10.11
1115µs38µsmain::::BEGIN@9.10main::BEGIN@9.10
1114µs13µsmain::::BEGIN@14.13main::BEGIN@14.13
1114µs17µsmain::::BEGIN@11main::BEGIN@11
1113µs3µsmain::::BEGIN@12.12main::BEGIN@12.12
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1#
2# NewSolveGame: solve coloroid using NewBoard and pickbest helper function.
3#
4
5450µs364µs
# spent 28µs (5+22) within main::BEGIN@5.8 which was called: # once (5µs+22µs) by main::BEGIN@14.7 at line 5 # spent 14µs within main::BEGIN@5 which was called: # once (14µs+0s) by main::BEGIN@14.7 at line 5
use v5.12;
# spent 28µs making 1 call to main::BEGIN@5.8 # spent 22µs making 1 call to feature::import # spent 14µs making 1 call to main::BEGIN@5
6219µs2175µs
# spent 90µs (5+85) within main::BEGIN@6 which was called: # once (5µs+85µs) by main::BEGIN@14.7 at line 6
use Function::Parameters;
# spent 90µs making 1 call to main::BEGIN@6 # spent 85µs making 1 call to Function::Parameters::import
7219µs236µs
# spent 20µs (5+16) within main::BEGIN@7.9 which was called: # once (5µs+16µs) by main::BEGIN@14.7 at line 7
use Data::Dumper;
# spent 20µs making 1 call to main::BEGIN@7.9 # spent 16µs making 1 call to Exporter::import
8
9219µs270µs
# spent 38µs (5+33) within main::BEGIN@9.10 which was called: # once (5µs+33µs) by main::BEGIN@14.7 at line 9
use lib qw(/homes/dcw/lib/perl5/DCW);
# spent 38µs making 1 call to main::BEGIN@9.10 # spent 33µs making 1 call to lib::import
10217µs234µs
# spent 20µs (5+15) within main::BEGIN@10.11 which was called: # once (5µs+15µs) by main::BEGIN@14.7 at line 10
use Tuple qw(tuple);
# spent 20µs making 1 call to main::BEGIN@10.11 # spent 15µs making 1 call to Exporter::import
11215µs230µs
# spent 17µs (4+13) within main::BEGIN@11 which was called: # once (4µs+13µs) by main::BEGIN@14.7 at line 11
use List qw(list);
# spent 17µs making 1 call to main::BEGIN@11 # spent 13µs making 1 call to Exporter::import
12215µs13µs
# spent 3µs within main::BEGIN@12.12 which was called: # once (3µs+0s) by main::BEGIN@14.7 at line 12
use Sorthash;
# spent 3µs making 1 call to main::BEGIN@12.12
13
142163µs222µs
# spent 13µs (4+9) within main::BEGIN@14.13 which was called: # once (4µs+9µs) by main::BEGIN@14.7 at line 14
use NewBoard;
# spent 13µs making 1 call to main::BEGIN@14.13 # spent 9µs making 1 call to Exporter::import
15
16
17#
18# my $nmoves = solve_game( $board, $pickbest, optional $postmove );
19# Play a complete game, given $board and a picker
20# function $pickbest. Each move we call $pickbest
21# to pick the best single move, make that move and
22# then call the $postmove callback. return the
23# number of moves taken to finish.
24#
25
# spent 58.1s (2.94ms+58.1) within main::solve_game which was called: # once (2.94ms+58.1s) by main::RUNTIME at line 45 of testnewboardincnply
fun solve_game( $board, $pickbest, $postmove=undef )
264562.02ms{
27 # for each move
28 my $moves;
2957557µs for( $moves=1; ! $board->solved; $moves++ )
# spent 557µs making 57 calls to NewBoard::solved, avg 10µs/call
30 {
3156153µs my( $nregion, $adjcolbag ) = $board->region;
# spent 153µs making 56 calls to NewBoard::region, avg 3µs/call
3216.76ms112171ms print "\nmove $moves: board=\n$board\n";
# spent 165ms making 56 calls to NewBoard::as_string, avg 2.94ms/call # spent 6.46ms making 56 calls to main::CORE:print, avg 115µs/call
331530µs1121.76ms print " adjcolbag = $adjcolbag, nregion=$nregion\n";
# spent 1.37ms making 56 calls to Sorthash::as_string, avg 24µs/call # spent 389µs making 56 calls to main::CORE:print, avg 7µs/call
34
355657.1s my $playcolour = $pickbest->( $moves, $adjcolbag, $board );
# spent 57.1s making 56 calls to main::incnply_pick_best, avg 1.02s/call
3656258µs print " playing $playcolour\n";
# spent 258µs making 56 calls to main::CORE:print, avg 5µs/call
3756274ms $board->changeregioncolour( $playcolour );
# spent 274ms making 56 calls to NewBoard::changeregioncolour, avg 4.88ms/call
3856263ms $board->extendregion;
# spent 263ms making 56 calls to NewBoard::extendregion, avg 4.71ms/call
3956348ms $postmove->( $board, $playcolour ) if defined $postmove;
# spent 348ms making 56 calls to main::incnply_makenm1ply, avg 6.22ms/call
40 }
41 $moves--;
4211µs my( $nregion, $adjcolbag ) = $board->region;
# spent 1µs making 1 call to NewBoard::region
431112µs21.01ms print "\ngame over after $moves moves: board=\n$board\n";
# spent 906µs making 1 call to NewBoard::as_string # spent 102µs making 1 call to main::CORE:print
4418µs210µs print " adjcolbag = $adjcolbag, nregion=$nregion\n";
# spent 5µs making 1 call to Sorthash::as_string # spent 5µs making 1 call to main::CORE:print
45 return $moves;
46}
47
48
4912µs1;
Report produced by the NYTProf 4.06 Perl profiler, developed by Tim Bunce and Adam Kaplan.