← Index
NYTProf Performance Profile   « line view »
For /usr/local/bin/sa-learn
  Run on Tue Nov 7 05:38:10 2017
Reported on Tue Nov 7 06:16:00 2017

Filename/usr/local/lib/perl5/5.24/mach/Time/HiRes.pm
StatementsExecuted 62 statements in 2.00ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
8118.80s8.80sTime::HiRes::::sleepTime::HiRes::sleep (xsub)
51126430.3ms30.3msTime::HiRes::::timeTime::HiRes::time (xsub)
999370µs3.75msTime::HiRes::::importTime::HiRes::import
11178µs78µsTime::HiRes::::bootstrapTime::HiRes::bootstrap (xsub)
11166µs66µsTime::HiRes::::BEGIN@3Time::HiRes::BEGIN@3
11159µs87µsTime::HiRes::::AUTOLOADTime::HiRes::AUTOLOAD
11128µs80µsTime::HiRes::::BEGIN@48Time::HiRes::BEGIN@48
11125µs36µsTime::HiRes::::BEGIN@4Time::HiRes::BEGIN@4
11121µs21µsTime::HiRes::::constantTime::HiRes::constant (xsub)
11111µs11µsTime::HiRes::::clock_getresTime::HiRes::clock_getres (xsub)
11111µs11µ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
32115µs166µs
# spent 66µs within Time::HiRes::BEGIN@3 which was called: # once (66µs+0s) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 3
{ use 5.006; }
# spent 66µs making 1 call to Time::HiRes::BEGIN@3
43452µs248µs
# spent 36µs (25+12) within Time::HiRes::BEGIN@4 which was called: # once (25µs+12µs) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 4
use strict;
# spent 36µs making 1 call to Time::HiRes::BEGIN@4 # spent 12µs making 1 call to strict::import
5
615µsrequire Exporter;
71283µsrequire DynaLoader;
8
9125µsour @ISA = qw(Exporter DynaLoader);
10
1112µsour @EXPORT = qw( );
12115µ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;
33139µs$VERSION = eval $VERSION;
# spent 5µs executing statements in string eval
34
35our $AUTOLOAD;
36
# spent 87µs (59+28) within Time::HiRes::AUTOLOAD which was called: # once (59µs+28µs) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 52 of Mail/SpamAssassin/AsyncLoop.pm
sub AUTOLOAD {
3712µs my $constname;
38120µ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';
41135µs121µs my ($error, $val) = constant($constname);
# spent 21µ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 {
483602µs2134µs
# spent 80µs (28+53) within Time::HiRes::BEGIN@48 which was called: # once (28µs+53µs) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 48
no strict 'refs';
# spent 80µs making 1 call to Time::HiRes::BEGIN@48 # spent 53µs making 1 call to strict::unimport
49220µs
# spent 11µs within Time::HiRes::__ANON__[/usr/local/lib/perl5/5.24/mach/Time/HiRes.pm:49] which was called: # once (11µs+0s) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 51
*$AUTOLOAD = sub { $val };
50 }
51120µs111µs goto &$AUTOLOAD;
# spent 11µs making 1 call to Time::HiRes::__ANON__[Time/HiRes.pm:49]
52}
53
54
# spent 3.75ms (370µs+3.38) within Time::HiRes::import which was called 9 times, avg 416µs/call: # once (48µs+846µs) by Mail::SpamAssassin::NetSet::BEGIN@25 at line 25 of Mail/SpamAssassin/NetSet.pm # once (42µs+339µs) by Mail::SpamAssassin::Plugin::Check::BEGIN@21 at line 21 of Mail/SpamAssassin/Plugin/Check.pm # once (44µs+331µs) by Mail::SpamAssassin::PerMsgStatus::BEGIN@57 at line 57 of Mail/SpamAssassin/PerMsgStatus.pm # once (40µs+333µs) by Mail::SpamAssassin::DnsResolver::BEGIN@52 at line 52 of Mail/SpamAssassin/DnsResolver.pm # once (34µs+337µs) by Mail::SpamAssassin::AsyncLoop::BEGIN@41 at line 41 of Mail/SpamAssassin/AsyncLoop.pm # once (41µs+307µs) by Mail::SpamAssassin::BEGIN@86 at line 86 of Mail/SpamAssassin.pm # once (40µs+301µs) by Mail::SpamAssassin::Util::Progress::BEGIN@50 at line 50 of Mail/SpamAssassin/Util/Progress.pm # once (41µs+299µs) by Razor2::Logger::BEGIN@7 at line 7 of Razor2/Logger.pm # once (38µs+285µs) by Mail::SpamAssassin::Timeout::BEGIN@61 at line 61 of Mail/SpamAssassin/Timeout.pm
sub import {
55925µs my $this = shift;
56939µs for my $i (@_) {
57978µ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 }
699161µs9600µs Time::HiRes->export_to_level(1, $this, @_);
# spent 600µs making 9 calls to Exporter::export_to_level, avg 67µs/call
70}
71
72117µs1749µsbootstrap Time::HiRes;
# spent 749µ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
85134µ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 78µs within Time::HiRes::bootstrap which was called: # once (78µs+0s) by DynaLoader::bootstrap at line 210 of DynaLoader.pm
sub Time::HiRes::bootstrap; # xsub
# spent 11µs within Time::HiRes::clock_getres which was called: # once (11µs+0s) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 52 of Mail/SpamAssassin/AsyncLoop.pm
sub Time::HiRes::clock_getres; # xsub
# spent 21µs within Time::HiRes::constant which was called: # once (21µs+0s) by Time::HiRes::AUTOLOAD at line 41
sub Time::HiRes::constant; # xsub
# spent 8.80s within Time::HiRes::sleep which was called 8 times, avg 1.10s/call: # 8 times (8.80s+0s) by Mail::SpamAssassin::Locker::jittery_one_second_sleep at line 73 of Mail/SpamAssassin/Locker.pm, avg 1.10s/call
sub Time::HiRes::sleep; # xsub
# spent 30.3ms within Time::HiRes::time which was called 5112 times, avg 6µs/call: # 1968 times (12.6ms+0s) by Mail::SpamAssassin::AsyncLoop::start_lookup at line 183 of Mail/SpamAssassin/AsyncLoop.pm, avg 6µs/call # 1968 times (9.21ms+0s) by Mail::SpamAssassin::AsyncLoop::start_lookup at line 222 of Mail/SpamAssassin/AsyncLoop.pm, avg 5µs/call # 470 times (3.32ms+0s) by Mail::SpamAssassin::PerMsgStatus::is_dns_available at line 489 of Mail/SpamAssassin/Dns.pm, avg 7µs/call # 470 times (3.21ms+0s) by Mail::SpamAssassin::PerMsgStatus::new at line 284 of Mail/SpamAssassin/PerMsgStatus.pm, avg 7µs/call # 235 times (1.98ms+0s) by Mail::SpamAssassin::parse at line 528 of Mail/SpamAssassin.pm, avg 8µ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.