All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH i-g-t 0/8] trace.pl fixes and improvements
@ 2018-07-18  9:45 ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

Dropped the scaling patch since it is possible to build timeline objects
directly with micro-seconds (conversion to dates is not needed)! This also makes
the time axis look correct in Firefox.

Only three and a half unreviewed patches remain. :)

John Harrison (1):
  trace.pl: Improved key/colours

Tvrtko Ursulin (7):
  trace.pl: Improve time axis labels
  trace.pl: Improve readability of graphical timeline representation
  trace.pl: Improve context colouring for large context id's
  trace.pl: Context save only applies to last request of a bunch
  trace.pl: Fix incomplete request handling
  trace.pl: Basic preemption support
  trace.pl: Fix request split mode

 scripts/media-bench.pl |   2 +-
 scripts/trace.pl       | 552 ++++++++++++++++++++++++++++++-----------
 2 files changed, 413 insertions(+), 141 deletions(-)

-- 
2.17.1

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* [Intel-gfx] [PATCH i-g-t 0/8] trace.pl fixes and improvements
@ 2018-07-18  9:45 ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

Dropped the scaling patch since it is possible to build timeline objects
directly with micro-seconds (conversion to dates is not needed)! This also makes
the time axis look correct in Firefox.

Only three and a half unreviewed patches remain. :)

John Harrison (1):
  trace.pl: Improved key/colours

Tvrtko Ursulin (7):
  trace.pl: Improve time axis labels
  trace.pl: Improve readability of graphical timeline representation
  trace.pl: Improve context colouring for large context id's
  trace.pl: Context save only applies to last request of a bunch
  trace.pl: Fix incomplete request handling
  trace.pl: Basic preemption support
  trace.pl: Fix request split mode

 scripts/media-bench.pl |   2 +-
 scripts/trace.pl       | 552 ++++++++++++++++++++++++++++++-----------
 2 files changed, 413 insertions(+), 141 deletions(-)

-- 
2.17.1

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

It is possible to customize the axis display so change it to display
timestamps in seconds on the major axis (with six decimal spaces) and
millisecond offsets on the minor axis.

v2:
 * Give up on broken relative timestamps.

v3:
 * Drop all date complications and just use micro seconds throughout.
   (John Harrison)

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Suggested-by: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: John Harrison <John.C.Harrison@Intel.com>
Reviewed-by: John Harrison <John.C.Harrison@Intel.com> # v2
---
 scripts/trace.pl | 72 ++++++++++++++++++++++++++++++++----------------
 1 file changed, 48 insertions(+), 24 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index fc1713e4f9a7..3ad5effafd0a 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -329,20 +329,6 @@ sub sanitize_ctx
 	}
 }
 
-sub ts
-{
-	my ($us) = @_;
-	my ($y, $mo, $d, $h, $m, $s);
-
-	$s = int($us / 1000000);
-	$us = $us % 1000000;
-
-	($s, $m, $h, $d, $mo, $y) = gmtime($s);
-
-	return sprintf('%04u-%02u-%02u %02u:%02u:%02u.%06u',
-		        $y, 1 + $mo, $d, $h, $m, $s, int($us));
-}
-
 # Main input loop - parse lines and build the internal representation of the
 # trace using a hash of requests and some auxilliary data structures.
 my $prev_freq = 0;
@@ -912,7 +898,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$style = 'color: black; background-color: ' .
 			 ctx_colour($ctx, 'queue');
 		$content = "$name<br>$db{$key}->{'submit-delay'}us <small>($db{$key}->{'execute-delay'}us)</small>";
-		$startend = 'start: \'' . ts($queue) . '\', end: \'' . ts($submit) . '\'';
+		$startend = 'start: ' . $queue . ', end: ' . $submit;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -923,7 +909,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$style = 'color: black; background-color: ' .
 			 ctx_colour($ctx, 'ready');
 		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
-		$startend = 'start: \'' . ts($submit) . '\', end: \'' . ts($start) . '\'';
+		$startend = 'start: ' . $submit . ', end: ' . $start;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -942,7 +928,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
 		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
 		$content .= "<br>$db{$key}->{'duration'}us <small>($db{$key}->{'context-complete-delay'}us)</small>";
-		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($notify) . '\'';
+		$startend = 'start: ' . $start . ', end: ' . $notify;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -956,7 +942,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
 		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
 		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
-		$startend = 'start: \'' . ts($notify) . '\', end: \'' . ts($end) . '\'';
+		$startend = 'start: ' . $notify . ', end: ' . $end;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -974,7 +960,7 @@ foreach my $item (@freqs) {
 
 	$start = $first_ts if $start < $first_ts;
 	$end = $last_ts if $end > $last_ts;
-	$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
+	$startend = 'start: ' . $start . ', end: ' . $end;
 	print "\t{id: $i, type: 'range', group: 0, content: '$freq', $startend},\n";
 	$i++;
 }
@@ -988,18 +974,55 @@ if ($gpu_timeline) {
 
 		$start = $first_ts if $start < $first_ts;
 		$end = $last_ts if $end > $last_ts;
-		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
+		$startend = 'start: ' . $start . ', end: ' . $end;
 		print "\t{id: $i, type: 'range', group: 1, $startend},\n";
 		$i++;
 	}
 }
 
-my $end_ts = ts($first_ts + $width_us);
-$first_ts = ts($first_ts);
+my $end_ts = $first_ts + $width_us;
+$first_ts = $first_ts;
 
 print <<ENDHTML;
   ]);
 
+  function majorAxis(date, scale, step) {
+	var s = date / 1000000;
+	var precision;
+
+	if (scale == 'millisecond')
+		precision = 6;
+	else if (scale == 'second')
+		precision = 3;
+	else
+		precision = 0;
+
+	return s.toFixed(precision) + "s";
+  }
+
+  function minorAxis(date, scale, step) {
+	var t = date;
+	var precision;
+	var unit;
+
+	if (scale == 'millisecond') {
+		t %= 1000;
+		precision = 0;
+		unit = 'us';
+	} else if (scale == 'second') {
+		t /= 1000;
+		t %= 1000;
+		precision = 0;
+		unit = 'ms';
+	} else {
+		t /= 1000000;
+		precision = 1;
+		unit = 's';
+	}
+
+	return t.toFixed(precision) + unit;
+  }
+
   // Configuration for the Timeline
   var options = { groupOrder: 'content',
 		  horizontalScroll: true,
@@ -1007,8 +1030,9 @@ print <<ENDHTML;
 		  stackSubgroups: false,
 		  zoomKey: 'ctrlKey',
 		  orientation: 'top',
-		  start: '$first_ts',
-		  end: '$end_ts'};
+		  format: { majorLabels: majorAxis, minorLabels: minorAxis },
+		  start: $first_ts,
+		  end: $end_ts};
 
   // Create a Timeline
   var timeline = new vis.Timeline(container, items, groups, options);
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [igt-dev] [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx, Tvrtko Ursulin

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

It is possible to customize the axis display so change it to display
timestamps in seconds on the major axis (with six decimal spaces) and
millisecond offsets on the minor axis.

v2:
 * Give up on broken relative timestamps.

v3:
 * Drop all date complications and just use micro seconds throughout.
   (John Harrison)

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Suggested-by: Chris Wilson <chris@chris-wilson.co.uk>
Cc: Chris Wilson <chris@chris-wilson.co.uk>
Cc: John Harrison <John.C.Harrison@Intel.com>
Reviewed-by: John Harrison <John.C.Harrison@Intel.com> # v2
---
 scripts/trace.pl | 72 ++++++++++++++++++++++++++++++++----------------
 1 file changed, 48 insertions(+), 24 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index fc1713e4f9a7..3ad5effafd0a 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -329,20 +329,6 @@ sub sanitize_ctx
 	}
 }
 
-sub ts
-{
-	my ($us) = @_;
-	my ($y, $mo, $d, $h, $m, $s);
-
-	$s = int($us / 1000000);
-	$us = $us % 1000000;
-
-	($s, $m, $h, $d, $mo, $y) = gmtime($s);
-
-	return sprintf('%04u-%02u-%02u %02u:%02u:%02u.%06u',
-		        $y, 1 + $mo, $d, $h, $m, $s, int($us));
-}
-
 # Main input loop - parse lines and build the internal representation of the
 # trace using a hash of requests and some auxilliary data structures.
 my $prev_freq = 0;
@@ -912,7 +898,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$style = 'color: black; background-color: ' .
 			 ctx_colour($ctx, 'queue');
 		$content = "$name<br>$db{$key}->{'submit-delay'}us <small>($db{$key}->{'execute-delay'}us)</small>";
-		$startend = 'start: \'' . ts($queue) . '\', end: \'' . ts($submit) . '\'';
+		$startend = 'start: ' . $queue . ', end: ' . $submit;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -923,7 +909,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$style = 'color: black; background-color: ' .
 			 ctx_colour($ctx, 'ready');
 		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
-		$startend = 'start: \'' . ts($submit) . '\', end: \'' . ts($start) . '\'';
+		$startend = 'start: ' . $submit . ', end: ' . $start;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -942,7 +928,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
 		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
 		$content .= "<br>$db{$key}->{'duration'}us <small>($db{$key}->{'context-complete-delay'}us)</small>";
-		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($notify) . '\'';
+		$startend = 'start: ' . $start . ', end: ' . $notify;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -956,7 +942,7 @@ foreach my $key (sort sortQueue keys %db) {
 		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
 		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
 		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
-		$startend = 'start: \'' . ts($notify) . '\', end: \'' . ts($end) . '\'';
+		$startend = 'start: ' . $notify . ', end: ' . $end;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
 		$i++;
 	}
@@ -974,7 +960,7 @@ foreach my $item (@freqs) {
 
 	$start = $first_ts if $start < $first_ts;
 	$end = $last_ts if $end > $last_ts;
-	$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
+	$startend = 'start: ' . $start . ', end: ' . $end;
 	print "\t{id: $i, type: 'range', group: 0, content: '$freq', $startend},\n";
 	$i++;
 }
@@ -988,18 +974,55 @@ if ($gpu_timeline) {
 
 		$start = $first_ts if $start < $first_ts;
 		$end = $last_ts if $end > $last_ts;
-		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
+		$startend = 'start: ' . $start . ', end: ' . $end;
 		print "\t{id: $i, type: 'range', group: 1, $startend},\n";
 		$i++;
 	}
 }
 
-my $end_ts = ts($first_ts + $width_us);
-$first_ts = ts($first_ts);
+my $end_ts = $first_ts + $width_us;
+$first_ts = $first_ts;
 
 print <<ENDHTML;
   ]);
 
+  function majorAxis(date, scale, step) {
+	var s = date / 1000000;
+	var precision;
+
+	if (scale == 'millisecond')
+		precision = 6;
+	else if (scale == 'second')
+		precision = 3;
+	else
+		precision = 0;
+
+	return s.toFixed(precision) + "s";
+  }
+
+  function minorAxis(date, scale, step) {
+	var t = date;
+	var precision;
+	var unit;
+
+	if (scale == 'millisecond') {
+		t %= 1000;
+		precision = 0;
+		unit = 'us';
+	} else if (scale == 'second') {
+		t /= 1000;
+		t %= 1000;
+		precision = 0;
+		unit = 'ms';
+	} else {
+		t /= 1000000;
+		precision = 1;
+		unit = 's';
+	}
+
+	return t.toFixed(precision) + unit;
+  }
+
   // Configuration for the Timeline
   var options = { groupOrder: 'content',
 		  horizontalScroll: true,
@@ -1007,8 +1030,9 @@ print <<ENDHTML;
 		  stackSubgroups: false,
 		  zoomKey: 'ctrlKey',
 		  orientation: 'top',
-		  start: '$first_ts',
-		  end: '$end_ts'};
+		  format: { majorLabels: majorAxis, minorLabels: minorAxis },
+		  start: $first_ts,
+		  end: $end_ts};
 
   // Create a Timeline
   var timeline = new vis.Timeline(container, items, groups, options);
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 2/8] trace.pl: Improve readability of graphical timeline representation
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

We add stripes for different stages of request execution so it is easier
to follow one context in the multi-colour mode.

Vertical stripe pattern indicates pipeline "blockages" - requests waiting
for dependencies before they are runnable.

Diagonal stripes indicate runnable requests waiting for GPU time.

Horizontal strips are requests executing on the GPU.

Also use this new multi-coloured mode from media-bench.pl.

v2:
 John Harrison:
 * Mention media-bench.pl in the commit.
 * Fix HTML for single colour mode.

v3:
 * Rebase.
 * Apply stripes to legacy colouring as well.

v4:
 John Harrison:
 * Use per context colours for ctxsave and incomplete boxes.
 * Clearer timeline legend.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: John Harrison <John.C.Harrison@Intel.com>
Reviewed-by: John Harrison <John.C.Harrison@Intel.com>
---
 scripts/media-bench.pl |   2 +-
 scripts/trace.pl       | 112 ++++++++++++++++++++++++++++++++---------
 2 files changed, 90 insertions(+), 24 deletions(-)

diff --git a/scripts/media-bench.pl b/scripts/media-bench.pl
index c5628c7f2836..375844d9cdf6 100755
--- a/scripts/media-bench.pl
+++ b/scripts/media-bench.pl
@@ -207,7 +207,7 @@ sub trace_workload
 	show_cmd($cmd);
 	system($cmd);
 
-	$cmd = "perf script | $tracepl --html -x ctxsave -s ";
+	$cmd = "perf script | $tracepl --html -x ctxsave -s -c ";
 	$cmd .= join ' ', map("-i $_", @skip_engine);
 	$cmd .= " > ${file}.html";
 	show_cmd($cmd);
diff --git a/scripts/trace.pl b/scripts/trace.pl
index 3ad5effafd0a..b9188123ba65 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -707,9 +707,14 @@ foreach my $key (keys %reqwait) {
 say sprintf('GPU: %.2f%% idle, %.2f%% busy',
 	     $flat_busy{'gpu-idle'}, $flat_busy{'gpu-busy'}) unless $html;
 
-my $queued_colour = $colour_contexts ? 'multi-colour light' : 'blue';
-my $runnable_colour = $colour_contexts ? 'multi-colour dark' : 'grey';
-my $execute_colour = $colour_contexts ? 'multi-colour' : 'pink';
+my $timeline_text = $colour_contexts ?
+		    'Per context coloured shading like:' : 'Box shading like:';
+
+my $queued_style = box_style($min_ctx, 'queue');
+my $ready_style = box_style($min_ctx, 'ready');
+my $execute_style = box_style($min_ctx, 'execute');
+my $ctxsave_style = box_style($min_ctx, 'ctxsave');
+my $incomplete_style = box_style($min_ctx, 'incomplete');
 
 print <<ENDHTML if $html;
 <!DOCTYPE HTML>
@@ -728,9 +733,28 @@ print <<ENDHTML if $html;
 </head>
 <body>
 <p>
-$execute_colour = requests executing on the GPU<br>
-$runnable_colour = runnable requests waiting for a slot on GPU<br>
-$queued_colour = requests waiting on fences and dependencies before they are runnable<br>
+<b>Timeline request view:</b>
+<table>
+<tr><td colspan='4'>$timeline_text</td></tr>
+<tr>
+<td align='center'><div style='$queued_style'>QUEUED</div></td>
+<td align='center'><div style='$ready_style'>READY</div></td>
+<td align='center'><div style='$execute_style'>EXECUTE</div></td>
+<td align='center'><div style='$ctxsave_style'>CTXSAVE</div></td>
+</tr><tr>
+<td></td>
+<td></td>
+<td align='center'><div style='$incomplete_style'>(INCOMPLETE)</div></td>
+<td></td>
+</tr/></table>
+</p>
+<p>
+<small>
+QUEUED = requests executing on the GPU<br>
+READY = runnable requests waiting for a slot on GPU<br>
+EXECUTE = requests waiting on fences and dependencies before they are runnable<br>
+CTXSAVE = GPU saving the context image<br>
+</small>
 </p>
 <p>
 Boxes are in format 'ctx-id/seqno'.
@@ -850,17 +874,31 @@ sub sortQueue {
 
 sub ctx_colour
 {
-	my ($ctx, $stage) = (@_);
+	my ($ctx, $stage, $lfac) = (@_);
 	my ($s, $l);
 	my $val;
 
 	unless ($colour_contexts) {
 		if ($stage eq 'queue') {
-			return 'lightblue;';
+			$val = 210;
+			$s = 65;
+			$l = 52;
 		} elsif ($stage eq 'ready') {
-			return 'lightgrey;';
+			$val = 0;
+			$s = 0;
+			$l = 47;
 		} elsif ($stage eq 'execute') {
-			return 'pink;';
+			$val = 346;
+			$s = 68;
+			$l = 65;
+		} elsif ($stage eq 'ctxsave') {
+			$val = 26;
+			$s = 90;
+			$l = 52;
+		} elsif ($stage eq 'incomplete') {
+			$val = 0;
+			$s = 85;
+			$l = 50;
 		}
 	} else {
 		if ($stage eq 'queue') {
@@ -872,12 +910,45 @@ sub ctx_colour
 		} elsif ($stage eq 'execute') {
 			$s = 80;
 			$l = 65;
+		} elsif ($stage eq 'ctxsave') {
+			$s = 75;
+			$l = 70;
+		} elsif ($stage eq 'incomplete') {
+			$s = 80;
+			$l = 25;
 		}
+
+		$val = int(360 / ($max_ctx - $min_ctx + 1)) * ($ctx - $min_ctx);
 	}
 
-	$val = int(360 / ($max_ctx - $min_ctx + 1)) * ($ctx - $min_ctx);
+	$l = int($l * $lfac);
 
-	return "hsl($val, $s%, $l%);";
+	return "hsl($val, $s%, $l%)";
+}
+
+sub box_style
+{
+	my ($ctx, $stage) = @_;
+	my $deg;
+
+	if ($stage eq 'queue') {
+		$deg = 90;
+	} elsif ($stage eq 'ready') {
+		$deg = 45;
+	} elsif ($stage eq 'execute') {
+		$deg = 0;
+	} elsif ($stage eq 'ctxsave') {
+		$deg = 105;
+	} elsif ($stage eq 'incomplete') {
+		$deg = 0;
+	}
+
+	return 'color: black; background: repeating-linear-gradient(' .
+		$deg . 'deg, ' .
+		ctx_colour($ctx, $stage, 1.0) . ', ' .
+		ctx_colour($ctx, $stage, 1.0) . ' 10px, ' .
+		ctx_colour($ctx, $stage, 0.90) . ' 10px, ' .
+		ctx_colour($ctx, $stage, 0.90) . ' 20px);';
 }
 
 my $i = 0;
@@ -895,8 +966,7 @@ foreach my $key (sort sortQueue keys %db) {
 	# submit to execute
 	unless (exists $skip_box{'queue'}) {
 		$skey = 2 * $max_seqno * $ctx + 2 * $seqno;
-		$style = 'color: black; background-color: ' .
-			 ctx_colour($ctx, 'queue');
+		$style = box_style($ctx, 'queue');
 		$content = "$name<br>$db{$key}->{'submit-delay'}us <small>($db{$key}->{'execute-delay'}us)</small>";
 		$startend = 'start: ' . $queue . ', end: ' . $submit;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
@@ -906,8 +976,7 @@ foreach my $key (sort sortQueue keys %db) {
 	# execute to start
 	unless (exists $skip_box{'ready'}) {
 		$skey = 2 * $max_seqno * $ctx + 2 * $seqno + 1;
-		$style = 'color: black; background-color: ' .
-			 ctx_colour($ctx, 'ready');
+		$style = box_style($ctx, 'ready');
 		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
 		$startend = 'start: ' . $submit . ', end: ' . $start;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
@@ -917,12 +986,9 @@ foreach my $key (sort sortQueue keys %db) {
 	# start to user interrupt
 	unless (exists $skip_box{'execute'}) {
 		$skey = -2 * $max_seqno * $ctx - 2 * $seqno - 1;
-		if (exists $db{$key}->{'incomplete'}) {
-			$style = 'color: white; background-color: red;';
-		} else {
-			$style = 'color: black; background-color: ' .
-				  ctx_colour($ctx, 'execute');
-		}
+		$style = box_style($ctx,
+				   exists $db{$key}->{'incomplete'} ?
+				   'incomplete' : 'execute');
 		$content = "$name <small>$db{$key}->{'port'}</small>";
 		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
 		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
@@ -936,7 +1002,7 @@ foreach my $key (sort sortQueue keys %db) {
 	# user interrupt to context complete
 	unless (exists $skip_box{'ctxsave'}) {
 		$skey = -2 * $max_seqno * $ctx - 2 * $seqno;
-		$style = 'color: black; background-color: orange;';
+		$style = box_style($ctx, 'ctxsave');
 		my $ctxsave = $db{$key}->{'end'} - $db{$key}->{'notify'};
 		$content = "<small>$name<br>${ctxsave}us</small>";
 		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [Intel-gfx] [PATCH i-g-t 2/8] trace.pl: Improve readability of graphical timeline representation
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

We add stripes for different stages of request execution so it is easier
to follow one context in the multi-colour mode.

Vertical stripe pattern indicates pipeline "blockages" - requests waiting
for dependencies before they are runnable.

Diagonal stripes indicate runnable requests waiting for GPU time.

Horizontal strips are requests executing on the GPU.

Also use this new multi-coloured mode from media-bench.pl.

v2:
 John Harrison:
 * Mention media-bench.pl in the commit.
 * Fix HTML for single colour mode.

v3:
 * Rebase.
 * Apply stripes to legacy colouring as well.

v4:
 John Harrison:
 * Use per context colours for ctxsave and incomplete boxes.
 * Clearer timeline legend.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: John Harrison <John.C.Harrison@Intel.com>
Reviewed-by: John Harrison <John.C.Harrison@Intel.com>
---
 scripts/media-bench.pl |   2 +-
 scripts/trace.pl       | 112 ++++++++++++++++++++++++++++++++---------
 2 files changed, 90 insertions(+), 24 deletions(-)

diff --git a/scripts/media-bench.pl b/scripts/media-bench.pl
index c5628c7f2836..375844d9cdf6 100755
--- a/scripts/media-bench.pl
+++ b/scripts/media-bench.pl
@@ -207,7 +207,7 @@ sub trace_workload
 	show_cmd($cmd);
 	system($cmd);
 
-	$cmd = "perf script | $tracepl --html -x ctxsave -s ";
+	$cmd = "perf script | $tracepl --html -x ctxsave -s -c ";
 	$cmd .= join ' ', map("-i $_", @skip_engine);
 	$cmd .= " > ${file}.html";
 	show_cmd($cmd);
diff --git a/scripts/trace.pl b/scripts/trace.pl
index 3ad5effafd0a..b9188123ba65 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -707,9 +707,14 @@ foreach my $key (keys %reqwait) {
 say sprintf('GPU: %.2f%% idle, %.2f%% busy',
 	     $flat_busy{'gpu-idle'}, $flat_busy{'gpu-busy'}) unless $html;
 
-my $queued_colour = $colour_contexts ? 'multi-colour light' : 'blue';
-my $runnable_colour = $colour_contexts ? 'multi-colour dark' : 'grey';
-my $execute_colour = $colour_contexts ? 'multi-colour' : 'pink';
+my $timeline_text = $colour_contexts ?
+		    'Per context coloured shading like:' : 'Box shading like:';
+
+my $queued_style = box_style($min_ctx, 'queue');
+my $ready_style = box_style($min_ctx, 'ready');
+my $execute_style = box_style($min_ctx, 'execute');
+my $ctxsave_style = box_style($min_ctx, 'ctxsave');
+my $incomplete_style = box_style($min_ctx, 'incomplete');
 
 print <<ENDHTML if $html;
 <!DOCTYPE HTML>
@@ -728,9 +733,28 @@ print <<ENDHTML if $html;
 </head>
 <body>
 <p>
-$execute_colour = requests executing on the GPU<br>
-$runnable_colour = runnable requests waiting for a slot on GPU<br>
-$queued_colour = requests waiting on fences and dependencies before they are runnable<br>
+<b>Timeline request view:</b>
+<table>
+<tr><td colspan='4'>$timeline_text</td></tr>
+<tr>
+<td align='center'><div style='$queued_style'>QUEUED</div></td>
+<td align='center'><div style='$ready_style'>READY</div></td>
+<td align='center'><div style='$execute_style'>EXECUTE</div></td>
+<td align='center'><div style='$ctxsave_style'>CTXSAVE</div></td>
+</tr><tr>
+<td></td>
+<td></td>
+<td align='center'><div style='$incomplete_style'>(INCOMPLETE)</div></td>
+<td></td>
+</tr/></table>
+</p>
+<p>
+<small>
+QUEUED = requests executing on the GPU<br>
+READY = runnable requests waiting for a slot on GPU<br>
+EXECUTE = requests waiting on fences and dependencies before they are runnable<br>
+CTXSAVE = GPU saving the context image<br>
+</small>
 </p>
 <p>
 Boxes are in format 'ctx-id/seqno'.
@@ -850,17 +874,31 @@ sub sortQueue {
 
 sub ctx_colour
 {
-	my ($ctx, $stage) = (@_);
+	my ($ctx, $stage, $lfac) = (@_);
 	my ($s, $l);
 	my $val;
 
 	unless ($colour_contexts) {
 		if ($stage eq 'queue') {
-			return 'lightblue;';
+			$val = 210;
+			$s = 65;
+			$l = 52;
 		} elsif ($stage eq 'ready') {
-			return 'lightgrey;';
+			$val = 0;
+			$s = 0;
+			$l = 47;
 		} elsif ($stage eq 'execute') {
-			return 'pink;';
+			$val = 346;
+			$s = 68;
+			$l = 65;
+		} elsif ($stage eq 'ctxsave') {
+			$val = 26;
+			$s = 90;
+			$l = 52;
+		} elsif ($stage eq 'incomplete') {
+			$val = 0;
+			$s = 85;
+			$l = 50;
 		}
 	} else {
 		if ($stage eq 'queue') {
@@ -872,12 +910,45 @@ sub ctx_colour
 		} elsif ($stage eq 'execute') {
 			$s = 80;
 			$l = 65;
+		} elsif ($stage eq 'ctxsave') {
+			$s = 75;
+			$l = 70;
+		} elsif ($stage eq 'incomplete') {
+			$s = 80;
+			$l = 25;
 		}
+
+		$val = int(360 / ($max_ctx - $min_ctx + 1)) * ($ctx - $min_ctx);
 	}
 
-	$val = int(360 / ($max_ctx - $min_ctx + 1)) * ($ctx - $min_ctx);
+	$l = int($l * $lfac);
 
-	return "hsl($val, $s%, $l%);";
+	return "hsl($val, $s%, $l%)";
+}
+
+sub box_style
+{
+	my ($ctx, $stage) = @_;
+	my $deg;
+
+	if ($stage eq 'queue') {
+		$deg = 90;
+	} elsif ($stage eq 'ready') {
+		$deg = 45;
+	} elsif ($stage eq 'execute') {
+		$deg = 0;
+	} elsif ($stage eq 'ctxsave') {
+		$deg = 105;
+	} elsif ($stage eq 'incomplete') {
+		$deg = 0;
+	}
+
+	return 'color: black; background: repeating-linear-gradient(' .
+		$deg . 'deg, ' .
+		ctx_colour($ctx, $stage, 1.0) . ', ' .
+		ctx_colour($ctx, $stage, 1.0) . ' 10px, ' .
+		ctx_colour($ctx, $stage, 0.90) . ' 10px, ' .
+		ctx_colour($ctx, $stage, 0.90) . ' 20px);';
 }
 
 my $i = 0;
@@ -895,8 +966,7 @@ foreach my $key (sort sortQueue keys %db) {
 	# submit to execute
 	unless (exists $skip_box{'queue'}) {
 		$skey = 2 * $max_seqno * $ctx + 2 * $seqno;
-		$style = 'color: black; background-color: ' .
-			 ctx_colour($ctx, 'queue');
+		$style = box_style($ctx, 'queue');
 		$content = "$name<br>$db{$key}->{'submit-delay'}us <small>($db{$key}->{'execute-delay'}us)</small>";
 		$startend = 'start: ' . $queue . ', end: ' . $submit;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
@@ -906,8 +976,7 @@ foreach my $key (sort sortQueue keys %db) {
 	# execute to start
 	unless (exists $skip_box{'ready'}) {
 		$skey = 2 * $max_seqno * $ctx + 2 * $seqno + 1;
-		$style = 'color: black; background-color: ' .
-			 ctx_colour($ctx, 'ready');
+		$style = box_style($ctx, 'ready');
 		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
 		$startend = 'start: ' . $submit . ', end: ' . $start;
 		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
@@ -917,12 +986,9 @@ foreach my $key (sort sortQueue keys %db) {
 	# start to user interrupt
 	unless (exists $skip_box{'execute'}) {
 		$skey = -2 * $max_seqno * $ctx - 2 * $seqno - 1;
-		if (exists $db{$key}->{'incomplete'}) {
-			$style = 'color: white; background-color: red;';
-		} else {
-			$style = 'color: black; background-color: ' .
-				  ctx_colour($ctx, 'execute');
-		}
+		$style = box_style($ctx,
+				   exists $db{$key}->{'incomplete'} ?
+				   'incomplete' : 'execute');
 		$content = "$name <small>$db{$key}->{'port'}</small>";
 		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
 		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
@@ -936,7 +1002,7 @@ foreach my $key (sort sortQueue keys %db) {
 	# user interrupt to context complete
 	unless (exists $skip_box{'ctxsave'}) {
 		$skey = -2 * $max_seqno * $ctx - 2 * $seqno;
-		$style = 'color: black; background-color: orange;';
+		$style = box_style($ctx, 'ctxsave');
 		my $ctxsave = $db{$key}->{'end'} - $db{$key}->{'notify'};
 		$content = "<small>$name<br>${ctxsave}us</small>";
 		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 3/8] trace.pl: Improve context colouring for large context id's
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

John reports that on a long runnning systems the huge disparity between
kernel context and user context id's causes all interesting colours to be
clustered too close together.

Fix this by assigning colours to seen contexts instead of basing purely
on context id's.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Suggested-by: John Harrison <John.C.Harrison@Intel.com>
Cc: John Harrison <John.C.Harrison@Intel.com>
Reviewed-by: John Harrison <John.C.Harrison@Intel.com>
---
 scripts/trace.pl | 25 ++++++++++++++++++++-----
 1 file changed, 20 insertions(+), 5 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index b9188123ba65..b57922c24e16 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -322,7 +322,7 @@ sub sanitize_ctx
 {
 	my ($ctx, $ring) = @_;
 
-	if (exists $ctxdb{$ctx}) {
+	if (exists $ctxdb{$ctx} and $ctxdb{$ctx} > 1) {
 		return $ctx . '.' . $ctxdb{$ctx};
 	} else {
 		return $ctx;
@@ -395,6 +395,8 @@ while (<>) {
 			$ctxdb{$orig_ctx}++;
 			$ctx = sanitize_ctx($orig_ctx, $ring);
 			$key = db_key($ring, $ctx, $seqno);
+		} else {
+			$ctxdb{$orig_ctx} = 1;
 		}
 
 		$queue{$key} = $time;
@@ -562,7 +564,7 @@ foreach my $key (@sorted_keys) {
 
 my $last_ts = 0;
 my $first_ts;
-my ($min_ctx, $max_ctx);
+my $min_ctx;
 
 foreach my $key (@sorted_keys) {
 	my $ring = $db{$key}->{'ring'};
@@ -574,8 +576,6 @@ foreach my $key (@sorted_keys) {
 	$last_ts = $end if $end > $last_ts;
 	$min_ctx = $db{$key}->{'ctx'} if not defined $min_ctx or
 					 $db{$key}->{'ctx'} < $min_ctx;
-	$max_ctx = $db{$key}->{'ctx'} if not defined $max_ctx or
-					 $db{$key}->{'ctx'} > $max_ctx;
 
 	$db{$key}->{'context-complete-delay'} = $end - $notify;
 	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
@@ -710,6 +710,21 @@ say sprintf('GPU: %.2f%% idle, %.2f%% busy',
 my $timeline_text = $colour_contexts ?
 		    'Per context coloured shading like:' : 'Box shading like:';
 
+my %ctx_colours;
+
+sub generate_ctx_colours
+{
+	my $num_ctx = keys %ctxdb;
+	my $i = 0;
+
+	foreach my $ctx (sort keys %ctxdb) {
+		$ctx_colours{$ctx} = int(360 / $num_ctx * $i++);
+	}
+}
+
+
+generate_ctx_colours() if $html and $colour_contexts;
+
 my $queued_style = box_style($min_ctx, 'queue');
 my $ready_style = box_style($min_ctx, 'ready');
 my $execute_style = box_style($min_ctx, 'execute');
@@ -918,7 +933,7 @@ sub ctx_colour
 			$l = 25;
 		}
 
-		$val = int(360 / ($max_ctx - $min_ctx + 1)) * ($ctx - $min_ctx);
+		$val = $ctx_colours{$ctx};
 	}
 
 	$l = int($l * $lfac);
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [igt-dev] [PATCH i-g-t 3/8] trace.pl: Improve context colouring for large context id's
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx, Tvrtko Ursulin

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

John reports that on a long runnning systems the huge disparity between
kernel context and user context id's causes all interesting colours to be
clustered too close together.

Fix this by assigning colours to seen contexts instead of basing purely
on context id's.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Suggested-by: John Harrison <John.C.Harrison@Intel.com>
Cc: John Harrison <John.C.Harrison@Intel.com>
Reviewed-by: John Harrison <John.C.Harrison@Intel.com>
---
 scripts/trace.pl | 25 ++++++++++++++++++++-----
 1 file changed, 20 insertions(+), 5 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index b9188123ba65..b57922c24e16 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -322,7 +322,7 @@ sub sanitize_ctx
 {
 	my ($ctx, $ring) = @_;
 
-	if (exists $ctxdb{$ctx}) {
+	if (exists $ctxdb{$ctx} and $ctxdb{$ctx} > 1) {
 		return $ctx . '.' . $ctxdb{$ctx};
 	} else {
 		return $ctx;
@@ -395,6 +395,8 @@ while (<>) {
 			$ctxdb{$orig_ctx}++;
 			$ctx = sanitize_ctx($orig_ctx, $ring);
 			$key = db_key($ring, $ctx, $seqno);
+		} else {
+			$ctxdb{$orig_ctx} = 1;
 		}
 
 		$queue{$key} = $time;
@@ -562,7 +564,7 @@ foreach my $key (@sorted_keys) {
 
 my $last_ts = 0;
 my $first_ts;
-my ($min_ctx, $max_ctx);
+my $min_ctx;
 
 foreach my $key (@sorted_keys) {
 	my $ring = $db{$key}->{'ring'};
@@ -574,8 +576,6 @@ foreach my $key (@sorted_keys) {
 	$last_ts = $end if $end > $last_ts;
 	$min_ctx = $db{$key}->{'ctx'} if not defined $min_ctx or
 					 $db{$key}->{'ctx'} < $min_ctx;
-	$max_ctx = $db{$key}->{'ctx'} if not defined $max_ctx or
-					 $db{$key}->{'ctx'} > $max_ctx;
 
 	$db{$key}->{'context-complete-delay'} = $end - $notify;
 	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
@@ -710,6 +710,21 @@ say sprintf('GPU: %.2f%% idle, %.2f%% busy',
 my $timeline_text = $colour_contexts ?
 		    'Per context coloured shading like:' : 'Box shading like:';
 
+my %ctx_colours;
+
+sub generate_ctx_colours
+{
+	my $num_ctx = keys %ctxdb;
+	my $i = 0;
+
+	foreach my $ctx (sort keys %ctxdb) {
+		$ctx_colours{$ctx} = int(360 / $num_ctx * $i++);
+	}
+}
+
+
+generate_ctx_colours() if $html and $colour_contexts;
+
 my $queued_style = box_style($min_ctx, 'queue');
 my $ready_style = box_style($min_ctx, 'ready');
 my $execute_style = box_style($min_ctx, 'execute');
@@ -918,7 +933,7 @@ sub ctx_colour
 			$l = 25;
 		}
 
-		$val = int(360 / ($max_ctx - $min_ctx + 1)) * ($ctx - $min_ctx);
+		$val = $ctx_colours{$ctx};
 	}
 
 	$l = int($l * $lfac);
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 4/8] trace.pl: Improved key/colours
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

From: John Harrison <John.C.Harrison@Intel.com>

Improve the timeline legend to show actual context colours.

v2: (Tvrtko Ursulin)
 * Commit msg.
 * Tweak layout for more compactness and more readability.

v3:
 * Limit number of shown contexts in the legend. (John Harrison)

v4:
 * Unbreak legend display with small context counts. (John Harrison)

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

diff --git a/scripts/trace.pl b/scripts/trace.pl
index b57922c24e16..575fe83d8550 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -708,9 +708,48 @@ say sprintf('GPU: %.2f%% idle, %.2f%% busy',
 	     $flat_busy{'gpu-idle'}, $flat_busy{'gpu-busy'}) unless $html;
 
 my $timeline_text = $colour_contexts ?
-		    'Per context coloured shading like:' : 'Box shading like:';
+		    'per context coloured shading like' : 'box shading like';
 
 my %ctx_colours;
+my $ctx_table;
+
+sub generate_ctx_table
+{
+	my @states = ('queue', 'ready', 'execute', 'ctxsave', 'incomplete');
+	my $max_show = 6;
+	my (@ctxts, @disp_ctxts);
+	my $step;
+
+	if( $colour_contexts ) {
+		@ctxts = sort keys %ctxdb;
+	} else {
+		@ctxts = ($min_ctx);
+	}
+
+	# Limit number of shown context examples
+	$step = int(scalar(@ctxts) / $max_show);
+	if ($step) {
+		foreach my $i (0..$#ctxts) {
+			push @disp_ctxts, $ctxts[$i] unless $i % $step;
+			last if scalar(@disp_ctxts) == $max_show;
+		}
+	} else {
+		@disp_ctxts = @ctxts;
+	}
+
+	$ctx_table .= '<table>';
+
+	foreach my $ctx (@disp_ctxts) {
+		$ctx_table .= "<tr>\n";
+		$ctx_table .= "  <td>Context $ctx</td>\n" if $colour_contexts;
+		foreach my $state (@states) {
+			$ctx_table .= "  <td align='center' valign='middle'><div style='" . box_style($ctx, $state) . " padding-top: 6px; padding-bottom: 6px; padding-left: 6x; padding-right: 6px;'>" . uc($state) . "</div></td>\n";
+		}
+		$ctx_table .= "</tr>\n";
+	}
+
+	$ctx_table .= '</table>';
+}
 
 sub generate_ctx_colours
 {
@@ -724,12 +763,7 @@ sub generate_ctx_colours
 
 
 generate_ctx_colours() if $html and $colour_contexts;
-
-my $queued_style = box_style($min_ctx, 'queue');
-my $ready_style = box_style($min_ctx, 'ready');
-my $execute_style = box_style($min_ctx, 'execute');
-my $ctxsave_style = box_style($min_ctx, 'ctxsave');
-my $incomplete_style = box_style($min_ctx, 'incomplete');
+generate_ctx_table() if $html;
 
 print <<ENDHTML if $html;
 <!DOCTYPE HTML>
@@ -748,35 +782,27 @@ print <<ENDHTML if $html;
 </head>
 <body>
 <p>
-<b>Timeline request view:</b>
+<b>Timeline request view is $timeline_text:</b>
 <table>
-<tr><td colspan='4'>$timeline_text</td></tr>
 <tr>
-<td align='center'><div style='$queued_style'>QUEUED</div></td>
-<td align='center'><div style='$ready_style'>READY</div></td>
-<td align='center'><div style='$execute_style'>EXECUTE</div></td>
-<td align='center'><div style='$ctxsave_style'>CTXSAVE</div></td>
-</tr><tr>
-<td></td>
-<td></td>
-<td align='center'><div style='$incomplete_style'>(INCOMPLETE)</div></td>
-<td></td>
-</tr/></table>
-</p>
-<p>
-<small>
-QUEUED = requests executing on the GPU<br>
+<td>
+$ctx_table
+</td>
+<td>
+QUEUE = requests executing on the GPU<br>
 READY = runnable requests waiting for a slot on GPU<br>
 EXECUTE = requests waiting on fences and dependencies before they are runnable<br>
 CTXSAVE = GPU saving the context image<br>
-</small>
-</p>
+INCOMPLETE = request of unknown completion time
 <p>
 Boxes are in format 'ctx-id/seqno'.
 </p>
 <p>
 Use Ctrl+scroll-action to zoom-in/out and scroll-action or dragging to move around the timeline.
 </p>
+</td>
+</tr>
+</table>
 <p>
 <b>GPU idle: $flat_busy{'gpu-idle'}%</b>
 <br>
@@ -945,20 +971,24 @@ sub box_style
 {
 	my ($ctx, $stage) = @_;
 	my $deg;
+	my $text_col = 'white';
 
 	if ($stage eq 'queue') {
 		$deg = 90;
+		$text_col = 'black' if $colour_contexts;
 	} elsif ($stage eq 'ready') {
 		$deg = 45;
 	} elsif ($stage eq 'execute') {
 		$deg = 0;
+		$text_col = 'black' if $colour_contexts;
 	} elsif ($stage eq 'ctxsave') {
 		$deg = 105;
+		$text_col = 'black' if $colour_contexts;
 	} elsif ($stage eq 'incomplete') {
 		$deg = 0;
 	}
 
-	return 'color: black; background: repeating-linear-gradient(' .
+	return "color: $text_col; background: repeating-linear-gradient(" .
 		$deg . 'deg, ' .
 		ctx_colour($ctx, $stage, 1.0) . ', ' .
 		ctx_colour($ctx, $stage, 1.0) . ' 10px, ' .
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [Intel-gfx] [PATCH i-g-t 4/8] trace.pl: Improved key/colours
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

From: John Harrison <John.C.Harrison@Intel.com>

Improve the timeline legend to show actual context colours.

v2: (Tvrtko Ursulin)
 * Commit msg.
 * Tweak layout for more compactness and more readability.

v3:
 * Limit number of shown contexts in the legend. (John Harrison)

v4:
 * Unbreak legend display with small context counts. (John Harrison)

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

diff --git a/scripts/trace.pl b/scripts/trace.pl
index b57922c24e16..575fe83d8550 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -708,9 +708,48 @@ say sprintf('GPU: %.2f%% idle, %.2f%% busy',
 	     $flat_busy{'gpu-idle'}, $flat_busy{'gpu-busy'}) unless $html;
 
 my $timeline_text = $colour_contexts ?
-		    'Per context coloured shading like:' : 'Box shading like:';
+		    'per context coloured shading like' : 'box shading like';
 
 my %ctx_colours;
+my $ctx_table;
+
+sub generate_ctx_table
+{
+	my @states = ('queue', 'ready', 'execute', 'ctxsave', 'incomplete');
+	my $max_show = 6;
+	my (@ctxts, @disp_ctxts);
+	my $step;
+
+	if( $colour_contexts ) {
+		@ctxts = sort keys %ctxdb;
+	} else {
+		@ctxts = ($min_ctx);
+	}
+
+	# Limit number of shown context examples
+	$step = int(scalar(@ctxts) / $max_show);
+	if ($step) {
+		foreach my $i (0..$#ctxts) {
+			push @disp_ctxts, $ctxts[$i] unless $i % $step;
+			last if scalar(@disp_ctxts) == $max_show;
+		}
+	} else {
+		@disp_ctxts = @ctxts;
+	}
+
+	$ctx_table .= '<table>';
+
+	foreach my $ctx (@disp_ctxts) {
+		$ctx_table .= "<tr>\n";
+		$ctx_table .= "  <td>Context $ctx</td>\n" if $colour_contexts;
+		foreach my $state (@states) {
+			$ctx_table .= "  <td align='center' valign='middle'><div style='" . box_style($ctx, $state) . " padding-top: 6px; padding-bottom: 6px; padding-left: 6x; padding-right: 6px;'>" . uc($state) . "</div></td>\n";
+		}
+		$ctx_table .= "</tr>\n";
+	}
+
+	$ctx_table .= '</table>';
+}
 
 sub generate_ctx_colours
 {
@@ -724,12 +763,7 @@ sub generate_ctx_colours
 
 
 generate_ctx_colours() if $html and $colour_contexts;
-
-my $queued_style = box_style($min_ctx, 'queue');
-my $ready_style = box_style($min_ctx, 'ready');
-my $execute_style = box_style($min_ctx, 'execute');
-my $ctxsave_style = box_style($min_ctx, 'ctxsave');
-my $incomplete_style = box_style($min_ctx, 'incomplete');
+generate_ctx_table() if $html;
 
 print <<ENDHTML if $html;
 <!DOCTYPE HTML>
@@ -748,35 +782,27 @@ print <<ENDHTML if $html;
 </head>
 <body>
 <p>
-<b>Timeline request view:</b>
+<b>Timeline request view is $timeline_text:</b>
 <table>
-<tr><td colspan='4'>$timeline_text</td></tr>
 <tr>
-<td align='center'><div style='$queued_style'>QUEUED</div></td>
-<td align='center'><div style='$ready_style'>READY</div></td>
-<td align='center'><div style='$execute_style'>EXECUTE</div></td>
-<td align='center'><div style='$ctxsave_style'>CTXSAVE</div></td>
-</tr><tr>
-<td></td>
-<td></td>
-<td align='center'><div style='$incomplete_style'>(INCOMPLETE)</div></td>
-<td></td>
-</tr/></table>
-</p>
-<p>
-<small>
-QUEUED = requests executing on the GPU<br>
+<td>
+$ctx_table
+</td>
+<td>
+QUEUE = requests executing on the GPU<br>
 READY = runnable requests waiting for a slot on GPU<br>
 EXECUTE = requests waiting on fences and dependencies before they are runnable<br>
 CTXSAVE = GPU saving the context image<br>
-</small>
-</p>
+INCOMPLETE = request of unknown completion time
 <p>
 Boxes are in format 'ctx-id/seqno'.
 </p>
 <p>
 Use Ctrl+scroll-action to zoom-in/out and scroll-action or dragging to move around the timeline.
 </p>
+</td>
+</tr>
+</table>
 <p>
 <b>GPU idle: $flat_busy{'gpu-idle'}%</b>
 <br>
@@ -945,20 +971,24 @@ sub box_style
 {
 	my ($ctx, $stage) = @_;
 	my $deg;
+	my $text_col = 'white';
 
 	if ($stage eq 'queue') {
 		$deg = 90;
+		$text_col = 'black' if $colour_contexts;
 	} elsif ($stage eq 'ready') {
 		$deg = 45;
 	} elsif ($stage eq 'execute') {
 		$deg = 0;
+		$text_col = 'black' if $colour_contexts;
 	} elsif ($stage eq 'ctxsave') {
 		$deg = 105;
+		$text_col = 'black' if $colour_contexts;
 	} elsif ($stage eq 'incomplete') {
 		$deg = 0;
 	}
 
-	return 'color: black; background: repeating-linear-gradient(' .
+	return "color: $text_col; background: repeating-linear-gradient(" .
 		$deg . 'deg, ' .
 		ctx_colour($ctx, $stage, 1.0) . ', ' .
 		ctx_colour($ctx, $stage, 1.0) . ' 10px, ' .
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 5/8] trace.pl: Context save only applies to last request of a bunch
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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 575fe83d8550..deb17e4a1816 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -577,7 +577,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'};
 	$db{$key}->{'duration'} = $notify - $start;
@@ -594,7 +598,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) {
@@ -1045,7 +1049,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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [igt-dev] [PATCH i-g-t 5/8] trace.pl: Context save only applies to last request of a bunch
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx, 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 575fe83d8550..deb17e4a1816 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -577,7 +577,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'};
 	$db{$key}->{'duration'} = $notify - $start;
@@ -594,7 +598,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) {
@@ -1045,7 +1049,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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 6/8] trace.pl: Fix incomplete request handling
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

Incomplete requests (no notify, no context complete) have to be corrected
by looking at the engine timeline, and not the sorted-by-start-time view
as was previously used.

Per-engine timelines are generated on demand and cached for later use.

v2: Find end of current context on the engine timeline instead of just
    using the next request for adjusting the incomplete start time.

v3: Improve scaling with large datasets by only walking each engine
    timeline once and some caching. (John Harrison)

v4:
 * Fix logic fail from v3.
 * Refactor the code a bit to separate the stages better.
 * Do not account batches with unknown duration in avg stats.
 * Handle two user interrupts with the same seqno.
 * Handle user interrupt arriving after request_out.

v5:
 * Update for class:instance.

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

diff --git a/scripts/trace.pl b/scripts/trace.pl
index deb17e4a1816..60d42865acbd 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -432,16 +432,11 @@ while (<>) {
 		die if exists $db{$key}->{'end'};
 
 		$db{$key}->{'end'} = $time;
-		if (exists $notify{$gkey}) {
-			$db{$key}->{'notify'} = $notify{$gkey};
-		} else {
-			# No notify so far. Maybe it will arrive later which
-			# will be handled in the sanitation loop below.
-			$db{$key}->{'notify'} = $db{$key}->{'end'};
-			$db{$key}->{'no-notify'} = 1;
-		}
+		$db{$key}->{'notify'} = $notify{$gkey} if exists $notify{$gkey};
 	} elsif ($tp_name eq 'i915:intel_engine_notify:') {
-		$notify{global_key($ring, $seqno)} = $time;
+		my $gkey = global_key($ring, $seqno);
+
+		$notify{$gkey} = $time unless exists $notify{$gkey};
 	} elsif ($tp_name eq 'i915:intel_gpu_freq_change:') {
 		push @freqs, [$prev_freq_ts, $time, $prev_freq] if $prev_freq;
 		$prev_freq_ts = $time;
@@ -454,66 +449,116 @@ while (<>) {
 my $max_seqno = 0;
 foreach my $key (keys %db) {
 	my $gkey = global_key($db{$key}->{'ring'}, $db{$key}->{'global'});
-	my $notify = $notify{$gkey};
 
 	die unless exists $db{$key}->{'start'};
 
 	$max_seqno = $db{$key}->{'seqno'} if $db{$key}->{'seqno'} > $max_seqno;
 
-	unless (exists $db{$key}->{'end'}) {
-		# Context complete not received.
-		$db{$key}->{'no-end'} = 1;
+	# Notify arrived after context complete?
+	$db{$key}->{'notify'} = $notify{$gkey} if not exists $db{$key}->{'notify'}
+						  and exists $notify{$gkey};
 
-		if (defined($notify)) {
-			# No context complete due req merging - use notify.
-			$db{$key}->{'notify'} = $notify;
-			$db{$key}->{'end'} = $notify;
-		} else {
-			# No notify and no context complete - give up for now.
-			$db{$key}->{'incomplete'} = 1;
-		}
-	} else {
-		# Notify arrived after context complete.
-		if (exists $db{$key}->{'no-notify'} and defined($notify)) {
-			delete $db{$key}->{'no-notify'};
-			$db{$key}->{'notify'} = $notify;
-		}
+	# No notify but we have end?
+	$db{$key}->{'notify'} = $db{$key}->{'end'} if exists $db{$key}->{'end'} and
+						      not exists $db{$key}->{'notify'};
+
+	# If user interrupt arrived out of order push it back to be no later
+	# than request out.
+	if (exists $db{$key}->{'end'} and exists $db{$key}->{'notify'} and
+	    $db{$key}->{'notify'} > $db{$key}->{'end'}) {
+		$db{$key}->{'notify'} = $db{$key}->{'end'};
 	}
 }
 
-# Fix up incompletes
 my $key_count = scalar(keys %db);
-foreach my $key (keys %db) {
-	next unless exists $db{$key}->{'incomplete'};
 
-	# End the incomplete batch at the time next one starts
-	my $ring = $db{$key}->{'ring'};
-	my $ctx = $db{$key}->{'ctx'};
-	my $seqno = $db{$key}->{'seqno'};
-	my $next_key;
-	my $i = 1;
-	my $end;
-
-	do {
-		$next_key = db_key($ring, $ctx, $seqno + $i);
-		$i++;
-	} until ((exists $db{$next_key} and not exists $db{$next_key}->{'incomplete'})
-		 or $i > $key_count);  # ugly stop hack
+my %engine_timelines;
 
-	if (exists $db{$next_key}) {
-		$end = $db{$next_key}->{'end'};
-	} else {
-		# No info at all, fake it:
-		$end = $db{$key}->{'start'} + 999;
-	}
+sub sortEngine {
+	my $as = $db{$a}->{'global'};
+	my $bs = $db{$b}->{'global'};
+	my $val;
+
+	$val = $as <=> $bs;
 
-	$db{$key}->{'notify'} = $end;
-	$db{$key}->{'end'} = $end;
+	die if $val == 0;
+
+	return $val;
 }
 
-# GPU time accounting
-my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count);
-my (%submit_avg, %execute_avg, %ctxsave_avg);
+sub get_engine_timeline {
+	my ($ring) = @_;
+	my @timeline;
+
+	return $engine_timelines{$ring} if exists $engine_timelines{$ring};
+
+	@timeline = grep { $db{$_}->{'ring'} eq $ring } keys %db;
+	# FIXME seqno restart
+	@timeline = sort sortEngine @timeline;
+
+	$engine_timelines{$ring} = \@timeline;
+
+	return \@timeline;
+}
+
+# Fix up coalesced requests by ending them either when the following same
+# context request with known end ends, or when a different context starts.
+foreach my $gid (sort keys %rings) {
+	my $ring = $ringmap{$rings{$gid}};
+	my $timeline = get_engine_timeline($ring);
+	my $last_complete = -1;
+	my $last_ctx = -1;
+	my $complete;
+
+	foreach my $pos (0..$#{$timeline}) {
+		my $key = @{$timeline}[$pos];
+		my ($ctx, $end);
+
+		next if exists $db{$key}->{'end'};
+
+		$db{$key}->{'no-end'} = 1;
+		$ctx = $db{$key}->{'ctx'};
+
+		if ($pos > $last_complete or $ctx != $last_ctx) {
+			my $next = $pos;
+
+			undef $complete;
+
+			while ($next < $#{$timeline}) {
+				my $next_key = ${$timeline}[++$next];
+				if ($ctx == $db{$next_key}->{'ctx'} and
+				    exists $db{$next_key}->{'end'}) {
+					$last_ctx = $db{$next_key}->{'ctx'};
+					$last_complete = $next;
+					$complete = $next_key;
+					last;
+				}
+			}
+		}
+
+		if (defined $complete) {
+			if ($ctx == $db{$complete}->{'ctx'}) {
+				$end = $db{$complete}->{'end'};
+			} else {
+				$end = $db{$complete}->{'start'};
+			}
+		} else {
+			# No next submission. Use notify if available or give up.
+			if (exists $db{$key}->{'notify'}) {
+				$end = $db{$key}->{'notify'};
+			} else {
+				$end = $db{$key}->{'start'};
+				$db{$key}->{'incomplete'} = 1;
+			}
+		}
+
+		unless (exists $db{$key}->{'notify'}) {
+			$db{$key}->{'notify'} = $end;
+			$db{$key}->{'no-notify'} = 1;
+		}
+		$db{$key}->{'end'} = $end;
+	}
+}
 
 sub sortStart {
 	my $as = $db{$a}->{'start'};
@@ -562,6 +607,10 @@ foreach my $key (@sorted_keys) {
 
 @sorted_keys = sort sortStart keys %db if $re_sort;
 
+# GPU time accounting
+my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count);
+my (%submit_avg, %execute_avg, %ctxsave_avg);
+
 my $last_ts = 0;
 my $first_ts;
 my $min_ctx;
@@ -584,7 +633,11 @@ foreach my $key (@sorted_keys) {
 	}
 	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
 	$db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
-	$db{$key}->{'duration'} = $notify - $start;
+	unless (exists $db{$key}->{'no-notify'}) {
+		$db{$key}->{'duration'} = $notify - $start;
+	} else {
+		$db{$key}->{'duration'} = 0;
+	}
 
 	$running{$ring} += $end - $start if $correct_durations or
 					    not exists $db{$key}->{'no-end'};
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [igt-dev] [PATCH i-g-t 6/8] trace.pl: Fix incomplete request handling
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx, Tvrtko Ursulin

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

Incomplete requests (no notify, no context complete) have to be corrected
by looking at the engine timeline, and not the sorted-by-start-time view
as was previously used.

Per-engine timelines are generated on demand and cached for later use.

v2: Find end of current context on the engine timeline instead of just
    using the next request for adjusting the incomplete start time.

v3: Improve scaling with large datasets by only walking each engine
    timeline once and some caching. (John Harrison)

v4:
 * Fix logic fail from v3.
 * Refactor the code a bit to separate the stages better.
 * Do not account batches with unknown duration in avg stats.
 * Handle two user interrupts with the same seqno.
 * Handle user interrupt arriving after request_out.

v5:
 * Update for class:instance.

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

diff --git a/scripts/trace.pl b/scripts/trace.pl
index deb17e4a1816..60d42865acbd 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -432,16 +432,11 @@ while (<>) {
 		die if exists $db{$key}->{'end'};
 
 		$db{$key}->{'end'} = $time;
-		if (exists $notify{$gkey}) {
-			$db{$key}->{'notify'} = $notify{$gkey};
-		} else {
-			# No notify so far. Maybe it will arrive later which
-			# will be handled in the sanitation loop below.
-			$db{$key}->{'notify'} = $db{$key}->{'end'};
-			$db{$key}->{'no-notify'} = 1;
-		}
+		$db{$key}->{'notify'} = $notify{$gkey} if exists $notify{$gkey};
 	} elsif ($tp_name eq 'i915:intel_engine_notify:') {
-		$notify{global_key($ring, $seqno)} = $time;
+		my $gkey = global_key($ring, $seqno);
+
+		$notify{$gkey} = $time unless exists $notify{$gkey};
 	} elsif ($tp_name eq 'i915:intel_gpu_freq_change:') {
 		push @freqs, [$prev_freq_ts, $time, $prev_freq] if $prev_freq;
 		$prev_freq_ts = $time;
@@ -454,66 +449,116 @@ while (<>) {
 my $max_seqno = 0;
 foreach my $key (keys %db) {
 	my $gkey = global_key($db{$key}->{'ring'}, $db{$key}->{'global'});
-	my $notify = $notify{$gkey};
 
 	die unless exists $db{$key}->{'start'};
 
 	$max_seqno = $db{$key}->{'seqno'} if $db{$key}->{'seqno'} > $max_seqno;
 
-	unless (exists $db{$key}->{'end'}) {
-		# Context complete not received.
-		$db{$key}->{'no-end'} = 1;
+	# Notify arrived after context complete?
+	$db{$key}->{'notify'} = $notify{$gkey} if not exists $db{$key}->{'notify'}
+						  and exists $notify{$gkey};
 
-		if (defined($notify)) {
-			# No context complete due req merging - use notify.
-			$db{$key}->{'notify'} = $notify;
-			$db{$key}->{'end'} = $notify;
-		} else {
-			# No notify and no context complete - give up for now.
-			$db{$key}->{'incomplete'} = 1;
-		}
-	} else {
-		# Notify arrived after context complete.
-		if (exists $db{$key}->{'no-notify'} and defined($notify)) {
-			delete $db{$key}->{'no-notify'};
-			$db{$key}->{'notify'} = $notify;
-		}
+	# No notify but we have end?
+	$db{$key}->{'notify'} = $db{$key}->{'end'} if exists $db{$key}->{'end'} and
+						      not exists $db{$key}->{'notify'};
+
+	# If user interrupt arrived out of order push it back to be no later
+	# than request out.
+	if (exists $db{$key}->{'end'} and exists $db{$key}->{'notify'} and
+	    $db{$key}->{'notify'} > $db{$key}->{'end'}) {
+		$db{$key}->{'notify'} = $db{$key}->{'end'};
 	}
 }
 
-# Fix up incompletes
 my $key_count = scalar(keys %db);
-foreach my $key (keys %db) {
-	next unless exists $db{$key}->{'incomplete'};
 
-	# End the incomplete batch at the time next one starts
-	my $ring = $db{$key}->{'ring'};
-	my $ctx = $db{$key}->{'ctx'};
-	my $seqno = $db{$key}->{'seqno'};
-	my $next_key;
-	my $i = 1;
-	my $end;
-
-	do {
-		$next_key = db_key($ring, $ctx, $seqno + $i);
-		$i++;
-	} until ((exists $db{$next_key} and not exists $db{$next_key}->{'incomplete'})
-		 or $i > $key_count);  # ugly stop hack
+my %engine_timelines;
 
-	if (exists $db{$next_key}) {
-		$end = $db{$next_key}->{'end'};
-	} else {
-		# No info at all, fake it:
-		$end = $db{$key}->{'start'} + 999;
-	}
+sub sortEngine {
+	my $as = $db{$a}->{'global'};
+	my $bs = $db{$b}->{'global'};
+	my $val;
+
+	$val = $as <=> $bs;
 
-	$db{$key}->{'notify'} = $end;
-	$db{$key}->{'end'} = $end;
+	die if $val == 0;
+
+	return $val;
 }
 
-# GPU time accounting
-my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count);
-my (%submit_avg, %execute_avg, %ctxsave_avg);
+sub get_engine_timeline {
+	my ($ring) = @_;
+	my @timeline;
+
+	return $engine_timelines{$ring} if exists $engine_timelines{$ring};
+
+	@timeline = grep { $db{$_}->{'ring'} eq $ring } keys %db;
+	# FIXME seqno restart
+	@timeline = sort sortEngine @timeline;
+
+	$engine_timelines{$ring} = \@timeline;
+
+	return \@timeline;
+}
+
+# Fix up coalesced requests by ending them either when the following same
+# context request with known end ends, or when a different context starts.
+foreach my $gid (sort keys %rings) {
+	my $ring = $ringmap{$rings{$gid}};
+	my $timeline = get_engine_timeline($ring);
+	my $last_complete = -1;
+	my $last_ctx = -1;
+	my $complete;
+
+	foreach my $pos (0..$#{$timeline}) {
+		my $key = @{$timeline}[$pos];
+		my ($ctx, $end);
+
+		next if exists $db{$key}->{'end'};
+
+		$db{$key}->{'no-end'} = 1;
+		$ctx = $db{$key}->{'ctx'};
+
+		if ($pos > $last_complete or $ctx != $last_ctx) {
+			my $next = $pos;
+
+			undef $complete;
+
+			while ($next < $#{$timeline}) {
+				my $next_key = ${$timeline}[++$next];
+				if ($ctx == $db{$next_key}->{'ctx'} and
+				    exists $db{$next_key}->{'end'}) {
+					$last_ctx = $db{$next_key}->{'ctx'};
+					$last_complete = $next;
+					$complete = $next_key;
+					last;
+				}
+			}
+		}
+
+		if (defined $complete) {
+			if ($ctx == $db{$complete}->{'ctx'}) {
+				$end = $db{$complete}->{'end'};
+			} else {
+				$end = $db{$complete}->{'start'};
+			}
+		} else {
+			# No next submission. Use notify if available or give up.
+			if (exists $db{$key}->{'notify'}) {
+				$end = $db{$key}->{'notify'};
+			} else {
+				$end = $db{$key}->{'start'};
+				$db{$key}->{'incomplete'} = 1;
+			}
+		}
+
+		unless (exists $db{$key}->{'notify'}) {
+			$db{$key}->{'notify'} = $end;
+			$db{$key}->{'no-notify'} = 1;
+		}
+		$db{$key}->{'end'} = $end;
+	}
+}
 
 sub sortStart {
 	my $as = $db{$a}->{'start'};
@@ -562,6 +607,10 @@ foreach my $key (@sorted_keys) {
 
 @sorted_keys = sort sortStart keys %db if $re_sort;
 
+# GPU time accounting
+my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count);
+my (%submit_avg, %execute_avg, %ctxsave_avg);
+
 my $last_ts = 0;
 my $first_ts;
 my $min_ctx;
@@ -584,7 +633,11 @@ foreach my $key (@sorted_keys) {
 	}
 	$db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
 	$db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
-	$db{$key}->{'duration'} = $notify - $start;
+	unless (exists $db{$key}->{'no-notify'}) {
+		$db{$key}->{'duration'} = $notify - $start;
+	} else {
+		$db{$key}->{'duration'} = 0;
+	}
 
 	$running{$ring} += $end - $start if $correct_durations or
 					    not exists $db{$key}->{'no-end'};
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 7/8] trace.pl: Basic preemption support
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

Just forget about earlier request_in events.

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

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 60d42865acbd..41bedeefb776 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -408,7 +408,9 @@ while (<>) {
 	} elsif ($tp_name eq 'i915:i915_request_in:') {
 		my %req;
 
-		die if exists $db{$key};
+		# preemption
+		delete $db{$key} if exists $db{$key};
+
 		die unless exists $queue{$key};
 		die unless exists $submit{$key};
 
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [Intel-gfx] [PATCH i-g-t 7/8] trace.pl: Basic preemption support
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

Just forget about earlier request_in events.

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

diff --git a/scripts/trace.pl b/scripts/trace.pl
index 60d42865acbd..41bedeefb776 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -408,7 +408,9 @@ while (<>) {
 	} elsif ($tp_name eq 'i915:i915_request_in:') {
 		my %req;
 
-		die if exists $db{$key};
+		# preemption
+		delete $db{$key} if exists $db{$key};
+
 		die unless exists $queue{$key};
 		die unless exists $submit{$key};
 
-- 
2.17.1

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [PATCH i-g-t 8/8] trace.pl: Fix request split mode
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx

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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [igt-dev] [PATCH i-g-t 8/8] trace.pl: Fix request split mode
@ 2018-07-18  9:45   ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-18  9:45 UTC (permalink / raw)
  To: igt-dev; +Cc: intel-gfx, 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

^ permalink raw reply related	[flat|nested] 29+ messages in thread

* [igt-dev] ✓ Fi.CI.BAT: success for trace.pl fixes and improvements (rev12)
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
                   ` (8 preceding siblings ...)
  (?)
@ 2018-07-18 10:16 ` Patchwork
  -1 siblings, 0 replies; 29+ messages in thread
From: Patchwork @ 2018-07-18 10:16 UTC (permalink / raw)
  To: Tvrtko Ursulin; +Cc: igt-dev

== Series Details ==

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

== Summary ==

= CI Bug Log - changes from CI_DRM_4503 -> IGTPW_1602 =

== Summary - WARNING ==

  Minor unknown changes coming with IGTPW_1602 need to be verified
  manually.
  
  If you think the reported changes have nothing to do with the changes
  introduced in IGTPW_1602, 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/12/mbox/

== Possible new issues ==

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

  === IGT changes ===

    ==== Warnings ====

    igt@gem_render_linear_blits@basic:
      fi-bwr-2160:        SKIP -> PASS +1

    igt@gem_render_tiled_blits@basic:
      fi-elk-e7500:       SKIP -> PASS +1
      fi-ilk-650:         SKIP -> PASS +2

    
== Known issues ==

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

  === IGT changes ===

    ==== Issues hit ====

    igt@gem_exec_suspend@basic-s4-devices:
      {fi-kbl-8809g}:     NOTRUN -> INCOMPLETE (fdo#107139)

    
    ==== Possible fixes ====

    igt@kms_chamelium@dp-crc-fast:
      fi-kbl-7500u:       FAIL (fdo#103841) -> PASS +1

    igt@kms_flip@basic-flip-vs-dpms:
      fi-skl-6700hq:      DMESG-WARN (fdo#105998) -> PASS

    igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b:
      fi-snb-2520m:       INCOMPLETE (fdo#103713) -> PASS

    
  {name}: This element is suppressed. This means it is ignored when computing
          the status of the difference (SUCCESS, WARNING, or FAILURE).

  fdo#103713 https://bugs.freedesktop.org/show_bug.cgi?id=103713
  fdo#103841 https://bugs.freedesktop.org/show_bug.cgi?id=103841
  fdo#105998 https://bugs.freedesktop.org/show_bug.cgi?id=105998
  fdo#107139 https://bugs.freedesktop.org/show_bug.cgi?id=107139


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

  Additional (1): fi-kbl-8809g 
  Missing    (8): fi-ilk-m540 fi-bxt-dsi fi-hsw-4200u fi-bdw-gvtdvm fi-byt-squawks fi-bsw-cyan fi-ctg-p8600 fi-kbl-7560u 


== Build changes ==

    * IGT: IGT_4562 -> IGTPW_1602

  CI_DRM_4503: 4aa6797dfafaf527949bf55d3c8513c6902dfec2 @ git://anongit.freedesktop.org/gfx-ci/linux
  IGTPW_1602: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1602/
  IGT_4562: 8781fd89a63eabed9359d02b50583cca67ff3673 @ git://anongit.freedesktop.org/xorg/app/intel-gpu-tools

== Logs ==

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* [igt-dev] ✓ Fi.CI.IGT: success for trace.pl fixes and improvements (rev12)
  2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
                   ` (9 preceding siblings ...)
  (?)
@ 2018-07-18 13:13 ` Patchwork
  -1 siblings, 0 replies; 29+ messages in thread
From: Patchwork @ 2018-07-18 13:13 UTC (permalink / raw)
  To: Tvrtko Ursulin; +Cc: igt-dev

== Series Details ==

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

== Summary ==

= CI Bug Log - changes from IGT_4562_full -> IGTPW_1602_full =

== Summary - WARNING ==

  Minor unknown changes coming with IGTPW_1602_full need to be verified
  manually.
  
  If you think the reported changes have nothing to do with the changes
  introduced in IGTPW_1602_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/12/mbox/

== Possible new issues ==

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

  === IGT changes ===

    ==== Warnings ====

    igt@gem_exec_schedule@deep-bsd2:
      shard-kbl:          SKIP -> PASS +2

    
== Known issues ==

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

  === IGT changes ===

    ==== Issues hit ====

    igt@gem_caching@writes:
      shard-snb:          PASS -> INCOMPLETE (fdo#105411)

    igt@gem_ppgtt@blt-vs-render-ctx0:
      shard-kbl:          PASS -> INCOMPLETE (fdo#103665, fdo#106023)

    igt@gem_workarounds@suspend-resume-fd:
      shard-kbl:          PASS -> INCOMPLETE (fdo#103665)

    igt@kms_atomic_transition@1x-modeset-transitions-nonblocking-fencing:
      shard-glk:          PASS -> FAIL (fdo#105703)

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

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

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

    igt@testdisplay:
      shard-glk:          PASS -> INCOMPLETE (k.org#198133, fdo#103359)

    
    ==== Possible fixes ====

    igt@kms_flip@2x-modeset-vs-vblank-race-interruptible:
      shard-glk:          FAIL (fdo#103060) -> PASS

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

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

    igt@kms_plane_lowres@pipe-a-tiling-y:
      shard-glk:          FAIL (fdo#103166) -> PASS

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

    igt@kms_universal_plane@cursor-fb-leak-pipe-b:
      shard-glk:          FAIL -> PASS

    
  fdo#100368 https://bugs.freedesktop.org/show_bug.cgi?id=100368
  fdo#102887 https://bugs.freedesktop.org/show_bug.cgi?id=102887
  fdo#103060 https://bugs.freedesktop.org/show_bug.cgi?id=103060
  fdo#103166 https://bugs.freedesktop.org/show_bug.cgi?id=103166
  fdo#103359 https://bugs.freedesktop.org/show_bug.cgi?id=103359
  fdo#103665 https://bugs.freedesktop.org/show_bug.cgi?id=103665
  fdo#103925 https://bugs.freedesktop.org/show_bug.cgi?id=103925
  fdo#105411 https://bugs.freedesktop.org/show_bug.cgi?id=105411
  fdo#105703 https://bugs.freedesktop.org/show_bug.cgi?id=105703
  fdo#106023 https://bugs.freedesktop.org/show_bug.cgi?id=106023
  fdo#99912 https://bugs.freedesktop.org/show_bug.cgi?id=99912
  k.org#198133 https://bugzilla.kernel.org/show_bug.cgi?id=198133


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

  No changes in participating hosts


== Build changes ==

    * IGT: IGT_4562 -> IGTPW_1602
    * Linux: CI_DRM_4501 -> CI_DRM_4503

  CI_DRM_4501: 692d13f7b75baf0bb8c58b9784569c52d68f01e2 @ git://anongit.freedesktop.org/gfx-ci/linux
  CI_DRM_4503: 4aa6797dfafaf527949bf55d3c8513c6902dfec2 @ git://anongit.freedesktop.org/gfx-ci/linux
  IGTPW_1602: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1602/
  IGT_4562: 8781fd89a63eabed9359d02b50583cca67ff3673 @ git://anongit.freedesktop.org/xorg/app/intel-gpu-tools

== Logs ==

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
  2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
@ 2018-07-18 20:03     ` John Harrison
  -1 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-18 20:03 UTC (permalink / raw)
  To: Tvrtko Ursulin, igt-dev; +Cc: intel-gfx

On 7/18/2018 2:45 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> It is possible to customize the axis display so change it to display
> timestamps in seconds on the major axis (with six decimal spaces) and
> millisecond offsets on the minor axis.
>
> v2:
>   * Give up on broken relative timestamps.
>
> v3:
>   * Drop all date complications and just use micro seconds throughout.
>     (John Harrison)
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Suggested-by: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: John Harrison <John.C.Harrison@Intel.com>
> Reviewed-by: John Harrison <John.C.Harrison@Intel.com> # v2
> ---
>   scripts/trace.pl | 72 ++++++++++++++++++++++++++++++++----------------
>   1 file changed, 48 insertions(+), 24 deletions(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index fc1713e4f9a7..3ad5effafd0a 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -329,20 +329,6 @@ sub sanitize_ctx
>   	}
>   }
>   
> -sub ts
> -{
> -	my ($us) = @_;
> -	my ($y, $mo, $d, $h, $m, $s);
> -
> -	$s = int($us / 1000000);
> -	$us = $us % 1000000;
> -
> -	($s, $m, $h, $d, $mo, $y) = gmtime($s);
> -
> -	return sprintf('%04u-%02u-%02u %02u:%02u:%02u.%06u',
> -		        $y, 1 + $mo, $d, $h, $m, $s, int($us));
> -}
> -
>   # Main input loop - parse lines and build the internal representation of the
>   # trace using a hash of requests and some auxilliary data structures.
>   my $prev_freq = 0;
> @@ -912,7 +898,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$style = 'color: black; background-color: ' .
>   			 ctx_colour($ctx, 'queue');
>   		$content = "$name<br>$db{$key}->{'submit-delay'}us <small>($db{$key}->{'execute-delay'}us)</small>";
> -		$startend = 'start: \'' . ts($queue) . '\', end: \'' . ts($submit) . '\'';
> +		$startend = 'start: ' . $queue . ', end: ' . $submit;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -923,7 +909,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$style = 'color: black; background-color: ' .
>   			 ctx_colour($ctx, 'ready');
>   		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
> -		$startend = 'start: \'' . ts($submit) . '\', end: \'' . ts($start) . '\'';
> +		$startend = 'start: ' . $submit . ', end: ' . $start;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -942,7 +928,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
>   		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
>   		$content .= "<br>$db{$key}->{'duration'}us <small>($db{$key}->{'context-complete-delay'}us)</small>";
> -		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($notify) . '\'';
> +		$startend = 'start: ' . $start . ', end: ' . $notify;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -956,7 +942,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
>   		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
>   		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
> -		$startend = 'start: \'' . ts($notify) . '\', end: \'' . ts($end) . '\'';
> +		$startend = 'start: ' . $notify . ', end: ' . $end;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -974,7 +960,7 @@ foreach my $item (@freqs) {
>   
>   	$start = $first_ts if $start < $first_ts;
>   	$end = $last_ts if $end > $last_ts;
> -	$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
> +	$startend = 'start: ' . $start . ', end: ' . $end;
>   	print "\t{id: $i, type: 'range', group: 0, content: '$freq', $startend},\n";
>   	$i++;
>   }
> @@ -988,18 +974,55 @@ if ($gpu_timeline) {
>   
>   		$start = $first_ts if $start < $first_ts;
>   		$end = $last_ts if $end > $last_ts;
> -		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
> +		$startend = 'start: ' . $start . ', end: ' . $end;
>   		print "\t{id: $i, type: 'range', group: 1, $startend},\n";
>   		$i++;
>   	}
>   }
>   
> -my $end_ts = ts($first_ts + $width_us);
> -$first_ts = ts($first_ts);
> +my $end_ts = $first_ts + $width_us;
> +$first_ts = $first_ts;
>   
>   print <<ENDHTML;
>     ]);
>   
> +  function majorAxis(date, scale, step) {
> +	var s = date / 1000000;
> +	var precision;
> +
> +	if (scale == 'millisecond')
> +		precision = 6;
> +	else if (scale == 'second')
> +		precision = 3;
> +	else
> +		precision = 0;
> +
> +	return s.toFixed(precision) + "s";
> +  }
> +
> +  function minorAxis(date, scale, step) {
> +	var t = date;
> +	var precision;
> +	var unit;
> +
> +	if (scale == 'millisecond') {
> +		t %= 1000;
> +		precision = 0;
> +		unit = 'us';
> +	} else if (scale == 'second') {
> +		t /= 1000;
> +		t %= 1000;
> +		precision = 0;
> +		unit = 'ms';
> +	} else {
> +		t /= 1000000;
> +		precision = 1;
> +		unit = 's';
> +	}
> +
> +	return t.toFixed(precision) + unit;
> +  }
> +
>     // Configuration for the Timeline
>     var options = { groupOrder: 'content',
>   		  horizontalScroll: true,
> @@ -1007,8 +1030,9 @@ print <<ENDHTML;
>   		  stackSubgroups: false,
>   		  zoomKey: 'ctrlKey',
>   		  orientation: 'top',
> -		  start: '$first_ts',
> -		  end: '$end_ts'};
> +		  format: { majorLabels: majorAxis, minorLabels: minorAxis },
> +		  start: $first_ts,
> +		  end: $end_ts};
>   
>     // Create a Timeline
>     var timeline = new vis.Timeline(container, items, groups, options);

Woohoo!

This one seems to work fine on both Firefox and Chrome. It even works on 
IE and Edge unlike the previous version! I guess they can only cope with 
raw times not dates!?

One thing I've just noticed is that there is also a 'now' line on the 
timeline - a red vertical bar across the entire timeline. On the old 
'date' versions, it was following the current system time and hence 
wandering forwards at one second per second. On this version, it is out 
of position and advancing at one millisecond per second. Presumably 
because you are scaling the axes by a factor of one thousand in order to 
gain the necessary precision in the plot. Something of a curiosity but 
certainly not a problem!

Ship it :)

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


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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
@ 2018-07-18 20:03     ` John Harrison
  0 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-18 20:03 UTC (permalink / raw)
  To: Tvrtko Ursulin, igt-dev; +Cc: intel-gfx, Tvrtko Ursulin

On 7/18/2018 2:45 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> It is possible to customize the axis display so change it to display
> timestamps in seconds on the major axis (with six decimal spaces) and
> millisecond offsets on the minor axis.
>
> v2:
>   * Give up on broken relative timestamps.
>
> v3:
>   * Drop all date complications and just use micro seconds throughout.
>     (John Harrison)
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Suggested-by: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: Chris Wilson <chris@chris-wilson.co.uk>
> Cc: John Harrison <John.C.Harrison@Intel.com>
> Reviewed-by: John Harrison <John.C.Harrison@Intel.com> # v2
> ---
>   scripts/trace.pl | 72 ++++++++++++++++++++++++++++++++----------------
>   1 file changed, 48 insertions(+), 24 deletions(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index fc1713e4f9a7..3ad5effafd0a 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -329,20 +329,6 @@ sub sanitize_ctx
>   	}
>   }
>   
> -sub ts
> -{
> -	my ($us) = @_;
> -	my ($y, $mo, $d, $h, $m, $s);
> -
> -	$s = int($us / 1000000);
> -	$us = $us % 1000000;
> -
> -	($s, $m, $h, $d, $mo, $y) = gmtime($s);
> -
> -	return sprintf('%04u-%02u-%02u %02u:%02u:%02u.%06u',
> -		        $y, 1 + $mo, $d, $h, $m, $s, int($us));
> -}
> -
>   # Main input loop - parse lines and build the internal representation of the
>   # trace using a hash of requests and some auxilliary data structures.
>   my $prev_freq = 0;
> @@ -912,7 +898,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$style = 'color: black; background-color: ' .
>   			 ctx_colour($ctx, 'queue');
>   		$content = "$name<br>$db{$key}->{'submit-delay'}us <small>($db{$key}->{'execute-delay'}us)</small>";
> -		$startend = 'start: \'' . ts($queue) . '\', end: \'' . ts($submit) . '\'';
> +		$startend = 'start: ' . $queue . ', end: ' . $submit;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -923,7 +909,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$style = 'color: black; background-color: ' .
>   			 ctx_colour($ctx, 'ready');
>   		$content = "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
> -		$startend = 'start: \'' . ts($submit) . '\', end: \'' . ts($start) . '\'';
> +		$startend = 'start: ' . $submit . ', end: ' . $start;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -942,7 +928,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
>   		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
>   		$content .= "<br>$db{$key}->{'duration'}us <small>($db{$key}->{'context-complete-delay'}us)</small>";
> -		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($notify) . '\'';
> +		$startend = 'start: ' . $start . ', end: ' . $notify;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -956,7 +942,7 @@ foreach my $key (sort sortQueue keys %db) {
>   		$content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
>   		$content .= ' <small><i>++</i></small> ' if exists $db{$key}->{'no-end'};
>   		$content .= ' <small><i>+</i></small> ' if exists $db{$key}->{'no-notify'};
> -		$startend = 'start: \'' . ts($notify) . '\', end: \'' . ts($end) . '\'';
> +		$startend = 'start: ' . $notify . ', end: ' . $end;
>   		print "\t{id: $i, key: $skey, $type group: $group, subgroup: $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, style: \'$style\'},\n";
>   		$i++;
>   	}
> @@ -974,7 +960,7 @@ foreach my $item (@freqs) {
>   
>   	$start = $first_ts if $start < $first_ts;
>   	$end = $last_ts if $end > $last_ts;
> -	$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
> +	$startend = 'start: ' . $start . ', end: ' . $end;
>   	print "\t{id: $i, type: 'range', group: 0, content: '$freq', $startend},\n";
>   	$i++;
>   }
> @@ -988,18 +974,55 @@ if ($gpu_timeline) {
>   
>   		$start = $first_ts if $start < $first_ts;
>   		$end = $last_ts if $end > $last_ts;
> -		$startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . '\'';
> +		$startend = 'start: ' . $start . ', end: ' . $end;
>   		print "\t{id: $i, type: 'range', group: 1, $startend},\n";
>   		$i++;
>   	}
>   }
>   
> -my $end_ts = ts($first_ts + $width_us);
> -$first_ts = ts($first_ts);
> +my $end_ts = $first_ts + $width_us;
> +$first_ts = $first_ts;
>   
>   print <<ENDHTML;
>     ]);
>   
> +  function majorAxis(date, scale, step) {
> +	var s = date / 1000000;
> +	var precision;
> +
> +	if (scale == 'millisecond')
> +		precision = 6;
> +	else if (scale == 'second')
> +		precision = 3;
> +	else
> +		precision = 0;
> +
> +	return s.toFixed(precision) + "s";
> +  }
> +
> +  function minorAxis(date, scale, step) {
> +	var t = date;
> +	var precision;
> +	var unit;
> +
> +	if (scale == 'millisecond') {
> +		t %= 1000;
> +		precision = 0;
> +		unit = 'us';
> +	} else if (scale == 'second') {
> +		t /= 1000;
> +		t %= 1000;
> +		precision = 0;
> +		unit = 'ms';
> +	} else {
> +		t /= 1000000;
> +		precision = 1;
> +		unit = 's';
> +	}
> +
> +	return t.toFixed(precision) + unit;
> +  }
> +
>     // Configuration for the Timeline
>     var options = { groupOrder: 'content',
>   		  horizontalScroll: true,
> @@ -1007,8 +1030,9 @@ print <<ENDHTML;
>   		  stackSubgroups: false,
>   		  zoomKey: 'ctrlKey',
>   		  orientation: 'top',
> -		  start: '$first_ts',
> -		  end: '$end_ts'};
> +		  format: { majorLabels: majorAxis, minorLabels: minorAxis },
> +		  start: $first_ts,
> +		  end: $end_ts};
>   
>     // Create a Timeline
>     var timeline = new vis.Timeline(container, items, groups, options);

Woohoo!

This one seems to work fine on both Firefox and Chrome. It even works on 
IE and Edge unlike the previous version! I guess they can only cope with 
raw times not dates!?

One thing I've just noticed is that there is also a 'now' line on the 
timeline - a red vertical bar across the entire timeline. On the old 
'date' versions, it was following the current system time and hence 
wandering forwards at one second per second. On this version, it is out 
of position and advancing at one millisecond per second. Presumably 
because you are scaling the axes by a factor of one thousand in order to 
gain the necessary precision in the plot. Something of a curiosity but 
certainly not a problem!

Ship it :)

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


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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 5/8] trace.pl: Context save only applies to last request of a bunch
  2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
  (?)
@ 2018-07-18 20:11   ` John Harrison
  -1 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-18 20:11 UTC (permalink / raw)
  To: igt-dev


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

On 7/18/2018 2:45 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(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index 575fe83d8550..deb17e4a1816 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -577,7 +577,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'};
>   	$db{$key}->{'duration'} = $notify - $start;
> @@ -594,7 +598,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) {
> @@ -1045,7 +1049,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'};

Dunno if you missed it but I definitely sent an r-b to this patch in the 
last series. And I can't see any changes since, so...

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


[-- Attachment #1.2: Type: text/html, Size: 2621 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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 7/8] trace.pl: Basic preemption support
  2018-07-18  9:45   ` [Intel-gfx] " Tvrtko Ursulin
@ 2018-07-18 20:13     ` John Harrison
  -1 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-18 20:13 UTC (permalink / raw)
  To: Tvrtko Ursulin, igt-dev; +Cc: intel-gfx


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

On 7/18/2018 2:45 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Just forget about earlier request_in events.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   scripts/trace.pl | 4 +++-
>   1 file changed, 3 insertions(+), 1 deletion(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index 60d42865acbd..41bedeefb776 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -408,7 +408,9 @@ while (<>) {
>   	} elsif ($tp_name eq 'i915:i915_request_in:') {
>   		my %req;
>   
> -		die if exists $db{$key};
> +		# preemption
> +		delete $db{$key} if exists $db{$key};
> +
>   		die unless exists $queue{$key};
>   		die unless exists $submit{$key};
>   

I've definitely r-b'd this one before too. And no changes so still...

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


[-- Attachment #1.2: Type: text/html, Size: 1401 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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 7/8] trace.pl: Basic preemption support
@ 2018-07-18 20:13     ` John Harrison
  0 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-18 20:13 UTC (permalink / raw)
  To: Tvrtko Ursulin, igt-dev; +Cc: intel-gfx, Tvrtko Ursulin


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

On 7/18/2018 2:45 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Just forget about earlier request_in events.
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>   scripts/trace.pl | 4 +++-
>   1 file changed, 3 insertions(+), 1 deletion(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index 60d42865acbd..41bedeefb776 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -408,7 +408,9 @@ while (<>) {
>   	} elsif ($tp_name eq 'i915:i915_request_in:') {
>   		my %req;
>   
> -		die if exists $db{$key};
> +		# preemption
> +		delete $db{$key} if exists $db{$key};
> +
>   		die unless exists $queue{$key};
>   		die unless exists $submit{$key};
>   

I've definitely r-b'd this one before too. And no changes so still...

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


[-- Attachment #1.2: Type: text/html, Size: 1401 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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
  2018-07-18 20:03     ` [igt-dev] " John Harrison
@ 2018-07-19  9:39       ` Tvrtko Ursulin
  -1 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-19  9:39 UTC (permalink / raw)
  To: John Harrison, Tvrtko Ursulin, igt-dev; +Cc: intel-gfx


On 18/07/2018 21:03, John Harrison wrote:
> On 7/18/2018 2:45 AM, Tvrtko Ursulin wrote:
>> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>>
>> It is possible to customize the axis display so change it to display
>> timestamps in seconds on the major axis (with six decimal spaces) and
>> millisecond offsets on the minor axis.
>>
>> v2:
>>   * Give up on broken relative timestamps.
>>
>> v3:
>>   * Drop all date complications and just use micro seconds throughout.
>>     (John Harrison)
>>
>> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>> Suggested-by: Chris Wilson <chris@chris-wilson.co.uk>
>> Cc: Chris Wilson <chris@chris-wilson.co.uk>
>> Cc: John Harrison <John.C.Harrison@Intel.com>
>> Reviewed-by: John Harrison <John.C.Harrison@Intel.com> # v2
>> ---
>>   scripts/trace.pl | 72 ++++++++++++++++++++++++++++++++----------------
>>   1 file changed, 48 insertions(+), 24 deletions(-)
>>
>> diff --git a/scripts/trace.pl b/scripts/trace.pl
>> index fc1713e4f9a7..3ad5effafd0a 100755
>> --- a/scripts/trace.pl
>> +++ b/scripts/trace.pl
>> @@ -329,20 +329,6 @@ sub sanitize_ctx
>>       }
>>   }
>> -sub ts
>> -{
>> -    my ($us) = @_;
>> -    my ($y, $mo, $d, $h, $m, $s);
>> -
>> -    $s = int($us / 1000000);
>> -    $us = $us % 1000000;
>> -
>> -    ($s, $m, $h, $d, $mo, $y) = gmtime($s);
>> -
>> -    return sprintf('%04u-%02u-%02u %02u:%02u:%02u.%06u',
>> -                $y, 1 + $mo, $d, $h, $m, $s, int($us));
>> -}
>> -
>>   # Main input loop - parse lines and build the internal 
>> representation of the
>>   # trace using a hash of requests and some auxilliary data structures.
>>   my $prev_freq = 0;
>> @@ -912,7 +898,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $style = 'color: black; background-color: ' .
>>                ctx_colour($ctx, 'queue');
>>           $content = "$name<br>$db{$key}->{'submit-delay'}us 
>> <small>($db{$key}->{'execute-delay'}us)</small>";
>> -        $startend = 'start: \'' . ts($queue) . '\', end: \'' . 
>> ts($submit) . '\'';
>> +        $startend = 'start: ' . $queue . ', end: ' . $submit;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -923,7 +909,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $style = 'color: black; background-color: ' .
>>                ctx_colour($ctx, 'ready');
>>           $content = 
>> "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
>> -        $startend = 'start: \'' . ts($submit) . '\', end: \'' . 
>> ts($start) . '\'';
>> +        $startend = 'start: ' . $submit . ', end: ' . $start;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -942,7 +928,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $content .= ' <small><i>++</i></small> ' if exists 
>> $db{$key}->{'no-end'};
>>           $content .= ' <small><i>+</i></small> ' if exists 
>> $db{$key}->{'no-notify'};
>>           $content .= "<br>$db{$key}->{'duration'}us 
>> <small>($db{$key}->{'context-complete-delay'}us)</small>";
>> -        $startend = 'start: \'' . ts($start) . '\', end: \'' . 
>> ts($notify) . '\'';
>> +        $startend = 'start: ' . $start . ', end: ' . $notify;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -956,7 +942,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $content .= ' <small><i>???</i></small> ' if exists 
>> $db{$key}->{'incomplete'};
>>           $content .= ' <small><i>++</i></small> ' if exists 
>> $db{$key}->{'no-end'};
>>           $content .= ' <small><i>+</i></small> ' if exists 
>> $db{$key}->{'no-notify'};
>> -        $startend = 'start: \'' . ts($notify) . '\', end: \'' . 
>> ts($end) . '\'';
>> +        $startend = 'start: ' . $notify . ', end: ' . $end;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -974,7 +960,7 @@ foreach my $item (@freqs) {
>>       $start = $first_ts if $start < $first_ts;
>>       $end = $last_ts if $end > $last_ts;
>> -    $startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . 
>> '\'';
>> +    $startend = 'start: ' . $start . ', end: ' . $end;
>>       print "\t{id: $i, type: 'range', group: 0, content: '$freq', 
>> $startend},\n";
>>       $i++;
>>   }
>> @@ -988,18 +974,55 @@ if ($gpu_timeline) {
>>           $start = $first_ts if $start < $first_ts;
>>           $end = $last_ts if $end > $last_ts;
>> -        $startend = 'start: \'' . ts($start) . '\', end: \'' . 
>> ts($end) . '\'';
>> +        $startend = 'start: ' . $start . ', end: ' . $end;
>>           print "\t{id: $i, type: 'range', group: 1, $startend},\n";
>>           $i++;
>>       }
>>   }
>> -my $end_ts = ts($first_ts + $width_us);
>> -$first_ts = ts($first_ts);
>> +my $end_ts = $first_ts + $width_us;
>> +$first_ts = $first_ts;
>>   print <<ENDHTML;
>>     ]);
>> +  function majorAxis(date, scale, step) {
>> +    var s = date / 1000000;
>> +    var precision;
>> +
>> +    if (scale == 'millisecond')
>> +        precision = 6;
>> +    else if (scale == 'second')
>> +        precision = 3;
>> +    else
>> +        precision = 0;
>> +
>> +    return s.toFixed(precision) + "s";
>> +  }
>> +
>> +  function minorAxis(date, scale, step) {
>> +    var t = date;
>> +    var precision;
>> +    var unit;
>> +
>> +    if (scale == 'millisecond') {
>> +        t %= 1000;
>> +        precision = 0;
>> +        unit = 'us';
>> +    } else if (scale == 'second') {
>> +        t /= 1000;
>> +        t %= 1000;
>> +        precision = 0;
>> +        unit = 'ms';
>> +    } else {
>> +        t /= 1000000;
>> +        precision = 1;
>> +        unit = 's';
>> +    }
>> +
>> +    return t.toFixed(precision) + unit;
>> +  }
>> +
>>     // Configuration for the Timeline
>>     var options = { groupOrder: 'content',
>>             horizontalScroll: true,
>> @@ -1007,8 +1030,9 @@ print <<ENDHTML;
>>             stackSubgroups: false,
>>             zoomKey: 'ctrlKey',
>>             orientation: 'top',
>> -          start: '$first_ts',
>> -          end: '$end_ts'};
>> +          format: { majorLabels: majorAxis, minorLabels: minorAxis },
>> +          start: $first_ts,
>> +          end: $end_ts};
>>     // Create a Timeline
>>     var timeline = new vis.Timeline(container, items, groups, options);
> 
> Woohoo!
> 
> This one seems to work fine on both Firefox and Chrome. It even works on 
> IE and Edge unlike the previous version! I guess they can only cope with 
> raw times not dates!?
> 
> One thing I've just noticed is that there is also a 'now' line on the 
> timeline - a red vertical bar across the entire timeline. On the old 
> 'date' versions, it was following the current system time and hence 
> wandering forwards at one second per second. On this version, it is out 
> of position and advancing at one millisecond per second. Presumably 
> because you are scaling the axes by a factor of one thousand in order to 
> gain the necessary precision in the plot. Something of a curiosity but 
> certainly not a problem!

A moving red line? I never saw that! In any browser?

> Ship it :)

I have shipped it, thanks!

I have resent the remaining two unreviewed patches, plus two new ones. 
One is a fix for frequency timeline, and another is bringing back (now 
working) stacking button. (But it is off by default.)

Regards,

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
@ 2018-07-19  9:39       ` Tvrtko Ursulin
  0 siblings, 0 replies; 29+ messages in thread
From: Tvrtko Ursulin @ 2018-07-19  9:39 UTC (permalink / raw)
  To: John Harrison, Tvrtko Ursulin, igt-dev; +Cc: intel-gfx, Tvrtko Ursulin


On 18/07/2018 21:03, John Harrison wrote:
> On 7/18/2018 2:45 AM, Tvrtko Ursulin wrote:
>> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>>
>> It is possible to customize the axis display so change it to display
>> timestamps in seconds on the major axis (with six decimal spaces) and
>> millisecond offsets on the minor axis.
>>
>> v2:
>>   * Give up on broken relative timestamps.
>>
>> v3:
>>   * Drop all date complications and just use micro seconds throughout.
>>     (John Harrison)
>>
>> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>> Suggested-by: Chris Wilson <chris@chris-wilson.co.uk>
>> Cc: Chris Wilson <chris@chris-wilson.co.uk>
>> Cc: John Harrison <John.C.Harrison@Intel.com>
>> Reviewed-by: John Harrison <John.C.Harrison@Intel.com> # v2
>> ---
>>   scripts/trace.pl | 72 ++++++++++++++++++++++++++++++++----------------
>>   1 file changed, 48 insertions(+), 24 deletions(-)
>>
>> diff --git a/scripts/trace.pl b/scripts/trace.pl
>> index fc1713e4f9a7..3ad5effafd0a 100755
>> --- a/scripts/trace.pl
>> +++ b/scripts/trace.pl
>> @@ -329,20 +329,6 @@ sub sanitize_ctx
>>       }
>>   }
>> -sub ts
>> -{
>> -    my ($us) = @_;
>> -    my ($y, $mo, $d, $h, $m, $s);
>> -
>> -    $s = int($us / 1000000);
>> -    $us = $us % 1000000;
>> -
>> -    ($s, $m, $h, $d, $mo, $y) = gmtime($s);
>> -
>> -    return sprintf('%04u-%02u-%02u %02u:%02u:%02u.%06u',
>> -                $y, 1 + $mo, $d, $h, $m, $s, int($us));
>> -}
>> -
>>   # Main input loop - parse lines and build the internal 
>> representation of the
>>   # trace using a hash of requests and some auxilliary data structures.
>>   my $prev_freq = 0;
>> @@ -912,7 +898,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $style = 'color: black; background-color: ' .
>>                ctx_colour($ctx, 'queue');
>>           $content = "$name<br>$db{$key}->{'submit-delay'}us 
>> <small>($db{$key}->{'execute-delay'}us)</small>";
>> -        $startend = 'start: \'' . ts($queue) . '\', end: \'' . 
>> ts($submit) . '\'';
>> +        $startend = 'start: ' . $queue . ', end: ' . $submit;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -923,7 +909,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $style = 'color: black; background-color: ' .
>>                ctx_colour($ctx, 'ready');
>>           $content = 
>> "<small>$name<br>$db{$key}->{'execute-delay'}us</small>";
>> -        $startend = 'start: \'' . ts($submit) . '\', end: \'' . 
>> ts($start) . '\'';
>> +        $startend = 'start: ' . $submit . ', end: ' . $start;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -942,7 +928,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $content .= ' <small><i>++</i></small> ' if exists 
>> $db{$key}->{'no-end'};
>>           $content .= ' <small><i>+</i></small> ' if exists 
>> $db{$key}->{'no-notify'};
>>           $content .= "<br>$db{$key}->{'duration'}us 
>> <small>($db{$key}->{'context-complete-delay'}us)</small>";
>> -        $startend = 'start: \'' . ts($start) . '\', end: \'' . 
>> ts($notify) . '\'';
>> +        $startend = 'start: ' . $start . ', end: ' . $notify;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -956,7 +942,7 @@ foreach my $key (sort sortQueue keys %db) {
>>           $content .= ' <small><i>???</i></small> ' if exists 
>> $db{$key}->{'incomplete'};
>>           $content .= ' <small><i>++</i></small> ' if exists 
>> $db{$key}->{'no-end'};
>>           $content .= ' <small><i>+</i></small> ' if exists 
>> $db{$key}->{'no-notify'};
>> -        $startend = 'start: \'' . ts($notify) . '\', end: \'' . 
>> ts($end) . '\'';
>> +        $startend = 'start: ' . $notify . ', end: ' . $end;
>>           print "\t{id: $i, key: $skey, $type group: $group, subgroup: 
>> $subgroup, subgroupOrder: $subgroup, content: '$content', $startend, 
>> style: \'$style\'},\n";
>>           $i++;
>>       }
>> @@ -974,7 +960,7 @@ foreach my $item (@freqs) {
>>       $start = $first_ts if $start < $first_ts;
>>       $end = $last_ts if $end > $last_ts;
>> -    $startend = 'start: \'' . ts($start) . '\', end: \'' . ts($end) . 
>> '\'';
>> +    $startend = 'start: ' . $start . ', end: ' . $end;
>>       print "\t{id: $i, type: 'range', group: 0, content: '$freq', 
>> $startend},\n";
>>       $i++;
>>   }
>> @@ -988,18 +974,55 @@ if ($gpu_timeline) {
>>           $start = $first_ts if $start < $first_ts;
>>           $end = $last_ts if $end > $last_ts;
>> -        $startend = 'start: \'' . ts($start) . '\', end: \'' . 
>> ts($end) . '\'';
>> +        $startend = 'start: ' . $start . ', end: ' . $end;
>>           print "\t{id: $i, type: 'range', group: 1, $startend},\n";
>>           $i++;
>>       }
>>   }
>> -my $end_ts = ts($first_ts + $width_us);
>> -$first_ts = ts($first_ts);
>> +my $end_ts = $first_ts + $width_us;
>> +$first_ts = $first_ts;
>>   print <<ENDHTML;
>>     ]);
>> +  function majorAxis(date, scale, step) {
>> +    var s = date / 1000000;
>> +    var precision;
>> +
>> +    if (scale == 'millisecond')
>> +        precision = 6;
>> +    else if (scale == 'second')
>> +        precision = 3;
>> +    else
>> +        precision = 0;
>> +
>> +    return s.toFixed(precision) + "s";
>> +  }
>> +
>> +  function minorAxis(date, scale, step) {
>> +    var t = date;
>> +    var precision;
>> +    var unit;
>> +
>> +    if (scale == 'millisecond') {
>> +        t %= 1000;
>> +        precision = 0;
>> +        unit = 'us';
>> +    } else if (scale == 'second') {
>> +        t /= 1000;
>> +        t %= 1000;
>> +        precision = 0;
>> +        unit = 'ms';
>> +    } else {
>> +        t /= 1000000;
>> +        precision = 1;
>> +        unit = 's';
>> +    }
>> +
>> +    return t.toFixed(precision) + unit;
>> +  }
>> +
>>     // Configuration for the Timeline
>>     var options = { groupOrder: 'content',
>>             horizontalScroll: true,
>> @@ -1007,8 +1030,9 @@ print <<ENDHTML;
>>             stackSubgroups: false,
>>             zoomKey: 'ctrlKey',
>>             orientation: 'top',
>> -          start: '$first_ts',
>> -          end: '$end_ts'};
>> +          format: { majorLabels: majorAxis, minorLabels: minorAxis },
>> +          start: $first_ts,
>> +          end: $end_ts};
>>     // Create a Timeline
>>     var timeline = new vis.Timeline(container, items, groups, options);
> 
> Woohoo!
> 
> This one seems to work fine on both Firefox and Chrome. It even works on 
> IE and Edge unlike the previous version! I guess they can only cope with 
> raw times not dates!?
> 
> One thing I've just noticed is that there is also a 'now' line on the 
> timeline - a red vertical bar across the entire timeline. On the old 
> 'date' versions, it was following the current system time and hence 
> wandering forwards at one second per second. On this version, it is out 
> of position and advancing at one millisecond per second. Presumably 
> because you are scaling the axes by a factor of one thousand in order to 
> gain the necessary precision in the plot. Something of a curiosity but 
> certainly not a problem!

A moving red line? I never saw that! In any browser?

> Ship it :)

I have shipped it, thanks!

I have resent the remaining two unreviewed patches, plus two new ones. 
One is a fix for frequency timeline, and another is bringing back (now 
working) stacking button. (But it is off by default.)

Regards,

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
  2018-07-19  9:39       ` Tvrtko Ursulin
@ 2018-07-27 22:22         ` John Harrison
  -1 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-27 22:22 UTC (permalink / raw)
  To: Tvrtko Ursulin, Tvrtko Ursulin, igt-dev; +Cc: intel-gfx

On 7/19/2018 2:39 AM, Tvrtko Ursulin wrote:
>
> On 18/07/2018 21:03, John Harrison wrote:
>>
>> One thing I've just noticed is that there is also a 'now' line on the 
>> timeline - a red vertical bar across the entire timeline. On the old 
>> 'date' versions, it was following the current system time and hence 
>> wandering forwards at one second per second. On this version, it is 
>> out of position and advancing at one millisecond per second. 
>> Presumably because you are scaling the axes by a factor of one 
>> thousand in order to gain the necessary precision in the plot. 
>> Something of a curiosity but certainly not a problem!
>
> A moving red line? I never saw that! In any browser?
>

You have to zoom out a long way to see it. The trace files are time 
stamped from system boot, so fairly low numbers of seconds. The 'now' 
line is referenced from 1/1/1970 or whenever (albeit in milliseconds 
rather than seconds now). So is massively far into the future compared 
to any of the log data.

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

* Re: [igt-dev] [PATCH i-g-t 1/8] trace.pl: Improve time axis labels
@ 2018-07-27 22:22         ` John Harrison
  0 siblings, 0 replies; 29+ messages in thread
From: John Harrison @ 2018-07-27 22:22 UTC (permalink / raw)
  To: Tvrtko Ursulin, Tvrtko Ursulin, igt-dev; +Cc: intel-gfx, Tvrtko Ursulin

On 7/19/2018 2:39 AM, Tvrtko Ursulin wrote:
>
> On 18/07/2018 21:03, John Harrison wrote:
>>
>> One thing I've just noticed is that there is also a 'now' line on the 
>> timeline - a red vertical bar across the entire timeline. On the old 
>> 'date' versions, it was following the current system time and hence 
>> wandering forwards at one second per second. On this version, it is 
>> out of position and advancing at one millisecond per second. 
>> Presumably because you are scaling the axes by a factor of one 
>> thousand in order to gain the necessary precision in the plot. 
>> Something of a curiosity but certainly not a problem!
>
> A moving red line? I never saw that! In any browser?
>

You have to zoom out a long way to see it. The trace files are time 
stamped from system boot, so fairly low numbers of seconds. The 'now' 
line is referenced from 1/1/1970 or whenever (albeit in milliseconds 
rather than seconds now). So is massively far into the future compared 
to any of the log data.

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

^ permalink raw reply	[flat|nested] 29+ messages in thread

end of thread, other threads:[~2018-07-27 22:22 UTC | newest]

Thread overview: 29+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-07-18  9:45 [PATCH i-g-t 0/8] trace.pl fixes and improvements Tvrtko Ursulin
2018-07-18  9:45 ` [Intel-gfx] " Tvrtko Ursulin
2018-07-18  9:45 ` [PATCH i-g-t 1/8] trace.pl: Improve time axis labels Tvrtko Ursulin
2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
2018-07-18 20:03   ` John Harrison
2018-07-18 20:03     ` [igt-dev] " John Harrison
2018-07-19  9:39     ` Tvrtko Ursulin
2018-07-19  9:39       ` Tvrtko Ursulin
2018-07-27 22:22       ` John Harrison
2018-07-27 22:22         ` John Harrison
2018-07-18  9:45 ` [PATCH i-g-t 2/8] trace.pl: Improve readability of graphical timeline representation Tvrtko Ursulin
2018-07-18  9:45   ` [Intel-gfx] " Tvrtko Ursulin
2018-07-18  9:45 ` [PATCH i-g-t 3/8] trace.pl: Improve context colouring for large context id's Tvrtko Ursulin
2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
2018-07-18  9:45 ` [PATCH i-g-t 4/8] trace.pl: Improved key/colours Tvrtko Ursulin
2018-07-18  9:45   ` [Intel-gfx] " Tvrtko Ursulin
2018-07-18  9:45 ` [PATCH i-g-t 5/8] trace.pl: Context save only applies to last request of a bunch Tvrtko Ursulin
2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
2018-07-18 20:11   ` John Harrison
2018-07-18  9:45 ` [PATCH i-g-t 6/8] trace.pl: Fix incomplete request handling Tvrtko Ursulin
2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
2018-07-18  9:45 ` [PATCH i-g-t 7/8] trace.pl: Basic preemption support Tvrtko Ursulin
2018-07-18  9:45   ` [Intel-gfx] " Tvrtko Ursulin
2018-07-18 20:13   ` [igt-dev] " John Harrison
2018-07-18 20:13     ` John Harrison
2018-07-18  9:45 ` [PATCH i-g-t 8/8] trace.pl: Fix request split mode Tvrtko Ursulin
2018-07-18  9:45   ` [igt-dev] " Tvrtko Ursulin
2018-07-18 10:16 ` [igt-dev] ✓ Fi.CI.BAT: success for trace.pl fixes and improvements (rev12) Patchwork
2018-07-18 13:13 ` [igt-dev] ✓ Fi.CI.IGT: " Patchwork

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.