On 20/01/2018 00:24, John.C.Harrison@xxxxxxxxx wrote:
From: John Harrison <John.C.Harrison@xxxxxxxxx>
There are various statistics being calculated multiple times in
multiple places while the log file is being read in. Some of these are
then re-calculated when the database is munged to correct various
issues with the logs. This patch consolidates the calculations into a
separate pass after all the reading and munging has been done.
Note that this actually produces a different final output as the
'execute-delay' values were not previously being re-calculated after
all the fixups. Thus were based on an incorrect calculation.
Signed-off-by: John Harrison <John.C.Harrison@xxxxxxxxx>
Cc: Tvrtko Ursulin <tvrtko.ursulin@xxxxxxxxx>
---
scripts/trace.pl | 54 ++++++++++++++++++++++++++++--------------------------
1 file changed, 28 insertions(+), 26 deletions(-)
diff --git a/scripts/trace.pl b/scripts/trace.pl
index cf841b7e..c5d822aa 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -437,8 +437,7 @@ while (<>) {
$req{'global'} = $tp{'global'};
$req{'port'} = $tp{'port'};
$req{'queue'} = $queue{$key};
- $req{'submit-delay'} = $submit{$key} - $queue{$key};
- $req{'execute-delay'} = $req{'start'} - $submit{$key};
+ $req{'submit'} = $submit{$key};
You only use the submit key to look up things two times, so you could
use the %submit hash directly to save some lookups, but on the other
hand maybe you were going for nicer split between data structures over
performance.
When I look at it again, I was using the same approach for 'queue' when
%queue was also available so never mind.. maybe an optimisation
opportunity with both for later, if would be worth it.
$rings{$ring} = $gid++ unless exists $rings{$ring};
$ringmap{$rings{$ring}} = $ring;
$db{$key} = \%req;
@@ -458,8 +457,6 @@ while (<>) {
$db{$key}->{'notify'} = $db{$key}->{'end'};
$db{$key}->{'no-notify'} = 1;
}
- $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
- $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
} elsif ($tp_name eq 'i915:intel_engine_notify:') {
$notify{global_key($ring, $seqno)} = $time;
} elsif ($tp_name eq 'i915:intel_gpu_freq_change:') {
@@ -493,16 +490,11 @@ foreach my $key (keys %db) {
$db{$key}->{'notify'} = $db{$key}->{'end'};
$db{$key}->{'incomplete'} = 1;
}
-
- $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
- $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
} else {
# Notify arrived after context complete.
if (exists $db{$key}->{'no-notify'} and exists $notify{$gkey}) {
delete $db{$key}->{'no-notify'};
$db{$key}->{'notify'} = $notify{$gkey};
- $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
- $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
}
}
}
@@ -529,8 +521,6 @@ foreach my $key (@keys) {
if (exists $db{$next_key}) {
$db{$key}->{'notify'} = $db{$next_key}->{'end'};
$db{$key}->{'end'} = $db{$key}->{'notify'};
- $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
- $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
}
}
@@ -565,19 +555,14 @@ die "Database changed size?!" unless scalar(@sorted_keys) == $keyCount;
foreach my $key (@sorted_keys) {
my $ring = $db{$key}->{'ring'};
my $end = $db{$key}->{'end'};
+ my $start = $db{$key}->{'start'};
+ my $notify = $db{$key}->{'notify'};
Why did you move/put these two here since they are not used outside the
$correct_durations block? I'd avoid hash queries if not needed.
$first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts;
$last_ts = $end if $end > $last_ts;
- $running{$ring} += $end - $db{$key}->{'start'} unless exists $db{$key}->{'no-end'};
- $runnable{$ring} += $db{$key}->{'execute-delay'};
- $queued{$ring} += $db{$key}->{'start'} - $db{$key}->{'execute-delay'} - $db{$key}->{'queue'};
-
- $batch_count{$ring}++;
-
# correct duration of merged batches
if ($correct_durations and exists $db{$key}->{'no-end'}) {
- my $start = $db{$key}->{'start'};
my $ctx = $db{$key}->{'ctx'};
my $seqno = $db{$key}->{'seqno'};
my $next_key;
@@ -591,24 +576,41 @@ foreach my $key (@sorted_keys) {
# 20us tolerance
if (exists $db{$next_key} and $db{$next_key}->{'start'} < $start + 20) {
$re_sort = 1;
- $db{$next_key}->{'start'} = $start + $db{$key}->{'duration'};
+ $db{$next_key}->{'start'} = $notify;
Makes sense, mine was silly!
$db{$next_key}->{'start'} = $db{$next_key}->{'end'} if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
- $db{$next_key}->{'duration'} = $db{$next_key}->{'notify'} - $db{$next_key}->{'start'};
- $end = $db{$key}->{'notify'};
die if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
}
- die if $db{$key}->{'start'} > $db{$key}->{'end'};
+ die if $start > $end;
}
+}
+
+@sorted_keys = sort sortStart keys %db if $re_sort;
+
+foreach my $key (@sorted_keys) {
+ my $ring = $db{$key}->{'ring'};
+ my $end = $db{$key}->{'end'};
+ my $start = $db{$key}->{'start'};
+ my $notify = $db{$key}->{'notify'};
+
+ $db{$key}->{'context-complete-delay'} = $end - $notify;
+ $db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
+ $db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
+ $db{$key}->{'duration'} = $notify - $start;
+
+ $running{$ring} += $end - $start unless exists $db{$key}->{'no-end'};
+ $runnable{$ring} += $db{$key}->{'execute-delay'};
+ $queued{$ring} += $start - $db{$key}->{'execute-delay'} - $db{$key}->{'queue'};
+
+ $batch_count{$ring}++;
+
$batch_avg{$ring} += $db{$key}->{'duration'};
- $batch_total_avg{$ring} += $end - $db{$key}->{'start'};
+ $batch_total_avg{$ring} += $end - $start;
$submit_avg{$ring} += $db{$key}->{'submit-delay'};
$execute_avg{$ring} += $db{$key}->{'execute-delay'};
- $ctxsave_avg{$ring} += $db{$key}->{'end'} - $db{$key}->{'notify'};
+ $ctxsave_avg{$ring} += $end - $notify;
}
-@sorted_keys = sort sortStart keys %db if $re_sort;
-
foreach my $ring (sort keys %batch_avg) {
$batch_avg{$ring} /= $batch_count{$ring};
$batch_total_avg{$ring} /= $batch_count{$ring};
A great improvement! I didn't spot that you've changed anything which
would break the flow.
I'd move those two locals in the if block, but otherwise:
Reviewed-by: Tvrtko Ursulin <tvrtko.ursulin@xxxxxxxxx>
Regards,
Tvrtko
_______________________________________________
Intel-gfx mailing list
Intel-gfx@xxxxxxxxxxxxxxxxxxxxx
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
