[3/4] scripts/trace.pl: Calculate stats only after all munging

Submitted by John.C.Harrison@Intel.com on Jan. 20, 2018, 12:24 a.m.

Details

Message ID 20180120002421.13919-4-John.C.Harrison@Intel.com
State New
Headers show
Series "scripts/trace.pl: Re-order calculations and fixups" ( rev: 1 ) in IGT (deprecated)

Not browsing as part of any series.

Commit Message

John.C.Harrison@Intel.com Jan. 20, 2018, 12:24 a.m.
From: John Harrison <John.C.Harrison@Intel.com>

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@intel.com>
Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 54 ++++++++++++++++++++++++++++--------------------------
 1 file changed, 28 insertions(+), 26 deletions(-)

Patch hide | download patch | download mbox

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};
 		$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'};
 
 	$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;
 			$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};

Comments

On 20/01/2018 00:24, John.C.Harrison@Intel.com wrote:
> From: John Harrison <John.C.Harrison@Intel.com>
> 
> 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@intel.com>
> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   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@intel.com>

Regards,

Tvrtko
On 1/22/2018 2:54 AM, Tvrtko Ursulin wrote:
>
> On 20/01/2018 00:24, John.C.Harrison@Intel.com wrote:
>> From: John Harrison <John.C.Harrison@Intel.com>
>>
>> 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@intel.com>
>> Cc: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>> ---
>>   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.
Yeah, I wasn't 100% certain the queue/submit things were safe to use 
later given that you weren't. However, I think it definitely makes the 
code easier to maintain if %db is assumed to be the one true source of 
all information. Once that is constructed, all else can be forgotten 
about and all subsequent processing only needs to operate on that one 
data structure.


>
>>           $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.

The code had mutated a lot before arriving at this point, yer honour. It 
all made sense at one point in time!

>
>>         $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@intel.com>
>
> Regards,
>
> Tvrtko
>