NAME

profiler -- finds out how long functions run and how often they are called.

USAGE

cp -r <makepp-root> /tmp/makeppcopy
cd /tmp/makeppcopy
perl profiler.pm [-r fn-name-beginning-regexp] [Module ...]
cd ...
/tmp/makeppcopy/makepp ...
cat profiler.log

DESCRIPTION

When called as a script, this modifies every source of makepp, adding a my variable to each named sub. If a fn-name-beginning-regexp is given, only functions whose name beginning match it get instrumented. If a list of modules is given, only those are instrumented. However makepp itself is always instrumented, since that sets up the profiler and outputs the results.

At makepp runtime this variable records the hires time, and its destructor stores the difference minus the time of any other makepp subs it called. The number of calls is also stored.

Independently each sub also records the above info per different caller it got invoked from.

This information is output as a delta for the top cases roughly every PROFMPP_INTERVAL seconds and as a total at the end of the run.

Four environment variables control the relevancy and granularity:

$PROFMPP_MINTIME		# .5 seconds
$PROFMPP_MINCOUNT		# 100 calls
$PROFMPP_CHILDFRACTION	# 100
$PROFMPP_INTERVAL		# 60 seconds

Values which are less than these per time interval or in the final tally are not considered. Child processes only have a final tally, and the time and count are 1/PROFMPP_CHILDFRACTIONth of these values there.

BUGS

This counts real time -- I don't know how to get the CPU time, since times() is far too coarse. It is only shown indicatively per interval.