trace.pl fixes
v2 cover trace.pl fixes
From: Tvrtko Ursulin <[email protected]>
Collection of fixes on top of John's recent work.
Problems were mostly in the request split logic which had several issues both in my original version, and also after John's improvements.
Handling of "incomplete" requests (the ones which received neither notify nor context complete) was also a bit incorrect.
After this series it seems to work fine, famous last words. Anyway with my test data it correctly draws the timeline with no overalaps considering both merged requests and submission to port 1.
I also added context colouring mode so it is easier to follow the timeline and started using hw_id for context id's for additional readability.
v2:
* Update for tracepoint renames. (new in series)
* Remove hw_id change. (droppped from series)
* Fix incomplete handling in split mode (-s).
This did not work well for workloads which generate very few intel_engine_notify events. I am not that confident it is 100% correct now, but at least it doesn't crash the script and output for one other workload I had lying around looks correct.
I guess the moral of the story here is split mode is not easy to get right if it is considered just a side project and more time needs to be set aside to triple-check it.
John Harrison (4):
scripts/trace.pl: More hash key optimisations scripts/trace.pl: Sort order
scripts/trace.pl: Calculate stats only after all munging scripts/trace.pl: Simplify 'end' & 'notify' generation
Tvrtko Ursulin (7):
trace.pl: Catch-up with tracepoint renames trace.pl: Move sortQueue near its user trace.pl: Move min/max timestamp lookup to last loop trace.pl: Fix engine busy accounting in split mode trace.pl: Add support for colouring context execution trace.pl: Fix incomplete request handling trace.pl: Fix request split mode
scripts/trace.pl | 372 +++++++++++++++++++++++++++++++++++++++++-------------- 1 file changed, 278 insertions(+), 94 deletions(-)
Signature · 6 lines
2.14.1 _______________________________________________ Intel-gfx mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/intel-gfx
PATCH v2 1/11 trace.pl: Catch-up with tracepoint renames
From: Tvrtko Ursulin <[email protected]>
i915 renamed the request related tracepoints so catch up with that.
--- scripts/trace.pl | 36 ++++++++++++++++++------------------ 1 file changed, 18 insertions(+), 18 deletions(-)
scripts/trace.pl +18 -18
@@ -62,13 +62,13 @@ Notes: The above will invoke perf record, or alternatively it can be done directly: perf record -a -c 1 -e i915:intel_gpu_freq_change, \ - i915:i915_gem_request_add, \ - i915:i915_gem_request_submit, \ - i915:i915_gem_request_in, \ - i915:i915_gem_request_out, \ + i915:i915_request_add, \ + i915:i915_request_submit, \ + i915:i915_request_in, \ + i915:i915_request_out, \ i915:intel_engine_notify, \ - i915:i915_gem_request_wait_begin, \ - i915:i915_gem_request_wait_end \ + i915:i915_request_wait_begin, \ + i915:i915_request_wait_end \ [command-to-be-profiled] Then create the log file with:
@@ -169,13 +169,13 @@ sub arg_gpu_timeline sub arg_trace { my @events = ( 'i915:intel_gpu_freq_change', - 'i915:i915_gem_request_add', - 'i915:i915_gem_request_submit', - 'i915:i915_gem_request_in', - 'i915:i915_gem_request_out', + 'i915:i915_request_add', + 'i915:i915_request_submit', + 'i915:i915_request_in', + 'i915:i915_request_out', 'i915:intel_engine_notify', - 'i915:i915_gem_request_wait_begin', - 'i915:i915_gem_request_wait_end' ); + 'i915:i915_request_wait_begin', + 'i915:i915_request_wait_end' ); return unless scalar(@_);
@@ -394,7 +394,7 @@ while (<>) { } } - if ($tp_name eq 'i915:i915_gem_request_wait_begin:') { + if ($tp_name eq 'i915:i915_request_wait_begin:') { my %rw; next if exists $reqwait{$key};
@@ -405,11 +405,11 @@ while (<>) { $rw{'ctx'} = $ctx; $rw{'start'} = $time; $reqwait{$key} = \%rw; - } elsif ($tp_name eq 'i915:i915_gem_request_wait_end:') { + } elsif ($tp_name eq 'i915:i915_request_wait_end:') { next unless exists $reqwait{$key}; $reqwait{$key}->{'end'} = $time; - } elsif ($tp_name eq 'i915:i915_gem_request_add:') { + } elsif ($tp_name eq 'i915:i915_request_add:') { if (exists $queue{$key}) { $ctxdb{$orig_ctx}++; $ctx = sanitize_ctx($orig_ctx, $ring);
@@ -417,12 +417,12 @@ while (<>) { } $queue{$key} = $time; - } elsif ($tp_name eq 'i915:i915_gem_request_submit:') { + } elsif ($tp_name eq 'i915:i915_request_submit:') { die if exists $submit{$key}; die unless exists $queue{$key}; $submit{$key} = $time; - } elsif ($tp_name eq 'i915:i915_gem_request_in:') { + } elsif ($tp_name eq 'i915:i915_request_in:') { my %req; die if exists $db{$key};
@@ -442,7 +442,7 @@ while (<>) { $rings{$ring} = $gid++ unless exists $rings{$ring}; $ringmap{$rings{$ring}} = $ring; $db{$key} = \%req; - } elsif ($tp_name eq 'i915:i915_gem_request_out:') { + } elsif ($tp_name eq 'i915:i915_request_out:') { my $gkey = global_key($ring, $tp{'global'}); die unless exists $db{$key};
Signature · 6 lines
2.14.1 _______________________________________________ Intel-gfx mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/intel-gfx
PATCH v2 2/11 scripts/trace.pl: More hash key optimisations
In reply to Tvrtko UrsulinFrom: John Harrison <[email protected]>
Cache the key count value rather than querying the hash every time. Also assert that the database does not magically change size after the fixups.
v2: Rename variable according to style guide [Tvrtko]
v3: Reverted accidental style change and added a blank line. [Tvrtko]
--- scripts/trace.pl | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-)
scripts/trace.pl +5 -2
@@ -508,6 +508,7 @@ foreach my $key (keys %db) { } # Fix up incompletes +my $key_count = scalar(keys %db); foreach my $key (keys %db) { next unless exists $db{$key}->{'incomplete'};
@@ -522,7 +523,7 @@ foreach my $key (keys %db) { $next_key = db_key($ring, $ctx, $seqno + $i); $i++; } until ((exists $db{$next_key} and not exists $db{$next_key}->{'incomplete'}) - or $i > scalar(keys(%db))); # ugly stop hack + or $i > $key_count); # ugly stop hack if (exists $db{$next_key}) { $db{$key}->{'notify'} = $db{$next_key}->{'end'};
@@ -541,6 +542,8 @@ my $first_ts; my @sorted_keys = sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db; my $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'};
@@ -565,7 +568,7 @@ foreach my $key (@sorted_keys) { do { $next_key = db_key($ring, $ctx, $seqno + $i); $i++; - } until (exists $db{$next_key} or $i > scalar(keys(%db))); # ugly stop hack + } 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) {
Signature · 6 lines
2.14.1 _______________________________________________ igt-dev mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/igt-dev
PATCH v2 3/11 scripts/trace.pl: Sort order
In reply to Tvrtko UrsulinFrom: John Harrison <[email protected]>
Add an extra level to the databse key sort so that the ordering is deterministic. If the time stamp matches, it now compares the key itself as well (context/seqno). This makes it much easier to determine if a change has actually broken anything. Previously back to back runs with no changes could still produce different output, especially when adding extra debug output during the calculations.
As the comparison test is now more than a single equation, moved it out into a separate sort function.
v2: Re-work sort func for readability/performance [Tvrtko]
--- scripts/trace.pl | 30 ++++++++++++++++++++++++++---- 1 file changed, 26 insertions(+), 4 deletions(-)
scripts/trace.pl +26 -4
@@ -539,7 +539,29 @@ my (%submit_avg, %execute_avg, %ctxsave_avg); my $last_ts = 0; my $first_ts; -my @sorted_keys = sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db; +sub sortStart { + my $as = $db{$a}->{'start'}; + my $bs = $db{$b}->{'start'}; + my $val; + + $val = $as <=> $bs; + $val = $a cmp $b if $val == 0; + + return $val; +} + +sub sortQueue { + my $as = $db{$a}->{'queue'}; + my $bs = $db{$b}->{'queue'}; + my $val; + + $val = $as <=> $bs; + $val = $a cmp $b if $val == 0; + + return $val; +} + +my @sorted_keys = sort sortStart keys %db; my $re_sort = 0; die "Database changed size?!" unless scalar(@sorted_keys) == $key_count;
@@ -589,9 +611,9 @@ foreach my $key (@sorted_keys) { $ctxsave_avg{$ring} += $db{$key}->{'end'} - $db{$key}->{'notify'}; } -@sorted_keys = sort {$db{$a}->{'start'} <=> $db{$b}->{'start'}} keys %db if $re_sort; +@sorted_keys = sort sortStart keys %db if $re_sort; -foreach my $ring (keys %batch_avg) { +foreach my $ring (sort keys %batch_avg) { $batch_avg{$ring} /= $batch_count{$ring}; $batch_total_avg{$ring} /= $batch_count{$ring}; $submit_avg{$ring} /= $batch_count{$ring};
@@ -831,7 +853,7 @@ print <<ENDHTML; ENDHTML my $i = 0; -foreach my $key (sort {$db{$a}->{'queue'} <=> $db{$b}->{'queue'}} keys %db) { +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 $submit = $queue + $db{$key}->{'submit-delay'};
Signature · 6 lines
2.14.1 _______________________________________________ igt-dev mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/igt-dev
PATCH v2 4/11 scripts/trace.pl: Calculate stats only after all munging
In reply to Tvrtko UrsulinFrom: John Harrison <[email protected]>
There are various statistics being calculated multiple times in multiple places while the log file is being read in. Some of these are then re-calculated when the database is munged to correct various issues with the logs. This patch consolidates the calculations into a separate pass after all the reading and munging has been done.
Note that this actually produces a different final output as the 'execute-delay' values were not previously being re-calculated after all the fixups. Thus were based on an incorrect calculation.
v2: Reduce scope of some local variables [Tvrtko]
--- scripts/trace.pl | 54 ++++++++++++++++++++++++++++-------------------------- 1 file changed, 28 insertions(+), 26 deletions(-)
scripts/trace.pl +28 -26
@@ -437,8 +437,7 @@ while (<>) { $req{'global'} = $tp{'global'}; $req{'port'} = $tp{'port'}; $req{'queue'} = $queue{$key}; - $req{'submit-delay'} = $submit{$key} - $queue{$key}; - $req{'execute-delay'} = $req{'start'} - $submit{$key}; + $req{'submit'} = $submit{$key}; $rings{$ring} = $gid++ unless exists $rings{$ring}; $ringmap{$rings{$ring}} = $ring; $db{$key} = \%req;
@@ -458,8 +457,6 @@ while (<>) { $db{$key}->{'notify'} = $db{$key}->{'end'}; $db{$key}->{'no-notify'} = 1; } - $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'}; - $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'}; } elsif ($tp_name eq 'i915:intel_engine_notify:') { $notify{global_key($ring, $seqno)} = $time; } elsif ($tp_name eq 'i915:intel_gpu_freq_change:') {
@@ -493,16 +490,11 @@ foreach my $key (keys %db) { $db{$key}->{'notify'} = $db{$key}->{'end'}; $db{$key}->{'incomplete'} = 1; } - - $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'}; - $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'}; } else { # Notify arrived after context complete. if (exists $db{$key}->{'no-notify'} and exists $notify{$gkey}) { delete $db{$key}->{'no-notify'}; $db{$key}->{'notify'} = $notify{$gkey}; - $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'}; - $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'}; } } }
@@ -528,8 +520,6 @@ foreach my $key (keys %db) { if (exists $db{$next_key}) { $db{$key}->{'notify'} = $db{$next_key}->{'end'}; $db{$key}->{'end'} = $db{$key}->{'notify'}; - $db{$key}->{'duration'} = $db{$key}->{'notify'} - $db{$key}->{'start'}; - $db{$key}->{'context-complete-delay'} = $db{$key}->{'end'} - $db{$key}->{'notify'}; } }
@@ -573,17 +563,11 @@ foreach my $key (@sorted_keys) { $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; $last_ts = $end if $end > $last_ts; - $running{$ring} += $end - $db{$key}->{'start'} unless exists $db{$key}->{'no-end'}; - $runnable{$ring} += $db{$key}->{'execute-delay'}; - $queued{$ring} += $db{$key}->{'start'} - $db{$key}->{'execute-delay'} - $db{$key}->{'queue'}; - - $batch_count{$ring}++; - # correct duration of merged batches if ($correct_durations and exists $db{$key}->{'no-end'}) { - my $start = $db{$key}->{'start'}; my $ctx = $db{$key}->{'ctx'}; my $seqno = $db{$key}->{'seqno'}; + my $start = $db{$key}->{'start'}; my $next_key; my $i = 1;
@@ -594,25 +578,43 @@ foreach my $key (@sorted_keys) { # 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'} = $start + $db{$key}->{'duration'}; + $db{$next_key}->{'start'} = $notify; $db{$next_key}->{'start'} = $db{$next_key}->{'end'} if $db{$next_key}->{'start'} > $db{$next_key}->{'end'}; - $db{$next_key}->{'duration'} = $db{$next_key}->{'notify'} - $db{$next_key}->{'start'}; - $end = $db{$key}->{'notify'}; die if $db{$next_key}->{'start'} > $db{$next_key}->{'end'}; } - die if $db{$key}->{'start'} > $db{$key}->{'end'}; + die if $start > $end; } +} + +@sorted_keys = sort sortStart keys %db if $re_sort; + +foreach my $key (@sorted_keys) { + my $ring = $db{$key}->{'ring'}; + my $end = $db{$key}->{'end'}; + my $start = $db{$key}->{'start'}; + my $notify = $db{$key}->{'notify'}; + + $db{$key}->{'context-complete-delay'} = $end - $notify; + $db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'}; + $db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'}; + $db{$key}->{'duration'} = $notify - $start; + + $running{$ring} += $end - $start unless exists $db{$key}->{'no-end'}; + $runnable{$ring} += $db{$key}->{'execute-delay'}; + $queued{$ring} += $start - $db{$key}->{'execute-delay'} - $db{$key}->{'queue'}; + + $batch_count{$ring}++; + $batch_avg{$ring} += $db{$key}->{'duration'}; - $batch_total_avg{$ring} += $end - $db{$key}->{'start'}; + $batch_total_avg{$ring} += $end - $start; $submit_avg{$ring} += $db{$key}->{'submit-delay'}; $execute_avg{$ring} += $db{$key}->{'execute-delay'}; - $ctxsave_avg{$ring} += $db{$key}->{'end'} - $db{$key}->{'notify'}; + $ctxsave_avg{$ring} += $end - $notify; } -@sorted_keys = sort sortStart keys %db if $re_sort; - foreach my $ring (sort keys %batch_avg) { $batch_avg{$ring} /= $batch_count{$ring}; $batch_total_avg{$ring} /= $batch_count{$ring};
Signature · 6 lines
2.14.1 _______________________________________________ igt-dev mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/igt-dev
PATCH v2 5/11 scripts/trace.pl: Simplify 'end' & 'notify' generation
In reply to Tvrtko UrsulinFrom: John Harrison <[email protected]>
Delay the auto-generation of end/notify values until the point where everything is known. As opposed to potentially generating them multiple times with differing values (in the case of 'incomplete' entries).
v2: More complete description. [Tvrtko]
--- scripts/trace.pl | 31 ++++++++++++++++++------------- 1 file changed, 18 insertions(+), 13 deletions(-)
scripts/trace.pl +18 -13
@@ -467,10 +467,11 @@ while (<>) { } # Sanitation pass to fixup up out of order notify and context complete, and to -# fine the largest seqno to be used for timeline sorting purposes. +# find the largest seqno to be used for timeline sorting purposes. 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'};
@@ -478,23 +479,21 @@ foreach my $key (keys %db) { unless (exists $db{$key}->{'end'}) { # Context complete not received. - if (exists $notify{$gkey}) { + $db{$key}->{'no-end'} = 1; + + if (defined($notify)) { # No context complete due req merging - use notify. - $db{$key}->{'notify'} = $notify{$gkey}; - $db{$key}->{'end'} = $db{$key}->{'notify'}; - $db{$key}->{'no-end'} = 1; + $db{$key}->{'notify'} = $notify; + $db{$key}->{'end'} = $notify; } else { - # No notify and no context complete - mark it. - $db{$key}->{'no-end'} = 1; - $db{$key}->{'end'} = $db{$key}->{'start'} + 999; - $db{$key}->{'notify'} = $db{$key}->{'end'}; + # 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 exists $notify{$gkey}) { + if (exists $db{$key}->{'no-notify'} and defined($notify)) { delete $db{$key}->{'no-notify'}; - $db{$key}->{'notify'} = $notify{$gkey}; + $db{$key}->{'notify'} = $notify; } } }
@@ -510,6 +509,7 @@ foreach my $key (keys %db) { my $seqno = $db{$key}->{'seqno'}; my $next_key; my $i = 1; + my $end; do { $next_key = db_key($ring, $ctx, $seqno + $i);
@@ -518,9 +518,14 @@ foreach my $key (keys %db) { or $i > $key_count); # ugly stop hack if (exists $db{$next_key}) { - $db{$key}->{'notify'} = $db{$next_key}->{'end'}; - $db{$key}->{'end'} = $db{$key}->{'notify'}; + $end = $db{$next_key}->{'end'}; + } else { + # No info at all, fake it: + $end = $db{$key}->{'start'} + 999; } + + $db{$key}->{'notify'} = $end; + $db{$key}->{'end'} = $end; } # GPU time accounting
Signature · 6 lines
2.14.1 _______________________________________________ Intel-gfx mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/intel-gfx
PATCH v2 6/11 trace.pl: Move sortQueue near its user
In reply to Tvrtko UrsulinFrom: Tvrtko Ursulin <[email protected]>
Just to clear up some space for incoming code refactoring.
--- scripts/trace.pl | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-)
scripts/trace.pl +11 -11
@@ -545,17 +545,6 @@ sub sortStart { return $val; } -sub sortQueue { - my $as = $db{$a}->{'queue'}; - my $bs = $db{$b}->{'queue'}; - my $val; - - $val = $as <=> $bs; - $val = $a cmp $b if $val == 0; - - return $val; -} - my @sorted_keys = sort sortStart keys %db; my $re_sort = 0;
@@ -859,6 +848,17 @@ print <<ENDHTML; var items = new vis.DataSet([ ENDHTML +sub sortQueue { + my $as = $db{$a}->{'queue'}; + my $bs = $db{$b}->{'queue'}; + my $val; + + $val = $as <=> $bs; + $val = $a cmp $b if $val == 0; + + return $val; +} + my $i = 0; foreach my $key (sort sortQueue keys %db) { my ($name, $ctx, $seqno) = ($db{$key}->{'name'}, $db{$key}->{'ctx'}, $db{$key}->{'seqno'});
Signature · 6 lines
2.14.1 _______________________________________________ Intel-gfx mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/intel-gfx
Re: [Intel-gfx] [igt-dev] [PATCH i-g-t 06/11] trace.pl: Move sortQueue near its user
Quoted 40 lines · Tvrtko Ursulin
From: Tvrtko Ursulin <[email protected]>
Just to clear up some space for incoming code refactoring.
Signed-off-by Tvrtko Ursulin <[email protected]>Cc John Harrison <[email protected]>--- scripts/trace.pl | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-)scripts/trace.pl +4
-11@@ -545,17 +545,6 @@ sub sortStart { return $val; } -sub sortQueue { - my $as = $db{$a}->{'queue'}; - my $bs = $db{$b}->{'queue'}; - my $val; - - $val = $as <=> $bs; - $val = $a cmp $b if $val == 0; - - return $val; -} - my @sorted_keys = sort sortStart keys %db; my $re_sort = 0;@@ -859,6 +848,17 @@ print <<ENDHTML; var items = new vis.DataSet([ ENDHTML +sub sortQueue { + my $as = $db{$a}->{'queue'}; + my $bs = $db{$b}->{'queue'}; + my $val;
scripts/trace.pl print <<ENDHTML; · line 864
Quoted 10 lines
scripts/trace.pl +7
-0+ + $val = $as <=> $bs; + $val = $a cmp $b if $val == 0; + + return $val; +} + my $i = 0; foreach my $key (sort sortQueue keys %db) { my ($name, $ctx, $seqno) = ($db{$key}->{'name'}, $db{$key}->{'ctx'}, $db{$key}->{'seqno'});
_______________________________________________
Intel-gfx mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/intel-gfx
PATCH v2 7/11 trace.pl: Move min/max timestamp lookup to last loop
In reply to Tvrtko UrsulinFrom: Tvrtko Ursulin <[email protected]>
It makes sense to fetch the min and max timestamp only after the last sort of the array.
--- scripts/trace.pl | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-)
scripts/trace.pl +6 -5
@@ -531,8 +531,6 @@ foreach my $key (keys %db) { # 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; sub sortStart { my $as = $db{$a}->{'start'};
@@ -554,9 +552,6 @@ foreach my $key (@sorted_keys) { my $ring = $db{$key}->{'ring'}; my $end = $db{$key}->{'end'}; - $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; - $last_ts = $end if $end > $last_ts; - # correct duration of merged batches if ($correct_durations and exists $db{$key}->{'no-end'}) { my $ctx = $db{$key}->{'ctx'};
@@ -584,12 +579,18 @@ foreach my $key (@sorted_keys) { @sorted_keys = sort sortStart keys %db if $re_sort; +my $last_ts = 0; +my $first_ts; + foreach my $key (@sorted_keys) { my $ring = $db{$key}->{'ring'}; my $end = $db{$key}->{'end'}; my $start = $db{$key}->{'start'}; my $notify = $db{$key}->{'notify'}; + $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; + $last_ts = $end if $end > $last_ts; + $db{$key}->{'context-complete-delay'} = $end - $notify; $db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'}; $db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
Signature · 6 lines
2.14.1 _______________________________________________ igt-dev mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/igt-dev
Re: [igt-dev] [PATCH i-g-t 07/11] trace.pl: Move min/max timestamp lookup to last loop
Quoted 43 lines · Tvrtko Ursulin
From: Tvrtko Ursulin <[email protected]>
It makes sense to fetch the min and max timestamp only after the last sort of the array.
Signed-off-by Tvrtko Ursulin <[email protected]>Cc John Harrison <[email protected]>--- scripts/trace.pl | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-)scripts/trace.pl +3
-5@@ -531,8 +531,6 @@ foreach my $key (keys %db) { # 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; sub sortStart { my $as = $db{$a}->{'start'};@@ -554,9 +552,6 @@ foreach my $key (@sorted_keys) { my $ring = $db{$key}->{'ring'}; my $end = $db{$key}->{'end'}; - $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; - $last_ts = $end if $end > $last_ts; - # correct duration of merged batches if ($correct_durations and exists $db{$key}->{'no-end'}) { my $ctx = $db{$key}->{'ctx'};@@ -584,12 +579,18 @@ foreach my $key (@sorted_keys) { @sorted_keys = sort sortStart keys %db if $re_sort; +my $last_ts = 0; +my $first_ts; + foreach my $key (@sorted_keys) { my $ring = $db{$key}->{'ring'};
scripts/trace.pl foreach my $key (@sorted_keys) { · line 596
Quoted 10 lines
scripts/trace.pl +3
-0my $end = $db{$key}->{'end'}; my $start = $db{$key}->{'start'}; my $notify = $db{$key}->{'notify'}; + $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; + $last_ts = $end if $end > $last_ts; + $db{$key}->{'context-complete-delay'} = $end - $notify; $db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'}; $db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'};
_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev
PATCH v2 8/11 trace.pl: Fix engine busy accounting in split mode
In reply to Tvrtko UrsulinFrom: Tvrtko Ursulin <[email protected]>
In split mode all requests have to be added up since they were previously re-arranged so there is no overlap.
--- scripts/trace.pl | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-)
scripts/trace.pl +2 -1
@@ -596,7 +596,8 @@ foreach my $key (@sorted_keys) { $db{$key}->{'submit-delay'} = $db{$key}->{'submit'} - $db{$key}->{'queue'}; $db{$key}->{'duration'} = $notify - $start; - $running{$ring} += $end - $start unless exists $db{$key}->{'no-end'}; + $running{$ring} += $end - $start if $correct_durations or + not exists $db{$key}->{'no-end'}; $runnable{$ring} += $db{$key}->{'execute-delay'}; $queued{$ring} += $start - $db{$key}->{'execute-delay'} - $db{$key}->{'queue'};
Signature · 6 lines
2.14.1 _______________________________________________ igt-dev mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/igt-dev
PATCH v2 9/11 trace.pl: Add support for colouring context execution
In reply to Tvrtko UrsulinFrom: Tvrtko Ursulin <[email protected]>
Add the command line switch which uses different colours for different context execution boxes.
--- scripts/trace.pl | 41 +++++++++++++++++++++++++++++++++++++++-- 1 file changed, 39 insertions(+), 2 deletions(-)
scripts/trace.pl +39 -2
@@ -40,6 +40,7 @@ my $trace = 0; my $avg_delay_stats = 0; my $squash_context_id = 0; my $gpu_timeline = 0; +my $colour_contexts = 0; my @args;
@@ -110,6 +111,8 @@ Usage: --squash-ctx-id Squash context id by substracting engine id from ctx id. --gpu-timeline Draw overall GPU busy timeline. + --colour-contexts / -c Use different colours for different + context execution boxes. ENDHELP exit 0;
@@ -279,6 +282,20 @@ sub arg_skip_box return @_; } +sub arg_colour_contexts +{ + return unless scalar(@_); + + if ($_[0] eq '--colour-contexts' or + $_[0] eq '--color-contexts' or + $_[0] eq '-c') { + shift @_; + $colour_contexts = 1; + } + + return @_; +} + @args = @ARGV; while (@args) { my $left = scalar(@args);
@@ -294,6 +311,7 @@ while (@args) { @args = arg_split_requests(@args); @args = arg_ignore_ring(@args); @args = arg_skip_box(@args); + @args = arg_colour_contexts(@args); last if $left == scalar(@args); }
@@ -581,6 +599,7 @@ foreach my $key (@sorted_keys) { my $last_ts = 0; my $first_ts; +my $min_ctx; foreach my $key (@sorted_keys) { my $ring = $db{$key}->{'ring'};
@@ -590,6 +609,8 @@ foreach my $key (@sorted_keys) { $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; $last_ts = $end if $end > $last_ts; + $min_ctx = $db{$key}->{'ctx'} if not defined $min_ctx or + $db{$key}->{'ctx'} < $min_ctx; $db{$key}->{'context-complete-delay'} = $end - $notify; $db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};
@@ -721,6 +742,8 @@ foreach my $key (keys %reqwait) { say sprintf('GPU: %.2f%% idle, %.2f%% busy', $flat_busy{'gpu-idle'}, $flat_busy{'gpu-busy'}) unless $html; +my $execute_colour = $colour_contexts ? 'multi-colour' : 'pink'; + print <<ENDHTML if $html; <!DOCTYPE HTML> <html>
@@ -741,7 +764,7 @@ print <<ENDHTML if $html; <button onclick="toggleStackSubgroups()">Toggle stacking</button> <p> -pink = requests executing on the GPU<br> +$execute_colour = requests executing on the GPU<br> grey = runnable requests waiting for a slot on GPU<br> blue = requests waiting on fences and dependencies before they are runnable<br> </p>
@@ -861,6 +884,19 @@ sub sortQueue { return $val; } +my @html_colours = ( 'Pink', 'Green', 'Purple', 'Gold', 'Cyan', 'Brown', + 'DeepPink', 'LightGreen', 'Plum', 'Orange', 'Teal', 'Peru', + 'Indigo', 'Khaki', 'Coral', 'Olive' ); + +sub ctx_colour +{ + my ($ctx) = (@_); + + return 'Pink' unless $colour_contexts; + + return $html_colours[($ctx - $min_ctx) % scalar(@html_colours)]; +} + my $i = 0; foreach my $key (sort sortQueue keys %db) { my ($name, $ctx, $seqno) = ($db{$key}->{'name'}, $db{$key}->{'ctx'}, $db{$key}->{'seqno'});
@@ -898,7 +934,8 @@ foreach my $key (sort sortQueue keys %db) { if (exists $db{$key}->{'incomplete'}) { $style = 'color: white; background-color: red;'; } else { - $style = 'color: black; background-color: pink;'; + $style = 'color: black; background-color: ' . + ctx_colour($ctx) . ';'; } $content = "$name <small>$db{$key}->{'port'}</small>"; $content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
Signature · 6 lines
2.14.1 _______________________________________________ igt-dev mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/igt-dev
Re: [igt-dev] [Intel-gfx] [PATCH i-g-t 09/11] trace.pl: Add support for colouring context execution
One suggestion below, otherwise :
Quoted 97 lines · Tvrtko Ursulin
From: Tvrtko Ursulin <[email protected]>
Add the command line switch which uses different colours for different context execution boxes.
Signed-off-by Tvrtko Ursulin <[email protected]>Cc John Harrison <[email protected]>--- scripts/trace.pl | 41 +++++++++++++++++++++++++++++++++++++++-- 1 file changed, 39 insertions(+), 2 deletions(-)scripts/trace.pl +24
-1@@ -40,6 +40,7 @@ my $trace = 0; my $avg_delay_stats = 0; my $squash_context_id = 0; my $gpu_timeline = 0; +my $colour_contexts = 0; my @args;@@ -110,6 +111,8 @@ Usage: --squash-ctx-id Squash context id by substracting engine id from ctx id. --gpu-timeline Draw overall GPU busy timeline. + --colour-contexts / -c Use different colours for different + context execution boxes. ENDHELP exit 0;@@ -279,6 +282,20 @@ sub arg_skip_box return @_; } +sub arg_colour_contexts +{ + return unless scalar(@_); + + if ($_[0] eq '--colour-contexts' or + $_[0] eq '--color-contexts' or + $_[0] eq '-c') { + shift @_; + $colour_contexts = 1; + } + + return @_; +} + @args = @ARGV; while (@args) { my $left = scalar(@args);@@ -294,6 +311,7 @@ while (@args) { @args = arg_split_requests(@args); @args = arg_ignore_ring(@args); @args = arg_skip_box(@args); + @args = arg_colour_contexts(@args); last if $left == scalar(@args); }@@ -581,6 +599,7 @@ foreach my $key (@sorted_keys) { my $last_ts = 0; my $first_ts; +my $min_ctx; foreach my $key (@sorted_keys) { my $ring = $db{$key}->{'ring'};@@ -590,6 +609,8 @@ foreach my $key (@sorted_keys) { $first_ts = $db{$key}->{'queue'} if not defined $first_ts or $db{$key}->{'queue'} < $first_ts; $last_ts = $end if $end > $last_ts; + $min_ctx = $db{$key}->{'ctx'} if not defined $min_ctx or + $db{$key}->{'ctx'} < $min_ctx; $db{$key}->{'context-complete-delay'} = $end - $notify; $db{$key}->{'execute-delay'} = $start - $db{$key}->{'submit'};@@ -721,6 +742,8 @@ foreach my $key (keys %reqwait) { say sprintf('GPU: %.2f%% idle, %.2f%% busy', $flat_busy{'gpu-idle'}, $flat_busy{'gpu-busy'}) unless $html; +my $execute_colour = $colour_contexts ? 'multi-colour' : 'pink'; + print <<ENDHTML if $html; <!DOCTYPE HTML> <html>@@ -741,7 +764,7 @@ print <<ENDHTML if $html; <button onclick="toggleStackSubgroups()">Toggle stacking</button> <p> -pink = requests executing on the GPU<br> +$execute_colour = requests executing on the GPU<br> grey = runnable requests waiting for a slot on GPU<br> blue = requests waiting on fences and dependencies before they are runnable<br> </p>
scripts/trace.pl sub sortQueue { · line 889
Quoted 6 lines
scripts/trace.pl +3
-0@@ -861,6 +884,19 @@ sub sortQueue { return $val; } +my @html_colours = ( 'Pink', 'Green', 'Purple', 'Gold', 'Cyan', 'Brown', + 'DeepPink', 'LightGreen', 'Plum', 'Orange', 'Teal', 'Peru', + 'Indigo', 'Khaki', 'Coral', 'Olive' );
One way to generate as many colors as you need is to use hsv and divide the hue range into as many colors you need. Then the color for element X is X * 360 / n_colors (http://colorizer.org/)
Just a suggestion :)
Quoted 14 lines
scripts/trace.pl +10
-0+ +sub ctx_colour +{ + my ($ctx) = (@_); + + return 'Pink' unless $colour_contexts; + + return $html_colours[($ctx - $min_ctx) % scalar(@html_colours)]; +} + my $i = 0; foreach my $key (sort sortQueue keys %db) { my ($name, $ctx, $seqno) = ($db{$key}->{'name'}, $db{$key}->{'ctx'}, $db{$key}->{'seqno'});
scripts/trace.pl foreach my $key (sort sortQueue keys %db) { · line 941
Quoted 9 lines
scripts/trace.pl +2
-1@@ -898,7 +934,8 @@ foreach my $key (sort sortQueue keys %db) { if (exists $db{$key}->{'incomplete'}) { $style = 'color: white; background-color: red;'; } else { - $style = 'color: black; background-color: pink;'; + $style = 'color: black; background-color: ' . + ctx_colour($ctx) . ';'; } $content = "$name <small>$db{$key}->{'port'}</small>"; $content .= ' <small><i>???</i></small> ' if exists $db{$key}->{'incomplete'};
_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev
PATCH v2 10/11 trace.pl: Fix incomplete request handling
In reply to Tvrtko UrsulinFrom: Tvrtko Ursulin <[email protected]>
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.
--- scripts/trace.pl | 86 ++++++++++++++++++++++++++++++++++++++++++-------------- 1 file changed, 65 insertions(+), 21 deletions(-)
scripts/trace.pl +65 -21
@@ -26,6 +26,8 @@ use strict; use warnings; use 5.010; +use List::Util; + my $gid = 0; my (%db, %queue, %submit, %notify, %rings, %ctxdb, %ringmap, %reqwait); my @freqs;
@@ -516,29 +518,71 @@ foreach my $key (keys %db) { } } -# 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 %engine_timelines; + +sub sortEngine { + my $as = $db{$a}->{'global'}; + my $bs = $db{$b}->{'global'}; + my $val; + + $val = $as <=> $bs; + + die if $val == 0; + + return $val; +} + +sub get_engine_timeline { + my ($ring) = @_; + my @timeline; + + return $engine_timelines{$ring} if exists $engine_timelines{$ring}; + + @timeline = grep { $db{$_}->{'ring'} == $ring } keys %db; + # FIXME seqno restart + @timeline = sort sortEngine @timeline; + + $engine_timelines{$ring} = \@timeline; + + return \@timeline; +} + +# Fix up incompletes by ending them when the last request of a coalesced group +# ends. Start by filtering out the incomplete requests. +my @incompletes = sort grep { exists $db{$_}->{'incomplete'} } keys %db; + +foreach my $key (@incompletes) { + my $timeline; + my $last_key; my $end; + my $i; - 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 + # Find the next request on the engine timeline. + $timeline = get_engine_timeline($db{$key}->{'ring'}); + $i = List::Util::first { ${$timeline}[$_] eq $key } 0..$#{$timeline}; + + while ($i < $#{$timeline}) { + my $next; + + $i = $i + 1; + $next = ${$timeline}[$i]; + + next if exists $db{$next}->{'incomplete'}; - if (exists $db{$next_key}) { - $end = $db{$next_key}->{'end'}; + $last_key = $next; + last; + } + + if (defined $last_key) { + if ($db{$key}->{'ctx'} eq $db{$last_key}->{'ctx'}) { + $end = $db{$last_key}->{'end'}; + } else { + $end = $db{$last_key}->{'start'}; + } } else { - # No info at all, fake it: + # No next submission, fake it. $end = $db{$key}->{'start'} + 999; }
@@ -546,10 +590,6 @@ foreach my $key (keys %db) { $db{$key}->{'end'} = $end; } -# GPU time accounting -my (%running, %runnable, %queued, %batch_avg, %batch_total_avg, %batch_count); -my (%submit_avg, %execute_avg, %ctxsave_avg); - sub sortStart { my $as = $db{$a}->{'start'}; my $bs = $db{$b}->{'start'};
@@ -597,6 +637,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;
Signature · 6 lines
2.14.1 _______________________________________________ Intel-gfx mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/intel-gfx
PATCH v2 11/11 trace.pl: Fix request split mode
In reply to Tvrtko UrsulinFrom: Tvrtko Ursulin <[email protected]>
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.
--- scripts/trace.pl | 121 +++++++++++++++++++++++++++++++++++++++++++------------ 1 file changed, 95 insertions(+), 26 deletions(-)
scripts/trace.pl +95 -26
@@ -601,41 +601,110 @@ 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; - # correct duration of merged batches - if ($correct_durations and exists $db{$key}->{'no-end'}) { + return $ctx_timelines{$key} if exists $ctx_timelines{$key}; + + @timeline = grep { $db{$_}->{'ring'} == $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) { + my @port1; + my @no_end; + + # Shift !port0 requests start time to after the previous context on the + # same timeline has finished. + @port1 = grep { $db{$_}->{'port'} != 0 } @sorted_keys; + foreach my $key (@port1) { + my $timeline = get_engine_timeline($db{$key}->{'ring'}); + my $i = List::Util::first { ${$timeline}[$_] eq $key } 0..$#{$timeline}; + my $prev_key; + my $start; + + while ($i > 0) { + my $prev; + + $i = $i - 1; + $prev = ${$timeline}[$i]; + + next if exists $db{$prev}->{'no-end'}; + + $prev_key = $prev; + last; + } + + $start = $db{$prev_key}->{'end'}; + $db{$key}->{'start'} = $start; + die if $start > $db{$key}->{'end'}; + + $re_sort = 1; + } + + maybe_sort_keys(); + + # Batch with no-end (no request_out) means it was submitted as part of + # colaesced context. This means it's start time should be set to the end + # time of a precedeing request on this timeline. + @no_end = grep { exists $db{$_}->{'no-end'} } @sorted_keys; + foreach my $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'}; + my $ring = $db{$key}->{'ring'}; + my $tkey = $ctx . '/' . $ring; + my $timeline = get_ctx_timeline($ctx, $ring, $tkey); + my $i; + + $i = List::Util::first { ${$timeline}[$_] eq $key } 0..$#{$timeline}; + + # Shift following request to start after the current one. + if ($i < $#{$timeline}) { + my $next_key = ${$timeline}[$i + 1]; + + $db{$next_key}->{'start'} = $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; } } -@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);
Signature · 6 lines
2.14.1 _______________________________________________ Intel-gfx mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/intel-gfx
Patchwork
CI[igt-dev] ✓ Fi.CI.BAT: success for trace.pl fixes (rev2)
In reply to Tvrtko Ursulin== Series Details ==
== Series Details ==
Series: trace.pl fixes (rev2)
URL : https://patchwork.freedesktop.org/series/37330/
State : success
== Summary ==
IGT patchset tested on top of latest successful build b4689dce36d0fbd9aec70d5a4b077c43a6b9c254 igt: Remove gen7_forcewake_mt
with latest DRM-Tip kernel build CI_DRM_38803d35bb0a8966 drm-tip: 2018y-03m-06d-12h-23m-04s UTC integration manifest
No testlist changes.
---- Known issues:
Test kms_pipe_crc_basic:
Subgroup suspend-read-crc-pipe-b:
pass -> INCOMPLETE (fi-snb-2520m) fdo#103713
Test prime_vgem:
Subgroup basic-fence-flip:
pass -> FAIL (fi-ilk-650) fdo#104008fdo#103713 https://bugs.freedesktop.org/show_bug.cgi?id=103713
fdo#104008 https://bugs.freedesktop.org/show_bug.cgi?id=104008
fi-bdw-5557u total:288 pass:267 dwarn:0 dfail:0 fail:0 skip:21 time:425s fi-bdw-gvtdvm total:288 pass:264 dwarn:0 dfail:0 fail:0 skip:24 time:424s fi-blb-e6850 total:288 pass:223 dwarn:1 dfail:0 fail:0 skip:64 time:379s fi-bsw-n3050 total:288 pass:242 dwarn:0 dfail:0 fail:0 skip:46 time:512s fi-bwr-2160 total:288 pass:183 dwarn:0 dfail:0 fail:0 skip:105 time:279s fi-bxt-dsi total:288 pass:258 dwarn:0 dfail:0 fail:0 skip:30 time:490s fi-bxt-j4205 total:288 pass:259 dwarn:0 dfail:0 fail:0 skip:29 time:495s 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:474s fi-cfl-8700k total:288 pass:260 dwarn:0 dfail:0 fail:0 skip:28 time:403s fi-cfl-s2 total:288 pass:262 dwarn:0 dfail:0 fail:0 skip:26 time:568s fi-cnl-y3 total:288 pass:262 dwarn:0 dfail:0 fail:0 skip:26 time:589s fi-elk-e7500 total:288 pass:229 dwarn:0 dfail:0 fail:0 skip:59 time:415s fi-gdg-551 total:288 pass:179 dwarn:0 dfail:0 fail:1 skip:108 time:286s fi-glk-1 total:288 pass:260 dwarn:0 dfail:0 fail:0 skip:28 time:521s fi-hsw-4770 total:288 pass:261 dwarn:0 dfail:0 fail:0 skip:27 time:397s fi-ilk-650 total:288 pass:227 dwarn:0 dfail:0 fail:1 skip:60 time:414s fi-ivb-3520m total:288 pass:259 dwarn:0 dfail:0 fail:0 skip:29 time:473s fi-ivb-3770 total:288 pass:255 dwarn:0 dfail:0 fail:0 skip:33 time:419s fi-kbl-7500u total:288 pass:263 dwarn:1 dfail:0 fail:0 skip:24 time:474s fi-kbl-7560u total:108 pass:104 dwarn:0 dfail:0 fail:0 skip:3 fi-kbl-7567u total:288 pass:268 dwarn:0 dfail:0 fail:0 skip:20 time:462s fi-kbl-r total:288 pass:261 dwarn:0 dfail:0 fail:0 skip:27 time:507s fi-pnv-d510 total:288 pass:222 dwarn:1 dfail:0 fail:0 skip:65 time:589s fi-skl-6260u total:288 pass:268 dwarn:0 dfail:0 fail:0 skip:20 time:442s fi-skl-6600u total:288 pass:261 dwarn:0 dfail:0 fail:0 skip:27 time:517s fi-skl-6700hq total:288 pass:262 dwarn:0 dfail:0 fail:0 skip:26 time:536s fi-skl-6700k2 total:288 pass:264 dwarn:0 dfail:0 fail:0 skip:24 time:500s fi-skl-6770hq total:288 pass:268 dwarn:0 dfail:0 fail:0 skip:20 time:484s fi-skl-guc total:288 pass:260 dwarn:0 dfail:0 fail:0 skip:28 time:421s fi-snb-2520m total:245 pass:211 dwarn:0 dfail:0 fail:0 skip:33 fi-snb-2600 total:288 pass:248 dwarn:0 dfail:0 fail:0 skip:40 time:401s
== Logs ==
For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1070/issues.html
_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev
Patchwork
CI[igt-dev] ✓ Fi.CI.IGT: success for trace.pl fixes (rev2)
In reply to Tvrtko Ursulin== Series Details ==
== Series Details ==
Series: trace.pl fixes (rev2)
URL : https://patchwork.freedesktop.org/series/37330/
State : success
== Summary ==
---- Known issues:
Test gem_eio:
Subgroup in-flight-contexts:
incomplete -> PASS (shard-apl) fdo#105341 +1
Test gem_softpin:
Subgroup noreloc-s3:
skip -> PASS (shard-snb) fdo#103375
Test kms_chv_cursor_fail:
Subgroup pipe-b-64x64-top-edge:
pass -> DMESG-WARN (shard-snb) fdo#105185 +3
Test kms_flip:
Subgroup flip-vs-expired-vblank:
fail -> PASS (shard-hsw) fdo#102887
Test kms_frontbuffer_tracking:
Subgroup fbc-suspend:
fail -> PASS (shard-apl) fdo#101623 +1
Test kms_plane:
Subgroup plane-panning-bottom-right-suspend-pipe-b-planes:
incomplete -> PASS (shard-hsw) fdo#103540
Test kms_rotation_crc:
Subgroup primary-rotation-180:
fail -> PASS (shard-snb) fdo#103925
Subgroup sprite-rotation-90-pos-100-0:
dmesg-warn -> PASS (shard-apl) fdo#103356fdo#105341 https://bugs.freedesktop.org/show_bug.cgi?id=105341
fdo#103375 https://bugs.freedesktop.org/show_bug.cgi?id=103375
fdo#105185 https://bugs.freedesktop.org/show_bug.cgi?id=105185
fdo#102887 https://bugs.freedesktop.org/show_bug.cgi?id=102887
fdo#101623 https://bugs.freedesktop.org/show_bug.cgi?id=101623
fdo#103540 https://bugs.freedesktop.org/show_bug.cgi?id=103540
fdo#103925 https://bugs.freedesktop.org/show_bug.cgi?id=103925
fdo#103356 https://bugs.freedesktop.org/show_bug.cgi?id=103356
shard-apl total:3467 pass:1826 dwarn:1 dfail:0 fail:7 skip:1632 time:12427s shard-hsw total:3467 pass:1772 dwarn:2 dfail:0 fail:1 skip:1691 time:11915s shard-snb total:3467 pass:1362 dwarn:3 dfail:0 fail:2 skip:2100 time:7121s
Blacklisted hosts:
shard-kbl total:3433 pass:1934 dwarn:1 dfail:0 fail:7 skip:1490 time:9260s
== Logs ==
For more details see: https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_1070/shards.html
_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev
Quoted 33 lines · Tvrtko Ursulin
From: Tvrtko Ursulin <[email protected]>
Collection of fixes on top of John's recent work.
Problems were mostly in the request split logic which had several issues both in my original version, and also after John's improvements.
Handling of "incomplete" requests (the ones which received neither notify nor context complete) was also a bit incorrect.
After this series it seems to work fine, famous last words. Anyway with my test data it correctly draws the timeline with no overalaps considering both merged requests and submission to port 1.
I also added context colouring mode so it is easier to follow the timeline and started using
hw_idfor context id's for additional readability.v2:
* Update for tracepoint renames. (new in series)
* Removehw_idchange. (droppped from series)* Fix incomplete handling in split mode (-s).
This did not work well for workloads which generate very few
intel_engine_notifyevents. I am not that confident it is 100% correct now, but at least it doesn't crash the script and output for one other workload I had lying around looks correct.I guess the moral of the story here is split mode is not easy to get right if it is considered just a side project and more time needs to be set aside to triple-check it.
Quoted 8 lines
John Harrison (4):
scripts/trace.pl: More hash key optimisationsscripts/trace.pl: Sort order
scripts/trace.pl: Calculate stats only after all mungingscripts/trace.pl: Simplify 'end' & 'notify' generationTvrtko Ursulin (7):
trace.pl: Catch-up with tracepoint renames
From here vvvvv...
Quoted 6 lines
trace.pl: Move sortQueue near its user trace.pl: Move min/max timestamp lookup to last loop trace.pl: Fix engine busy accounting in split mode trace.pl: Add support for colouring context execution trace.pl: Fix incomplete request handling trace.pl: Fix request split mode
... to here ^^^^^.
Only six patches to review and four even don't need much thinking!
Regards,
Tvrtko
_______________________________________________
igt-dev mailing list
[email protected]
https://lists.freedesktop.org/mailman/listinfo/igt-dev