maxjhandsome
/
llvm-project
forked from OSchip/llvm-project
1
0
Fork 0
Code Issues Pull Requests Packages Releases Wiki Activity

If timestamps are enabled when logging GDB remote packets ("log enable -T -f /tmp/packets.log gdb-remote logs") then get the amount of time spent executing each packet and summarize at the end of a dump. Sample timing output looks like: 

----------------------------------------------------------------------
Packet timing summary:
----------------------------------------------------------------------
Packet                 Time       %
---------------------- -------- ------
       qThreadStopInfo 0.363844  35.35
                     m 0.281967  27.39
                     s 0.147160  14.30
          qfThreadInfo 0.070865   6.88
          qsThreadInfo 0.061608   5.99
                     z 0.036796   3.57
                     Z 0.036271   3.52
                     c 0.018410   1.79
                     H 0.012418   1.21
---------------------- -------- ------
                 Total 1.029339 100.00

llvm-svn: 148983
This commit is contained in:
Greg Clayton 2012-01-25 21:52:15 +00:00
parent bfecca3331
commit 5c3de1560a
1 changed files with 97 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

99
lldb/scripts/disasm-gdb-remote.pl
View File

@ -25,6 +25,12 @@ our $float32_href = { extract => \&get32, format => "0x%8.8x" };
our $float64_href = { extract => \&get64, format => "0x%s" };
our $float96_href = { extract => \&get96, format => "0x%s" };
our $curr_cmd = undef;
our $curr_full_cmd = undef;
our %packet_times;
our $curr_time = 0.0;
our $last_time = 0.0;
our $base_time = 0.0;
our $packet_start_time = 0.0;
our $reg_cmd_reg;
our %reg_map = (
'i386-gdb' => [
@ -1829,8 +1835,22 @@ sub dump_raw_command
my $cmd_aref = shift;
my $callback_ref;
$curr_cmd = $$cmd_aref[0];
$curr_cmd eq '_' and $curr_cmd .= $$cmd_aref[1];
if ($curr_cmd eq 'q' or $curr_cmd eq 'Q' or $curr_cmd eq '_')
{
$curr_full_cmd = '';
foreach my $ch (@$cmd_aref)
{
$ch !~ /[A-Za-z_]/ and last;
$curr_full_cmd .= $ch;
}
}
else
{
$curr_full_cmd = $curr_cmd;
}
$curr_cmd eq '_' and $curr_cmd .= $$cmd_aref[1];
$callback_ref = $cmd_callbacks{$curr_cmd};
if ($callback_ref)
{
@ -1874,6 +1894,19 @@ sub dump_raw_response
my $cmd_aref = shift;
my $callback_ref;
if ($packet_start_time != 0.0)
{
if (length($curr_full_cmd) > 0)
{
$packet_times{$curr_full_cmd} += $curr_time - $packet_start_time;
}
else
{
$packet_times{$curr_cmd} += $curr_time - $packet_start_time;
}
$packet_start_time = 0.0;
}
$callback_ref = $rsp_callbacks{$curr_cmd};
if ($callback_ref)
@ -1956,16 +1989,41 @@ sub dump_command
#----------------------------------------------------------------------
# Process a gdbserver log line by looking for getpkt and putkpt and
# tossing any other lines.
#----------------------------------------------------------------------
sub process_log_line
{
my $line = shift;
#($opt_v and $opt_g) and print "# $line";
my $extract_cmd = 0;
my $delta_time = 0.0;
if ($line =~ /^(\s*)([1-9][0-9]+\.[0-9]+)([^0-9].*)$/)
{
my $leading_space = $1;
$curr_time = $2;
$line = $3;
if ($base_time == 0.0)
{
$base_time = $curr_time;
}
else
{
$delta_time = $curr_time - $last_time;
}
printf ("(%.6f, %+.6f): ", $curr_time - $base_time, $delta_time);
$last_time = $curr_time;
}
else
{
$curr_time = 0.0
}
if ($line =~ /getpkt /)
{
$extract_cmd = 1;
print "\n--> ";
$packet_start_time = $curr_time;
}
elsif ($line =~ /putpkt /)
{
@ -1976,6 +2034,7 @@ sub process_log_line
{
$opt_g and print "maintenance dump-packets command: $1\n";
my @raw_cmd_bytes = split(/ */, $1);
$packet_start_time = $curr_time;
print "\n--> ";
dump_raw_command(\@raw_cmd_bytes);
process_log_line($2);
@ -1995,6 +2054,7 @@ sub process_log_line
$opt_g and print "command: $1\n";
my @raw_cmd_bytes = split(/ */, $1);
print "--> ";
$packet_start_time = $curr_time;
dump_raw_command(\@raw_cmd_bytes);
}
elsif ($1 =~ /\+/)
@ -2032,6 +2092,7 @@ sub process_log_line
$opt_g and print "command: $1\n";
my @raw_cmd_bytes = split(/ */, $1);
print "--> ";
$packet_start_time = $curr_time;
dump_raw_command(\@raw_cmd_bytes);
}
elsif ($1 =~ /\+/)
@ -2067,6 +2128,7 @@ sub process_log_line
$opt_g and print "command: $1\n";
my @raw_cmd_bytes = split(/ */, $1);
print "\n--> ";
$packet_start_time = $curr_time;
dump_raw_command(\@raw_cmd_bytes);
process_log_line($2);
}
@ -2083,6 +2145,7 @@ sub process_log_line
{
my $beg = index($line, '("') + 2;
my $end = rindex($line, '");');
$packet_start_time = $curr_time;
dump_command(substr($line, $beg, $end - $beg));
}
}
@ -2096,6 +2159,38 @@ while(<>)
process_log_line($_);
}
if (%packet_times)
{
print "----------------------------------------------------------------------\n";
print "Packet timing summary:\n";
print "----------------------------------------------------------------------\n";
print "Packet Time %\n";
print "---------------------- -------- ------\n";
my @packet_names = keys %packet_times;
my $total_packet_times = 0.0;
foreach my $key (@packet_names)
{
$total_packet_times += $packet_times{$key};
}
foreach my $value (sort {$packet_times{$b} cmp $packet_times{$a}} @packet_names)
{
my $percent = ($packet_times{$value} / $total_packet_times) * 100.0;
if ($percent < 10.0)
{
printf("%22s %1.6f %2.2f\n", $value, $packet_times{$value}, $percent);
}
else
{
printf("%22s %1.6f %2.2f\n", $value, $packet_times{$value}, $percent);
}
}
print "---------------------- -------- ------\n";
printf (" Total %1.6f 100.00\n", $total_packet_times);
}