← Index
NYTProf Performance Profile   « line view »
For /usr/local/bin/sa-learn
  Run on Sun Nov 5 02:36:06 2017
Reported on Sun Nov 5 02:56:17 2017

Filename/usr/local/lib/perl5/5.24/mach/Time/HiRes.pm
StatementsExecuted 62 statements in 2.01ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
5115.64s5.64sTime::HiRes::::sleepTime::HiRes::sleep (xsub)
51076429.2ms29.2msTime::HiRes::::timeTime::HiRes::time (xsub)
999386µs3.77msTime::HiRes::::importTime::HiRes::import
11184µs84µsTime::HiRes::::bootstrapTime::HiRes::bootstrap (xsub)
11156µs84µsTime::HiRes::::AUTOLOADTime::HiRes::AUTOLOAD
11151µs51µsTime::HiRes::::BEGIN@3Time::HiRes::BEGIN@3
11131µs44µsTime::HiRes::::BEGIN@4Time::HiRes::BEGIN@4
11128µs79µsTime::HiRes::::BEGIN@48Time::HiRes::BEGIN@48
11122µs22µsTime::HiRes::::constantTime::HiRes::constant (xsub)
11120µs20µ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
32119µ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
43474µs258µs
# spent 44µs (31+14) within Time::HiRes::BEGIN@4 which was called: # once (31µs+14µs) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 4
use strict;
# spent 44µs making 1 call to Time::HiRes::BEGIN@4 # spent 14µs making 1 call to strict::import
5
619µsrequire Exporter;
71267µsrequire DynaLoader;
8
9124µsour @ISA = qw(Exporter DynaLoader);
10
1112µsour @EXPORT = qw( );
12118µ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 84µs (56+29) within Time::HiRes::AUTOLOAD which was called: # once (56µs+29µ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";
4012µs die "&Time::HiRes::constant not defined" if $constname eq 'constant';
41135µs122µs my ($error, $val) = constant($constname);
# spent 22µ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 {
483588µs2131µs
# spent 79µs (28+52) within Time::HiRes::BEGIN@48 which was called: # once (28µs+52µs) by Mail::SpamAssassin::Logger::Stderr::BEGIN@38 at line 48
no strict 'refs';
# spent 79µs making 1 call to Time::HiRes::BEGIN@48 # spent 52µs making 1 call to strict::unimport
49218µ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 }
51119µs111µs goto &$AUTOLOAD;
# spent 11µs making 1 call to Time::HiRes::__ANON__[Time/HiRes.pm:49]
52}
53
54
# spent 3.77ms (386µs+3.38) within Time::HiRes::import which was called 9 times, avg 419µs/call: # once (48µs+828µs) by Mail::SpamAssassin::NetSet::BEGIN@25 at line 25 of Mail/SpamAssassin/NetSet.pm # once (43µs+340µs) by Mail::SpamAssassin::Plugin::Check::BEGIN@21 at line 21 of Mail/SpamAssassin/Plugin/Check.pm # once (42µs+335µs) by Mail::SpamAssassin::PerMsgStatus::BEGIN@57 at line 57 of Mail/SpamAssassin/PerMsgStatus.pm # once (43µs+333µs) by Mail::SpamAssassin::DnsResolver::BEGIN@52 at line 52 of Mail/SpamAssassin/DnsResolver.pm # once (43µs+325µs) by Razor2::Logger::BEGIN@7 at line 7 of Razor2/Logger.pm # once (45µs+314µs) by Mail::SpamAssassin::BEGIN@86 at line 86 of Mail/SpamAssassin.pm # once (40µs+317µs) by Mail::SpamAssassin::Util::Progress::BEGIN@50 at line 50 of Mail/SpamAssassin/Util/Progress.pm # once (48µs+290µs) by Mail::SpamAssassin::AsyncLoop::BEGIN@41 at line 41 of Mail/SpamAssassin/AsyncLoop.pm # once (34µs+301µs) by Mail::SpamAssassin::Timeout::BEGIN@61 at line 61 of Mail/SpamAssassin/Timeout.pm
sub import {
55923µs my $this = shift;
56939µs for my $i (@_) {
57988µ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µs9634µs Time::HiRes->export_to_level(1, $this, @_);
# spent 634µs making 9 calls to Exporter::export_to_level, avg 70µs/call
70}
71
72115µs1726µsbootstrap Time::HiRes;
# spent 726µ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
85139µ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 84µs within Time::HiRes::bootstrap which was called: # once (84µs+0s) by DynaLoader::bootstrap at line 210 of DynaLoader.pm
sub Time::HiRes::bootstrap; # xsub
# spent 20µs within Time::HiRes::clock_getres which was called: # once (20µs+0s) by Mail::SpamAssassin::AsyncLoop::BEGIN@49 at line 52 of Mail/SpamAssassin/AsyncLoop.pm
sub Time::HiRes::clock_getres; # xsub
# spent 22µs within Time::HiRes::constant which was called: # once (22µs+0s) by Time::HiRes::AUTOLOAD at line 41
sub Time::HiRes::constant; # xsub
# spent 5.64s within Time::HiRes::sleep which was called 5 times, avg 1.13s/call: # 5 times (5.64s+0s) by Mail::SpamAssassin::Locker::jittery_one_second_sleep at line 73 of Mail/SpamAssassin/Locker.pm, avg 1.13s/call
sub Time::HiRes::sleep; # xsub
# spent 29.2ms within Time::HiRes::time which was called 5107 times, avg 6µs/call: # 1968 times (12.0ms+0s) by Mail::SpamAssassin::AsyncLoop::start_lookup at line 183 of Mail/SpamAssassin/AsyncLoop.pm, avg 6µs/call # 1968 times (8.76ms+0s) by Mail::SpamAssassin::AsyncLoop::start_lookup at line 222 of Mail/SpamAssassin/AsyncLoop.pm, avg 4µs/call # 468 times (3.46ms+0s) by Mail::SpamAssassin::PerMsgStatus::is_dns_available at line 489 of Mail/SpamAssassin/Dns.pm, avg 7µ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 (1.99ms+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.