← Index
NYTProf Performance Profile   « line view »
For /Users/brian/bin/perls/cpan5.26.1
  Run on Sat Dec 30 01:41:10 2017
Reported on Sat Dec 30 01:44:14 2017

Filename/usr/local/perls/perl-5.26.1/lib/5.26.1/CPAN/Debug.pm
StatementsExecuted 4522 statements in 16.0ms
Subroutines
Calls P F Exclusive
Time
Inclusive
Time
Subroutine
1195411.9ms16.1msCPAN::Debug::::debugCPAN::Debug::debug
952214.27ms4.27msCPAN::Debug::::CORE:substCPAN::Debug::CORE:subst (opcode)
0000s0sCPAN::Debug::::BEGINCPAN::Debug::BEGIN
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments
Time
on line
Calls Time
in subs
Code
1# -*- Mode: cperl; coding: utf-8; cperl-indent-level: 4 -*-
2package CPAN::Debug;
3use strict;
4use vars qw($VERSION);
5
6$VERSION = "5.5001";
7# module is internal to CPAN.pm
8
9%CPAN::DEBUG = qw[
10 CPAN 1
11 Index 2
12 InfoObj 4
13 Author 8
14 Distribution 16
15 Bundle 32
16 Module 64
17 CacheMgr 128
18 Complete 256
19 FTP 512
20 Shell 1024
21 Eval 2048
22 HandleConfig 4096
23 Tarzip 8192
24 Version 16384
25 Queue 32768
26 FirstTime 65536
27];
28
29$CPAN::DEBUG ||= 0;
30
31#-> sub CPAN::Debug::debug ;
32
# spent 16.1ms (11.9+4.27) within CPAN::Debug::debug which was called 119 times, avg 136µs/call: # 114 times (11.5ms+4.12ms) by CPAN::CacheMgr::_clean_cache at line 183 of CPAN/CacheMgr.pm, avg 137µs/call # 2 times (133µs+34µs) by CPAN::Shell::o at line 370 of CPAN/Shell.pm, avg 84µs/call # once (92µs+66µs) by CPAN::Distribution::check_integrity at line 458 of CPAN/Distribution.pm # once (63µs+23µs) by CPAN::Tarzip::TIEHANDLE at line 172 of CPAN/Tarzip.pm # once (57µs+24µs) by CPAN::Tarzip::TIEHANDLE at line 190 of CPAN/Tarzip.pm
sub debug {
33119168µs my($self,$arg) = @_;
34
3511966µs my @caller;
3611967µs my $i = 0;
3711944µs while () {
383573.95ms my(@c) = (caller($i))[0 .. ($i ? 3 : 2)];
39357239µs last unless defined $c[0];
40357342µs push @caller, \@c;
41357300µs for (0,3) {
42714432µs last if $_ > $#c;
435955.71ms5953.10ms $c[$_] =~ s/.*:://;
# spent 3.10ms making 595 calls to CPAN::Debug::CORE:subst, avg 5µs/call
44 }
45357219µs for (1) {
463572.74ms3571.17ms $c[$_] =~ s|.*/||;
# spent 1.17ms making 357 calls to CPAN::Debug::CORE:subst, avg 3µs/call
47 }
48357354µs last if ++$i>=3;
49 }
50119263µs pop @caller;
511191.12ms if ($CPAN::DEBUG{$caller[0][0]} & $CPAN::DEBUG) {
52 if ($arg and ref $arg) {
53 eval { require Data::Dumper };
54 if ($@) {
55 $CPAN::Frontend->myprint("Debug(\n" . $arg->as_string . ")\n");
56 } else {
57 $CPAN::Frontend->myprint("Debug(\n" . Data::Dumper::Dumper($arg) . ")\n");
58 }
59 } else {
60 my $outer = "";
61 local $" = ",";
62 if (@caller>1) {
63 $outer = ",[@{$caller[1]}]";
64 }
65 $CPAN::Frontend->myprint("Debug(@{$caller[0]}$outer): $arg\n");
66 }
67 }
68}
69
701;
71
72__END__
 
# spent 4.27ms within CPAN::Debug::CORE:subst which was called 952 times, avg 4µs/call: # 595 times (3.10ms+0s) by CPAN::Debug::debug at line 43, avg 5µs/call # 357 times (1.17ms+0s) by CPAN::Debug::debug at line 46, avg 3µs/call
sub CPAN::Debug::CORE:subst; # opcode