Revision: 1422
Author: [email protected]
Date: Wed Jun 27 06:13:42 2012
Log: Added section on "subroutine calls had negative time" to
TROUBLESHOOTING docs
http://code.google.com/p/perl-devel-nytprof/source/detail?r=1422
Modified:
/trunk/Changes
/trunk/NYTProf.xs
/trunk/lib/Devel/NYTProf.pm
=======================================
--- /trunk/Changes Thu Mar 22 09:29:50 2012
+++ /trunk/Changes Wed Jun 27 06:13:42 2012
@@ -9,14 +9,17 @@
=head2 Changes in Devel::NYTProf 4.07
Fixed html generation to be valid, RT#70207 (H.Merijn Brand).
- Enable file=/dev/null to work as fix for RT#74565.
- Added and clarified some notes in the troubleshooting docs.
- Added warning for Apache2::SizeLimit in ::Apache, RT#75912.
- Updated ::Apache docs including troubleshooting, RT#75912.
nytprofmerge no longer dies on some errors, RT#75918.
nytprofmerge now sums cumulative_overhead_ticks, RT#75909.
nytprofmerge now gets in man page installed, RT#75911.
+
+ Enable file=/dev/null to work as fix for RT#74565.
+ Updated ::Apache docs including troubleshooting, RT#75912.
Note Devel::NYTProf::Data is undocumented and why, RT#75914.
+ Use Browser::Open if installed for nytprofhtml --open.
+
+ Added and clarified some notes in the troubleshooting docs.
+ Added warning for Apache2::SizeLimit in ::Apache, RT#75912.
=head2 Changes in Devel::NYTProf 4.06 (svn r1406) 30th Nov 2010
=======================================
--- /trunk/NYTProf.xs Thu Mar 22 08:44:22 2012
+++ /trunk/NYTProf.xs Wed Jun 27 06:13:42 2012
@@ -3473,7 +3473,7 @@
}
}
if (negative_time_calls) {
- logwarn("Warning: %d subroutine calls had negative time! The clock
being used (%d) is probably unstable, so the results will be as well.\n",
+ logwarn("Warning: %d subroutine calls had negative time! See
TROUBLESHOOTING in the documentation. (Clock %d)\n",
negative_time_calls, profile_clock);
}
}
=======================================
--- /trunk/lib/Devel/NYTProf.pm Fri Jun 15 09:00:23 2012
+++ /trunk/lib/Devel/NYTProf.pm Wed Jun 27 06:13:42 2012
@@ -1152,6 +1152,32 @@
The invoking fid is known but gets assigned a fid and output after the fid
for
the eval, and that causes the warning when the file is read.
+=head2 Warning: %d subroutine calls had negative time
+
+There are two likely causes for this: clock instability, or accumulated
timing
+errors.
+
+Clock instability, if present on your system, is most likely to be
noticable on
+very small/fast subroutines that are called very few times.
+
+Accumulated timing errors can arise because the subroutine profiler uses
+floating point values (NVs) to store the times. They are most likely to be
+noticed on subroutines that are called a few times but which make a large
+number of calls to very fast subroutines (such as opcodes). In this case
the
+accumulated time apparently spent making those calls can be greater than
the
+time spent in the calling subroutine.
+
+If you rerun nytprofhtml (etc.) with the L</trace=N> option set >0 you'll
see
+trace messages like "%s call has negative time: incl %fs, excl %fs" for
each
+affected subroutine.
+
+Try profiling with the L</slowops=N> option set to 0 to disable the
profiling
+of opcodes. Since opcodes often execute in a few microseconds they are a
common
+cause of this warning.
+
+You could also try recompiling perl to use 'long doubles' for the NV
floating
+point type (use Configure -Duselongdouble). If you try this please let me
know.
+I'd also happily take a patch to use long doubles, if available, by
default.
=head1 AUTHORS AND CONTRIBUTORS
--
You've received this message because you are subscribed to
the Devel::NYTProf Development User group.
Group hosted at: http://groups.google.com/group/develnytprof-dev
Project hosted at: http://perl-devel-nytprof.googlecode.com
CPAN distribution: http://search.cpan.org/dist/Devel-NYTProf
To post, email: [email protected]
To unsubscribe, email: [email protected]
