From patchwork Tue Jun 5 17:50:48 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Tvrtko Ursulin X-Patchwork-Id: 10448917 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id 6D73560284 for ; Tue, 5 Jun 2018 17:51:07 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 5A74C29ACD for ; Tue, 5 Jun 2018 17:51:07 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 4F87529B27; Tue, 5 Jun 2018 17:51:07 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-5.2 required=2.0 tests=BAYES_00, MAILING_LIST_MULTI, RCVD_IN_DNSWL_MED autolearn=ham version=3.3.1 Received: from gabe.freedesktop.org (gabe.freedesktop.org [131.252.210.177]) (using TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.wl.linuxfoundation.org (Postfix) with ESMTPS id C4C1D29ACD for ; Tue, 5 Jun 2018 17:51:06 +0000 (UTC) Received: from gabe.freedesktop.org (localhost [127.0.0.1]) by gabe.freedesktop.org (Postfix) with ESMTP id 3B6AE6EEEC; Tue, 5 Jun 2018 17:51:06 +0000 (UTC) X-Original-To: intel-gfx@lists.freedesktop.org Delivered-To: intel-gfx@lists.freedesktop.org Received: from mail-wr0-x243.google.com (mail-wr0-x243.google.com [IPv6:2a00:1450:400c:c0c::243]) by gabe.freedesktop.org (Postfix) with ESMTPS id 829C56EEEA for ; Tue, 5 Jun 2018 17:51:04 +0000 (UTC) Received: by mail-wr0-x243.google.com with SMTP id 94-v6so3357161wrf.5 for ; Tue, 05 Jun 2018 10:51:04 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references; bh=hI++/7erqtZrCPCF7+aMi+MZLFMwnZk99J/Rtlu5mAc=; b=Dcm88BnuuiV8i2VoCavg69OAIqEDdj3zQisL3IpMr7YpHU3P84E+8z+ybGmetI1hjI BsO5kRSaegXTPML40U1DF9Wup2b4A7JjoZzbyZ/UvjWyK3yjURQA5kStZWHifSgv9i8a fsd0Utl+KcKjpYsTwQqPA8Kqo2OCWHBcIw/XfmAFmGAUFSnYnyTgGV1R1WZJ8LWMLjqb D8kM7wZOHfLgJ/DW3k1HFSE0IS69jrbiiNSjLOQmIPpBoNMoL7H1iMMhRdi9fPwt6Pn9 Cnmj3iatNtbNLVIizVkyUqtJP+6PDTU6lg0RZL2BHXFWeG6J2vu4rMw16cEM6quY50fo j+Kg== X-Gm-Message-State: ALKqPwd+kCrLYzOcDSCWfZKbQuZJp7tFjDkTNkye6i/TUhZUEJ2nMwMn LY3C71aXIeqRP02FTRjdlf7aWg== X-Google-Smtp-Source: ADUXVKItBMNUfBARyP/dztbo43Qsqm+tYe3zmliRgXvzLn8GYSbiybgdDxypct93pmHin1VLq14gSQ== X-Received: by 2002:adf:c4d0:: with SMTP id o16-v6mr20332818wrf.173.1528221062894; Tue, 05 Jun 2018 10:51:02 -0700 (PDT) Received: from localhost.localdomain ([95.146.151.144]) by smtp.gmail.com with ESMTPSA id u108-v6sm59739052wrc.40.2018.06.05.10.51.02 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Tue, 05 Jun 2018 10:51:02 -0700 (PDT) From: Tvrtko Ursulin X-Google-Original-From: Tvrtko Ursulin To: igt-dev@lists.freedesktop.org Date: Tue, 5 Jun 2018 18:50:48 +0100 Message-Id: <20180605175050.29850-6-tvrtko.ursulin@linux.intel.com> X-Mailer: git-send-email 2.17.0 In-Reply-To: <20180605175050.29850-1-tvrtko.ursulin@linux.intel.com> References: <20180605175050.29850-1-tvrtko.ursulin@linux.intel.com> Subject: [Intel-gfx] [PATCH i-g-t 6/8] trace.pl: Fix incomplete request handling X-BeenThere: intel-gfx@lists.freedesktop.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: Intel graphics driver community testing & development List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: intel-gfx@lists.freedesktop.org MIME-Version: 1.0 Errors-To: intel-gfx-bounces@lists.freedesktop.org Sender: "Intel-gfx" X-Virus-Scanned: ClamAV using ClamSMTP From: Tvrtko Ursulin 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 Cc: John Harrison --- scripts/trace.pl | 163 +++++++++++++++++++++++++++++++---------------- 1 file changed, 108 insertions(+), 55 deletions(-) diff --git a/scripts/trace.pl b/scripts/trace.pl index c2f1df5afa9e..1d42f2749710 100755 --- a/scripts/trace.pl +++ b/scripts/trace.pl @@ -452,16 +452,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; @@ -474,66 +469,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'}; @@ -582,6 +627,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, $max_ctx); @@ -606,7 +655,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'};