← Index
NYTProf Performance Profile   « block view • line view • sub view »
For -e
  Run on Wed Nov 17 21:42:38 2010
Reported on Wed Nov 17 22:05:44 2010

Filename/home/doy/coding/src/namespace-clean/namespace-clean-0.18/blib/lib/namespace/clean.pm
StatementsExecuted 12414 statements in 332ms
Subroutines
Calls P F Exclusive
Time
Inclusive
Time
Subroutine
4611139ms266msnamespace::clean::::__ANON__[:59] namespace::clean::__ANON__[:59]
46464623.5ms80.1msnamespace::clean::::import namespace::clean::import
461110.3ms28.9msnamespace::clean::::get_functions namespace::clean::get_functions
46113.14ms7.56msnamespace::clean::::get_class_store namespace::clean::get_class_store
1112.06ms11.3msnamespace::clean::::BEGIN@17 namespace::clean::BEGIN@17
1111.99ms4.17msnamespace::clean::::BEGIN@15 namespace::clean::BEGIN@15
46111.67ms268msnamespace::clean::::__ANON__[:117] namespace::clean::__ANON__[:117]
4611485µs485µsnamespace::clean::::CORE:match namespace::clean::CORE:match (opcode)
11175µs351µsnamespace::clean::::BEGIN@14 namespace::clean::BEGIN@14
11169µs152µsnamespace::clean::::BEGIN@16 namespace::clean::BEGIN@16
11168µs160µsnamespace::clean::::BEGIN@166 namespace::clean::BEGIN@166
11152µs123µsnamespace::clean::::BEGIN@10 namespace::clean::BEGIN@10
11148µs48µsnamespace::clean::::BEGIN@2 namespace::clean::BEGIN@2
11138µs53µsnamespace::clean::::BEGIN@11 namespace::clean::BEGIN@11
11136µs150µsnamespace::clean::::BEGIN@13 namespace::clean::BEGIN@13
11117µs17µsnamespace::clean::::BEGIN@5 namespace::clean::BEGIN@5
0000s0snamespace::clean::::__ANON__[:90] namespace::clean::__ANON__[:90]
0000s0snamespace::clean::::clean_subroutines namespace::clean::clean_subroutines
0000s0snamespace::clean::deleted::KiokuDB::TypeMap::Entry::MOP::::does_rolenamespace::clean::deleted::KiokuDB::TypeMap::Entry::MOP::does_role
0000s0snamespace::clean::::unimport namespace::clean::unimport
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments
Time
on line
Calls Time
in subs
Code
1package namespace::clean;
2
# spent 48µs within namespace::clean::BEGIN@2 which was called: # once (48µs+0s) by KiokuDB::Backend::BEGIN@9 at line 4
BEGIN {
3127µs $namespace::clean::AUTHORITY = 'cpan:PHAYLON';
4183µs148µs}
# spent 48µs making 1 call to namespace::clean::BEGIN@2
5
# spent 17µs within namespace::clean::BEGIN@5 which was called: # once (17µs+0s) by KiokuDB::Backend::BEGIN@9 at line 7
BEGIN {
6119µs $namespace::clean::VERSION = '0.18';
7166µs117µs}
# spent 17µs making 1 call to namespace::clean::BEGIN@5
8# ABSTRACT: Keep imports and functions out of your namespace
9
10397µs2195µs
# spent 123µs (52+71) within namespace::clean::BEGIN@10 which was called: # once (52µs+71µs) by KiokuDB::Backend::BEGIN@9 at line 10
use warnings;
# spent 123µs making 1 call to namespace::clean::BEGIN@10 # spent 71µs making 1 call to warnings::import
113130µs269µs
# spent 53µs (38+15) within namespace::clean::BEGIN@11 which was called: # once (38µs+15µs) by KiokuDB::Backend::BEGIN@9 at line 11
use strict;
# spent 53µs making 1 call to namespace::clean::BEGIN@11 # spent 15µs making 1 call to strict::import
12
133114µs2264µs
# spent 150µs (36+114) within namespace::clean::BEGIN@13 which was called: # once (36µs+114µs) by KiokuDB::Backend::BEGIN@9 at line 13
use vars qw( $STORAGE_VAR );
# spent 150µs making 1 call to namespace::clean::BEGIN@13 # spent 114µs making 1 call to vars::import
143282µs3627µs
# spent 351µs (75+276) within namespace::clean::BEGIN@14 which was called: # once (75µs+276µs) by KiokuDB::Backend::BEGIN@9 at line 14
use Sub::Name 0.04 qw(subname);
# spent 351µs making 1 call to namespace::clean::BEGIN@14 # spent 151µs making 1 call to Exporter::import # spent 125µs making 1 call to UNIVERSAL::VERSION
153729µs34.49ms
# spent 4.17ms (1.99+2.18) within namespace::clean::BEGIN@15 which was called: # once (1.99ms+2.18ms) by KiokuDB::Backend::BEGIN@9 at line 15
use Sub::Identify 0.04 qw(sub_fullname);
# spent 4.17ms making 1 call to namespace::clean::BEGIN@15 # spent 242µs making 1 call to Exporter::import # spent 80µs making 1 call to UNIVERSAL::VERSION
163184µs3235µs
# spent 152µs (69+83) within namespace::clean::BEGIN@16 which was called: # once (69µs+83µs) by KiokuDB::Backend::BEGIN@9 at line 16
use Package::Stash 0.03;
# spent 152µs making 1 call to namespace::clean::BEGIN@16 # spent 51µs making 1 call to UNIVERSAL::VERSION # spent 32µs making 1 call to Package::DeprecationManager::__ANON__[Package/DeprecationManager.pm:61]
1734.39ms313.1ms
# spent 11.3ms (2.06+9.27) within namespace::clean::BEGIN@17 which was called: # once (2.06ms+9.27ms) by KiokuDB::Backend::BEGIN@9 at line 17
use B::Hooks::EndOfScope 0.07;
# spent 11.3ms making 1 call to namespace::clean::BEGIN@17 # spent 1.65ms making 1 call to Sub::Exporter::__ANON__[Sub/Exporter.pm:756] # spent 75µs making 1 call to UNIVERSAL::VERSION
18
1915µs$STORAGE_VAR = '__NAMESPACE_CLEAN_STORAGE';
20
21
22
# spent 266ms (139+127) within namespace::clean::__ANON__[/home/doy/coding/src/namespace-clean/namespace-clean-0.18/blib/lib/namespace/clean.pm:59] which was called 46 times, avg 5.79ms/call: # 46 times (139ms+127ms) by namespace::clean::__ANON__[/home/doy/coding/src/namespace-clean/namespace-clean-0.18/blib/lib/namespace/clean.pm:117] at line 116, avg 5.79ms/call
my $RemoveSubs = sub {
23
242305.77ms my $cleanee = shift;
25 my $store = shift;
2646993µs my $cleanee_stash = Package::Stash->new($cleanee);
# spent 993µs making 46 calls to Package::Stash::XS::new, avg 22µs/call
27461.20ms my $deleted_stash = Package::Stash->new("namespace::clean::deleted::$cleanee");
# spent 1.20ms making 46 calls to Package::Stash::XS::new, avg 26µs/call
28 SYMBOL:
29 for my $f (@_) {
304753164ms my $variable = "&$f";
31 # ignore already removed symbols
32 next SYMBOL if $store->{exclude}{ $f };
33
34135818.3ms next SYMBOL unless $cleanee_stash->has_symbol($variable);
# spent 15.4ms making 679 calls to Package::Stash::XS::has_symbol, avg 23µs/call # spent 2.86ms making 679 calls to Package::Stash::XS::namespace, avg 4µs/call
35
36135840.9ms6793.13ms if (ref(\$cleanee_stash->namespace->{$f}) eq 'GLOB') {
# spent 3.13ms making 679 calls to Package::Stash::XS::namespace, avg 5µs/call
37 # convince the Perl debugger to work
38 # it assumes that sub_fullname($sub) can always be used to find the CV again
39 # since we are deleting the glob where the subroutine was originally
40 # defined, that assumption no longer holds, so we need to move it
41 # elsewhere and point the CV's name to the new glob.
42135817.4ms my $sub = $cleanee_stash->get_symbol($variable);
# spent 14.7ms making 679 calls to Package::Stash::XS::get_symbol, avg 22µs/call # spent 2.68ms making 679 calls to Package::Stash::XS::namespace, avg 4µs/call
433137µs135820.2ms if ( sub_fullname($sub) eq ($cleanee_stash->name . "::$f") ) {
# spent 16.8ms making 679 calls to Sub::Identify::sub_fullname, avg 25µs/call # spent 3.40ms making 679 calls to Package::Stash::XS::name, avg 5µs/call
4414µs my $new_fq = $deleted_stash->name . "::$f";
# spent 4µs making 1 call to Package::Stash::XS::name
45121µs subname($new_fq, $sub);
# spent 21µs making 1 call to Sub::Name::subname
46257µs $deleted_stash->add_symbol($variable, $sub);
# spent 53µs making 1 call to Package::Stash::XS::add_symbol # spent 4µs making 1 call to Package::Stash::XS::name
47 }
48 }
49
50 my ($scalar, $array, $hash, $io) = map {
51543264.3ms $cleanee_stash->get_symbol($_ . $f)
# spent 53.7ms making 2716 calls to Package::Stash::XS::get_symbol, avg 20µs/call # spent 10.6ms making 2716 calls to Package::Stash::XS::namespace, avg 4µs/call
52 } '$', '@', '%', '';
53135820.6ms $cleanee_stash->remove_glob($f);
# spent 18.0ms making 679 calls to Package::Stash::XS::remove_glob, avg 26µs/call # spent 2.60ms making 679 calls to Package::Stash::XS::namespace, avg 4µs/call
54 for my $var (['$', $scalar], ['@', $array], ['%', $hash], ['', $io]) {
55271637.6ms next unless defined $var->[1];
56 $cleanee_stash->add_symbol($var->[0] . $f, $var->[1]);
57 }
58 }
59122µs};
60
61sub clean_subroutines {
62 my ($nc, $cleanee, @subs) = @_;
63 $RemoveSubs->($cleanee, {}, @subs);
64}
65
66
67
# spent 80.1ms (23.5+56.7) within namespace::clean::import which was called 46 times, avg 1.74ms/call: # once (1.25ms+3.15ms) by KiokuDB::Backend::BEGIN@9 at line 9 of KiokuDB/Backend.pm # once (895µs+2.20ms) by KiokuDB::LiveObjects::BEGIN@18 at line 18 of KiokuDB/LiveObjects.pm # once (782µs+1.96ms) by KiokuDB::Entry::BEGIN@8 at line 8 of KiokuDB/Entry.pm # once (725µs+1.90ms) by KiokuDB::TypeMap::Entry::BEGIN@6 at line 6 of KiokuDB/TypeMap/Entry.pm # once (558µs+1.36ms) by KiokuDB::Collapser::BEGIN@22 at line 22 of KiokuDB/Collapser.pm # once (547µs+1.36ms) by KiokuDB::Role::UUIDs::LibUUID::BEGIN@8 at line 8 of KiokuDB/Role/UUIDs/LibUUID.pm # once (575µs+1.32ms) by KiokuDB::BEGIN@23 at line 23 of KiokuDB.pm # once (542µs+1.32ms) by MooseX::Clone::Meta::Attribute::Trait::Copy::BEGIN@8 at line 8 of MooseX/Clone/Meta/Attribute/Trait/Copy.pm # once (558µs+1.29ms) by KiokuDB::TypeMap::BEGIN@12 at line 12 of KiokuDB/TypeMap.pm # once (516µs+1.27ms) by KiokuDB::Linker::BEGIN@20 at line 20 of KiokuDB/Linker.pm # once (490µs+1.30ms) by MooseX::Clone::Meta::Attribute::Trait::StrableClone::BEGIN@8 at line 8 of MooseX/Clone/Meta/Attribute/Trait/StorableClone.pm # once (528µs+1.24ms) by KiokuDB::Role::UUIDs::BEGIN@8 at line 8 of KiokuDB/Role/UUIDs.pm # once (508µs+1.24ms) by Data::Visitor::BEGIN@14 at line 14 of Data/Visitor.pm # once (496µs+1.24ms) by KiokuDB::TypeMap::Entry::MOP::BEGIN@19 at line 19 of KiokuDB/TypeMap/Entry/MOP.pm # once (486µs+1.23ms) by MooseX::Clone::BEGIN@15 at line 15 of MooseX/Clone.pm # once (473µs+1.20ms) by KiokuDB::TypeMap::Entry::Std::BEGIN@8 at line 8 of KiokuDB/TypeMap/Entry/Std.pm # once (483µs+1.19ms) by MooseX::Clone::Meta::Attribute::Trait::Clone::BEGIN@8 at line 8 of MooseX/Clone/Meta/Attribute/Trait/Clone.pm # once (484µs+1.19ms) by KiokuDB::Error::BEGIN@4 at line 4 of KiokuDB/Error.pm # once (482µs+1.18ms) by KiokuDB::TypeMap::Entry::Std::ID::BEGIN@4 at line 4 of KiokuDB/TypeMap/Entry/Std/ID.pm # once (541µs+1.11ms) by KiokuDB::Role::API::BEGIN@4 at line 4 of KiokuDB/Role/API.pm # once (480µs+1.17ms) by KiokuDB::TypeMap::Entry::Std::Expand::BEGIN@6 at line 6 of KiokuDB/TypeMap/Entry/Std/Expand.pm # once (500µs+1.14ms) by Data::Stream::Bulk::BEGIN@12 at line 12 of Data/Stream/Bulk.pm # once (467µs+1.17ms) by KiokuDB::TypeMap::Entry::Std::Intrinsic::BEGIN@6 at line 6 of KiokuDB/TypeMap/Entry/Std/Intrinsic.pm # once (471µs+1.16ms) by KiokuDB::Role::TypeMap::BEGIN@6 at line 6 of KiokuDB/Role/TypeMap.pm # once (467µs+1.12ms) by MooseX::Clone::Meta::Attribute::Trait::Clone::Base::BEGIN@6 at line 6 of MooseX/Clone/Meta/Attribute/Trait/Clone/Base.pm # once (464µs+1.12ms) by KiokuDB::TypeMap::Entry::Std::Compile::BEGIN@6 at line 6 of KiokuDB/TypeMap/Entry/Std/Compile.pm # once (476µs+1.11ms) by MooseX::Clone::Meta::Attribute::Trait::NoClone::BEGIN@6 at line 6 of MooseX/Clone/Meta/Attribute/Trait/NoClone.pm # once (470µs+1.11ms) by Devel::PartialDump::BEGIN@9 at line 9 of Devel/PartialDump.pm # once (456µs+1.11ms) by KiokuDB::TypeMap::Resolver::BEGIN@11 at line 11 of KiokuDB/TypeMap/Resolver.pm # once (445µs+1.12ms) by KiokuDB::Collapser::Buffer::BEGIN@7 at line 7 of KiokuDB/Collapser/Buffer.pm # once (463µs+1.10ms) by MooseX::Clone::Meta::Attribute::Trait::Clone::Std::BEGIN@4 at line 4 of MooseX/Clone/Meta/Attribute/Trait/Clone/Std.pm # once (477µs+1.05ms) by KiokuDB::TypeMap::Entry::Alias::BEGIN@6 at line 6 of KiokuDB/TypeMap/Entry/Alias.pm # once (449µs+1.06ms) by KiokuDB::LiveObjects::TXNScope::BEGIN@8 at line 8 of KiokuDB/LiveObjects/TXNScope.pm # once (447µs+1.06ms) by KiokuDB::TypeMap::Shadow::BEGIN@6 at line 6 of KiokuDB/TypeMap/Shadow.pm # once (438µs+1.07ms) by KiokuDB::Stream::Objects::BEGIN@6 at line 6 of KiokuDB/Stream/Objects.pm # once (436µs+1.07ms) by KiokuDB::LiveObjects::Scope::BEGIN@6 at line 6 of KiokuDB/LiveObjects/Scope.pm # once (433µs+1.07ms) by KiokuDB::Reference::BEGIN@6 at line 6 of KiokuDB/Reference.pm # once (438µs+1.06ms) by KiokuDB::Error::UnknownObjects::BEGIN@4 at line 4 of KiokuDB/Error/UnknownObjects.pm # once (444µs+1.04ms) by Data::Stream::Bulk::Filter::BEGIN@14 at line 14 of Data/Stream/Bulk/Filter.pm # once (438µs+1.03ms) by KiokuDB::Entry::Skip::BEGIN@6 at line 6 of KiokuDB/Entry/Skip.pm # once (459µs+1.01ms) by Data::Stream::Bulk::Cat::BEGIN@12 at line 12 of Data/Stream/Bulk/Cat.pm # once (424µs+1.02ms) by KiokuDB::TypeMap::Entry::Compiled::BEGIN@6 at line 6 of KiokuDB/TypeMap/Entry/Compiled.pm # once (427µs+1.01ms) by KiokuDB::Error::MissingObjects::BEGIN@4 at line 4 of KiokuDB/Error/MissingObjects.pm # once (429µs+1.01ms) by KiokuDB::Thunk::BEGIN@6 at line 6 of KiokuDB/Thunk.pm # once (422µs+1.01ms) by Data::Stream::Bulk::Nil::BEGIN@12 at line 12 of Data/Stream/Bulk/Nil.pm # once (218µs+411µs) by KiokuDB::LiveObjects::Guard::BEGIN@8 at line 8 of KiokuDB/LiveObjects/Guard.pm
sub import {
682301.17ms my ($pragma, @args) = @_;
69
70 my (%args, $is_explicit);
71
72 ARG:
73 while (@args) {
74
751842.04ms46485µs if ($args[0] =~ /^\-/) {
# spent 485µs making 46 calls to namespace::clean::CORE:match, avg 11µs/call
76 my $key = shift @args;
77 my $value = shift @args;
78 $args{ $key } = $value;
79 }
80 else {
81 $is_explicit++;
82 last ARG;
83 }
84 }
85
86 my $cleanee = exists $args{ -cleanee } ? $args{ -cleanee } : scalar caller;
873226.29ms if ($is_explicit) {
88 on_scope_end {
89 $RemoveSubs->($cleanee, {}, @args);
90 };
91 }
92 else {
93
94 # calling class, all current functions and our storage
954628.9ms my $functions = $pragma->get_functions($cleanee);
# spent 28.9ms making 46 calls to namespace::clean::get_functions, avg 629µs/call
96467.56ms my $store = $pragma->get_class_store($cleanee);
# spent 7.56ms making 46 calls to namespace::clean::get_class_store, avg 164µs/call
9746558µs my $stash = Package::Stash->new($cleanee);
# spent 558µs making 46 calls to Package::Stash::XS::new, avg 12µs/call
98
99 # except parameter can be array ref or single value
100 my %except = map {( $_ => 1 )} (
101 $args{ -except }
102 ? ( ref $args{ -except } eq 'ARRAY' ? @{ $args{ -except } } : $args{ -except } )
103 : ()
104 );
105
106 # register symbols for removal, if they have a CODE entry
107 for my $f (keys %$functions) {
108208328.9ms next if $except{ $f };
109135817.6ms next unless $stash->has_symbol("&$f");
# spent 14.9ms making 679 calls to Package::Stash::XS::has_symbol, avg 22µs/call # spent 2.72ms making 679 calls to Package::Stash::XS::namespace, avg 4µs/call
110 $store->{remove}{ $f } = 1;
111 }
112
113 # register EOF handler on first call to import
114921.25ms unless ($store->{handler_is_installed}) {
115
# spent 268ms (1.67+266) within namespace::clean::__ANON__[/home/doy/coding/src/namespace-clean/namespace-clean-0.18/blib/lib/namespace/clean.pm:117] which was called 46 times, avg 5.82ms/call: # 46 times (1.67ms+266ms) by B::Hooks::EndOfScope::__ANON__[/home/doy/perl5/perlbrew/perls/perl-5.10.1/lib/site_perl/5.10.1/B/Hooks/EndOfScope.pm:26] at line 26 of B/Hooks/EndOfScope.pm, avg 5.82ms/call
on_scope_end {
116461.67ms46266ms $RemoveSubs->($cleanee, $store, keys %{ $store->{remove} });
# spent 266ms making 46 calls to namespace::clean::__ANON__[namespace/clean.pm:59], avg 5.79ms/call
117464.28ms };
# spent 4.28ms making 46 calls to B::Hooks::EndOfScope::on_scope_end, avg 93µs/call
118 $store->{handler_is_installed} = 1;
119 }
120
121 return 1;
122 }
123}
124
125
126sub unimport {
127 my ($pragma, %args) = @_;
128
129 # the calling class, the current functions and our storage
130 my $cleanee = exists $args{ -cleanee } ? $args{ -cleanee } : scalar caller;
131 my $functions = $pragma->get_functions($cleanee);
132 my $store = $pragma->get_class_store($cleanee);
133
134 # register all unknown previous functions as excluded
135 for my $f (keys %$functions) {
136 next if $store->{remove}{ $f }
137 or $store->{exclude}{ $f };
138 $store->{exclude}{ $f } = 1;
139 }
140
141 return 1;
142}
143
144
145
# spent 7.56ms (3.14+4.42) within namespace::clean::get_class_store which was called 46 times, avg 164µs/call: # 46 times (3.14ms+4.42ms) by namespace::clean::import at line 96, avg 164µs/call
sub get_class_store {
1462307.59ms my ($pragma, $class) = @_;
14746587µs my $stash = Package::Stash->new($class);
# spent 587µs making 46 calls to Package::Stash::XS::new, avg 13µs/call
148 my $var = "%$STORAGE_VAR";
1491843.16ms $stash->add_symbol($var, {})
# spent 1.75ms making 46 calls to Package::Stash::XS::add_symbol, avg 38µs/call # spent 1.04ms making 46 calls to Package::Stash::XS::has_symbol, avg 23µs/call # spent 194µs making 46 calls to Package::Stash::XS::name, avg 4µs/call # spent 183µs making 46 calls to Package::Stash::XS::namespace, avg 4µs/call
150 unless $stash->has_symbol($var);
151921.23ms return $stash->get_symbol($var);
# spent 1.05ms making 46 calls to Package::Stash::XS::get_symbol, avg 23µs/call # spent 181µs making 46 calls to Package::Stash::XS::namespace, avg 4µs/call
152}
153
154
155
# spent 28.9ms (10.3+18.6) within namespace::clean::get_functions which was called 46 times, avg 629µs/call: # 46 times (10.3ms+18.6ms) by namespace::clean::import at line 95, avg 629µs/call
sub get_functions {
15613829.1ms my ($pragma, $class) = @_;
157
15846969µs my $stash = Package::Stash->new($class);
# spent 969µs making 46 calls to Package::Stash::XS::new, avg 21µs/call
159 return {
160154221.0ms map { $_ => $stash->get_symbol("&$_") }
# spent 15.6ms making 725 calls to Package::Stash::XS::get_symbol, avg 22µs/call # spent 3.33ms making 771 calls to Package::Stash::XS::namespace, avg 4µs/call # spent 2.05ms making 46 calls to Package::Stash::XS::list_all_symbols, avg 45µs/call
161 $stash->list_all_symbols('CODE')
162 };
163}
164
165
1663140µs2253µs
# spent 160µs (68+92) within namespace::clean::BEGIN@166 which was called: # once (68µs+92µs) by KiokuDB::Backend::BEGIN@9 at line 166
no warnings;
# spent 160µs making 1 call to namespace::clean::BEGIN@166 # spent 92µs making 1 call to warnings::unimport
167116µs'Danger! Laws of Thermodynamics may not apply.'
168
169__END__
 
# spent 485µs within namespace::clean::CORE:match which was called 46 times, avg 11µs/call: # 46 times (485µs+0s) by namespace::clean::import at line 75, avg 11µs/call
sub namespace::clean::CORE:match; # opcode