utils/profiling/prof2callgrind.pl

   1 #!/usr/bin/perl
   2
   3 use strict;
   4 use warnings;
   5
   6 my $executablename = $ARGV[0];
   7 my %entries = ();
   8
   9 print "events: Microseconds\n";
  10
  11 my @msAlreadyAccountedFor = (0,0,0,0,0,0,0);
  12 my @callstack = ();
  13
  14 my %callframe = ();
  15 $callframe{"function"} = "toplevel";
  16 $callframe{"file"} = "toplevel";
  17 $callframe{"line"} = 0;
  18 push(@callstack, \%callframe);
  19
  20 while (<STDIN> =~ /^(\w)\t(\S+) ([^:]+):(\d+)\t(\S+) ([^:]+):(\d+)\t(\d+)\.(\d{6})\d*/) {
  21   my ($action, $calledfunction, $calledfile, $calledline,
  22         $callerfunction, $callerfile, $callerline, $sec, $msec) = ($1, $2, $3, $4, $5, $6, $7, $8, $9);
  23   my $callkey = "$calledfile$calledline $callerfile$callerline";
  24   my $entryArrayRef = $entries{$callkey};
  25   if ($action eq "e") {
  26     push(@msAlreadyAccountedFor, 0);
  27
  28     my %callframe = ();
  29     $callframe{"function"} = $calledfunction;
  30     $callframe{"file"} = $calledfile;
  31     $callframe{"line"} = $calledline;
  32     push(@callstack, \%callframe);
  33
  34     if (!defined($entryArrayRef)) {
  35       $entryArrayRef = [];
  36       $entries{$callkey} = $entryArrayRef;
  37     }
  38     push(@$entryArrayRef, "$sec$msec");
  39   }
  40   if ($action eq "x") {
  41     if(defined($entryArrayRef) && (scalar(@$entryArrayRef) > 0)) {
  42       my $entry = pop(@$entryArrayRef);
  43
  44       # Record the 'own time' spent inside the function we're exiting
  45       print "fl=$calledfile\nfn=$calledfunction\n";
  46       my $timespentinchildren = pop(@msAlreadyAccountedFor);
  47       my $timespentinclusive  = "$sec$msec" - $entry;
  48       my $timespentself = $timespentinclusive - $timespentinchildren;
  49       if ($timespentself < 0) {
  50           print STDERR "Spent negative amount of time in $calledfunction ($entry-$sec$msec minus $timespentinchildren) !?\n";
  51           exit 1;
  52       }
  53       #print "Time spent in $calledfunction (inclusive): $timespentinclusive\n";
  54       my $accountedForSoFar = $msAlreadyAccountedFor[-1];
  55       my $accountedFor = $accountedForSoFar + $timespentinclusive;
  56       $msAlreadyAccountedFor[-1] = $accountedFor;
  57       print "$calledline $timespentself\n";
  58
  59       # Record the fact that the parent function called the function we're exiting
  60       pop(@callstack);
  61       if (scalar(@callstack) > 0) {
  62         my %parentframe = %{$callstack[-1]};
  63         my $callerfile = $parentframe{"file"};
  64         my $callerfunction = $parentframe{"function"};
  65         my $callerline = $parentframe{"line"};
  66         print "fl=$callerfile\nfn=$callerfunction\n";
  67         print "cfl=$calledfile\ncfn=$calledfunction\n";
  68         print "calls=1 $calledline\n$callerline $timespentinclusive\n";
  69
  70         #print "Time spent in children of $callerfunction so far: $accountedForSoFar + $timespentinclusive = $accountedFor\n";
  71       }
  72     }
  73   }
  74 }