← Index
NYTProf Performance Profile   « block view • line view • sub view »
For ddd2.pl
  Run on Tue May 25 16:52:24 2010
Reported on Tue May 25 16:56:51 2010

File /project/perl/lib/LWP/Debug.pm
Statements Executed 2322
Statement Execution Time 35.3ms
Subroutines — ordered by exclusive time
Calls P F Exclusive
Time
Inclusive
Time
Subroutine
13844216.6ms16.6msLWP::Debug::::traceLWP::Debug::trace
9293211.4ms11.4msLWP::Debug::::debugLWP::Debug::debug
0000s0sLWP::Debug::::BEGINLWP::Debug::BEGIN
0000s0sLWP::Debug::::_logLWP::Debug::_log
0000s0sLWP::Debug::::connsLWP::Debug::conns
0000s0sLWP::Debug::::importLWP::Debug::import
0000s0sLWP::Debug::::levelLWP::Debug::level
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments
Time
on line
Calls Time
in subs
Code
1package LWP::Debug;
2
3# $Id: Debug.pm,v 1.15 2004/04/09 15:07:04 gisle Exp $
4
516µsrequire Exporter;
6111µs@ISA = qw(Exporter);
717µs@EXPORT_OK = qw(level trace debug conns);
8
93838µsuse Carp ();
10
1116µsmy @levels = qw(trace debug conns);
1215µs%current_level = ();
13
14
15sub import
16{
17 my $pack = shift;
18 my $callpkg = caller(0);
19 my @symbols = ();
20 my @levels = ();
21 for (@_) {
22 if (/^[-+]/) {
23 push(@levels, $_);
24 }
25 else {
26 push(@symbols, $_);
27 }
28 }
29 Exporter::export($pack, $callpkg, @symbols);
30 level(@levels);
31}
32
33
34sub level
35{
36 for (@_) {
37 if ($_ eq '+') { # all on
38 # switch on all levels
39 %current_level = map { $_ => 1 } @levels;
40 }
41 elsif ($_ eq '-') { # all off
42 %current_level = ();
43 }
44 elsif (/^([-+])(\w+)$/) {
45 $current_level{$2} = $1 eq '+';
46 }
47 else {
48 Carp::croak("Illegal level format $_");
49 }
50 }
51}
52
53
54138421.2ms
# spent 16.6ms within LWP::Debug::trace which was called 1384 times, avg 12µs/call: # 461 times (5.85ms+0s) by LWP::UserAgent::request at line 280 of LWP/UserAgent.pm, avg 13µs/call # 461 times (5.62ms+0s) by LWP::UserAgent::send_request at line 149 of LWP/UserAgent.pm, avg 12µs/call # 461 times (5.17ms+0s) by LWP::Protocol::http::request at line 122 of LWP/Protocol/http.pm, avg 11µs/call # once (13µs+0s) by LWP::UserAgent::new at line 36 of LWP/UserAgent.pm
sub trace { _log(@_) if $current_level{'trace'}; }
5592913.2ms
# spent 11.4ms within LWP::Debug::debug which was called 929 times, avg 12µs/call: # 461 times (5.85ms+0s) by LWP::UserAgent::request at line 287 of LWP/UserAgent.pm, avg 13µs/call # 461 times (5.47ms+0s) by LWP::UserAgent::_need_proxy at line 792 of LWP/UserAgent.pm, avg 12µs/call # 7 times (94µs+0s) by LWP::Protocol::collect at line 116 of LWP/Protocol.pm, avg 13µs/call
sub debug { _log(@_) if $current_level{'debug'}; }
56sub conns { _log(@_) if $current_level{'conns'}; }
57
58
59sub _log
60{
61 my $msg = shift;
62 $msg .= "\n" unless $msg =~ /\n$/; # ensure trailing "\n"
63
64 my($package,$filename,$line,$sub) = caller(2);
65 print STDERR "$sub: $msg";
66}
67
68118µs1;
69
70
71__END__
72
73=head1 NAME
74
75LWP::Debug - debug routines for the libwww-perl library
76
77=head1 SYNOPSIS
78
79 use LWP::Debug qw(+ -conns);
80
81 # Used internally in the library
82 LWP::Debug::trace('send()');
83 LWP::Debug::debug('url ok');
84 LWP::Debug::conns("read $n bytes: $data");
85
86=head1 DESCRIPTION
87
88LWP::Debug provides tracing facilities. The trace(), debug() and
89conns() function are called within the library and they log
90information at increasing levels of detail. Which level of detail is
91actually printed is controlled with the C<level()> function.
92
93The following functions are available:
94
95=over 4
96
97=item level(...)
98
99The C<level()> function controls the level of detail being
100logged. Passing '+' or '-' indicates full and no logging
101respectively. Individual levels can switched on and of by passing the
102name of the level with a '+' or '-' prepended. The levels are:
103
104 trace : trace function calls
105 debug : print debug messages
106 conns : show all data transfered over the connections
107
108The LWP::Debug module provide a special import() method that allows
109you to pass the level() arguments with initial use statement. If a
110use argument start with '+' or '-' then it is passed to the level
111function, else the name is exported as usual. The following two
112statements are thus equivalent (if you ignore that the second pollutes
113your namespace):
114
115 use LWP::Debug qw(+);
116 use LWP::Debug qw(level); level('+');
117
118=item trace($msg)
119
120The C<trace()> function is used for tracing function
121calls. The package and calling subroutine name is
122printed along with the passed argument. This should
123be called at the start of every major function.
124
125=item debug($msg)
126
127The C<debug()> function is used for high-granularity
128reporting of state in functions.
129
130=item conns($msg)
131
132The C<conns()> function is used to show data being
133transferred over the connections. This may generate
134considerable output.
135
136=back