[PATCH i-g-t] scripts/trace.pl: Auto-detect tracepoint field order

[PATCH i-g-t] scripts/trace.pl: Auto-detect tracepoint field order

[Tvrtko Ursulin]

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

Instead of hard-coding the order of key-value pairs into regular
expressions, auto-detect them as we go.

At the same time re-factor the code so it is smaller and even
slightly faster (10-15% by a quick measurement).

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
Cc: Lionel Landwerlin <lionel.g.landwerlin@intel.com>
Cc: John Harrison <John.C.Harrison@intel.com>
---
 scripts/trace.pl | 223 ++++++++++++++++++-------------------------------------
 1 file changed, 71 insertions(+), 152 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index aed9b20d8407..9b3fb6486fec 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -302,74 +302,6 @@ die if scalar(@args);
 
 @ARGV = @args;
 
-sub parse_req
-{
-	my ($line, $tp) = @_;
-	state %cache;
-
-	$cache{$tp} = qr/(\d+)\.(\d+):.*$tp.*ring=(\d+), ctx=(\d+), seqno=(\d+), global(?:_seqno)?=(\d+)/ unless exists $cache{$tp};
-
-	if ($line =~ $cache{$tp}) {
-		return ($1, $2, $3, $4, $5, $6);
-	} else {
-		return undef;
-	}
-}
-
-sub parse_req_hw
-{
-	my ($line, $tp) = @_;
-	state %cache;
-
-	$cache{$tp} = qr/(\d+)\.(\d+):.*$tp.*ring=(\d+), ctx=(\d+), seqno=(\d+), global(?:_seqno)?=(\d+), port=(\d+)/ unless exists $cache{$tp};
-
-	if ($line =~ $cache{$tp}) {
-		return ($1, $2, $3, $4, $5, $6, $7);
-	} else {
-		return undef;
-	}
-}
-
-sub parse_req_wait_begin
-{
-	my ($line, $tp) = @_;
-
-	if ($line =~ /(\d+)\.(\d+):.*i915_gem_request_wait_begin.*ring=(\d+), ctx=(\d+), seqno=(\d+)/) {
-		return ($1, $2, $3, $4, $5);
-	} else {
-		return undef;
-	}
-}
-
-sub parse_notify
-{
-	my ($line) = @_;
-
-	if ($line =~ /(\d+)\.(\d+):.*intel_engine_notify.*ring=(\d+), seqno=(\d+)/) {
-		return ($1, $2, $3, $4);
-	} else {
-		return undef;
-	}
-}
-
-sub parse_freq
-{
-	my ($line) = @_;
-
-	if ($line =~ /(\d+)\.(\d+):.*intel_gpu_freq_change.*new_freq=(\d+)/) {
-		return ($1, $2, $3);
-	} else {
-		return undef;
-	}
-}
-
-sub us
-{
-	my ($s, $us) = @_;
-
-	return $s * 1000000 + $us;
-}
-
 sub db_key
 {
 	my ($ring, $ctx, $seqno) = @_;
@@ -425,86 +357,87 @@ my $prev_freq_ts = 0;
 my $oldkernelwa = 0;
 my ($no_queue, $no_in);
 while (<>) {
-	my ($s, $us, $ring, $ctx, $seqno, $global_seqno, $port);
-	my $freq;
+	my @fields;
+	my @tmp;
+	my $tp_name;
+	my $time;
+	my %tp;
 	my $key;
 
 	chomp;
+	@fields = split ' ';
 
-	($s, $us, $ring, $ctx, $seqno) = parse_req_wait_begin($_);
-	if (defined $s) {
-		my %rw;
+	$tp_name = $fields[4];
+	@tmp = split ':', $tp_name, 2;
+	next unless $tmp[0] eq 'i915';
+	$tp_name = $tmp[1];
+	chop $tp_name;
 
-		next if exists $ignore_ring{$ring};
+	chop $fields[3];
+	$time = $fields[3] * 1000000.0;
+	splice @fields, 0, 5;
 
-		$ctx = sanitize_ctx($ctx, $ring);
-		$key = db_key($ring, $ctx, $seqno);
+	foreach my $f (@fields) {
+		my @kv = split '=|,', $f;
 
-		next if exists $reqwait{$key};
+		$kv[0] = 'global' if $kv[0] eq 'global_seqno';
 
-		$rw{'key'} = $key;
-		$rw{'ring'} = $ring;
-		$rw{'seqno'} = $seqno;
-		$rw{'ctx'} = $ctx;
-		$rw{'start'} = us($s, $us);
-		$reqwait{$key} = \%rw;
-		next;
+		$tp{$kv[0]} = $kv[1];
 	}
 
-	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_wait_end');
-	if (defined $s) {
-		next if exists $ignore_ring{$ring};
+	return undef if exists $tp{'ring'} and exists $ignore_ring{$tp{'ring'}};
+
+	if ($tp_name eq 'i915_gem_request_wait_begin') {
+		my %rw;
 
-		$ctx = sanitize_ctx($ctx, $ring);
-		$key = db_key($ring, $ctx, $seqno);
+		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 
-		next unless exists $reqwait{$key};
+		next if exists $reqwait{$key};
 
-		$reqwait{$key}->{'end'} = us($s, $us);
+		$rw{'key'} = $key;
+		$rw{'ring'} = $tp{'ring'};
+		$rw{'seqno'} = $tp{'seqno'};
+		$rw{'ctx'} = $tp{'ctx'};
+		$rw{'start'} = $time;
+		$reqwait{$key} = \%rw;
 		next;
-	}
+	} elsif ($tp_name eq 'i915_gem_request_wait_end') {
+		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 
-	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_add');
-	if (defined $s) {
-		my $orig_ctx = $ctx;
+		next unless exists $reqwait{$key};
 
-		next if exists $ignore_ring{$ring};
+		$reqwait{$key}->{'end'} = $time;
+		next;
+	} elsif ($tp_name eq 'i915_gem_request_add') {
+		my $orig_ctx = $tp{'ctx'};
 
-		$ctx = sanitize_ctx($ctx, $ring);
-		$key = db_key($ring, $ctx, $seqno);
+		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 
 		if (exists $queue{$key}) {
 			$ctxdb{$orig_ctx}++;
-			$ctx = sanitize_ctx($orig_ctx, $ring);
-			$key = db_key($ring, $ctx, $seqno);
+			$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+			$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 		}
 
-		$queue{$key} = us($s, $us);
+		$queue{$key} = $time;
 		next;
-	}
-
-	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_submit');
-	if (defined $s) {
-		next if exists $ignore_ring{$ring};
-
-		$ctx = sanitize_ctx($ctx, $ring);
-		$key = db_key($ring, $ctx, $seqno);
+	} elsif ($tp_name eq 'i915_gem_request_submit') {
+		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 
 		die if exists $submit{$key};
 		die unless exists $queue{$key};
 
-		$submit{$key} = us($s, $us);
+		$submit{$key} = $time;
 		next;
-	}
-
-	($s, $us, $ring, $ctx, $seqno, $global_seqno, $port) = parse_req_hw($_, 'i915:i915_gem_request_in');
-	if (defined $s) {
+	} elsif ($tp_name eq 'i915_gem_request_in') {
 		my %req;
 
-		next if exists $ignore_ring{$ring};
-
-		$ctx = sanitize_ctx($ctx, $ring);
-		$key = db_key($ring, $ctx, $seqno);
+		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 
 		die if exists $db{$key};
 		if (not exists $queue{$key} and $oldkernelwa) {
@@ -514,30 +447,25 @@ while (<>) {
 		die unless exists $queue{$key};
 		die unless exists $submit{$key};
 
-		$req{'start'} = us($s, $us);
-		$req{'ring'} = $ring;
-		$req{'seqno'} = $seqno;
-		$req{'ctx'} = $ctx;
-		$req{'name'} = $ctx . '/' . $seqno;
-		$req{'global'} = $global_seqno;
-		$req{'port'} = $port;
+		$req{'start'} = $time;
+		$req{'ring'} = $tp{'ring'};
+		$req{'seqno'} = $tp{'seqno'};
+		$req{'ctx'} = $tp{'ctx'};
+		$req{'name'} = $tp{'ctx'} . '/' . $tp{'seqno'};
+		$req{'global'} = $tp{'global'};
+		$req{'port'} = $tp{'port'};
 		$req{'queue'} = $queue{$key};
 		$req{'submit-delay'} = $submit{$key} - $queue{$key};
 		$req{'execute-delay'} = $req{'start'} - $submit{$key};
-		$rings{$ring} = $gid++ unless exists $rings{$ring};
-		$ringmap{$rings{$ring}} = $ring;
+		$rings{$tp{'ring'}} = $gid++ unless exists $rings{$tp{'ring'}};
+		$ringmap{$rings{$tp{'ring'}}} = $tp{'ring'};
 		$db{$key} = \%req;
 		next;
-	}
-
-	($s, $us, $ring, $ctx, $seqno, $global_seqno, $port) = parse_req($_, 'i915:i915_gem_request_out');
-	if (defined $s) {
-		my $gkey = global_key($ring, $global_seqno);
+	} elsif ($tp_name eq 'i915_gem_request_out') {
+		my $gkey = global_key($tp{'ring'}, $tp{'global'});
 
-		next if exists $ignore_ring{$ring};
-
-		$ctx = sanitize_ctx($ctx, $ring);
-		$key = db_key($ring, $ctx, $seqno);
+		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
+		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
 
 		if (not exists $db{$key} and $oldkernelwa) {
 			$no_in++;
@@ -547,7 +475,7 @@ while (<>) {
 		die unless exists $db{$key}->{'start'};
 		die if exists $db{$key}->{'end'};
 
-		$db{$key}->{'end'} = us($s, $us);
+		$db{$key}->{'end'} = $time;
 		if (exists $notify{$gkey}) {
 			$db{$key}->{'notify'} = $notify{$gkey};
 		} else {
@@ -559,22 +487,13 @@ while (<>) {
 		$db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
 		$db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
 		next;
-	}
-
-	($s, $us, $ring, $seqno) = parse_notify($_);
-	if (defined $s) {
-		next if exists $ignore_ring{$ring};
-		$notify{global_key($ring, $seqno)} = us($s, $us);
+	} elsif ($tp_name eq 'intel_engine_notify') {
+		$notify{global_key($tp{'ring'}, $tp{'seqno'})} = $time;
 		next;
-	}
-
-	($s, $us, $freq) = parse_freq($_);
-	if (defined $s) {
-		my $cur = us($s, $us);
-
-		push @freqs, [$prev_freq_ts, $cur, $prev_freq] if $prev_freq;
-		$prev_freq_ts = $cur;
-		$prev_freq = $freq;
+	} elsif ($tp_name eq 'intel_gpu_freq_change') {
+		push @freqs, [$prev_freq_ts, $time, $prev_freq] if $prev_freq;
+		$prev_freq_ts = $time;
+		$prev_freq = $tp{'new_freq'};
 		next;
 	}
 }
-- 
2.14.1

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

✓ Fi.CI.BAT: success for scripts/trace.pl: Auto-detect tracepoint field order

[Patchwork]

== Series Details ==

Series: scripts/trace.pl: Auto-detect tracepoint field order
URL   : https://patchwork.freedesktop.org/series/35504/
State : success

== Summary ==

IGT patchset tested on top of latest successful build
c0be3310715e2f744b892c51f09e62273bcc8e57 tests/kms_frontbuffer_tracking: Correctly handle debugfs errors

with latest DRM-Tip kernel build CI_DRM_3541
913d6a0d4d78 drm-tip: 2017y-12m-18d-13h-25m-28s UTC integration manifest

No testlist changes.

Test kms_busy:
        Subgroup basic-flip-a:
                pass       -> DMESG-WARN (fi-elk-e7500) fdo#103989
Test kms_pipe_crc_basic:
        Subgroup suspend-read-crc-pipe-a:
                dmesg-warn -> PASS       (fi-kbl-r) fdo#104172 +1
        Subgroup suspend-read-crc-pipe-c:
                incomplete -> PASS       (fi-bdw-5557u) fdo#104162

fdo#103989 https://bugs.freedesktop.org/show_bug.cgi?id=103989
fdo#104172 https://bugs.freedesktop.org/show_bug.cgi?id=104172
fdo#104162 https://bugs.freedesktop.org/show_bug.cgi?id=104162

fi-bdw-5557u     total:288  pass:267  dwarn:0   dfail:0   fail:0   skip:21  time:433s
fi-bdw-gvtdvm    total:288  pass:264  dwarn:0   dfail:0   fail:0   skip:24  time:444s
fi-blb-e6850     total:288  pass:223  dwarn:1   dfail:0   fail:0   skip:64  time:383s
fi-bsw-n3050     total:288  pass:242  dwarn:0   dfail:0   fail:0   skip:46  time:499s
fi-bwr-2160      total:288  pass:183  dwarn:0   dfail:0   fail:0   skip:105 time:277s
fi-bxt-dsi       total:288  pass:258  dwarn:0   dfail:0   fail:0   skip:30  time:495s
fi-bxt-j4205     total:288  pass:259  dwarn:0   dfail:0   fail:0   skip:29  time:501s
fi-byt-j1900     total:288  pass:253  dwarn:0   dfail:0   fail:0   skip:35  time:482s
fi-byt-n2820     total:288  pass:249  dwarn:0   dfail:0   fail:0   skip:39  time:477s
fi-elk-e7500     total:224  pass:163  dwarn:15  dfail:0   fail:0   skip:45 
fi-gdg-551       total:288  pass:178  dwarn:1   dfail:0   fail:1   skip:108 time:262s
fi-glk-1         total:288  pass:260  dwarn:0   dfail:0   fail:0   skip:28  time:533s
fi-hsw-4770      total:288  pass:261  dwarn:0   dfail:0   fail:0   skip:27  time:403s
fi-hsw-4770r     total:288  pass:261  dwarn:0   dfail:0   fail:0   skip:27  time:416s
fi-ilk-650       total:288  pass:228  dwarn:0   dfail:0   fail:0   skip:60  time:389s
fi-ivb-3520m     total:288  pass:259  dwarn:0   dfail:0   fail:0   skip:29  time:477s
fi-ivb-3770      total:288  pass:255  dwarn:0   dfail:0   fail:0   skip:33  time:427s
fi-kbl-7500u     total:288  pass:263  dwarn:1   dfail:0   fail:0   skip:24  time:487s
fi-kbl-7560u     total:288  pass:268  dwarn:1   dfail:0   fail:0   skip:19  time:518s
fi-kbl-7567u     total:288  pass:268  dwarn:0   dfail:0   fail:0   skip:20  time:471s
fi-kbl-r         total:288  pass:260  dwarn:1   dfail:0   fail:0   skip:27  time:524s
fi-pnv-d510      total:288  pass:222  dwarn:1   dfail:0   fail:0   skip:65  time:595s
fi-skl-6260u     total:288  pass:268  dwarn:0   dfail:0   fail:0   skip:20  time:452s
fi-skl-6600u     total:288  pass:260  dwarn:1   dfail:0   fail:0   skip:27  time:533s
fi-skl-6700hq    total:288  pass:262  dwarn:0   dfail:0   fail:0   skip:26  time:558s
fi-skl-6700k2    total:288  pass:264  dwarn:0   dfail:0   fail:0   skip:24  time:506s
fi-skl-6770hq    total:288  pass:268  dwarn:0   dfail:0   fail:0   skip:20  time:491s
fi-skl-gvtdvm    total:288  pass:265  dwarn:0   dfail:0   fail:0   skip:23  time:446s
fi-snb-2520m     total:288  pass:248  dwarn:0   dfail:0   fail:0   skip:40  time:544s
fi-snb-2600      total:288  pass:248  dwarn:0   dfail:0   fail:0   skip:40  time:412s
Blacklisted hosts:
fi-cfl-s2        total:288  pass:262  dwarn:0   dfail:0   fail:0   skip:26  time:592s
fi-cnl-y         total:288  pass:262  dwarn:0   dfail:0   fail:0   skip:26  time:617s
fi-glk-dsi       total:59   pass:51   dwarn:0   dfail:0   fail:0   skip:7  

== Logs ==

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

Re: [PATCH i-g-t] scripts/trace.pl: Auto-detect tracepoint field order

[Lionel Landwerlin]

On 18/12/17 12:02, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Instead of hard-coding the order of key-value pairs into regular
> expressions, auto-detect them as we go.
>
> At the same time re-factor the code so it is smaller and even
> slightly faster (10-15% by a quick measurement).
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Cc: Lionel Landwerlin <lionel.g.landwerlin@intel.com>
> Cc: John Harrison <John.C.Harrison@intel.com>
Tested-by: Lionel Landwerlin <lionel.g.landwerlin@intel.com>

> ---
>   scripts/trace.pl | 223 ++++++++++++++++++-------------------------------------
>   1 file changed, 71 insertions(+), 152 deletions(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index aed9b20d8407..9b3fb6486fec 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -302,74 +302,6 @@ die if scalar(@args);
>   
>   @ARGV = @args;
>   
> -sub parse_req
> -{
> -	my ($line, $tp) = @_;
> -	state %cache;
> -
> -	$cache{$tp} = qr/(\d+)\.(\d+):.*$tp.*ring=(\d+), ctx=(\d+), seqno=(\d+), global(?:_seqno)?=(\d+)/ unless exists $cache{$tp};
> -
> -	if ($line =~ $cache{$tp}) {
> -		return ($1, $2, $3, $4, $5, $6);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_req_hw
> -{
> -	my ($line, $tp) = @_;
> -	state %cache;
> -
> -	$cache{$tp} = qr/(\d+)\.(\d+):.*$tp.*ring=(\d+), ctx=(\d+), seqno=(\d+), global(?:_seqno)?=(\d+), port=(\d+)/ unless exists $cache{$tp};
> -
> -	if ($line =~ $cache{$tp}) {
> -		return ($1, $2, $3, $4, $5, $6, $7);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_req_wait_begin
> -{
> -	my ($line, $tp) = @_;
> -
> -	if ($line =~ /(\d+)\.(\d+):.*i915_gem_request_wait_begin.*ring=(\d+), ctx=(\d+), seqno=(\d+)/) {
> -		return ($1, $2, $3, $4, $5);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_notify
> -{
> -	my ($line) = @_;
> -
> -	if ($line =~ /(\d+)\.(\d+):.*intel_engine_notify.*ring=(\d+), seqno=(\d+)/) {
> -		return ($1, $2, $3, $4);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_freq
> -{
> -	my ($line) = @_;
> -
> -	if ($line =~ /(\d+)\.(\d+):.*intel_gpu_freq_change.*new_freq=(\d+)/) {
> -		return ($1, $2, $3);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub us
> -{
> -	my ($s, $us) = @_;
> -
> -	return $s * 1000000 + $us;
> -}
> -
>   sub db_key
>   {
>   	my ($ring, $ctx, $seqno) = @_;
> @@ -425,86 +357,87 @@ my $prev_freq_ts = 0;
>   my $oldkernelwa = 0;
>   my ($no_queue, $no_in);
>   while (<>) {
> -	my ($s, $us, $ring, $ctx, $seqno, $global_seqno, $port);
> -	my $freq;
> +	my @fields;
> +	my @tmp;
> +	my $tp_name;
> +	my $time;
> +	my %tp;
>   	my $key;
>   
>   	chomp;
> +	@fields = split ' ';
>   
> -	($s, $us, $ring, $ctx, $seqno) = parse_req_wait_begin($_);
> -	if (defined $s) {
> -		my %rw;
> +	$tp_name = $fields[4];
> +	@tmp = split ':', $tp_name, 2;
> +	next unless $tmp[0] eq 'i915';
> +	$tp_name = $tmp[1];
> +	chop $tp_name;
>   
> -		next if exists $ignore_ring{$ring};
> +	chop $fields[3];
> +	$time = $fields[3] * 1000000.0;
> +	splice @fields, 0, 5;
>   
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +	foreach my $f (@fields) {
> +		my @kv = split '=|,', $f;
>   
> -		next if exists $reqwait{$key};
> +		$kv[0] = 'global' if $kv[0] eq 'global_seqno';
>   
> -		$rw{'key'} = $key;
> -		$rw{'ring'} = $ring;
> -		$rw{'seqno'} = $seqno;
> -		$rw{'ctx'} = $ctx;
> -		$rw{'start'} = us($s, $us);
> -		$reqwait{$key} = \%rw;
> -		next;
> +		$tp{$kv[0]} = $kv[1];
>   	}
>   
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_wait_end');
> -	if (defined $s) {
> -		next if exists $ignore_ring{$ring};
> +	return undef if exists $tp{'ring'} and exists $ignore_ring{$tp{'ring'}};
> +
> +	if ($tp_name eq 'i915_gem_request_wait_begin') {
> +		my %rw;
>   
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
> -		next unless exists $reqwait{$key};
> +		next if exists $reqwait{$key};
>   
> -		$reqwait{$key}->{'end'} = us($s, $us);
> +		$rw{'key'} = $key;
> +		$rw{'ring'} = $tp{'ring'};
> +		$rw{'seqno'} = $tp{'seqno'};
> +		$rw{'ctx'} = $tp{'ctx'};
> +		$rw{'start'} = $time;
> +		$reqwait{$key} = \%rw;
>   		next;
> -	}
> +	} elsif ($tp_name eq 'i915_gem_request_wait_end') {
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_add');
> -	if (defined $s) {
> -		my $orig_ctx = $ctx;
> +		next unless exists $reqwait{$key};
>   
> -		next if exists $ignore_ring{$ring};
> +		$reqwait{$key}->{'end'} = $time;
> +		next;
> +	} elsif ($tp_name eq 'i915_gem_request_add') {
> +		my $orig_ctx = $tp{'ctx'};
>   
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		if (exists $queue{$key}) {
>   			$ctxdb{$orig_ctx}++;
> -			$ctx = sanitize_ctx($orig_ctx, $ring);
> -			$key = db_key($ring, $ctx, $seqno);
> +			$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +			$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   		}
>   
> -		$queue{$key} = us($s, $us);
> +		$queue{$key} = $time;
>   		next;
> -	}
> -
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_submit');
> -	if (defined $s) {
> -		next if exists $ignore_ring{$ring};
> -
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +	} elsif ($tp_name eq 'i915_gem_request_submit') {
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		die if exists $submit{$key};
>   		die unless exists $queue{$key};
>   
> -		$submit{$key} = us($s, $us);
> +		$submit{$key} = $time;
>   		next;
> -	}
> -
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno, $port) = parse_req_hw($_, 'i915:i915_gem_request_in');
> -	if (defined $s) {
> +	} elsif ($tp_name eq 'i915_gem_request_in') {
>   		my %req;
>   
> -		next if exists $ignore_ring{$ring};
> -
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		die if exists $db{$key};
>   		if (not exists $queue{$key} and $oldkernelwa) {
> @@ -514,30 +447,25 @@ while (<>) {
>   		die unless exists $queue{$key};
>   		die unless exists $submit{$key};
>   
> -		$req{'start'} = us($s, $us);
> -		$req{'ring'} = $ring;
> -		$req{'seqno'} = $seqno;
> -		$req{'ctx'} = $ctx;
> -		$req{'name'} = $ctx . '/' . $seqno;
> -		$req{'global'} = $global_seqno;
> -		$req{'port'} = $port;
> +		$req{'start'} = $time;
> +		$req{'ring'} = $tp{'ring'};
> +		$req{'seqno'} = $tp{'seqno'};
> +		$req{'ctx'} = $tp{'ctx'};
> +		$req{'name'} = $tp{'ctx'} . '/' . $tp{'seqno'};
> +		$req{'global'} = $tp{'global'};
> +		$req{'port'} = $tp{'port'};
>   		$req{'queue'} = $queue{$key};
>   		$req{'submit-delay'} = $submit{$key} - $queue{$key};
>   		$req{'execute-delay'} = $req{'start'} - $submit{$key};
> -		$rings{$ring} = $gid++ unless exists $rings{$ring};
> -		$ringmap{$rings{$ring}} = $ring;
> +		$rings{$tp{'ring'}} = $gid++ unless exists $rings{$tp{'ring'}};
> +		$ringmap{$rings{$tp{'ring'}}} = $tp{'ring'};
>   		$db{$key} = \%req;
>   		next;
> -	}
> -
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno, $port) = parse_req($_, 'i915:i915_gem_request_out');
> -	if (defined $s) {
> -		my $gkey = global_key($ring, $global_seqno);
> +	} elsif ($tp_name eq 'i915_gem_request_out') {
> +		my $gkey = global_key($tp{'ring'}, $tp{'global'});
>   
> -		next if exists $ignore_ring{$ring};
> -
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		if (not exists $db{$key} and $oldkernelwa) {
>   			$no_in++;
> @@ -547,7 +475,7 @@ while (<>) {
>   		die unless exists $db{$key}->{'start'};
>   		die if exists $db{$key}->{'end'};
>   
> -		$db{$key}->{'end'} = us($s, $us);
> +		$db{$key}->{'end'} = $time;
>   		if (exists $notify{$gkey}) {
>   			$db{$key}->{'notify'} = $notify{$gkey};
>   		} else {
> @@ -559,22 +487,13 @@ while (<>) {
>   		$db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
>   		$db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
>   		next;
> -	}
> -
> -	($s, $us, $ring, $seqno) = parse_notify($_);
> -	if (defined $s) {
> -		next if exists $ignore_ring{$ring};
> -		$notify{global_key($ring, $seqno)} = us($s, $us);
> +	} elsif ($tp_name eq 'intel_engine_notify') {
> +		$notify{global_key($tp{'ring'}, $tp{'seqno'})} = $time;
>   		next;
> -	}
> -
> -	($s, $us, $freq) = parse_freq($_);
> -	if (defined $s) {
> -		my $cur = us($s, $us);
> -
> -		push @freqs, [$prev_freq_ts, $cur, $prev_freq] if $prev_freq;
> -		$prev_freq_ts = $cur;
> -		$prev_freq = $freq;
> +	} elsif ($tp_name eq 'intel_gpu_freq_change') {
> +		push @freqs, [$prev_freq_ts, $time, $prev_freq] if $prev_freq;
> +		$prev_freq_ts = $time;
> +		$prev_freq = $tp{'new_freq'};
>   		next;
>   	}
>   }


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

Re: [PATCH i-g-t] scripts/trace.pl: Auto-detect tracepoint field order

[John Harrison]

On 12/18/2017 4:02 AM, Tvrtko Ursulin wrote:
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>
> Instead of hard-coding the order of key-value pairs into regular
> expressions, auto-detect them as we go.
>
> At the same time re-factor the code so it is smaller and even
> slightly faster (10-15% by a quick measurement).
>
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> Cc: Lionel Landwerlin <lionel.g.landwerlin@intel.com>
> Cc: John Harrison <John.C.Harrison@intel.com>
> ---
>   scripts/trace.pl | 223 ++++++++++++++++++-------------------------------------
>   1 file changed, 71 insertions(+), 152 deletions(-)
>
> diff --git a/scripts/trace.pl b/scripts/trace.pl
> index aed9b20d8407..9b3fb6486fec 100755
> --- a/scripts/trace.pl
> +++ b/scripts/trace.pl
> @@ -302,74 +302,6 @@ die if scalar(@args);
>   
>   @ARGV = @args;
>   
> -sub parse_req
> -{
> -	my ($line, $tp) = @_;
> -	state %cache;
> -
> -	$cache{$tp} = qr/(\d+)\.(\d+):.*$tp.*ring=(\d+), ctx=(\d+), seqno=(\d+), global(?:_seqno)?=(\d+)/ unless exists $cache{$tp};
> -
> -	if ($line =~ $cache{$tp}) {
> -		return ($1, $2, $3, $4, $5, $6);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_req_hw
> -{
> -	my ($line, $tp) = @_;
> -	state %cache;
> -
> -	$cache{$tp} = qr/(\d+)\.(\d+):.*$tp.*ring=(\d+), ctx=(\d+), seqno=(\d+), global(?:_seqno)?=(\d+), port=(\d+)/ unless exists $cache{$tp};
> -
> -	if ($line =~ $cache{$tp}) {
> -		return ($1, $2, $3, $4, $5, $6, $7);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_req_wait_begin
> -{
> -	my ($line, $tp) = @_;
> -
> -	if ($line =~ /(\d+)\.(\d+):.*i915_gem_request_wait_begin.*ring=(\d+), ctx=(\d+), seqno=(\d+)/) {
> -		return ($1, $2, $3, $4, $5);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_notify
> -{
> -	my ($line) = @_;
> -
> -	if ($line =~ /(\d+)\.(\d+):.*intel_engine_notify.*ring=(\d+), seqno=(\d+)/) {
> -		return ($1, $2, $3, $4);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub parse_freq
> -{
> -	my ($line) = @_;
> -
> -	if ($line =~ /(\d+)\.(\d+):.*intel_gpu_freq_change.*new_freq=(\d+)/) {
> -		return ($1, $2, $3);
> -	} else {
> -		return undef;
> -	}
> -}
> -
> -sub us
> -{
> -	my ($s, $us) = @_;
> -
> -	return $s * 1000000 + $us;
> -}
> -
>   sub db_key
>   {
>   	my ($ring, $ctx, $seqno) = @_;
> @@ -425,86 +357,87 @@ my $prev_freq_ts = 0;
>   my $oldkernelwa = 0;
>   my ($no_queue, $no_in);
>   while (<>) {
> -	my ($s, $us, $ring, $ctx, $seqno, $global_seqno, $port);
> -	my $freq;
> +	my @fields;
> +	my @tmp;
> +	my $tp_name;
> +	my $time;
> +	my %tp;
>   	my $key;
>   
>   	chomp;
> +	@fields = split ' ';
>   
> -	($s, $us, $ring, $ctx, $seqno) = parse_req_wait_begin($_);
> -	if (defined $s) {
> -		my %rw;
> +	$tp_name = $fields[4];
> +	@tmp = split ':', $tp_name, 2;
> +	next unless $tmp[0] eq 'i915';
> +	$tp_name = $tmp[1];
> +	chop $tp_name;
>   
> -		next if exists $ignore_ring{$ring};
> +	chop $fields[3];
> +	$time = $fields[3] * 1000000.0;
> +	splice @fields, 0, 5;
>   
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +	foreach my $f (@fields) {
> +		my @kv = split '=|,', $f;
>   
> -		next if exists $reqwait{$key};
> +		$kv[0] = 'global' if $kv[0] eq 'global_seqno';
>   
> -		$rw{'key'} = $key;
> -		$rw{'ring'} = $ring;
> -		$rw{'seqno'} = $seqno;
> -		$rw{'ctx'} = $ctx;
> -		$rw{'start'} = us($s, $us);
> -		$reqwait{$key} = \%rw;
> -		next;
> +		$tp{$kv[0]} = $kv[1];
>   	}
>   
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_wait_end');
> -	if (defined $s) {
> -		next if exists $ignore_ring{$ring};
> +	return undef if exists $tp{'ring'} and exists $ignore_ring{$tp{'ring'}};
Shouldn't this be 'next if exists...'? This is in a top level while loop 
not function call. Or alternatively, should this block of code be 
abstracted into a function call?


> +
> +	if ($tp_name eq 'i915_gem_request_wait_begin') {
> +		my %rw;
>   
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
> -		next unless exists $reqwait{$key};
> +		next if exists $reqwait{$key};
>   
> -		$reqwait{$key}->{'end'} = us($s, $us);
> +		$rw{'key'} = $key;
> +		$rw{'ring'} = $tp{'ring'};
> +		$rw{'seqno'} = $tp{'seqno'};
> +		$rw{'ctx'} = $tp{'ctx'};
> +		$rw{'start'} = $time;
> +		$reqwait{$key} = \%rw;
>   		next;
> -	}
> +	} elsif ($tp_name eq 'i915_gem_request_wait_end') {
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_add');
> -	if (defined $s) {
> -		my $orig_ctx = $ctx;
> +		next unless exists $reqwait{$key};
>   
> -		next if exists $ignore_ring{$ring};
> +		$reqwait{$key}->{'end'} = $time;
> +		next;
> +	} elsif ($tp_name eq 'i915_gem_request_add') {
> +		my $orig_ctx = $tp{'ctx'};
>   
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		if (exists $queue{$key}) {
>   			$ctxdb{$orig_ctx}++;
> -			$ctx = sanitize_ctx($orig_ctx, $ring);
> -			$key = db_key($ring, $ctx, $seqno);
> +			$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +			$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   		}
>   
> -		$queue{$key} = us($s, $us);
> +		$queue{$key} = $time;
>   		next;
> -	}
> -
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno) = parse_req($_, 'i915:i915_gem_request_submit');
> -	if (defined $s) {
> -		next if exists $ignore_ring{$ring};
> -
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +	} elsif ($tp_name eq 'i915_gem_request_submit') {
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		die if exists $submit{$key};
>   		die unless exists $queue{$key};
>   
> -		$submit{$key} = us($s, $us);
> +		$submit{$key} = $time;
>   		next;
> -	}
> -
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno, $port) = parse_req_hw($_, 'i915:i915_gem_request_in');
> -	if (defined $s) {
> +	} elsif ($tp_name eq 'i915_gem_request_in') {
>   		my %req;
>   
> -		next if exists $ignore_ring{$ring};
> -
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		die if exists $db{$key};
>   		if (not exists $queue{$key} and $oldkernelwa) {
> @@ -514,30 +447,25 @@ while (<>) {
>   		die unless exists $queue{$key};
>   		die unless exists $submit{$key};
>   
> -		$req{'start'} = us($s, $us);
> -		$req{'ring'} = $ring;
> -		$req{'seqno'} = $seqno;
> -		$req{'ctx'} = $ctx;
> -		$req{'name'} = $ctx . '/' . $seqno;
> -		$req{'global'} = $global_seqno;
> -		$req{'port'} = $port;
> +		$req{'start'} = $time;
> +		$req{'ring'} = $tp{'ring'};
> +		$req{'seqno'} = $tp{'seqno'};
> +		$req{'ctx'} = $tp{'ctx'};
> +		$req{'name'} = $tp{'ctx'} . '/' . $tp{'seqno'};
> +		$req{'global'} = $tp{'global'};
> +		$req{'port'} = $tp{'port'};
>   		$req{'queue'} = $queue{$key};
>   		$req{'submit-delay'} = $submit{$key} - $queue{$key};
>   		$req{'execute-delay'} = $req{'start'} - $submit{$key};
> -		$rings{$ring} = $gid++ unless exists $rings{$ring};
> -		$ringmap{$rings{$ring}} = $ring;
> +		$rings{$tp{'ring'}} = $gid++ unless exists $rings{$tp{'ring'}};
> +		$ringmap{$rings{$tp{'ring'}}} = $tp{'ring'};
>   		$db{$key} = \%req;
>   		next;
> -	}
> -
> -	($s, $us, $ring, $ctx, $seqno, $global_seqno, $port) = parse_req($_, 'i915:i915_gem_request_out');
> -	if (defined $s) {
> -		my $gkey = global_key($ring, $global_seqno);
> +	} elsif ($tp_name eq 'i915_gem_request_out') {
> +		my $gkey = global_key($tp{'ring'}, $tp{'global'});
>   
> -		next if exists $ignore_ring{$ring};
> -
> -		$ctx = sanitize_ctx($ctx, $ring);
> -		$key = db_key($ring, $ctx, $seqno);
> +		$tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
> +		$key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
>   
>   		if (not exists $db{$key} and $oldkernelwa) {
>   			$no_in++;
> @@ -547,7 +475,7 @@ while (<>) {
>   		die unless exists $db{$key}->{'start'};
>   		die if exists $db{$key}->{'end'};
>   
> -		$db{$key}->{'end'} = us($s, $us);
> +		$db{$key}->{'end'} = $time;
>   		if (exists $notify{$gkey}) {
>   			$db{$key}->{'notify'} = $notify{$gkey};
>   		} else {
> @@ -559,22 +487,13 @@ while (<>) {
>   		$db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
>   		$db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
>   		next;
> -	}
> -
> -	($s, $us, $ring, $seqno) = parse_notify($_);
> -	if (defined $s) {
> -		next if exists $ignore_ring{$ring};
> -		$notify{global_key($ring, $seqno)} = us($s, $us);
> +	} elsif ($tp_name eq 'intel_engine_notify') {
> +		$notify{global_key($tp{'ring'}, $tp{'seqno'})} = $time;
>   		next;
> -	}
> -
> -	($s, $us, $freq) = parse_freq($_);
> -	if (defined $s) {
> -		my $cur = us($s, $us);
> -
> -		push @freqs, [$prev_freq_ts, $cur, $prev_freq] if $prev_freq;
> -		$prev_freq_ts = $cur;
> -		$prev_freq = $freq;
> +	} elsif ($tp_name eq 'intel_gpu_freq_change') {
> +		push @freqs, [$prev_freq_ts, $time, $prev_freq] if $prev_freq;
> +		$prev_freq_ts = $time;
> +		$prev_freq = $tp{'new_freq'};
>   		next;
>   	}
>   }

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