in reply to Errors when using DProf to profile

Here is one of the ways that can cause these messages

junk.pm

package junk; use strict; use warnings; use Exporter qw[ import ]; our @ISA = 'Exporter'; our @EXPORT_OK = qw[ test test2 ]; sub test{ print 'test' } sub test2{ print 'test2'; goto &test; } 1;

junk.pl

#! perl -slw use strict; use junk qw[ test test2 ]; test; test2;

Profiling output

C:\test>perl -d:DProf junk.pl test test2 test C:\test>dprofpp tmon.out junk::test has 1 unstacked calls in outer junk::test2 has -1 unstacked calls in outer Total Elapsed Time = 0.014928 Seconds User+System Time = 0.015928 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 0.00 - -0.000 1 - - strict::bits 0.00 - -0.000 1 - - warnings::BEGIN 0.00 - -0.000 1 - - warnings::import 0.00 - -0.000 2 - - junk::test 0.00 - -0.000 2 - - strict::import 0.00 - -0.000 2 - - Exporter::import 0.00 - -0.000 1 - - junk::test2 0.00 - -0.000 3 - - junk::BEGIN 0.00 - -0.000 2 - - main::BEGIN

The use of the "magic" goto in subroutine test2(), goto &test, is an optimisation that is sometimes usefully used by packages. It's effect is to transfer control from the first subroutine to the second in such a way as to ensure that when the second subroutine returns, control is transferred directly back to the original caller, rather than back through the first subroutine. This can be used to implement a form of the 'tail call optimisation'.

As dprof tracks and logs entry and exits to subroutines and then tries to match them when calculating the timing information, this one-way transfer of control confuses it's matching process and the warnings you see reflect that.

Either ignore the warnings, or use one of the line-by-line profilers which time each line, rather than each subroutine as so do not become confused. They are often more useful, though the profiling process is necessarily much slower.


Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error.
Lingua non convalesco, consenesco et abolesco. -- Rule 1 has a caveat! -- Who broke the cabal?
"Science is about questioning the status quo. Questioning authority".
In the absence of evidence, opinion is indistinguishable from prejudice.

Replies are listed 'Best First'.
Re^2: Errors when using DProf to profile
by bowei_99 (Friar) on Mar 29, 2006 at 16:49 UTC
    OK, thanks. So I guess if a subroutine doesn't explicitly return a value, would that cause dprof to give an error?

    I'll try Devel::SmallProf to see what happens. I just tried dprof, since it was recommended in PBP.

    -- Burvil

      So I guess if a subroutine doesn't explicitly return a value, would that cause dprof to give an error?

      No it shouldn't. Dprof operates at a level that will see the subroutine return regardless of whether it uses an explicit return statement or not.

      The thing about the goto trick is that the subroutine never returns at all, which Dprof rightly warns as being unusual, althought the goto trick is a specially architected feature of Perl. I guess it would be nice if it could detect the goto and so not report it, but I would imagine that detecting it would be quite difficult to do.

      The chances are that you could just ignore the warnings and the results from dprofpp would be perfectly usable.


      Examine what is said, not who speaks -- Silence betokens consent -- Love the truth but pardon error.
      Lingua non convalesco, consenesco et abolesco. -- Rule 1 has a caveat! -- Who broke the cabal?
      "Science is about questioning the status quo. Questioning authority".
      In the absence of evidence, opinion is indistinguishable from prejudice.