← Index
NYTProf Performance Profile   « line view »
For /usr/local/bin/sa-learn
  Run on Sun Nov 5 03:09:29 2017
Reported on Mon Nov 6 13:20:45 2017

Filename/usr/local/lib/perl5/5.24/mach/Time/HiRes.pm
StatementsExecuted 62 statements in 1.78ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
908881194519s94519sTime::HiRes::::sleepTime::HiRes::sleep (xsub)
51076433.0ms33.0msTime::HiRes::::timeTime::HiRes::time (xsub)
999358µs3.25msTime::HiRes::::importTime::HiRes::import
11174µs74µsTime::HiRes::::bootstrapTime::HiRes::bootstrap (xsub)
11154µs81µsTime::HiRes::::AUTOLOADTime::HiRes::AUTOLOAD
11151µs51µsTime::HiRes::::BEGIN@3Time::HiRes::BEGIN@3
11121µs33µsTime::HiRes::::BEGIN@4Time::HiRes::BEGIN@4
11120µs20µsTime::HiRes::::constantTime::HiRes::constant (xsub)
11119µs69µsTime::HiRes::::BEGIN@48Time::HiRes::BEGIN@48
11112µs12µsTime::HiRes::::clock_getresTime::HiRes::clock_getres (xsub)
11112µs12µsTime::HiRes::::__ANON__[:49]Time::HiRes::__ANON__[:49]
1117µs7µsTime::HiRes::::CORE:substTime::HiRes::CORE:subst (opcode)
0000s0sTime::HiRes::::tv_intervalTime::HiRes::tv_interval
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1package Time::HiRes;
2
32112µs151µs
# spent 51µs within Time::HiRes::BEGIN@3 which was called: # once (51µs+0s) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 3
{ use 5.006; }
# spent 51µs making 1 call to Time::HiRes::BEGIN@3
43402µs245µs
# spent 33µs (21+12) within Time::HiRes::BEGIN@4 which was called: # once (21µs+12µs) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 4
use strict;
# spent 33µs making 1 call to Time::HiRes::BEGIN@4 # spent 12µs making 1 call to strict::import
5
612µsrequire Exporter;
71246µsrequire DynaLoader;
8
9117µsour @ISA = qw(Exporter DynaLoader);
10
1112µsour @EXPORT = qw( );
12112µsour @EXPORT_OK = qw (usleep sleep ualarm alarm gettimeofday time tv_interval
13 getitimer setitimer nanosleep clock_gettime clock_getres
14 clock clock_nanosleep
15 CLOCK_BOOTTIME CLOCK_HIGHRES
16 CLOCK_MONOTONIC CLOCK_MONOTONIC_COARSE
17 CLOCK_MONOTONIC_PRECISE CLOCK_MONOTONIC_RAW
18 CLOCK_PROCESS_CPUTIME_ID
19 CLOCK_REALTIME CLOCK_REALTIME_COARSE
20 CLOCK_REALTIME_FAST CLOCK_REALTIME_PRECISE
21 CLOCK_SECOND CLOCK_SOFTTIME CLOCK_THREAD_CPUTIME_ID
22 CLOCK_TIMEOFDAY CLOCKS_PER_SEC
23 ITIMER_REAL ITIMER_VIRTUAL ITIMER_PROF ITIMER_REALPROF
24 TIMER_ABSTIME
25 d_usleep d_ualarm d_gettimeofday d_getitimer d_setitimer
26 d_nanosleep d_clock_gettime d_clock_getres d_hires_utime
27 d_clock d_clock_nanosleep
28 stat lstat utime
29 );
30
3112µsour $VERSION = '1.9741';
3212µsour $XS_VERSION = $VERSION;
33129µs$VERSION = eval $VERSION;
# spent 5µs executing statements in string eval
34
35our $AUTOLOAD;
36
# spent 81µs (54+26) within Time::HiRes::AUTOLOAD which was called: # once (54µs+26µs) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 52 of Mail/SpamAssassin/AsyncLoop.pm
sub AUTOLOAD {
3712µs my $constname;
38119µs17µs ($constname = $AUTOLOAD) =~ s/.*:://;
# spent 7µs making 1 call to Time::HiRes::CORE:subst
39 # print "AUTOLOAD: constname = $constname ($AUTOLOAD)\n";
4013µs die "&Time::HiRes::constant not defined" if $constname eq 'constant';
41132µs120µs my ($error, $val) = constant($constname);
# spent 20µs making 1 call to Time::HiRes::constant
42 # print "AUTOLOAD: error = $error, val = $val\n";
4312µs if ($error) {
44 my (undef,$file,$line) = caller;
45 die "$error at $file line $line.\n";
46 }
47 {
483516µs2120µs
# spent 69µs (19+50) within Time::HiRes::BEGIN@48 which was called: # once (19µs+50µs) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 48
no strict 'refs';
# spent 69µs making 1 call to Time::HiRes::BEGIN@48 # spent 50µs making 1 call to strict::unimport
49218µs
# spent 12µs within Time::HiRes::__ANON__[/usr/local/lib/perl5/5.24/mach/Time/HiRes.pm:49] which was called: # once (12µs+0s) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 51
*$AUTOLOAD = sub { $val };
50 }
51120µs112µs goto &$AUTOLOAD;
# spent 12µs making 1 call to Time::HiRes::__ANON__[Time/HiRes.pm:49]
52}
53
54
# spent 3.25ms (358µs+2.89) within Time::HiRes::import which was called 9 times, avg 361µs/call: # once (48µs+724µs) by Mail::SpamAssassin::NetSet::BEGIN@25 at line 25 of Mail/SpamAssassin/NetSet.pm # once (45µs+326µs) by Mail::SpamAssassin::Plugin::Check::BEGIN@21 at line 21 of Mail/SpamAssassin/Plugin/Check.pm # once (43µs+308µs) by Mail::SpamAssassin::Util::Progress::BEGIN@50 at line 50 of Mail/SpamAssassin/Util/Progress.pm # once (43µs+297µs) by Mail::SpamAssassin::PerMsgStatus::BEGIN@57 at line 57 of Mail/SpamAssassin/PerMsgStatus.pm # once (41µs+291µs) by Mail::SpamAssassin::BEGIN@86 at line 86 of Mail/SpamAssassin.pm # once (42µs+252µs) by Razor2::Logger::BEGIN@7 at line 7 of Razor2/Logger.pm # once (41µs+230µs) by Mail::SpamAssassin::DnsResolver::BEGIN@52 at line 52 of Mail/SpamAssassin/DnsResolver.pm # once (28µs+238µs) by Mail::SpamAssassin::Timeout::BEGIN@61 at line 61 of Mail/SpamAssassin/Timeout.pm # once (27µs+226µs) by Mail::SpamAssassin::AsyncLoop::BEGIN@41 at line 41 of Mail/SpamAssassin/AsyncLoop.pm
sub import {
55923µs my $this = shift;
56937µs for my $i (@_) {
57981µs if (($i eq 'clock_getres' && !&d_clock_getres) ||
58 ($i eq 'clock_gettime' && !&d_clock_gettime) ||
59 ($i eq 'clock_nanosleep' && !&d_clock_nanosleep) ||
60 ($i eq 'clock' && !&d_clock) ||
61 ($i eq 'nanosleep' && !&d_nanosleep) ||
62 ($i eq 'usleep' && !&d_usleep) ||
63 ($i eq 'utime' && !&d_hires_utime) ||
64 ($i eq 'ualarm' && !&d_ualarm)) {
65 require Carp;
66 Carp::croak("Time::HiRes::$i(): unimplemented in this platform");
67 }
68 }
699163µs9576µs Time::HiRes->export_to_level(1, $this, @_);
# spent 576µs making 9 calls to Exporter::export_to_level, avg 64µs/call
70}
71
72114µs1633µsbootstrap Time::HiRes;
# spent 633µs making 1 call to DynaLoader::bootstrap
73
74# Preloaded methods go here.
75
76sub tv_interval {
77 # probably could have been done in C
78 my ($a, $b) = @_;
79 $b = [gettimeofday()] unless defined($b);
80 (${$b}[0] - ${$a}[0]) + ((${$b}[1] - ${$a}[1]) / 1_000_000);
81}
82
83# Autoload methods go after =cut, and are processed by the autosplit program.
84
85125µs1;
86__END__
 
# spent 7µs within Time::HiRes::CORE:subst which was called: # once (7µs+0s) by Time::HiRes::AUTOLOAD at line 38
sub Time::HiRes::CORE:subst; # opcode
# spent 74µs within Time::HiRes::bootstrap which was called: # once (74µs+0s) by DynaLoader::bootstrap at line 210 of DynaLoader.pm
sub Time::HiRes::bootstrap; # xsub
# spent 12µs within Time::HiRes::clock_getres which was called: # once (12µs+0s) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 52 of Mail/SpamAssassin/AsyncLoop.pm
sub Time::HiRes::clock_getres; # xsub
# spent 20µs within Time::HiRes::constant which was called: # once (20µs+0s) by Time::HiRes::AUTOLOAD at line 41
sub Time::HiRes::constant; # xsub
# spent 94519s within Time::HiRes::sleep which was called 90888 times, avg 1.04s/call: # 90888 times (94519s+0s) by Mail::SpamAssassin::Locker::jittery_one_second_sleep at line 73 of Mail/SpamAssassin/Locker.pm, avg 1.04s/call
sub Time::HiRes::sleep; # xsub
# spent 33.0ms within Time::HiRes::time which was called 5107 times, avg 6µs/call: # 1968 times (14.1ms+0s) by Mail::SpamAssassin::AsyncLoop::start_lookup at line 183 of Mail/SpamAssassin/AsyncLoop.pm, avg 7µs/call # 1968 times (10.0ms+0s) by Mail::SpamAssassin::AsyncLoop::start_lookup at line 222 of Mail/SpamAssassin/AsyncLoop.pm, avg 5µs/call # 468 times (3.63ms+0s) by Mail::SpamAssassin::PerMsgStatus::is_dns_available at line 489 of Mail/SpamAssassin/Dns.pm, avg 8µs/call # 468 times (3.07ms+0s) by Mail::SpamAssassin::PerMsgStatus::new at line 284 of Mail/SpamAssassin/PerMsgStatus.pm, avg 7µs/call # 234 times (2.11ms+0s) by Mail::SpamAssassin::parse at line 528 of Mail/SpamAssassin.pm, avg 9µs/call # once (4µs+0s) by Mail::SpamAssassin::PerMsgStatus::is_dns_available at line 500 of Mail/SpamAssassin/Dns.pm
sub Time::HiRes::time; # xsub
Report produced by the NYTProf 6.04 Perl profiler, developed by Tim Bunce based on work by Adam Kaplan and Salvador Fandiño García.