From 05dccc355144dc717b3cb9ef0074a9ab38a520f4 Mon Sep 17 00:00:00 2001 From: Brandon Low Date: Wed, 18 Jan 2006 20:54:13 +0000 Subject: Profiling support, tools and documentation. git-svn-id: svn://svn.rockbox.org/rockbox/trunk@8375 a1c6a512-1295-4272-9138-f99709370657 --- tools/FILES | 1 + tools/buildzip.pl | 1 + tools/configure | 38 ++++- tools/profile_reader/profile_comparator.pl | 104 +++++++++++++ tools/profile_reader/profile_reader.pl | 236 +++++++++++++++++++++++++++++ 5 files changed, 373 insertions(+), 7 deletions(-) create mode 100755 tools/profile_reader/profile_comparator.pl create mode 100755 tools/profile_reader/profile_reader.pl (limited to 'tools') diff --git a/tools/FILES b/tools/FILES index 19d3a5576f..f4b1c6dca7 100644 --- a/tools/FILES +++ b/tools/FILES @@ -23,3 +23,4 @@ ucl/*.[ch] ucl/src/*.[ch] ucl/src/Makefile ucl/include/ucl/*.h +profile_reader/*.pl diff --git a/tools/buildzip.pl b/tools/buildzip.pl index eabf739d0d..934b0035e4 100755 --- a/tools/buildzip.pl +++ b/tools/buildzip.pl @@ -199,6 +199,7 @@ sub buildzip { "CUSTOM_CFG_FORMAT", "CUSTOM_WPS_FORMAT", "FAQ", + "LICENSES", "NODO", "TECH")) { `cp $ROOT/docs/$_ .rockbox/docs/$_.txt`; diff --git a/tools/configure b/tools/configure index 2cd855e0c5..2bea201324 100755 --- a/tools/configure +++ b/tools/configure @@ -240,7 +240,7 @@ whichdevel () { # echo "" echo "Enter your developer options (press enter when done)" - echo "(D)EBUG, (L)ogf, (S)imulator" + echo "(D)EBUG, (L)ogf, (S)imulator, (P)rofiling" cont=1 while [ $cont = "1" ]; do @@ -249,19 +249,29 @@ whichdevel () { case $option in [Dd]) - echo "define DEBUG" - debug="-DDEBUG" - GCCOPTS="$GCCOPTS -g -DDEBUG" + if [ "yes" = "$profile" ]; then + echo "Debug is incompatible with profiling" + else + echo "define DEBUG" + use_debug="yes" + fi ;; [Ll]) - logf="yes" echo "logf() support enabled" - use_logf="#define ROCKBOX_HAS_LOGF 1" + logf="yes" ;; [Ss]) echo "Simulator build enabled" simulator="yes" ;; + [Pp]) + if [ "yes" = "$use_debug" ]; then + echo "Profiling is incompatible with debug" + else + echo "Profiling support is enabled" + profile="yes" + fi + ;; *) echo "done" cont=0 @@ -269,11 +279,23 @@ whichdevel () { esac done + if [ "yes" = "$use_debug" ]; then + debug="-DDEBUG" + GCCOPTS="$GCCOPTS -g -DDEBUG" + fi + if [ "yes" = "$logf" ]; then + use_logf="#define ROCKBOX_HAS_LOGF 1" + fi if [ "yes" = "$simulator" ]; then debug="-DDEBUG" - extradefines="-DSIMULATOR" + extradefines="$extradefines -DSIMULATOR" whichsim fi + if [ "yes" = "$profile" ]; then + extradefines="$extradefines -DRB_PROFILE" + PROFILE_OPTS="-finstrument-functions" + GCCOPTS="$GCCOPTS $GCCOPTIMIZE" + fi } whichsim () { @@ -902,6 +924,7 @@ sed > Makefile \ -e "s,@FLASHFILE@,${flash},g" \ -e "s,@PLUGINS@,${plugins},g" \ -e "s,@CODECS@,${codecs},g" \ + -e "s,@PROFILE_OPTS@,${PROFILE_OPTS},g" \ -e "s,@GCCOPTS@,${GCCOPTS},g" \ -e "s!@LDOPTS@!${LDOPTS}!g" \ -e "s,@LOADADDRESS@,${loadaddress},g" \ @@ -952,6 +975,7 @@ export WINDRES=@WINDRES@ export DLLTOOL=@DLLTOOL@ export DLLWRAP=@DLLWRAP@ export RANLIB=@RANLIB@ +export PROFILE_OPTS=@PROFILE_OPTS@ export GCCOPTS=@GCCOPTS@ export LOADADDRESS=@LOADADDRESS@ export SIMVER=@SIMVER@ diff --git a/tools/profile_reader/profile_comparator.pl b/tools/profile_reader/profile_comparator.pl new file mode 100755 index 0000000000..da5e3004c9 --- /dev/null +++ b/tools/profile_reader/profile_comparator.pl @@ -0,0 +1,104 @@ +#!/usr/bin/perl +sub error { + print("Error: @_\n"); + exit(1); +} +sub usage { + if (@_) { + print STDERR ("Error: @_\n"); + } + print STDERR ("USAGE:\n"); + print STDERR ("$0 file1 file2 [showcalldiff]\n"); + print STDERR + ("\tfile[12] output from profile_reader.pl to compare\n"); + print STDERR + ("\tshowcalldiff show the percent change in calls instead of ticks\n"); + exit(1); +} +if ($ARGV[0] =~ m/-(h|help|-help)/) { + usage(); +} +if (@ARGV < 2) { + usage("Requires at least 2 arguments"); +} +open(FILE1,shift) || error("Couldn't open file1"); +my @file1 = ; +close(FILE1); +open(FILE2,shift) || error("Couldn't open file2"); +my @file2 = ; +close(FILE2); +my $showcalldiff = shift; +my %calls1; +my %calls2; +my @calls = (\%calls1,\%calls2); +my $start = 0; +my @files = (\@file1,\@file2); +my @allcalls = (0,0); +my @allticks = (0,0); +for ( $i=0; $i <= $#files; $i++ ) { + my $file = $files[$i]; + foreach $line(@$file) { + chomp($line); + if ( $line =~ m/By calls/ ) { + $start = 1; + next; + } + if ( $line =~ m/By ticks/ ) { + $start = 0; + last; + } + if ( $start == 1) { + my @line = split(/[[:space:]]+/,$line); + $allcalls[$i] += $line[1]; + $allticks[$i] += $line[3]; + $calls[$i]{$line[5]} = [($line[1],$line[3])]; + } + } +} +printf("File one calls: %08ld, ticks: %08ld\n",$allcalls[0],$allticks[0]); +printf("File two calls: %08ld, ticks: %08ld\n",$allcalls[1],$allticks[1]); +printf("Percent change: %+7.2f%%, ticks: %+7.2f%%\n", + ($allcalls[1]-$allcalls[0])/$allcalls[0]*100, + ($allticks[1]-$allticks[0])/$allticks[0]*100); +my @allkeys = keys(%calls1); +push(@allkeys,keys(%calls2)); +my %u = (); +my @keys = grep {defined} map { + if (exists $u{$_}) { undef; } else { $u{$_}=undef;$_; } +} @allkeys; +undef %u; +my %byticks; +my %bycalls; +foreach $key(@keys) { + my $values1 = $calls1{$key}; + my $values2 = $calls2{$key}; + my $calldiff = @$values2[0]-@$values1[0]; + my $totalcalls = @$values2[0]+@$values1[0]; + my $tickdiff = @$values2[1]-@$values1[1]; + my $totalticks = @$values2[1]+@$values1[1]; + my $pdiff; + my $result; + if ($showcalldiff) { + $pdiff = $calldiff/(@$values1[0]>0?@$values1[0]:1)*100; + $result = sprintf("%+7.2f%% Calls: %+09d Symbol: %s$key\n", + $pdiff, $calldiff, + (exists $calls1{$key} && exists $calls2{$key})?"":"LONE "); + } else { + $pdiff = $tickdiff/(@$values1[1]>0?@$values1[1]:1)*100; + $result = sprintf("%+7.2f%% Ticks: %+09d Symbol: %s$key\n", + $pdiff, $tickdiff, + (exists $calls1{$key} && exists $calls2{$key})?"":"LONE "); + } + $bycalls{sprintf("%08X$key",$totalcalls)} = $result; + $byticks{sprintf("%08X$key",$totalticks)} = $result; +} +my @calls = sort(keys(%bycalls)); +print("By calls\n"); +foreach $call(@calls) { + print($bycalls{$call}); +} +my @ticks = sort(keys(%byticks)); +print("By ticks\n"); +foreach $tick(@ticks) { + print($byticks{$tick}); +} diff --git a/tools/profile_reader/profile_reader.pl b/tools/profile_reader/profile_reader.pl new file mode 100755 index 0000000000..088ba7186e --- /dev/null +++ b/tools/profile_reader/profile_reader.pl @@ -0,0 +1,236 @@ +#!/usr/bin/perl + +sub error { + print STDERR ("Error: @_\n"); + exit(1); +} + +sub warning { + print STDERR ("Warning: @_\n"); +} + +# string (filename.map) +# return hash(string:hash(string:number)) +sub read_map { + open(MAP_FILE,$_[0]) || error("Couldn't open a map $_[0]"); + my %retval; + while () { + chomp; + my @parts = split(/[[:space:]]+/); + if (@parts != 5) { + next; + } + if ($parts[1] =~ m/\.(text|data|rodata|bss|icode|idata|irodata|ibss)/) { + my $region = $parts[1]; + my $number = $parts[2]; + @parts = split(/\//,$parts[4]); + @parts = split(/[\(\)]/,$parts[$#parts]); + my $library = $retval{$parts[0]}; + my %library = %$library; + my $object = $parts[$#parts]; + $library{$object . $region} = $number; + $retval{$parts[0]} = \%library; + } + } + close(MAP_FILE); + return %retval; +} + +# string (filename.[ao]), hash(string:number) +# return hash(number:string) +sub read_library { + open(OBJECT_FILE,"objdump -t $_[0] |") || + error("Couldn't pipe objdump for $_[0]"); + my $library = $_[1]; + my %library = %$library; + my %retval; + my $object; + while () { + chomp; + my @parts = split(/[[:space:]]+/); + if ($parts[0] =~ m/:$/) { + $object = $parts[0]; + $object =~ s/:$//; + next; + } + if (@parts != 6) { + next; + } + if ($parts[0] eq "") { + next; + } + if ($parts[3] eq $parts[5]) { + next; + } + if ($parts[3] =~ m/\.(text|data|rodata|bss|icode|idata|irodata|ibss)/) { + my $region = $parts[3]; + my $symbolOffset = hex("0x" . $parts[0]); + my $sectionOffset = hex($library{$object . $region}); + my $location = $symbolOffset + $sectionOffset; + $retval{$location} = $parts[5] . "(" . $object . ")"; + } + } + close(OBJECT_FILE); + return %retval; +} + +# string (0xFFFFFFFF), hash(number:string) +# return string +sub get_name { + my $location = hex($_[0]); + my $offsets = $_[1]; + my %offsets = %$offsets; + if (exists $offsets{$location}) { + return $offsets{$location}; + } else { + my $retval = $_[0]; + $retval =~ y/[A-Z]/a-z/; + warning("No symbol found for $retval"); + return $retval; + } +} + +# string (filename), hash(number:string) +# return array(array(number,number,string)) +sub create_list { + open(PROFILE_FILE,$_[0]) || + error("Could not open profile file: $profile_file"); + my $offsets = $_[1]; + my $started = 0; + my %pfds; +# my $totalCalls = 0; +# my $totalTicks = 0; +# my $pfds = 0; + while () { + if ($started == 0) { + if (m/^0x/) { + $started = 1; + } else { + next; + } + } + my @parts = split(/[[:space:]]+/); + if ($parts[0] =~ m/^0x/) { + my $callName = get_name($parts[0],$offsets); + my $calls = $parts[1]; + my $ticks = $parts[2]; + my @pfd = ($calls,$ticks,$callName); + if (exists $pfds{$callName}) { + my $old_pfd = $pfds{$callName}; + $pfd[0]+=@$old_pfd[0]; + $pfd[1]+=@$old_pfd[1]; + } + $pfds{$callName} = \@pfd; +# $pfds++; +# $totalCalls+=$calls; +# $totalTicks+=$ticks; + } else { + last; + } + + } + close(PROFILE_FILE); +# print("FUNCTIONS\tTOTAL_CALLS\tTOTAL_TICKS\n"); +# printf(" %4d\t %8d\t %8d\n",$pfds,$totalCalls,$totalTicks); + return values(%pfds); +} + +# array(array(number,number,string)), number (sort element) +sub print_sorted { + my $pfds = $_[0]; + my @pfds = @$pfds; + my $sort_index = $_[1]; + my $percent = $_[2]; + my %elements; + my $totalCalls = 0; + my $totalTicks = 0; + $pfds = 0; + foreach $element(@pfds) { + $elements{@$element[$sort_index] . @$element[2]} = $element; + $pfds++; + $totalCalls += @$element[0]; + $totalTicks += @$element[1]; + } + my @keys = sort(keys(%elements)); + print("FUNCTIONS\tTOTAL_CALLS\tTOTAL_TICKS\n"); + printf(" %4d\t %8d\t %8d\n",$pfds,$totalCalls,$totalTicks); + foreach $key(@keys) { + my $element = $elements{$key}; + if ($percent) { + printf("Calls: %7.2f%% Ticks: %7.2f%% Symbol: %s\n", + @$element[0]/$totalCalls*100, + @$element[1]/$totalTicks*100, + @$element[2]); + } else { + printf("Calls: %08d Ticks: %08d Symbol: %s\n", + @$element); + } + } +} + +# merges two hashes +sub merge_hashes { + my $hash1 = $_[0]; + my $hash2 = $_[1]; + return (%$hash1,%$hash2); +} + +sub usage { + if (@_) { + print STDERR ("Error: @_\n"); + } + print STDERR ("USAGE:\n"); + print STDERR ("$0 profile.out map obj[...] [map obj[...]...] sort[...]\n"); + print STDERR + ("\tprofile.out output from the profiler, extension is .out\n"); + print STDERR + ("\tmap map file, extension is .map\n"); + print STDERR + ("\tobj library or object file, extension is .a or .o\n"); + print STDERR + ("\tformat 0-2[_p] 0: by calls, 1: by ticks, 2: by name\n"); + print STDERR + ("\t _p shows percents instead of counts\n"); + print STDERR ("NOTES:\n"); + print STDERR + ("\tmaps and objects come in sets, one map then many objects\n"); + exit(1); +} + + +if ($ARGV[0] =~ m/-(h|help|-help)/) { + usage(); +} +if (@ARGV < 2) { + usage("Requires at least 2 arguments"); +} +if ($ARGV[0] !~ m/\.out$/) { + usage("Profile file must end in .out"); +} +my $i = 1; +my %symbols; +{ + my %map; + for (; $i < @ARGV; $i++) { + my $file = $ARGV[$i]; + if ($file =~ m/\.map$/) { + %map = read_map($file); + } elsif ($file =~ m/\.[ao]$/) { + if (!%map) { + usage("No map file found before first object file"); + } + my @parts = split(/\//,$file); + my %new_symbols = read_library($file,$map{$parts[$#parts]}); + %symbols = merge_hashes(\%symbols,\%new_symbols); + } else { + last; + } + } +} +if (!%symbols) { + warning("No symbols found"); +} +my @pfds = create_list($ARGV[0],\%symbols); +for (; $i < @ARGV; $i++) { + print_sorted(\@pfds,split("_",$ARGV[$i])); +} -- cgit v1.2.3