http://qs321.pair.com?node_id=158615

dreadpiratepeter has asked for the wisdom of the Perl Monks concerning the following question:

I have been getting wierd results from dprofpp involving BEGIN blocks. I get an inordinately high number of call to BEGIN and I don't understand why. I have distilled the problem down to a simple example:

file 1 (T.pm):
package T; use strict; sub foo { } 1;


file2 (U.pm):
package U; use T; sub foo { T->foo; } 1;


file 3 (t.pl):
#!/usr/local/bin/perl use strict; use U; U->foo() foreach (0..10000);


When I run t.pl with perl -d:DProf t.pl and then run it though dprofpp tmon.out I get the following results:

Total Elapsed Time = -0.04006 Seconds User+System Time = 0 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 0.00 0.040 0.005 10002 0.0000 0.0000 U::BEGIN 0.00 0.010 -0.005 10001 0.0000 - T::foo 0.00 0.000 -0.000 2 0.0000 - main::BEGIN 0.00 0.000 -0.000 2 0.0000 - strict::import 0.00 0.000 -0.000 2 0.0000 - strict::bits 0.00 0.000 -0.000 1 0.0000 - T::BEGIN


It appears that I get a BEGIN call in U every time I call a method in T. That doesn't sound right. I also changed the example to use straight function calls instead of class methods and I get the same results. Can anyone familiar with the internals elighten this poor friar?

-pete
"I am Jack's utter lack of disbelief"

Replies are listed 'Best First'.
Re: Wierd dprofpp results.
by dug (Chaplain) on Apr 12, 2002 at 18:45 UTC
    DProf seems to be lying.

    If in U.pm you replace:
    use T;

    with:
    BEGIN { require T; warn "executing BEGIN\n"; }

    you will only see the warning once, and dprofpp will still show 10002 calls to U::BEGIN.

    from perldoc perlmod:

    use Module ();
    is exactly equivalent to
    BEGIN { require Module; }


    Now, that said, I can't tell you why it's lying :)

    dug