Revision: 1081 Author: tim.bunce Date: Wed Feb 24 02:40:49 2010 Log: More refinements to shed light on freebsd test failures like http://www.cpantesters.org/cpan/report/6859183
http://code.google.com/p/perl-devel-nytprof/source/detail?r=1081 Modified: /trunk/t/61-cputime.t ======================================= --- /trunk/t/61-cputime.t Tue Feb 23 01:40:54 2010 +++ /trunk/t/61-cputime.t Wed Feb 24 02:40:49 2010 @@ -26,7 +26,7 @@ src_code => $src_code, out_file => $env->{file}, #htmlopen => 1, - verbose => ($^O eq 'freebsd' or 1), # XXX temp + verbose => ($^O eq 'freebsd'), # XXX temp ); isa_ok $profile, 'Devel::NYTProf::Data'; @@ -42,15 +42,17 @@ __DATA__ #!perl + +BEGIN { eval { require Time::HiRes } and Time::HiRes->import('time') } alarm(20); # watchdog timer -my $trace = ($^O eq 'freebsd' or 1) ? 2 : 1; # XXX temp -my $cpu1 = (times)[0]; +my $trace = ($^O eq 'freebsd') ? 2 : 1; # XXX temp +my $cpu1; my $cpu2; sub foo { - my $end = shift; + my $cpuspend = shift; # sleep to separate cputime from realtime # (not very effective in cpu-starved VMs) @@ -60,25 +62,32 @@ my $prev; while (++$loops) { - my $crnt = (times)[0]; - warn "tick $crnt\t".time()."\n" - if $crnt != $prev and $trace >= 2; + my $crnt = (times)[0] - $cpu1; + warn sprintf "tick %.4f\t%f\n", $crnt, time() + if $trace >= 2 && $prev && $crnt != $prev; $prev = $crnt; - last if $crnt >= $end; - } - warn "cputime loop count $loops\n" if $trace; + last if $crnt >= $cpuspend; + } + warn "cputime loop count $loops\n" if $trace >= 2; } -# sync up: spin till clock ticks +# record start time +my $start = time() + 1; + +# sync up... + +# spin till wall clock ticks +1 while time() <= $start; + +# spin till cpu clock ticks (typically 0.1 sec max) +$cpu1 = (times)[0]; 1 while $cpu1 == ($cpu2 = (times)[0]); -warn "cputime step ".($cpu2-$cpu1)."\n" if $trace; - -# record start time -my $start = time(); + +warn sprintf "step %f\t%f\n", $cpu2-$cpu1, time() if $trace; # consume this much cpu time inside foo() -foo($cpu2 + 0.4); +foo(0.4); # report realtime to help identify is cputime is really measuring realtime print "realtime used ".(time()-$start)."\n" if $trace; -- 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]
