[PATCH i-g-t 0/4] trace.pl fixes and improvements

[PATCH i-g-t 0/4] trace.pl fixes and improvements

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Remaining patches plus two new ones:

1. Fix for frequency timeline display
2. Bring back working stacking button (but default is no stacking)

Tvrtko Ursulin (4):
  trace.pl: Context save only applies to last request of a bunch
  trace.pl: Fix request split mode
  trace.pl: Bring back timeline stacking
  trace.pl: Fix frequency timeline

 scripts/trace.pl | 157 +++++++++++++++++++++++++++++++++++++----------
 1 file changed, 124 insertions(+), 33 deletions(-)

-- 
2.17.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[Intel-gfx] [PATCH i-g-t 0/4] trace.pl fixes and improvements

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Remaining patches plus two new ones:

1. Fix for frequency timeline display
2. Bring back working stacking button (but default is no stacking)

Tvrtko Ursulin (4):
  trace.pl: Context save only applies to last request of a bunch
  trace.pl: Fix request split mode
  trace.pl: Bring back timeline stacking
  trace.pl: Fix frequency timeline

 scripts/trace.pl | 157 +++++++++++++++++++++++++++++++++++++----------
 1 file changed, 124 insertions(+), 33 deletions(-)

-- 
2.17.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 1/4] trace.pl: Context save only applies to last request of a bunch

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Skip accounting the context save time for anything but the last request of
the coalesced bunch, and also skip drawing those boxes on the timeline.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 10 +++++++---
 1 file changed, 7 insertions(+), 3 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 5ae53fc0b68b..41bedeefb776 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -628,7 +628,11 @@ foreach my $key (@sorted_keys) {
 	$min_ctx = $db{$key}->{'ctx'} if not defined $min_ctx or
 					 $db{$key}->{'ctx'} < $min_ctx;
 
-	$db{$key}->{'context-complete-delay'} = $end - $notify;
+	unless (exists $db{$key}->{'no-end'}) {
+		$db{$key}->{'context-complete-delay'} = $end - $notify;
+	} else {
+		$db{$key}->{'context-complete-delay'} = 0;
+	}
 	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
 	$db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
 	unless (exists $db{$key}->{'no-notify'}) {
@@ -649,7 +653,7 @@ foreach my $key (@sorted_keys) {
 
 	$submit_avg{$ring} += $db{$key}->{'submit-delay'};
 	$execute_avg{$ring} += $db{$key}->{'execute-delay'};
-	$ctxsave_avg{$ring} += $end - $notify;
+	$ctxsave_avg{$ring} += $db{$key}->{'context-complete-delay'};
 }
 
 foreach my $ring (sort keys %batch_avg) {
@@ -1100,7 +1104,7 @@ foreach my $key (sort sortQueue keys %db) {
 	}
 
 	# user interrupt to context complete
-	unless (exists $skip_box{'ctxsave'}) {
+	unless (exists $skip_box{'ctxsave'} or exists $db{$key}->{'no-end'}) {
 		$skey = -2 * $max_seqno * $ctx - 2 * $seqno;
 		$style = box_style($ctx, 'ctxsave');
 		my $ctxsave = $db{$key}->{'end'} - $db{$key}->{'notify'};
-- 
2.17.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[igt-dev] [PATCH i-g-t 1/4] trace.pl: Context save only applies to last request of a bunch

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Skip accounting the context save time for anything but the last request of
the coalesced bunch, and also skip drawing those boxes on the timeline.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 10 +++++++---
 1 file changed, 7 insertions(+), 3 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 5ae53fc0b68b..41bedeefb776 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -628,7 +628,11 @@ foreach my $key (@sorted_keys) {
 	$min_ctx = $db{$key}->{'ctx'} if not defined $min_ctx or
 					 $db{$key}->{'ctx'} < $min_ctx;
 
-	$db{$key}->{'context-complete-delay'} = $end - $notify;
+	unless (exists $db{$key}->{'no-end'}) {
+		$db{$key}->{'context-complete-delay'} = $end - $notify;
+	} else {
+		$db{$key}->{'context-complete-delay'} = 0;
+	}
 	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
 	$db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
 	unless (exists $db{$key}->{'no-notify'}) {
@@ -649,7 +653,7 @@ foreach my $key (@sorted_keys) {
 
 	$submit_avg{$ring} += $db{$key}->{'submit-delay'};
 	$execute_avg{$ring} += $db{$key}->{'execute-delay'};
-	$ctxsave_avg{$ring} += $end - $notify;
+	$ctxsave_avg{$ring} += $db{$key}->{'context-complete-delay'};
 }
 
 foreach my $ring (sort keys %batch_avg) {
@@ -1100,7 +1104,7 @@ foreach my $key (sort sortQueue keys %db) {
 	}
 
 	# user interrupt to context complete
-	unless (exists $skip_box{'ctxsave'}) {
+	unless (exists $skip_box{'ctxsave'} or exists $db{$key}->{'no-end'}) {
 		$skey = -2 * $max_seqno * $ctx - 2 * $seqno;
 		$style = box_style($ctx, 'ctxsave');
 		my $ctxsave = $db{$key}->{'end'} - $db{$key}->{'notify'};
-- 
2.17.1

_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

Re: [PATCH i-g-t 1/4] trace.pl: Context save only applies to last request of a bunch

[John Harrison]

[-- Attachment #1.1: Type: text/plain, Size: 835 bytes --]

On 7/19/2018 2:35 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Skip accounting the context save time for anything but the last request of
> the coalesced bunch, and also skip drawing those boxes on the timeline.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   scripts/trace.pl | 10 +++++++---
>   1 file changed, 7 insertions(+), 3 deletions(-)
>
>
Not sure if you are not getting some of my replies? I have definitely 
sent an R-B to this patch at least twice already. Maybe they are getting 
caught by some kind of mailing list filter? I know your patches appear 
randomly in one of three mailboxes for me - inbox, IGT or IntelGFX 
according to which rule happens to take precedence on any given second 
:(. Anyway...

Reviewed-by: John Harrison <John.C.Harrison@Intel.com>


[-- Attachment #1.2: Type: text/html, Size: 1425 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [igt-dev] [Intel-gfx] [PATCH i-g-t 1/4] trace.pl: Context save only applies to last request of a bunch

[John Harrison]

[-- Attachment #1.1: Type: text/plain, Size: 835 bytes --]

On 7/19/2018 2:35 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Skip accounting the context save time for anything but the last request of
> the coalesced bunch, and also skip drawing those boxes on the timeline.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   scripts/trace.pl | 10 +++++++---
>   1 file changed, 7 insertions(+), 3 deletions(-)
>
>
Not sure if you are not getting some of my replies? I have definitely 
sent an R-B to this patch at least twice already. Maybe they are getting 
caught by some kind of mailing list filter? I know your patches appear 
randomly in one of three mailboxes for me - inbox, IGT or IntelGFX 
according to which rule happens to take precedence on any given second 
:(. Anyway...

Reviewed-by: John Harrison <John.C.Harrison@Intel.com>


[-- Attachment #1.2: Type: text/html, Size: 1425 bytes --]

[-- Attachment #2: Type: text/plain, Size: 154 bytes --]

_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

Re: [igt-dev] [PATCH i-g-t 1/4] trace.pl: Context save only applies to last request of a bunch

[Tvrtko Ursulin]

On 27/07/2018 22:37, John Harrison wrote:
> On 7/19/2018 2:35 AM, Tvrtko Ursulin wrote:
>> From: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>>
>> Skip accounting the context save time for anything but the last request of
>> the coalesced bunch, and also skip drawing those boxes on the timeline.
>>
>> Signed-off-by: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>> ---
>>   scripts/trace.pl | 10 +++++++---
>>   1 file changed, 7 insertions(+), 3 deletions(-)
>>
>>
> Not sure if you are not getting some of my replies? I have definitely 
> sent an R-B to this patch at least twice already. Maybe they are getting 
> caught by some kind of mailing list filter? I know your patches appear 
> randomly in one of three mailboxes for me - inbox, IGT or IntelGFX 
> according to which rule happens to take precedence on any given second 
> :(. Anyway...
> 
> Reviewed-by: John Harrison <John.C.Harrison@Intel.com>

Thanks!

I looked backwards a bit and it seems (from my end at least!) that on 
previous two occasions you did a reply instead of reply to all so I 
missed it.

Regards,

Tvrtko
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [igt-dev] [Intel-gfx] [PATCH i-g-t 1/4] trace.pl: Context save only applies to last request of a bunch

[Tvrtko Ursulin]

On 27/07/2018 22:37, John Harrison wrote:
> On 7/19/2018 2:35 AM, Tvrtko Ursulin wrote:
>> From: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>>
>> Skip accounting the context save time for anything but the last request of
>> the coalesced bunch, and also skip drawing those boxes on the timeline.
>>
>> Signed-off-by: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>> ---
>>   scripts/trace.pl | 10 +++++++---
>>   1 file changed, 7 insertions(+), 3 deletions(-)
>>
>>
> Not sure if you are not getting some of my replies? I have definitely 
> sent an R-B to this patch at least twice already. Maybe they are getting 
> caught by some kind of mailing list filter? I know your patches appear 
> randomly in one of three mailboxes for me - inbox, IGT or IntelGFX 
> according to which rule happens to take precedence on any given second 
> :(. Anyway...
> 
> Reviewed-by: John Harrison <John.C.Harrison@Intel.com>

Thanks!

I looked backwards a bit and it seems (from my end at least!) that on 
previous two occasions you did a reply instead of reply to all so I 
missed it.

Regards,

Tvrtko
_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

[PATCH i-g-t 2/4] trace.pl: Fix request split mode

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Request split mode had several bugs, both in the original version and also
after the recent refactorings.

One big one was that it wasn't considering different submit ports as a
reason to split execution, and also that it was too time based instead of
looking at relevant timelines.

In this refactoring we address the former by using the engine timelines
introduced in the previous patch. Secondary port submissions are moved
to follow the preceding submission as a first step in the correction
process.

In the second step, we add context timelines and use then in a similar
fashion to separate start and end time of coalesced requests. For each
coalesced request we know its boundaries by looking at the engine
timeline (via global seqnos), and we know the previous request it should
only start after, by looking at the context timeline.

v2:
 * Remove some dead code.
 * Fix !port0 shifting logic.

v3:
 * Refactor for less list walking as with incomplete handling.

v4:
 * Database of context timelines should not contain duplicates!
   (Converted from array into a hash.)

v5:
 * Avoid over-accounting runnable time for a coalesced group by recording
   the time first request entered the GPU and ending the execute delay at
   that point for the whole group.

v6:
 * Update for engine class:instance.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: John Harrison <John.C.Harrison@intel.com>
---
 scripts/trace.pl | 138 ++++++++++++++++++++++++++++++++++++-----------
 1 file changed, 108 insertions(+), 30 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 41bedeefb776..59f6d32dc3c8 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -27,7 +27,7 @@ use warnings;
 use 5.010;
 
 my $gid = 0;
-my (%db, %queue, %submit, %notify, %rings, %ctxdb, %ringmap, %reqwait);
+my (%db, %queue, %submit, %notify, %rings, %ctxdb, %ringmap, %reqwait, %ctxtimelines);
 my @freqs;
 
 my $max_items = 3000;
@@ -418,6 +418,7 @@ while (<>) {
 		$req{'ring'} = $ring;
 		$req{'seqno'} = $seqno;
 		$req{'ctx'} = $ctx;
+		$ctxtimelines{$ctx . '/' . $ring} = 1;
 		$req{'name'} = $ctx . '/' . $seqno;
 		$req{'global'} = $tp{'global'};
 		$req{'port'} = $tp{'port'};
@@ -573,41 +574,113 @@ sub sortStart {
 	return $val;
 }
 
-my @sorted_keys = sort sortStart keys %db;
-my $re_sort = 0;
+my $re_sort = 1;
+my @sorted_keys;
 
-die "Database changed size?!" unless scalar(@sorted_keys) == $key_count;
+sub maybe_sort_keys
+{
+	if ($re_sort) {
+		@sorted_keys = sort sortStart keys %db;
+		$re_sort = 0;
+		die "Database changed size?!" unless scalar(@sorted_keys) ==
+						     $key_count;
+	}
+}
 
-foreach my $key (@sorted_keys) {
-	my $ring = $db{$key}->{'ring'};
-	my $end = $db{$key}->{'end'};
+maybe_sort_keys();
+
+my %ctx_timelines;
+
+sub sortContext {
+	my $as = $db{$a}->{'seqno'};
+	my $bs = $db{$b}->{'seqno'};
+	my $val;
+
+	$val = $as <=> $bs;
+
+	die if $val == 0;
+
+	return $val;
+}
+
+sub get_ctx_timeline {
+	my ($ctx, $ring, $key) = @_;
+	my @timeline;
+
+	return $ctx_timelines{$key} if exists $ctx_timelines{$key};
+
+	@timeline = grep { $db{$_}->{'ring'} eq $ring and
+			   $db{$_}->{'ctx'} == $ctx } @sorted_keys;
+	# FIXME seqno restart
+	@timeline = sort sortContext @timeline;
+
+	$ctx_timelines{$key} = \@timeline;
+
+	return \@timeline;
+}
+
+# Split out merged batches if requested.
+if ($correct_durations) {
+	# Shift !port0 requests start time to after the previous context on the
+	# same timeline has finished.
+	foreach my $gid (sort keys %rings) {
+		my $ring = $ringmap{$rings{$gid}};
+		my $timeline = get_engine_timeline($ring);
+		my $complete;
+
+		foreach my $pos (0..$#{$timeline}) {
+			my $key = @{$timeline}[$pos];
+			my $prev = $complete;
+			my $pkey;
+
+			$complete = $key unless exists $db{$key}->{'no-end'};
+			$pkey = $complete;
+
+			next if $db{$key}->{'port'} == 0;
+
+			$pkey = $prev if $complete eq $key;
+
+			die unless defined $pkey;
+
+			$db{$key}->{'start'} = $db{$pkey}->{'end'};
+			$db{$key}->{'start'} = $db{$pkey}->{'notify'} if $db{$key}->{'start'} > $db{$key}->{'end'};
+
+			die if $db{$key}->{'start'} > $db{$key}->{'end'};
 
-	# correct duration of merged batches
-	if ($correct_durations and exists $db{$key}->{'no-end'}) {
-		my $ctx = $db{$key}->{'ctx'};
-		my $seqno = $db{$key}->{'seqno'};
-		my $start = $db{$key}->{'start'};
-		my $next_key;
-		my $i = 1;
-
-		do {
-			$next_key = db_key($ring, $ctx, $seqno + $i);
-			$i++;
-		} until (exists $db{$next_key} or $i > $key_count);  # ugly stop hack
-
-		# 20us tolerance
-		if (exists $db{$next_key} and $db{$next_key}->{'start'} < $start + 20) {
-			my $notify = $db{$key}->{'notify'};
 			$re_sort = 1;
-			$db{$next_key}->{'start'} = $notify;
-			$db{$next_key}->{'start'} = $db{$next_key}->{'end'} if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
-			die if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
 		}
-		die if $start > $end;
+	}
+
+	maybe_sort_keys();
+
+	# Batch with no-end (no request_out) means it was submitted as part of
+	# coalesced context. This means it's start time should be set to the end
+	# time of a following request on this context timeline.
+	foreach my $tkey (sort keys %ctxtimelines) {
+		my ($ctx, $ring) = split '/', $tkey;
+		my $timeline = get_ctx_timeline($ctx, $ring, $tkey);
+		my $last_complete = -1;
+		my $complete;
+
+		foreach my $pos (0..$#{$timeline}) {
+			my $key = @{$timeline}[$pos];
+			my $next_key;
+
+			next unless exists $db{$key}->{'no-end'};
+			last if $pos == $#{$timeline};
+
+			# Shift following request to start after the current one
+			$next_key = ${$timeline}[$pos + 1];
+			if (exists $db{$key}->{'notify'}) {
+				$db{$next_key}->{'engine-start'} = $db{$next_key}->{'start'};
+				$db{$next_key}->{'start'} = $db{$key}->{'notify'};
+				$re_sort = 1;
+			}
+		}
 	}
 }
 
-@sorted_keys = sort sortStart keys %db if $re_sort;
+maybe_sort_keys();
 
 # GPU time accounting
 my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count);
@@ -621,6 +694,7 @@ foreach my $key (@sorted_keys) {
 	my $ring = $db{$key}->{'ring'};
 	my $end = $db{$key}->{'end'};
 	my $start = $db{$key}->{'start'};
+	my $engine_start = $db{$key}->{'engine_start'};
 	my $notify = $db{$key}->{'notify'};
 
 	$first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts;
@@ -633,7 +707,9 @@ foreach my $key (@sorted_keys) {
 	} else {
 		$db{$key}->{'context-complete-delay'} = 0;
 	}
-	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
+
+	$engine_start = $db{$key}->{'start'} unless defined $engine_start;
+	$db{$key}->{'execute-delay'} = $engine_start - $db{$key}->{'submit'};
 	$db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
 	unless (exists $db{$key}->{'no-notify'}) {
 		$db{$key}->{'duration'} = $notify - $start;
@@ -1059,6 +1135,7 @@ my $i = 0;
 foreach my $key (sort sortQueue keys %db) {
 	my ($name, $ctx, $seqno) = ($db{$key}->{'name'}, $db{$key}->{'ctx'}, $db{$key}->{'seqno'});
 	my ($queue, $start, $notify, $end) = ($db{$key}->{'queue'}, $db{$key}->{'start'}, $db{$key}->{'notify'}, $db{$key}->{'end'});
+	my $engine_start = $db{$key}->{'engine-start'};
 	my $submit = $queue + $db{$key}->{'submit-delay'};
 	my ($content, $style);
 	my $group = $engine_start_id + $rings{$db{$key}->{'ring'}};
@@ -1078,11 +1155,12 @@ foreach my $key (sort sortQueue keys %db) {
 	}
 
 	# execute to start
+	$engine_start = $db{$key}->{'start'} unless defined $engine_start;
 	unless (exists $skip_box{'ready'}) {
 		$skey = 2 * $max_seqno * $ctx + 2 * $seqno + 1;
 		$style = box_style($ctx, 'ready');
 		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
-		$startend = 'start: ' . $submit . ', end: ' . $start;
+		$startend = 'start: ' . $submit . ', end: ' . $engine_start;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
-- 
2.17.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[igt-dev] [PATCH i-g-t 2/4] trace.pl: Fix request split mode

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Request split mode had several bugs, both in the original version and also
after the recent refactorings.

One big one was that it wasn't considering different submit ports as a
reason to split execution, and also that it was too time based instead of
looking at relevant timelines.

In this refactoring we address the former by using the engine timelines
introduced in the previous patch. Secondary port submissions are moved
to follow the preceding submission as a first step in the correction
process.

In the second step, we add context timelines and use then in a similar
fashion to separate start and end time of coalesced requests. For each
coalesced request we know its boundaries by looking at the engine
timeline (via global seqnos), and we know the previous request it should
only start after, by looking at the context timeline.

v2:
 * Remove some dead code.
 * Fix !port0 shifting logic.

v3:
 * Refactor for less list walking as with incomplete handling.

v4:
 * Database of context timelines should not contain duplicates!
   (Converted from array into a hash.)

v5:
 * Avoid over-accounting runnable time for a coalesced group by recording
   the time first request entered the GPU and ending the execute delay at
   that point for the whole group.

v6:
 * Update for engine class:instance.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: John Harrison <John.C.Harrison@intel.com>
---
 scripts/trace.pl | 138 ++++++++++++++++++++++++++++++++++++-----------
 1 file changed, 108 insertions(+), 30 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 41bedeefb776..59f6d32dc3c8 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -27,7 +27,7 @@ use warnings;
 use 5.010;
 
 my $gid = 0;
-my (%db, %queue, %submit, %notify, %rings, %ctxdb, %ringmap, %reqwait);
+my (%db, %queue, %submit, %notify, %rings, %ctxdb, %ringmap, %reqwait, %ctxtimelines);
 my @freqs;
 
 my $max_items = 3000;
@@ -418,6 +418,7 @@ while (<>) {
 		$req{'ring'} = $ring;
 		$req{'seqno'} = $seqno;
 		$req{'ctx'} = $ctx;
+		$ctxtimelines{$ctx . '/' . $ring} = 1;
 		$req{'name'} = $ctx . '/' . $seqno;
 		$req{'global'} = $tp{'global'};
 		$req{'port'} = $tp{'port'};
@@ -573,41 +574,113 @@ sub sortStart {
 	return $val;
 }
 
-my @sorted_keys = sort sortStart keys %db;
-my $re_sort = 0;
+my $re_sort = 1;
+my @sorted_keys;
 
-die "Database changed size?!" unless scalar(@sorted_keys) == $key_count;
+sub maybe_sort_keys
+{
+	if ($re_sort) {
+		@sorted_keys = sort sortStart keys %db;
+		$re_sort = 0;
+		die "Database changed size?!" unless scalar(@sorted_keys) ==
+						     $key_count;
+	}
+}
 
-foreach my $key (@sorted_keys) {
-	my $ring = $db{$key}->{'ring'};
-	my $end = $db{$key}->{'end'};
+maybe_sort_keys();
+
+my %ctx_timelines;
+
+sub sortContext {
+	my $as = $db{$a}->{'seqno'};
+	my $bs = $db{$b}->{'seqno'};
+	my $val;
+
+	$val = $as <=> $bs;
+
+	die if $val == 0;
+
+	return $val;
+}
+
+sub get_ctx_timeline {
+	my ($ctx, $ring, $key) = @_;
+	my @timeline;
+
+	return $ctx_timelines{$key} if exists $ctx_timelines{$key};
+
+	@timeline = grep { $db{$_}->{'ring'} eq $ring and
+			   $db{$_}->{'ctx'} == $ctx } @sorted_keys;
+	# FIXME seqno restart
+	@timeline = sort sortContext @timeline;
+
+	$ctx_timelines{$key} = \@timeline;
+
+	return \@timeline;
+}
+
+# Split out merged batches if requested.
+if ($correct_durations) {
+	# Shift !port0 requests start time to after the previous context on the
+	# same timeline has finished.
+	foreach my $gid (sort keys %rings) {
+		my $ring = $ringmap{$rings{$gid}};
+		my $timeline = get_engine_timeline($ring);
+		my $complete;
+
+		foreach my $pos (0..$#{$timeline}) {
+			my $key = @{$timeline}[$pos];
+			my $prev = $complete;
+			my $pkey;
+
+			$complete = $key unless exists $db{$key}->{'no-end'};
+			$pkey = $complete;
+
+			next if $db{$key}->{'port'} == 0;
+
+			$pkey = $prev if $complete eq $key;
+
+			die unless defined $pkey;
+
+			$db{$key}->{'start'} = $db{$pkey}->{'end'};
+			$db{$key}->{'start'} = $db{$pkey}->{'notify'} if $db{$key}->{'start'} > $db{$key}->{'end'};
+
+			die if $db{$key}->{'start'} > $db{$key}->{'end'};
 
-	# correct duration of merged batches
-	if ($correct_durations and exists $db{$key}->{'no-end'}) {
-		my $ctx = $db{$key}->{'ctx'};
-		my $seqno = $db{$key}->{'seqno'};
-		my $start = $db{$key}->{'start'};
-		my $next_key;
-		my $i = 1;
-
-		do {
-			$next_key = db_key($ring, $ctx, $seqno + $i);
-			$i++;
-		} until (exists $db{$next_key} or $i > $key_count);  # ugly stop hack
-
-		# 20us tolerance
-		if (exists $db{$next_key} and $db{$next_key}->{'start'} < $start + 20) {
-			my $notify = $db{$key}->{'notify'};
 			$re_sort = 1;
-			$db{$next_key}->{'start'} = $notify;
-			$db{$next_key}->{'start'} = $db{$next_key}->{'end'} if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
-			die if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
 		}
-		die if $start > $end;
+	}
+
+	maybe_sort_keys();
+
+	# Batch with no-end (no request_out) means it was submitted as part of
+	# coalesced context. This means it's start time should be set to the end
+	# time of a following request on this context timeline.
+	foreach my $tkey (sort keys %ctxtimelines) {
+		my ($ctx, $ring) = split '/', $tkey;
+		my $timeline = get_ctx_timeline($ctx, $ring, $tkey);
+		my $last_complete = -1;
+		my $complete;
+
+		foreach my $pos (0..$#{$timeline}) {
+			my $key = @{$timeline}[$pos];
+			my $next_key;
+
+			next unless exists $db{$key}->{'no-end'};
+			last if $pos == $#{$timeline};
+
+			# Shift following request to start after the current one
+			$next_key = ${$timeline}[$pos + 1];
+			if (exists $db{$key}->{'notify'}) {
+				$db{$next_key}->{'engine-start'} = $db{$next_key}->{'start'};
+				$db{$next_key}->{'start'} = $db{$key}->{'notify'};
+				$re_sort = 1;
+			}
+		}
 	}
 }
 
-@sorted_keys = sort sortStart keys %db if $re_sort;
+maybe_sort_keys();
 
 # GPU time accounting
 my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count);
@@ -621,6 +694,7 @@ foreach my $key (@sorted_keys) {
 	my $ring = $db{$key}->{'ring'};
 	my $end = $db{$key}->{'end'};
 	my $start = $db{$key}->{'start'};
+	my $engine_start = $db{$key}->{'engine_start'};
 	my $notify = $db{$key}->{'notify'};
 
 	$first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts;
@@ -633,7 +707,9 @@ foreach my $key (@sorted_keys) {
 	} else {
 		$db{$key}->{'context-complete-delay'} = 0;
 	}
-	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
+
+	$engine_start = $db{$key}->{'start'} unless defined $engine_start;
+	$db{$key}->{'execute-delay'} = $engine_start - $db{$key}->{'submit'};
 	$db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
 	unless (exists $db{$key}->{'no-notify'}) {
 		$db{$key}->{'duration'} = $notify - $start;
@@ -1059,6 +1135,7 @@ my $i = 0;
 foreach my $key (sort sortQueue keys %db) {
 	my ($name, $ctx, $seqno) = ($db{$key}->{'name'}, $db{$key}->{'ctx'}, $db{$key}->{'seqno'});
 	my ($queue, $start, $notify, $end) = ($db{$key}->{'queue'}, $db{$key}->{'start'}, $db{$key}->{'notify'}, $db{$key}->{'end'});
+	my $engine_start = $db{$key}->{'engine-start'};
 	my $submit = $queue + $db{$key}->{'submit-delay'};
 	my ($content, $style);
 	my $group = $engine_start_id + $rings{$db{$key}->{'ring'}};
@@ -1078,11 +1155,12 @@ foreach my $key (sort sortQueue keys %db) {
 	}
 
 	# execute to start
+	$engine_start = $db{$key}->{'start'} unless defined $engine_start;
 	unless (exists $skip_box{'ready'}) {
 		$skey = 2 * $max_seqno * $ctx + 2 * $seqno + 1;
 		$style = box_style($ctx, 'ready');
 		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
-		$startend = 'start: ' . $submit . ', end: ' . $start;
+		$startend = 'start: ' . $submit . ', end: ' . $engine_start;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
-- 
2.17.1

_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

Re: [PATCH i-g-t 2/4] trace.pl: Fix request split mode

[John Harrison]

[-- Attachment #1.1: Type: text/plain, Size: 1783 bytes --]

On 7/19/2018 2:35 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Request split mode had several bugs, both in the original version and also
> after the recent refactorings.
>
> One big one was that it wasn't considering different submit ports as a
> reason to split execution, and also that it was too time based instead of
> looking at relevant timelines.
>
> In this refactoring we address the former by using the engine timelines
> introduced in the previous patch. Secondary port submissions are moved
> to follow the preceding submission as a first step in the correction
> process.
>
> In the second step, we add context timelines and use then in a similar
> fashion to separate start and end time of coalesced requests. For each
> coalesced request we know its boundaries by looking at the engine
> timeline (via global seqnos), and we know the previous request it should
> only start after, by looking at the context timeline.
>
> v2:
>   * Remove some dead code.
>   * Fix !port0 shifting logic.
>
> v3:
>   * Refactor for less list walking as with incomplete handling.
>
> v4:
>   * Database of context timelines should not contain duplicates!
>     (Converted from array into a hash.)
>
> v5:
>   * Avoid over-accounting runnable time for a coalesced group by recording
>     the time first request entered the GPU and ending the execute delay at
>     that point for the whole group.
>
> v6:
>   * Update for engine class:instance.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Cc: John Harrison <John.C.Harrison@intel.com>
> ---
>   scripts/trace.pl | 138 ++++++++++++++++++++++++++++++++++++-----------
>   1 file changed, 108 insertions(+), 30 deletions(-)
>
>

Reviewed-by: John Harrison <John.C.Harrison@Intel.com>


[-- Attachment #1.2: Type: text/html, Size: 2362 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [igt-dev] [PATCH i-g-t 2/4] trace.pl: Fix request split mode

[John Harrison]

[-- Attachment #1.1: Type: text/plain, Size: 1783 bytes --]

On 7/19/2018 2:35 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Request split mode had several bugs, both in the original version and also
> after the recent refactorings.
>
> One big one was that it wasn't considering different submit ports as a
> reason to split execution, and also that it was too time based instead of
> looking at relevant timelines.
>
> In this refactoring we address the former by using the engine timelines
> introduced in the previous patch. Secondary port submissions are moved
> to follow the preceding submission as a first step in the correction
> process.
>
> In the second step, we add context timelines and use then in a similar
> fashion to separate start and end time of coalesced requests. For each
> coalesced request we know its boundaries by looking at the engine
> timeline (via global seqnos), and we know the previous request it should
> only start after, by looking at the context timeline.
>
> v2:
>   * Remove some dead code.
>   * Fix !port0 shifting logic.
>
> v3:
>   * Refactor for less list walking as with incomplete handling.
>
> v4:
>   * Database of context timelines should not contain duplicates!
>     (Converted from array into a hash.)
>
> v5:
>   * Avoid over-accounting runnable time for a coalesced group by recording
>     the time first request entered the GPU and ending the execute delay at
>     that point for the whole group.
>
> v6:
>   * Update for engine class:instance.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Cc: John Harrison <John.C.Harrison@intel.com>
> ---
>   scripts/trace.pl | 138 ++++++++++++++++++++++++++++++++++++-----------
>   1 file changed, 108 insertions(+), 30 deletions(-)
>
>

Reviewed-by: John Harrison <John.C.Harrison@Intel.com>


[-- Attachment #1.2: Type: text/html, Size: 2362 bytes --]

[-- Attachment #2: Type: text/plain, Size: 154 bytes --]

_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

[PATCH i-g-t 3/4] trace.pl: Bring back timeline stacking

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Bring back the button which expands/stacks overlapping timeline boxes.

We default to no stacking, but sometimes expanding the view can be useful,
especially with deep request pipelines.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 59f6d32dc3c8..1924333e12b6 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -935,6 +935,7 @@ Boxes are in format 'ctx-id/seqno'.
 <p>
 Use Ctrl+scroll-action to zoom-in/out and scroll-action or dragging to move around the timeline.
 </p>
+<button onclick="toggleStacking()">Toggle overlap stacking</button>
 </td>
 </tr>
 </table>
@@ -1284,6 +1285,12 @@ print <<ENDHTML;
 
   // Create a Timeline
   var timeline = new vis.Timeline(container, items, groups, options);
+
+  function toggleStacking() {
+	options.stack = !options.stack;
+	options.stackSubgroups = !options.stackSubgroups;
+	timeline.setOptions(options);
+  }
 ENDHTML
 
 print <<ENDHTML;
-- 
2.17.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[igt-dev] [PATCH i-g-t 3/4] trace.pl: Bring back timeline stacking

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Bring back the button which expands/stacks overlapping timeline boxes.

We default to no stacking, but sometimes expanding the view can be useful,
especially with deep request pipelines.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 59f6d32dc3c8..1924333e12b6 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -935,6 +935,7 @@ Boxes are in format 'ctx-id/seqno'.
 <p>
 Use Ctrl+scroll-action to zoom-in/out and scroll-action or dragging to move around the timeline.
 </p>
+<button onclick="toggleStacking()">Toggle overlap stacking</button>
 </td>
 </tr>
 </table>
@@ -1284,6 +1285,12 @@ print <<ENDHTML;
 
   // Create a Timeline
   var timeline = new vis.Timeline(container, items, groups, options);
+
+  function toggleStacking() {
+	options.stack = !options.stack;
+	options.stackSubgroups = !options.stackSubgroups;
+	timeline.setOptions(options);
+  }
 ENDHTML
 
 print <<ENDHTML;
-- 
2.17.1

_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

Re: [PATCH i-g-t 3/4] trace.pl: Bring back timeline stacking

[John Harrison]

[-- Attachment #1.1: Type: text/plain, Size: 1262 bytes --]

On 7/19/2018 2:36 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Bring back the button which expands/stacks overlapping timeline boxes.
>
> We default to no stacking, but sometimes expanding the view can be useful,
> especially with deep request pipelines.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   scripts/trace.pl | 7 +++++++
>   1 file changed, 7 insertions(+)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index 59f6d32dc3c8..1924333e12b6 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -935,6 +935,7 @@ Boxes are in format 'ctx-id/seqno'.
>   <p>
>   Use Ctrl+scroll-action to zoom-in/out and scroll-action or dragging to move around the timeline.
>   </p>
> +<button onclick="toggleStacking()">Toggle overlap stacking</button>
>   </td>
>   </tr>
>   </table>
> @@ -1284,6 +1285,12 @@ print <<ENDHTML;
>   
>     // Create a Timeline
>     var timeline = new vis.Timeline(container, items, groups, options);
> +
> +  function toggleStacking() {
> +	options.stack = !options.stack;
> +	options.stackSubgroups = !options.stackSubgroups;
> +	timeline.setOptions(options);
> +  }
>   ENDHTML
>   
>   print <<ENDHTML;

Reviewed-by: John Harrison <John.C.Harrison@Intel.com>


[-- Attachment #1.2: Type: text/html, Size: 1819 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 3/4] trace.pl: Bring back timeline stacking

[Tvrtko Ursulin]

On 27/07/2018 22:47, John Harrison wrote:
> On 7/19/2018 2:36 AM, Tvrtko Ursulin wrote:
>> From: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>>
>> Bring back the button which expands/stacks overlapping timeline boxes.
>>
>> We default to no stacking, but sometimes expanding the view can be useful,
>> especially with deep request pipelines.
>>
>> Signed-off-by: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>> ---
>>   scripts/trace.pl | 7 +++++++
>>   1 file changed, 7 insertions(+)
>>
>> diff --git a/scripts/trace.pl b/scripts/trace.pl
>> index 59f6d32dc3c8..1924333e12b6 100755
>> --- a/scripts/trace.pl
>> +++ b/scripts/trace.pl
>> @@ -935,6 +935,7 @@ Boxes are in format 'ctx-id/seqno'.
>>   <p>
>>   Use Ctrl+scroll-action to zoom-in/out and scroll-action or dragging to move around the timeline.
>>   </p>
>> +<button onclick="toggleStacking()">Toggle overlap stacking</button>
>>   </td>
>>   </tr>
>>   </table>
>> @@ -1284,6 +1285,12 @@ print <<ENDHTML;
>>   
>>     // Create a Timeline
>>     var timeline = new vis.Timeline(container, items, groups, options);
>> +
>> +  function toggleStacking() {
>> +	options.stack = !options.stack;
>> +	options.stackSubgroups = !options.stackSubgroups;
>> +	timeline.setOptions(options);
>> +  }
>>   ENDHTML
>>   
>>   print <<ENDHTML;
> 
> Reviewed-by: John Harrison <John.C.Harrison@Intel.com>

Pushed up to this one, thanks! (BTW this reply even patchwork did not 
see. But it saw your replies to 1 & 2.)

Regards,

Tvrtko
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[PATCH i-g-t 4/4] trace.pl: Fix frequency timeline

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Frequency timeline needs to be finished with an entry spanning to the end
of known time so that the last known frequency is displayed.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 1924333e12b6..2976cfdf585a 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -1201,6 +1201,8 @@ foreach my $key (sort sortQueue keys %db) {
 	last if $i > $max_items;
 }
 
+push @freqs, [$prev_freq_ts, $last_ts, $prev_freq] if $prev_freq;
+
 foreach my $item (@freqs) {
 	my ($start, $end, $freq) = @$item;
 	my $startend;
-- 
2.17.1

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[igt-dev] [PATCH i-g-t 4/4] trace.pl: Fix frequency timeline

[Tvrtko Ursulin]

From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Frequency timeline needs to be finished with an entry spanning to the end
of known time so that the last known frequency is displayed.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 scripts/trace.pl | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 1924333e12b6..2976cfdf585a 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -1201,6 +1201,8 @@ foreach my $key (sort sortQueue keys %db) {
 	last if $i > $max_items;
 }
 
+push @freqs, [$prev_freq_ts, $last_ts, $prev_freq] if $prev_freq;
+
 foreach my $item (@freqs) {
 	my ($start, $end, $freq) = @$item;
 	my $startend;
-- 
2.17.1

_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

Re: [PATCH i-g-t 4/4] trace.pl: Fix frequency timeline

[John Harrison]

[-- Attachment #1.1: Type: text/plain, Size: 1963 bytes --]

On 7/19/2018 2:36 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Frequency timeline needs to be finished with an entry spanning to the end
> of known time so that the last known frequency is displayed.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   scripts/trace.pl | 2 ++
>   1 file changed, 2 insertions(+)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index 1924333e12b6..2976cfdf585a 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -1201,6 +1201,8 @@ foreach my $key (sort sortQueue keys %db) {
>   	last if $i > $max_items;
>   }
>   
> +push @freqs, [$prev_freq_ts, $last_ts, $prev_freq] if $prev_freq;
> +
>   foreach my $item (@freqs) {
>   	my ($start, $end, $freq) = @$item;
>   	my $startend;

This does not appear to do anything for me. At least not with any of my 
trace files. I get exactly the same output with or without the change. 
What situation is it meant to fix?

Note that I get the frequency line abbreviated to the size of the 
request trace. Not sure if that is intentional or not. E.g. with the 
following trace data the frequency bar starts with 300 at a time of 
728us not 706us. Likewise, it ends at 389838us not 392227us:

   gem_exec_trace  1316 [002] 856981.389706:   i915:intel_gpu_freq_change: new_freq=300
   gem_exec_trace  1316 [002] 856981.389728:        i915:i915_request_add: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, global=0
   gem_exec_trace  1316 [002] 856981.389732:     i915:i915_request_submit: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, global=0
   gem_exec_trace  1316 [002] 856981.389739:         i915:i915_request_in: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, prio=0, global=1, port=0
          swapper     0 [002] 856981.389838:        i915:i915_request_out: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, global=1, completed?=1
     kworker/u8:1  1246 [001] 856981.392227:   i915:intel_gpu_freq_change: new_freq=300




[-- Attachment #1.2: Type: text/html, Size: 2838 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: [PATCH i-g-t 4/4] trace.pl: Fix frequency timeline

[Tvrtko Ursulin]

On 27/07/2018 23:17, John Harrison wrote:
> On 7/19/2018 2:36 AM, Tvrtko Ursulin wrote:
>> From: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>>
>> Frequency timeline needs to be finished with an entry spanning to the end
>> of known time so that the last known frequency is displayed.
>>
>> Signed-off-by: Tvrtko Ursulin<tvrtko.ursulin@intel.com>
>> ---
>>   scripts/trace.pl | 2 ++
>>   1 file changed, 2 insertions(+)
>>
>> diff --git a/scripts/trace.pl b/scripts/trace.pl
>> index 1924333e12b6..2976cfdf585a 100755
>> --- a/scripts/trace.pl
>> +++ b/scripts/trace.pl
>> @@ -1201,6 +1201,8 @@ foreach my $key (sort sortQueue keys %db) {
>>   	last if $i > $max_items;
>>   }
>>   
>> +push @freqs, [$prev_freq_ts, $last_ts, $prev_freq] if $prev_freq;
>> +
>>   foreach my $item (@freqs) {
>>   	my ($start, $end, $freq) = @$item;
>>   	my $startend;
> 
> This does not appear to do anything for me. At least not with any of my 
> trace files. I get exactly the same output with or without the change. 
> What situation is it meant to fix?

It fixes the frequency box ending at the last intel_gpu_freq_change 
timestamp instead of at the end of the displayed timeline.

> Note that I get the frequency line abbreviated to the size of the 
> request trace. Not sure if that is intentional or not. E.g. with the 
> following trace data the frequency bar starts with 300 at a time of 
> 728us not 706us. Likewise, it ends at 389838us not 392227us:
> 
>    gem_exec_trace  1316 [002] 856981.389706:   i915:intel_gpu_freq_change: new_freq=300
>    gem_exec_trace  1316 [002] 856981.389728:        i915:i915_request_add: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, global=0
>    gem_exec_trace  1316 [002] 856981.389732:     i915:i915_request_submit: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, global=0
>    gem_exec_trace  1316 [002] 856981.389739:         i915:i915_request_in: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, prio=0, global=1, port=0
>           swapper     0 [002] 856981.389838:        i915:i915_request_out: dev=0, engine=0:0, hw_id=2, ctx=847, seqno=1, global=1, completed?=1
>      kworker/u8:1  1246 [001] 856981.392227:   i915:intel_gpu_freq_change: new_freq=300

For this I have no explanation. All processing is happening inside the 
freq change tracepoint so I don't understand how it could get one 
belonging to a different event.

Regards,

Tvrtko
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

[igt-dev] ✓ Fi.CI.BAT: success for trace.pl fixes and improvements (rev13)

[Patchwork]

== Series Details ==

Series: trace.pl fixes and improvements (rev13)
URL   : https://patchwork.freedesktop.org/series/46177/
State : success

== Summary ==

= CI Bug Log - changes from CI_DRM_4509 -> IGTPW_1605 =

== Summary - SUCCESS ==

  No regressions found.

  External URL: https://patchwork.freedesktop.org/api/1.0/series/46177/revisions/13/mbox/

== Known issues ==

  Here are the changes found in IGTPW_1605 that come from known issues:

  === IGT changes ===

    ==== Issues hit ====

    igt@kms_pipe_crc_basic@suspend-read-crc-pipe-c:
      fi-bxt-dsi:         PASS -> INCOMPLETE (fdo#103927)

    
  fdo#103927 https://bugs.freedesktop.org/show_bug.cgi?id=103927


== Participating hosts (46 -> 42) ==

  Additional (1): fi-kbl-7560u 
  Missing    (5): fi-ctg-p8600 fi-ilk-m540 fi-byt-squawks fi-bsw-cyan fi-hsw-4200u 


== Build changes ==

    * IGT: IGT_4567 -> IGTPW_1605

  CI_DRM_4509: e84aa0b47beed78a5a12db93e76fb00eab5db160 @ git://anongit.freedesktop.org/gfx-ci/linux
  IGTPW_1605: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1605/
  IGT_4567: 7f85adc4050182f490c7a5c48db3d57cdb00af4e @ git://anongit.freedesktop.org/xorg/app/intel-gpu-tools

== Logs ==

For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1605/issues.html
_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev

[igt-dev] ✓ Fi.CI.IGT: success for trace.pl fixes and improvements (rev13)

[Patchwork]

== Series Details ==

Series: trace.pl fixes and improvements (rev13)
URL   : https://patchwork.freedesktop.org/series/46177/
State : success

== Summary ==

= CI Bug Log - changes from IGT_4567_full -> IGTPW_1605_full =

== Summary - WARNING ==

  Minor unknown changes coming with IGTPW_1605_full need to be verified
  manually.
  
  If you think the reported changes have nothing to do with the changes
  introduced in IGTPW_1605_full, please notify your bug team to allow them
  to document this new failure mode, which will reduce false positives in CI.

  External URL: https://patchwork.freedesktop.org/api/1.0/series/46177/revisions/13/mbox/

== Possible new issues ==

  Here are the unknown changes that may have been introduced in IGTPW_1605_full:

  === IGT changes ===

    ==== Warnings ====

    igt@gem_mocs_settings@mocs-rc6-bsd2:
      shard-kbl:          PASS -> SKIP

    igt@perf_pmu@rc6:
      shard-kbl:          SKIP -> PASS

    
== Known issues ==

  Here are the changes found in IGTPW_1605_full that come from known issues:

  === IGT changes ===

    ==== Issues hit ====

    igt@kms_available_modes_crc@available_mode_test_crc:
      shard-glk:          NOTRUN -> FAIL (fdo#106641)

    igt@kms_flip@2x-plain-flip-fb-recreate:
      shard-glk:          PASS -> FAIL (fdo#100368)

    igt@prime_busy@after-blt:
      shard-snb:          PASS -> INCOMPLETE (fdo#105411)

    
    ==== Possible fixes ====

    igt@kms_flip@2x-flip-vs-expired-vblank:
      shard-glk:          FAIL (fdo#105189) -> PASS

    igt@kms_flip@plain-flip-fb-recreate:
      shard-glk:          FAIL (fdo#100368) -> PASS

    igt@kms_rotation_crc@primary-rotation-180:
      shard-snb:          FAIL (fdo#103925) -> PASS

    igt@kms_setmode@basic:
      shard-apl:          FAIL (fdo#99912) -> PASS

    igt@kms_vblank@pipe-a-ts-continuation-suspend:
      shard-hsw:          FAIL (fdo#104894) -> PASS

    igt@perf@polling:
      shard-hsw:          FAIL (fdo#102252) -> PASS

    
  fdo#100368 https://bugs.freedesktop.org/show_bug.cgi?id=100368
  fdo#102252 https://bugs.freedesktop.org/show_bug.cgi?id=102252
  fdo#103925 https://bugs.freedesktop.org/show_bug.cgi?id=103925
  fdo#104894 https://bugs.freedesktop.org/show_bug.cgi?id=104894
  fdo#105189 https://bugs.freedesktop.org/show_bug.cgi?id=105189
  fdo#105411 https://bugs.freedesktop.org/show_bug.cgi?id=105411
  fdo#106641 https://bugs.freedesktop.org/show_bug.cgi?id=106641
  fdo#99912 https://bugs.freedesktop.org/show_bug.cgi?id=99912


== Participating hosts (5 -> 5) ==

  No changes in participating hosts


== Build changes ==

    * IGT: IGT_4567 -> IGTPW_1605
    * Linux: CI_DRM_4507 -> CI_DRM_4509

  CI_DRM_4507: 3bbfaebaf3ba21d866c7823d9e4febf47b4b7b39 @ git://anongit.freedesktop.org/gfx-ci/linux
  CI_DRM_4509: e84aa0b47beed78a5a12db93e76fb00eab5db160 @ git://anongit.freedesktop.org/gfx-ci/linux
  IGTPW_1605: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1605/
  IGT_4567: 7f85adc4050182f490c7a5c48db3d57cdb00af4e @ git://anongit.freedesktop.org/xorg/app/intel-gpu-tools

== Logs ==

For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1605/shards.html
_______________________________________________
igt-dev mailing list
igt-dev@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/igt-dev