<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=utf-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    This one works for me. Loads faster but identical output to the
    original version.<br>
    <br>
    Reviewed-by:  John Harrison <a class="moz-txt-link-rfc2396E"
      href="mailto:John.C.Harrison@Intel.com"><John.C.Harrison@Intel.com></a><br>
    <br>
    <br>
    On 12/22/2017 1:16 AM, Tvrtko Ursulin wrote:<br>
    <blockquote type="cite"
      cite="mid:20171222091618.17123-1-tvrtko.ursulin@linux.intel.com">
      <pre wrap="">From: Tvrtko Ursulin <a class="moz-txt-link-rfc2396E" href="mailto:tvrtko.ursulin@intel.com"><tvrtko.ursulin@intel.com></a>

A couple of small optimizations which altogether bring around 30%
improvement in my testing.

1. Do less string processing on tracepoints names and push more of the
   check into the if-ladder.

2. Pull out common db key and ctx processing and cache common values in
   local vars.

3. Key value pair parsing is faster with a regexp.

4. Avoid sorting the db hash multiple times if possible.

v2:
 * Use faster key-value splitting method. (John Harrison)

v3:
 * Fix floating-point to int time conversion.

v4:
 * Fix refactoring and logic fails. (John Harrison)

Signed-off-by: Tvrtko Ursulin <a class="moz-txt-link-rfc2396E" href="mailto:tvrtko.ursulin@intel.com"><tvrtko.ursulin@intel.com></a>
Cc: John Harrison <a class="moz-txt-link-rfc2396E" href="mailto:John.C.Harrison@intel.com"><John.C.Harrison@intel.com></a>
---
 scripts/trace.pl | 117 +++++++++++++++++++++++++------------------------------
 1 file changed, 52 insertions(+), 65 deletions(-)

diff --git a/scripts/trace.pl b/scripts/trace.pl
index ade0a9154bd7..cb93900dd620 100755
--- a/scripts/trace.pl
+++ b/scripts/trace.pl
@@ -356,110 +356,94 @@ my $prev_freq = 0;
 my $prev_freq_ts = 0;
 while (<>) {
        my @fields;
-       my @tmp;
        my $tp_name;
-       my $time;
        my %tp;
-       my $key;
+       my ($time, $ctx, $ring, $seqno, $orig_ctx, $key);
 
        chomp;
        @fields = split ' ';
 
+       chop $fields[3];
+       $time = int($fields[3] * 1000000.0 + 0.5);
+
        $tp_name = $fields[4];
-       @tmp = split ':', $tp_name, 2;
-       next unless $tmp[0] eq 'i915';
-       $tp_name = $tmp[1];
-       chop $tp_name;
 
-       chop $fields[3];
-       $time = $fields[3] * 1000000.0;
        splice @fields, 0, 5;
 
        foreach my $f (@fields) {
-               my @kv = split '=|,', $f;
+               my ($k, $v);
 
-               $kv[0] = 'global' if $kv[0] eq 'global_seqno';
-
-               $tp{$kv[0]} = $kv[1];
+               next unless $f =~ m/=/;
+               ($k, $v) = ($`, $');
+               $k = 'global' if $k eq 'global_seqno';
+               chop $v if substr($v, -1, 1) eq ',';
+               $tp{$k} = $v;
        }
 
        next if exists $tp{'ring'} and exists $ignore_ring{$tp{'ring'}};
 
-       if ($tp_name eq 'i915_gem_request_wait_begin') {
-               my %rw;
+       if (exists $tp{'ring'} and exists $tp{'seqno'}) {
+               $ring = $tp{'ring'};
+               $seqno = $tp{'seqno'};
 
-               $tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
-               $key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
+               if (exists $tp{'ctx'}) {
+                       $ctx = $tp{'ctx'};
+                       $orig_ctx = $ctx;
+                       $ctx = sanitize_ctx($ctx, $ring);
+                       $key = db_key($ring, $ctx, $seqno);
+               }
+       }
+
+       if ($tp_name eq 'i915:i915_gem_request_wait_begin:') {
+               my %rw;
 
                next if exists $reqwait{$key};
 
                $rw{'key'} = $key;
-               $rw{'ring'} = $tp{'ring'};
-               $rw{'seqno'} = $tp{'seqno'};
-               $rw{'ctx'} = $tp{'ctx'};
+               $rw{'ring'} = $ring;
+               $rw{'seqno'} = $seqno;
+               $rw{'ctx'} = $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'});
-
+       } elsif ($tp_name eq 'i915:i915_gem_request_wait_end:') {
                next unless exists $reqwait{$key};
 
                $reqwait{$key}->{'end'} = $time;
-               next;
-       } elsif ($tp_name eq 'i915_gem_request_add') {
-               my $orig_ctx = $tp{'ctx'};
-
-               $tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
-               $key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
-
+       } elsif ($tp_name eq 'i915:i915_gem_request_add:') {
                if (exists $queue{$key}) {
                        $ctxdb{$orig_ctx}++;
-                       $tp{'ctx'} = sanitize_ctx($orig_ctx, $tp{'ring'});
-                       $key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
+                       $ctx = sanitize_ctx($orig_ctx, $ring);
+                       $key = db_key($ring, $ctx, $seqno);
                }
 
                $queue{$key} = $time;
-               next;
-       } 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'});
-
+       } elsif ($tp_name eq 'i915:i915_gem_request_submit:') {
                die if exists $submit{$key};
                die unless exists $queue{$key};
 
                $submit{$key} = $time;
-               next;
-       } elsif ($tp_name eq 'i915_gem_request_in') {
+       } elsif ($tp_name eq 'i915:i915_gem_request_in:') {
                my %req;
 
-               $tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
-               $key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
-
                die if exists $db{$key};
                die unless exists $queue{$key};
                die unless exists $submit{$key};
 
                $req{'start'} = $time;
-               $req{'ring'} = $tp{'ring'};
-               $req{'seqno'} = $tp{'seqno'};
-               $req{'ctx'} = $tp{'ctx'};
-               $req{'name'} = $tp{'ctx'} . '/' . $tp{'seqno'};
+               $req{'ring'} = $ring;
+               $req{'seqno'} = $seqno;
+               $req{'ctx'} = $ctx;
+               $req{'name'} = $ctx . '/' . $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{$tp{'ring'}} = $gid++ unless exists $rings{$tp{'ring'}};
-               $ringmap{$rings{$tp{'ring'}}} = $tp{'ring'};
+               $rings{$ring} = $gid++ unless exists $rings{$ring};
+               $ringmap{$rings{$ring}} = $ring;
                $db{$key} = \%req;
-               next;
-       } elsif ($tp_name eq 'i915_gem_request_out') {
-               my $gkey = global_key($tp{'ring'}, $tp{'global'});
-
-               $tp{'ctx'} = sanitize_ctx($tp{'ctx'}, $tp{'ring'});
-               $key = db_key($tp{'ring'}, $tp{'ctx'}, $tp{'seqno'});
+       } elsif ($tp_name eq 'i915:i915_gem_request_out:') {
+               my $gkey = global_key($ring, $tp{'global'});
 
                die unless exists $db{$key};
                die unless exists $db{$key}->{'start'};
@@ -476,15 +460,12 @@ while (<>) {
                }
                $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'};
                $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'};
-               next;
-       } elsif ($tp_name eq 'intel_engine_notify') {
-               $notify{global_key($tp{'ring'}, $tp{'seqno'})} = $time;
-               next;
-       } elsif ($tp_name eq 'intel_gpu_freq_change') {
+       } elsif ($tp_name eq 'i915:intel_engine_notify:') {
+               $notify{global_key($ring, $seqno)} = $time;
+       } elsif ($tp_name eq 'i915: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;
        }
 }
 
@@ -557,7 +538,10 @@ my (%submit_avg, %execute_avg, %ctxsave_avg);
 my $last_ts = 0;
 my $first_ts;
 
-foreach my $key (sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db) {
+my @sorted_keys = sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db;
+my $re_sort = 0;
+
+foreach my $key (@sorted_keys) {
        my $ring = $db{$key}->{'ring'};
        my $end = $db{$key}->{'end'};
 
@@ -585,6 +569,7 @@ foreach my $key (sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db) {
 
                # 20us tolerance
                if (exists $db{$next_key} and $db{$next_key}->{'start'} < $start + 20) {
+                       $re_sort = 1;
                        $db{$next_key}->{'start'} = $start + $db{$key}->{'duration'};
                        $db{$next_key}->{'start'} = $db{$next_key}->{'end'} if $db{$next_key}->{'start'} > $db{$next_key}->{'end'};
                        $db{$next_key}->{'duration'} = $db{$next_key}->{'notify'} - $db{$next_key}->{'start'};
@@ -601,6 +586,8 @@ foreach my $key (sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db) {
        $ctxsave_avg{$ring} += $db{$key}->{'end'} - $db{$key}->{'notify'};
 }
 
+@sorted_keys = sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db if $re_sort;
+
 foreach my $ring (keys %batch_avg) {
        $batch_avg{$ring} /= $batch_count{$ring};
        $batch_total_avg{$ring} /= $batch_count{$ring};
@@ -616,7 +603,7 @@ foreach my $gid (sort keys %rings) {
        my (@s_, @e_);
 
        # Extract all GPU busy intervals and sort them.
-       foreach my $key (sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db) {
+       foreach my $key (@sorted_keys) {
                next unless $db{$key}->{'ring'} == $ring;
                push @s_, $db{$key}->{'start'};
                push @e_, $db{$key}->{'end'};
@@ -660,7 +647,7 @@ my @gpu_intervals;
 my (@s_, @e_);
 
 # Extract all GPU busy intervals and sort them.
-foreach my $key (sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db) {
+foreach my $key (@sorted_keys) {
        push @s_, $db{$key}->{'start'};
        push @e_, $db{$key}->{'end'};
        die if $db{$key}->{'start'} > $db{$key}->{'end'};
</pre>
    </blockquote>
    <br>
  </body>
</html>