I wanted to profile some stuff today, so i tried out Devel::Dprof and Devel::Profiler. Unfortunately both have heart attacks with various things that I do in my script so I got nowhere. Fortunately i remembered that you can hand roll your own relatively easily. I came up with the following:

{
    package DB;
    use B;
    BEGIN {
        my $PROFILE="$0.profile";
        open PROFILE,">",$PROFILE or die "$PROFILE:$!";
    }
    sub DB  {}
    my %skip=();
    our $depth=0;
    sub sub {
        my $name=$sub;
        if (ref $name) {
            my $Bobj = B::svref_2object($sub);
            $name=$Bobj->GV->NAME();
        }
        $name=~s/^main::/::/;
        if ( $skip{$name} or $name=~/^[a-z]+(::|$)/ or $name=~/^__ANON
+__/ )
        {
            return &$sub;
        }
        my @time=(time,times);
        print PROFILE "> ",(" " x $depth),$name,"\n";
        my (@array,$scalar);
        {
            local $depth=$depth+1;
            if (wantarray) {
               @array=&$sub;
            } elsif (defined wantarray) {
               $scalar=&$sub;
            } else {
               &$sub;
            }
        }
        my @after=(time,times);
        my $time=join(", ",map {$after[$_]-$time[$_] } 0..$#time);
        print PROFILE "< ",(" " x $depth),$name,"=$time","\n";
        if (wantarray) {
           return @array
        } elsif (defined wantarray) {
           return $scalar
        }
    }
}
1
[download]

Which produces output like:

E:\>perl -I./lib -d:MyDB -e "sub X { Y() } sub Y { sleep(1) } X,X,Y"

E:\>type -e.profile
> ::X
>  ::Y
<  ::Y=1, 0, 0, 0, 0
< ::X=1, 0, 0, 0, 0
> ::X
>  ::Y
<  ::Y=1, 0, 0, 0, 0
< ::X=1, 0, 0, 0, 0
> ::Y
< ::Y=1, 0, 0, 0, 0
[download]

The following is a larger but better example.

>      Rating::CachedObject::new
>       Rating::ZoneTimePlan::init
>        Rating::DBI::dbh
<        Rating::DBI::dbh=0, 0, 0, 0, 0
>        DBI::db::selectall_arrayref
>         DBI::db::prepare
>          DBD::Sybase::db::prepare
>           DBI::_new_sth
>            DBI::_new_handle
>             DBI::st::TIEHASH
<             DBI::st::TIEHASH=0, 0, 0, 0, 0
>             DBI::_setup_handle
<             DBI::_setup_handle=0, 0.0150000000000006, 0, 0, 0
<            DBI::_new_handle=0, 0.0150000000000006, 0, 0, 0
<           DBI::_new_sth=0, 0.0150000000000006, 0, 0, 0
>           DBD::Sybase::st::_prepare
<           DBD::Sybase::st::_prepare=0, 0, 0, 0, 0
<          DBD::Sybase::db::prepare=0, 0.0150000000000006, 0, 0, 0
<         DBI::db::prepare=0, 0.0150000000000006, 0, 0, 0
>        DBI::st::DESTROY
<        DBI::st::DESTROY=0, 0, 0, 0, 0
>        DBI::st::DESTROY
<        DBI::st::DESTROY=0, 0, 0, 0, 0
>        DBD::_mem::common::DESTROY
<        DBD::_mem::common::DESTROY=0, 0, 0, 0, 0
<        DBI::db::selectall_arrayref=0, 0.0150000000000006, 0, 0, 0
>        Rating::CachedObject::new
<        Rating::CachedObject::new=0, 0, 0, 0, 0
<       Rating::ZoneTimePlan::init=0, 0.0150000000000006, 0, 0, 0
<      Rating::CachedObject::new=0, 0.0150000000000006, 0, 0, 0
[download]

The problem is I cant really think of too many ways to aggregate this information usefully. Any ideas from you folks would be very welcome.

Cheers.