dprofpp - understanding the output

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

I ran a piece of code with -d:DProf. I then ran 'dprofpp' to produce this output:

Total Elapsed Time = 19.44016 Seconds
  User+System Time = 0.230160 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 17.3   0.040  0.069     16   0.0025 0.0043  Alerts_Common::BEGIN
 13.0   0.030  0.204      4   0.0074 0.0511  main::BEGIN
 11.3   0.026  0.086     22   0.0012 0.0039  Switch::filter_blocks
 9.99   0.023  0.037    746   0.0000 0.0000  Text::Balanced::_match_va
+riable
 7.39   0.017  0.017   1532   0.0000 0.0000  Text::Balanced::_failmsg
 4.34   0.010  0.010      2   0.0050 0.0050  DynaLoader::BEGIN
 4.34   0.010  0.010     12   0.0008 0.0008  Exporter::as_heavy
 4.34   0.010  0.020      1   0.0100 0.0198  DBI::install_driver
 4.34   0.010  0.010     16   0.0006 0.0006  DBD::mysql::db::_login
 4.34   0.010  0.010     18   0.0006 0.0006  DBI::st::finish
 4.34   0.010  0.010     21   0.0005 0.0005  vars::import
 4.34   0.010  0.010      6   0.0017 0.0016  Mail::Sendmail::BEGIN
 4.34   0.010  0.010     17   0.0006 0.0006  DBI::db::prepare
 4.34   0.010  0.010     36   0.0003 0.0003  Exporter::import
 4.34   0.010  0.010      9   0.0011 0.0011  Switch::BEGIN
[download]

Question: the calls to "BEGIN" - these are the constructors?

Comment on dprofpp - understanding the output Download Code

Replies are listed 'Best First'.
Re: dprofpp - understanding the output by perrin (Chancellor) on Jul 20, 2007 at 16:27 UTC
Those are the BEGIN blocks in those modules. By the way, when profiling something that uses DBI, you almost always want to profile wallclock time, not CPU time. Use the -r flag to dprofpp.	[reply]
Re^2: dprofpp - understanding the output by kyle (Abbot) on Jul 20, 2007 at 17:33 UTC
when profiling something that uses DBI, you almost always want to profile wallclock time Yes. It's also handy to use the DBI's own profiling code (invoked by setting a `DBI_PROFILE` environment variable). See DBI::Profile.	[reply] [d/l]
Re^2: dprofpp - understanding the output by Joost (Canon) on Jul 20, 2007 at 20:03 UTC
Note that when you "use" a module, loading, compiling & importing the module and executing the immediate code in the module gets processed during a BEGIN block in the caller. See also use. In other words, a lot of the time in the OP's profiling data is probably spent loading & initializing modules. "What should it profit a man, if he should win a flame war, yet lose his cool?"	[reply]
Re: dprofpp - understanding the output by shmem (Chancellor) on Jul 20, 2007 at 17:45 UTC
Question: the calls to "BEGIN" - these are the constructors? See perlmod for explanation of `BEGIN, CHECK, INIT` and `END` blocks. In the dprofpp output, they only appear as if they were subroutines, which they aren't. --shmem _($_=" "x(1<<5)."?\n".q·/)Oo. G°\ / /\_¯/(q / ---------------------------- \__(m.====·.(_("always off the crowd"))."· ");sub _{s./.($e="'Itrs `mnsgdq Gdbj O`qkdq")=~y/"-y/#-z/;$e.e && print}	[reply] [d/l] [select]