From patchwork Tue Mar 6 12:43:08 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Tvrtko Ursulin X-Patchwork-Id: 10261579 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 7E37A60596 for ; Tue, 6 Mar 2018 12:43:35 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 6DF2828A57 for ; Tue, 6 Mar 2018 12:43:35 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 6229B28E43; Tue, 6 Mar 2018 12:43:35 +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=-4.1 required=2.0 tests=BAYES_00,DKIM_SIGNED, RCVD_IN_DNSWL_MED,T_DKIM_INVALID 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 E5D1E28AF4 for ; Tue, 6 Mar 2018 12:43:34 +0000 (UTC) Received: from gabe.freedesktop.org (localhost [127.0.0.1]) by gabe.freedesktop.org (Postfix) with ESMTP id 28BFE6E6B7; Tue, 6 Mar 2018 12:43:32 +0000 (UTC) X-Original-To: Intel-gfx@lists.freedesktop.org Delivered-To: Intel-gfx@lists.freedesktop.org Received: from mail-wr0-x231.google.com (mail-wr0-x231.google.com [IPv6:2a00:1450:400c:c0c::231]) by gabe.freedesktop.org (Postfix) with ESMTPS id 37C296E6B1 for ; Tue, 6 Mar 2018 12:43:30 +0000 (UTC) Received: by mail-wr0-x231.google.com with SMTP id m12so20757351wrm.13 for ; Tue, 06 Mar 2018 04:43:30 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=ursulin-net.20150623.gappssmtp.com; s=20150623; h=from:to:cc:subject:date:message-id:in-reply-to:references; bh=c1Gg2zcvMZYQQxvS3lvFNwetLosA2H9CdK8EGd+d05s=; b=yyoU2ILUSo5YUyHiJpv3vWZvxrFbSpcXFl7AWaKK0JVr7AqcIhRWgaFF3hvzpEU1GF 7fOt88HMBr1mYclqKZjCRm+6SQ1utzETi1bdjWzO49l6Y69EdASDmPVA8j514qzJUIdp a9rnnnHqWOTuOrd+5kb32pMZxt0L7+35tEnm1WeRSQTk0nTb1tsKE/JTuCw/1k03l2w7 Q2HNyuhKcgYZ3UP61lpQVBKY5P45r84wk0ciSquexbzydn1qxrF7+y0gLl1N1RaEmGc/ M3EAkz7K+l4Vh3K3eNemxcFYRCnnrAPGKIolxS3HSg0I6NpV3ufCoeBmQfF62r/lT6wO Ahzw== 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=c1Gg2zcvMZYQQxvS3lvFNwetLosA2H9CdK8EGd+d05s=; b=YJf/dk3EatevSqv7R0rtNmcLcKWNp3Hy4tU/lKuyqKYwpksXqjxG3hmUsD10Ua9qyL QISVjAQL5uUIukZPk2lubrCqyEIbt2iN+8g1kVH7bH76YxIBvlnQs7gY2NAAMl+hqaqy kRMzFj3ZHNebQFfiW3VOevr8PLKpRU34qwahEk9XDgTfBXweuGP5pLqkkrxPkPi/FOi/ 5i2f7sHkIQ3u3ZpR80KLqie9xkzXaINcPWWJKA/oVMwX1BsYFSdB2ybadB3yiQPVFlDm dYaiuagx/DyeYAuls8pQzTBYK6N9KmHSnPwHShV0BOv2rrl2peyNRKV3VGZ/wnKcs2Hv AUew== X-Gm-Message-State: APf1xPDOFXkTOLKoG4DZ/XvNBVTHQnBGG2gHESe+Ya1CvW8nSnfoy6RE remx52TVT9Lse2UnxUdDGFvYxA== X-Google-Smtp-Source: AG47ELs0XOMMoRhG9nzJe4C4ycn1OqxaxpNJPdkWDQh5N9capf/87Vl/zOFNFGULNiv44R2IfLm04w== X-Received: by 10.223.150.194 with SMTP id u60mr15325136wrb.47.1520340208820; Tue, 06 Mar 2018 04:43:28 -0800 (PST) Received: from localhost.localdomain ([95.146.144.186]) by smtp.gmail.com with ESMTPSA id v8sm3646560wmh.25.2018.03.06.04.43.28 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Tue, 06 Mar 2018 04:43:28 -0800 (PST) From: Tvrtko Ursulin X-Google-Original-From: Tvrtko Ursulin To: igt-dev@lists.freedesktop.org Date: Tue, 6 Mar 2018 12:43:08 +0000 Message-Id: <20180306124315.30208-5-tvrtko.ursulin@linux.intel.com> X-Mailer: git-send-email 2.14.1 In-Reply-To: <20180306124315.30208-1-tvrtko.ursulin@linux.intel.com> References: <20180306124315.30208-1-tvrtko.ursulin@linux.intel.com> Subject: [Intel-gfx] [PATCH i-g-t 04/11] scripts/trace.pl: Calculate stats only after all munging 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: John Harrison 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] Signed-off-by: John Harrison Cc: Tvrtko Ursulin Reviewed-by: Tvrtko Ursulin --- scripts/trace.pl | 54 ++++++++++++++++++++++++++++-------------------------- 1 file changed, 28 insertions(+), 26 deletions(-) diff --git a/scripts/trace.pl b/scripts/trace.pl index d571a870fca2..d880a733bff8 100755 --- a/scripts/trace.pl +++ b/scripts/trace.pl @@ -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};