Profile of /homes/dcw/src/perl/weeklychallenge/perlweeklychallenge-club/challenge-025/duncan-c-white/perl5/v1.pl

Filename	/homes/dcw/src/perl/weeklychallenge/perlweeklychallenge-club/challenge-025/duncan-c-white/perl5/v1.pl
Statements	Executed 52033291 statements in 32.4s

Subroutines
Calls	P	F	Exclusive Time	Inclusive Time	Subroutine
5016078	2	1	31.3s	32.4s	main::::findseq main::findseq (recurses: max depth 22, inclusive time 452s)
5016148	2	1	1.09s	1.09s	main::::CORE:match main::CORE:match (opcode)
1	1	1	5.24ms	7.91ms	main::::BEGIN@26 main::BEGIN@26
1	1	1	3.80ms	3.82ms	main::::BEGIN@24 main::BEGIN@24
1	1	1	3.63ms	13.5ms	main::::BEGIN@25 main::BEGIN@25
1	1	1	865µs	940µs	main::::BEGIN@23 main::BEGIN@23
1	1	1	29µs	29µs	main::::BEGIN@22 main::BEGIN@22
1	1	1	17µs	17µs	main::::CORE:print main::CORE:print (opcode)
1	1	1	12µs	12µs	UNIVERSAL::::VERSIONUNIVERSAL::VERSION (xsub)
3	3	1	2µs	2µs	Internals::::SvREADONLYInternals::SvREADONLY (xsub)
1	1	1	1µs	1µs	mro::::method_changed_in mro::method_changed_in (xsub)
0	0	0	0s	0s	main::::RUNTIME main::RUNTIME

Call graph for these subroutines as a Graphviz dot language file.

Line	State ments	Time on line	Calls	Time in subs	Code
1					#!/usr/bin/perl
2					#
3					# Challenge 1: "Generate a longest sequence of the following "English Pokemon"
4					# names where each name starts with the last letter of the previous name:
5					#
6					# audino bagon baltoy banette bidoof braviary bronzor carracosta
7					# charmeleon cresselia croagunk darmanitan deino emboar emolga
8					# exeggcute gabite girafarig gulpin haxorus heatmor heatran ivysaur
9					# jellicent jumpluff kangaskhan kricketune landorus ledyba loudred
10					# lumineon lunatone machamp magnezone mamoswine nosepass petilil
11					# pidgeotto pikachu pinsir poliwrath poochyena porygon2 porygonz
12					# registeel relicanth remoraid rufflet sableye scolipede scrafty
13					# seaking sealeo silcoon simisear snivy snorlax spoink starly
14					# tirtouga trapinch treecko tyrogue vigoroth vulpix wailord
15					# wartortle whismur wingull yamask"
16					#
17					# My notes: Clearly defined, nice, potentially tricky, let's do it.
18					#
19					# optimization v1: baseline code before starting to optimize: 32.6s.
20					#
21
22	2	106µs	1	29µs	# spent 29µs within main::BEGIN@22 which was called: # once (29µs+0s) by main::NULL at line 22 use v5.10; # to get "say" # spent 29µs making 1 call to main::BEGIN@22
23	2	550µs	2	947µs	# spent 940µs (865+75) within main::BEGIN@23 which was called: # once (865µs+75µs) by main::NULL at line 23 use strict; # spent 940µs making 1 call to main::BEGIN@23 # spent 7µs making 1 call to strict::import
24	2	3.63ms	2	3.83ms	# spent 3.82ms (3.80+17µs) within main::BEGIN@24 which was called: # once (3.80ms+17µs) by main::NULL at line 24 use warnings; # spent 3.82ms making 1 call to main::BEGIN@24 # spent 12µs making 1 call to warnings::import
25	2	178µs	2	13.9ms	# spent 13.5ms (3.63+9.90) within main::BEGIN@25 which was called: # once (3.63ms+9.90ms) by main::NULL at line 25 use Function::Parameters; # spent 13.5ms making 1 call to main::BEGIN@25 # spent 347µs making 1 call to Function::Parameters::import
26	2	456µs	2	7.94ms	# spent 7.91ms (5.24+2.67) within main::BEGIN@26 which was called: # once (5.24ms+2.67ms) by main::NULL at line 26 use Data::Dumper; # spent 7.91ms making 1 call to main::BEGIN@26 # spent 29µs making 1 call to Exporter::import
27
28	1	1µs			my $debug = @ARGV>0;
29
30	1	5µs			my @words = qw(audino bagon baltoy banette bidoof braviary bronzor carracosta
31					charmeleon cresselia croagunk darmanitan deino emboar emolga
32					exeggcute gabite girafarig gulpin haxorus heatmor heatran ivysaur
33					jellicent jumpluff kangaskhan kricketune landorus ledyba loudred
34					lumineon lunatone machamp magnezone mamoswine nosepass petilil
35					pidgeotto pikachu pinsir poliwrath poochyena porygon2 porygonz
36					registeel relicanth remoraid rufflet sableye scolipede scrafty
37					seaking sealeo silcoon simisear snivy snorlax spoink starly
38					tirtouga trapinch treecko tyrogue vigoroth vulpix wailord
39					wartortle whismur wingull yamask);
40					#@words = qw(hello ollie excellent thanks shelter runaround set to);
41
42	1	300ns			my %sw; # hash from letter to list of words starting with that letter.
43
44	1	500ns			foreach my $word (@words)
45					{
46	70	102µs	70	32µs	$word =~ /^(.)/; # spent 32µs making 70 calls to main::CORE:match, avg 464ns/call
47	70	14µs			my $letter = $1;
48	70	18µs			$sw{$letter} //= [];
49	70	31µs			push @{$sw{$letter}}, $word;
50					}
51
52					#die Dumper \%sw;
53
54	1	300ns			my @longseq = (); # longest sequence found so far..
55
56					# ok, start searching..
57	1	400ns			foreach my $sw (@words)
58					{
59	70	68µs	70	32.4s	findseq( $sw, () ); # spent 32.4s making 70 calls to main::findseq, avg 463ms/call
60					}
61
62	1	200ns			my $longest = @longseq;
63
64	1	24µs	1	17µs	print "\nlongest sequence is length $longest: @longseq\n"; # spent 17µs making 1 call to main::CORE:print
65	1	100ns			exit 0;
66
67
68					#
69					# findseq( $currw, @seq );
70					# Find all sequences of words from $currw onwards,
71					# given that we've already visited words in @seq,
72					# and update the global @longseq if any sequences
73					# we find are longer than that.
74					#
75					# spent 32.4s (31.3+1.09) within main::findseq which was called 5016078 times, avg 6µs/call: # 5016008 times (31.3s+-31.3s) by main::findseq at line 91, avg 0s/call # 70 times (359µs+32.4s) by main::RUNTIME at line 59, avg 463ms/call fun findseq( $currw, @seq )
76	10032156	2.93s			{
77	5016078	446ms			push @seq, $currw; # extend @seq sequence
78
79	5016078	9.77s			my %used = map { $_ => 1 } @seq; # convert to set
80
81	5016078	6.64s	5016078	1.09s	$currw =~ /(.)$/; # find the last letter of currw # spent 1.09s making 5016078 calls to main::CORE:match, avg 218ns/call
82	5016078	673ms			my $lastletter = $1;
83
84	5016078	517ms			my $nextw = $sw{$lastletter}; # all words starting with lastletter
85
86	5016078	8.07s			if( defined $nextw ) # if there are any, try each word
87					{
88					foreach my $nextword (@$nextw)
89					{
90					findseq( $nextword, @seq )
91	7864514	3.07s	5016008	0s	unless $used{$nextword}; # spent 452s making 5016008 calls to main::findseq, avg 90µs/call, recursion: max depth 22, sum of overlapping time 452s
92					}
93					} else # @seq is finished
94					{
95	1346584	116ms			my $len = @seq;
96	1346584	83.8ms			print "longest seq so far (len $len): @seq\n" if $debug;
97	1346584	124ms			if( $len > @longseq )
98					{
99	16	1µs			print "seq len $len, @seq\n" if $debug;
100	16	20µs			@longseq = @seq;
101					}
102					}
103	1	73µs	1	9µs	} # spent 9µs making 1 call to Function::Parameters::_register_info

					# spent 2µs within Internals::SvREADONLY which was called 3 times, avg 733ns/call: # once (1µs+0s) by constant::BEGIN@24 at line 33 of constant.pm # once (900ns+0s) by constant::import at line 164 of constant.pm # once (300ns+0s) by constant::BEGIN@24 at line 34 of constant.pm sub Internals::SvREADONLY; # xsub
					# spent 12µs within UNIVERSAL::VERSION which was called: # once (12µs+0s) by Function::Parameters::BEGIN@7 at line 24 of Scalar/Util.pm sub UNIVERSAL::VERSION; # xsub
					# spent 1.09s within main::CORE:match which was called 5016148 times, avg 218ns/call: # 5016078 times (1.09s+0s) by main::findseq at line 81, avg 218ns/call # 70 times (32µs+0s) by main::RUNTIME at line 46, avg 464ns/call sub main::CORE:match; # opcode
					# spent 17µs within main::CORE:print which was called: # once (17µs+0s) by main::RUNTIME at line 64 sub main::CORE:print; # opcode
					# spent 1µs within mro::method_changed_in which was called: # once (1µs+0s) by constant::import at line 198 of constant.pm sub mro::method_changed_in; # xsub