From patchwork Wed Jun 28 20:01:38 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Namhyung Kim X-Patchwork-Id: 114036 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a59:994d:0:b0:3d9:f83d:47d9 with SMTP id k13csp9181457vqr; Wed, 28 Jun 2023 13:10:57 -0700 (PDT) X-Google-Smtp-Source: ACHHUZ5pIgHHpe0n1hQhj4/SXFqqRBsdvCdMxd0bgoSA6l9RoSvzLmzyai3wzcLdflzNXmdRK7Kf X-Received: by 2002:a17:906:7a45:b0:988:8e7a:d953 with SMTP id i5-20020a1709067a4500b009888e7ad953mr579663ejo.1.1687983057415; Wed, 28 Jun 2023 13:10:57 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1687983057; cv=none; d=google.com; s=arc-20160816; b=d2y92uk3sDoNV+cKHwVWOQ61UEt4Z8KUu8EihKXbPTKEJAriv9QvSzX/oGJ8cCHx0m x042tD9GWoKdBINcytb+7GxYT+vesfPtfkPORWVBdA7P194v+IZJXIdsdjj9EbmHvNCP iADPCvyoMCV+LKk8JlnXwm2fd40qZPCI/Lwel/0lYa7scskO+fZvhMHmxWyFAs+pZ6Yk GxKYyPgIYssuiVzNp227V6r8Kk7FvTUfo1nNeL0n44jXKcQVTjepnUZ2mrw7bua7NheU 7MvCYCmYRSdZX60FzlyZQfaVvZAfEnPXwv2ktR+3dWUndZ/kXGKh+xVfKmhL3xqCsF5r YFJw== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:content-transfer-encoding:mime-version :references:in-reply-to:message-id:date:subject:cc:to:from:sender :dkim-signature; bh=c8rBC54h3TqzO9Dqa/LMLhbq/U3gSsKwzSwcc3zbIic=; fh=qg0XpHrrfjSy6nePy3ZLIayRkwEhRnO8Y6NeBhcC42U=; b=xJlwwMYJY1jF6aSsDQTmBbshQ6z9STPp9Vl4JKvzgVoqfLozIxfhBJsrAOwseSBkIL tYjD3pbPxKEkoSESLxY2iW3AsTZKmhm4WgdiA4VUL/+0lqPKoedBSUlYOTu5mdrqOAKG 5YyJitWunlyjQV2vWqp2tF6LXlzU8CzwH5CzdVVFRKvkiUUWGohBV4207G/BfV5eI8Bg dCpaVBgjQacZyGPywPdOPcfBRpf03qInzQwzRPmdI8DNIAz1V6XwZ3/JXf/cNBumSydj yFr9V/fHITEP1W/7oLO2kNPIfYg83VewPd0EAa4K67S0i0mMuxVHV/g+5jmPmIqH8NcS Gmbw== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b="TdpOW9/u"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id md6-20020a170906ae8600b009922cdfaf62si2357247ejb.42.2023.06.28.13.10.32; Wed, 28 Jun 2023 13:10:57 -0700 (PDT) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b="TdpOW9/u"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S231616AbjF1UBz (ORCPT + 99 others); Wed, 28 Jun 2023 16:01:55 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59392 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S231573AbjF1UBq (ORCPT ); Wed, 28 Jun 2023 16:01:46 -0400 Received: from mail-pf1-x435.google.com (mail-pf1-x435.google.com [IPv6:2607:f8b0:4864:20::435]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 09CA31FF6; Wed, 28 Jun 2023 13:01:46 -0700 (PDT) Received: by mail-pf1-x435.google.com with SMTP id d2e1a72fcca58-666eef03ebdso120873b3a.1; Wed, 28 Jun 2023 13:01:46 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20221208; t=1687982505; x=1690574505; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:from:to:cc:subject:date :message-id:reply-to; bh=c8rBC54h3TqzO9Dqa/LMLhbq/U3gSsKwzSwcc3zbIic=; b=TdpOW9/uiMYrng7phmY9h/ygcWEDPzlQXSGsOBafxfzi+fRuSbxfH94J6rkyP+LLVk wJngk0RxllDwKPxB88BPEAguKA4Gi9zccEOyEPyVyY0UDMQsZOQoV81w8+pJGDRGw2iB N2RGFxF7oiMnPKJkkxEGbMH+RBmdUMVkgSeY8WNG0m9kX4INHvE6EBy0mIj3X5GwO/Ro krrg9YY59wF1PAQg3GFop6kks8jV43g5o959MqhdiO+C0O7jhxkWQudVSJQDa1+8c0F+ jLZuU+KoOSf9WgOPudPy3tvibdexV6msFES0u8kcgoDPAyjeBgTIgqnAhbTPRn/buv/r EeyQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1687982505; x=1690574505; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:x-gm-message-state:from :to:cc:subject:date:message-id:reply-to; bh=c8rBC54h3TqzO9Dqa/LMLhbq/U3gSsKwzSwcc3zbIic=; b=hbvwXi9grLq2bqGuZuS6efkrZFpXyOefk9OIcF5YYZ+Boz1ZBsRpATwHR5ZPaXJ84J KJUFo6CMpeFmf4QucuBTEylaxwgs1g6ygTZYoicj5DudJ6xjdeduBOLScokltsPaxY9F 3b1Dht9OxhxN6xdLVXHQQachRlw/0pv9GS0XI0PpkGNHo8jF8kAKnQpt/2NWb4GG8qWs W//qeTCV+Nd9fZ+1y56Rlc8OqwBwOYzWcWE5H4LvlhHsaJ9GgzxNDezrCI6eo32wI2eE k3hhNxazQCy75vibpRnHDDMQpZzUmmO7RsFuVjSj9sao0aQCblB/NE5zDbjduo1iWN5t iv6g== X-Gm-Message-State: AC+VfDxPIcUv9MW0+XpWL1l4jZdotjaJCuEqyvTrYG28qO1yOeOleRU2 kZH8CHGsSqNEAkCBa4hHgtw= X-Received: by 2002:a05:6a20:4305:b0:123:c3dc:2052 with SMTP id h5-20020a056a20430500b00123c3dc2052mr17839261pzk.35.1687982505378; Wed, 28 Jun 2023 13:01:45 -0700 (PDT) Received: from bangji.corp.google.com ([2620:15c:2c0:5:fc6b:e50c:c8f0:b09b]) by smtp.gmail.com with ESMTPSA id f3-20020aa78b03000000b0065e154bac6dsm7340376pfd.133.2023.06.28.13.01.44 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 28 Jun 2023 13:01:45 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ian Rogers , Adrian Hunter , Peter Zijlstra , Ingo Molnar , LKML , linux-perf-users@vger.kernel.org, Song Liu , Hao Luo Subject: [PATCH 1/4] perf lock: Remove stale comments Date: Wed, 28 Jun 2023 13:01:38 -0700 Message-ID: <20230628200141.2739587-2-namhyung@kernel.org> X-Mailer: git-send-email 2.41.0.255.g8b1d071c50-goog In-Reply-To: <20230628200141.2739587-1-namhyung@kernel.org> References: <20230628200141.2739587-1-namhyung@kernel.org> MIME-Version: 1.0 X-Spam-Status: No, score=-1.5 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_EF,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE, SPF_PASS,T_SCC_BODY_TEXT_LINE autolearn=no autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?= X-GMAIL-THRID: =?utf-8?q?1769978522116426022?= X-GMAIL-MSGID: =?utf-8?q?1769978522116426022?= The comment was for symbol_conf.sort_by_name which was deleted already. Let's get rid of the stale comments as well. Signed-off-by: Namhyung Kim Acked-by: Ian Rogers --- tools/perf/builtin-lock.c | 2 -- 1 file changed, 2 deletions(-) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index da36ace66d68..187efb651436 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -1773,7 +1773,6 @@ static int __cmd_report(bool display_info) return PTR_ERR(session); } - /* for lock function check */ symbol_conf.allow_aliases = true; symbol__init(&session->header.env); @@ -1902,7 +1901,6 @@ static int __cmd_contention(int argc, const char **argv) if (con.aggr_mode == LOCK_AGGR_CALLER) con.save_callstack = true; - /* for lock function check */ symbol_conf.allow_aliases = true; symbol__init(&session->header.env); From patchwork Wed Jun 28 20:01:39 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Namhyung Kim X-Patchwork-Id: 114035 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a59:994d:0:b0:3d9:f83d:47d9 with SMTP id k13csp9181256vqr; Wed, 28 Jun 2023 13:10:34 -0700 (PDT) X-Google-Smtp-Source: ACHHUZ6PbeUpLIdv7r8EucmtcyZVkElJrA7hPpqSVhVHt9tfOJu+VQ6zzo/YCqzgiGk39ElAbAcb X-Received: by 2002:a05:6a00:1c8e:b0:679:a1f1:a5f8 with SMTP id y14-20020a056a001c8e00b00679a1f1a5f8mr932384pfw.3.1687983033911; Wed, 28 Jun 2023 13:10:33 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1687983033; cv=none; d=google.com; s=arc-20160816; b=IAx3rLyOk+Zfd+AnbEk1Y1Q3gO+V5+wWKe6S0FH8rcOK54/naGbo5o3DA2ucNFwira 7Wf5dlhY49MzZClsuzH8omGteOwszDmVSHUo2RGCG8Qm6Qf3Yiv9SVE50WnDKDA9XHYj Le96ElEjbRUjoFG6U3jaW3+gHCqAKTrHHSvwg4byGCx4OSlBlvyfbqSx1y1kM/R4vFYE 2ata2U1hszbd5E0aeR/y41JNThOToRj9m7j3XzY/rQRz7SisX6GR/kgr5V8m/jbyFonj 8PDGpeTTg0aL5kr2c6LfYNSMuPQdt89wk6KxU3PaRrOcaK6aDgwb/rdoQqdutrqHqiv/ 6szw== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:content-transfer-encoding:mime-version :references:in-reply-to:message-id:date:subject:cc:to:from:sender :dkim-signature; bh=DuqncC+fTY/BbgCjz5qMx8zbsDzwZzSyUWySAuRCBt0=; fh=qg0XpHrrfjSy6nePy3ZLIayRkwEhRnO8Y6NeBhcC42U=; b=xRG2mBqBGi2wHLuZH20Q96vdujeDJ48drvWf7eHNvGnEeS4KhmtvrUdC1vhHX+x9CD a0byl9E3m1NiT1F/jKh2uKPdH5dvhza/ePbA4ilf62GfcKX9FQ1O/zt52R9NEAJcUZmu 7tz7ijVAEw1WDq+sblgQvQg9PIJv4O9mIpH+GOieotRQymkCopelkY8PI/c3ywRGYmKl TzTNDBqWh9ygHz2KhtVhoXskyzTWmyuoLicD/ElBWbphrgOTLZ3BdTObhL2xv6QYO7Si HsI4J/jrZyfsCDohAf2Ox96aM09zLo9hDJv/gOTCZnGbMe8rXgjpi90q5q/ItbuKqj96 XQ7Q== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b=OcHU4EcH; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id l5-20020a056a0016c500b0064d3e917a90si9802764pfc.180.2023.06.28.13.10.19; Wed, 28 Jun 2023 13:10:33 -0700 (PDT) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b=OcHU4EcH; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S231678AbjF1UCC (ORCPT + 99 others); Wed, 28 Jun 2023 16:02:02 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59412 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S231598AbjF1UBs (ORCPT ); Wed, 28 Jun 2023 16:01:48 -0400 Received: from mail-pf1-x42c.google.com (mail-pf1-x42c.google.com [IPv6:2607:f8b0:4864:20::42c]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 4C5CE1FF7; Wed, 28 Jun 2023 13:01:47 -0700 (PDT) Received: by mail-pf1-x42c.google.com with SMTP id d2e1a72fcca58-6687446eaccso119461b3a.3; Wed, 28 Jun 2023 13:01:47 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20221208; t=1687982507; x=1690574507; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:from:to:cc:subject:date :message-id:reply-to; bh=DuqncC+fTY/BbgCjz5qMx8zbsDzwZzSyUWySAuRCBt0=; b=OcHU4EcHckCrFZ/OqcnKCSdBZ7H/SoUMAhS7L4wK65mtaIrxiB6xZybfH/x+Xz8dXn mRfOtIOglxBI006z3rkDLwqDcKH0kQw1IrKYTQmOibmXE1//a6m52UzbsPLGHbl/wDnh tW7Cke2/2KX5a0CCXyN+W8ilwrbEooize+uYET8vJDyGk7JDRwngAYg/JmCa1u0WMSyt h+0wo0tvlidu0i/gKxxNAyhS183jIck8nXWUhFN1gCNfV7BmqrYJqIkUxExuQcPVnmXG o6Gio4ICX7sTNZyx4RPd5bmmzovJOoEza7OeWoS6OrYkfBwACDuWbJhidTfs74r0LkLj inqw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1687982507; x=1690574507; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:x-gm-message-state:from :to:cc:subject:date:message-id:reply-to; bh=DuqncC+fTY/BbgCjz5qMx8zbsDzwZzSyUWySAuRCBt0=; b=L7hI5qPilVSXcH03P5Upjg425Lk1omuSSvL9jsAedjEVyNcZg5HLExgeqskEFFVA1o 44RaQn+Fp9eOYWWsCCPPb/SXC1Jmc68jCxEGY/5n0MJ4HgRi4VC3H0U85kMtznb1lORm W7W1K8Ovg4gmmRXI5Qa7ei2Y5XzOvnriNu4HnyWTuMNsPvCvY7NSlv1ePUZuyACsdb2w PAAGNHZ5SOVBZFc+L8XPPsAHn/0TGFMI4UH+YAQEUb+b4Qi8ABljxxEROV5FBAe5aCoD JwD/l2ME6r6xeduf918z5pYkGRlcUafRAhF3nBsqE1rAK4g/VeHanb+7QBU+B0nhmplE vMVQ== X-Gm-Message-State: AC+VfDy8pjcLJ6vLke7vGoGAnsTx8DXzo6ok5wtDDDPleBmLmj1futL7 FIQpRce2cwh/JZ57ilTnnNA= X-Received: by 2002:a05:6a00:2351:b0:668:6445:8931 with SMTP id j17-20020a056a00235100b0066864458931mr44656825pfj.29.1687982506584; Wed, 28 Jun 2023 13:01:46 -0700 (PDT) Received: from bangji.corp.google.com ([2620:15c:2c0:5:fc6b:e50c:c8f0:b09b]) by smtp.gmail.com with ESMTPSA id f3-20020aa78b03000000b0065e154bac6dsm7340376pfd.133.2023.06.28.13.01.45 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 28 Jun 2023 13:01:46 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ian Rogers , Adrian Hunter , Peter Zijlstra , Ingo Molnar , LKML , linux-perf-users@vger.kernel.org, Song Liu , Hao Luo Subject: [PATCH 2/4] perf lock contention: Add -x option for CSV style output Date: Wed, 28 Jun 2023 13:01:39 -0700 Message-ID: <20230628200141.2739587-3-namhyung@kernel.org> X-Mailer: git-send-email 2.41.0.255.g8b1d071c50-goog In-Reply-To: <20230628200141.2739587-1-namhyung@kernel.org> References: <20230628200141.2739587-1-namhyung@kernel.org> MIME-Version: 1.0 X-Spam-Status: No, score=-1.5 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_EF,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE, SPF_PASS,T_SCC_BODY_TEXT_LINE autolearn=no autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?= X-GMAIL-THRID: =?utf-8?q?1769978498187106930?= X-GMAIL-MSGID: =?utf-8?q?1769978498187106930?= Sometimes we want to process the output by external programs. Let's add the -x option to specify the field separator like perf stat. $ sudo ./perf lock con -ab -x, sleep 1 # output: contended, total wait, max wait, avg wait, type, caller 19, 194232, 21415, 10222, spinlock, process_one_work+0x1f0 15, 162748, 23843, 10849, rwsem:R, do_user_addr_fault+0x40e 4, 86740, 23415, 21685, rwlock:R, ep_poll_callback+0x2d 1, 84281, 84281, 84281, mutex, iwl_mvm_async_handlers_wk+0x135 8, 67608, 27404, 8451, spinlock, __queue_work+0x174 3, 58616, 31125, 19538, rwsem:W, do_mprotect_pkey+0xff 3, 52953, 21172, 17651, rwlock:W, do_epoll_wait+0x248 2, 30324, 19704, 15162, rwsem:R, do_madvise+0x3ad 1, 24619, 24619, 24619, spinlock, rcu_core+0xd4 The first line is a comment that shows the output format. Each line is separated by the given string ("," in this case). The time is printed in nsec without the unit so that it can be parsed easily. The characters can be used in the output like (":", "+" and ".") are not allowed for the -x option. $ ./perf lock con -x: Cannot use the separator that is already used Usage: perf lock contention [] -x, --field-separator print result in CSV format with custom separator The stacktraces are printed in the same line separated by ":". The header is updated to show the stacktrace. Also the debug output is added at the end as a comment. $ sudo ./perf lock con -abv -x, -F wait_total sleep 1 Looking at the vmlinux_path (8 entries long) symsrc__init: cannot get elf header. Using /proc/kcore for kernel data Using /proc/kallsyms for symbols # output: total wait, type, caller, stacktrace 37134, spinlock, rcu_core+0xd4, 0xffffffff9d0401e4 _raw_spin_lock_irqsave+0x44: 0xffffffff9c738114 rcu_core+0xd4: ... 21213, spinlock, raw_spin_rq_lock_nested+0x1b, 0xffffffff9d0407c0 _raw_spin_lock+0x30: 0xffffffff9c6d9cfb raw_spin_rq_lock_nested+0x1b: ... 20506, rwlock:W, ep_done_scan+0x2d, 0xffffffff9c9bc4dd ep_done_scan+0x2d: 0xffffffff9c9bd5f1 do_epoll_wait+0x6d1: ... 18044, rwlock:R, ep_poll_callback+0x2d, 0xffffffff9d040555 _raw_read_lock_irqsave+0x45: 0xffffffff9c9bc81d ep_poll_callback+0x2d: ... 17890, rwlock:W, do_epoll_wait+0x47b, 0xffffffff9c9bd39b do_epoll_wait+0x47b: 0xffffffff9c9be9ef __x64_sys_epoll_wait+0x6d1: ... 12114, spinlock, futex_wait_queue+0x60, 0xffffffff9d0407c0 _raw_spin_lock+0x30: 0xffffffff9d037cae __schedule+0xbe: ... # debug: total=7, bad=0, bad_task=0, bad_stack=0, bad_time=0, bad_data=0 Also note that some field (like lock symbols) can be empty. $ sudo ./perf lock con -abl -x, -E 10 sleep 1 # output: contended, total wait, max wait, avg wait, address, symbol, type 6, 275025, 61764, 45837, ffff9dcc9f7d60d0, , spinlock 18, 87716, 11196, 4873, ffff9dc540059000, , spinlock 2, 6472, 5499, 3236, ffff9dcc7f730e00, rq_lock, spinlock 3, 4429, 2341, 1476, ffff9dcc7f7b0e00, rq_lock, spinlock 3, 3974, 1635, 1324, ffff9dcc7f7f0e00, rq_lock, spinlock 4, 3290, 1326, 822, ffff9dc5f4e2cde0, , rwlock 3, 2894, 1023, 964, ffffffff9e0d7700, rcu_state, spinlock 1, 2567, 2567, 2567, ffff9dcc7f6b0e00, rq_lock, spinlock 4, 1259, 596, 314, ffff9dc69c2adde0, , rwlock 1, 934, 934, 934, ffff9dcc7f670e00, rq_lock, spinlock Signed-off-by: Namhyung Kim Acked-by: Ian Rogers --- tools/perf/Documentation/perf-lock.txt | 5 + tools/perf/builtin-lock.c | 303 +++++++++++++++++++------ 2 files changed, 241 insertions(+), 67 deletions(-) diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt index 6e5ba3cd2b72..d1efcbe7a470 100644 --- a/tools/perf/Documentation/perf-lock.txt +++ b/tools/perf/Documentation/perf-lock.txt @@ -200,6 +200,11 @@ CONTENTION OPTIONS Note that it matches the substring so 'rq' would match both 'raw_spin_rq_lock' and 'irq_enter_rcu'. +-x:: +--field-separator=:: + Show results using a CSV-style output to make it easy to import directly + into spreadsheets. Columns are separated by the string specified in SEP. + SEE ALSO -------- diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 187efb651436..98b0c0b1b307 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -225,6 +225,12 @@ static void lock_stat_key_print_time(unsigned long long nsec, int len) { 0, NULL }, }; + /* for CSV output */ + if (len == 0) { + pr_info("%llu", nsec); + return; + } + for (int i = 0; table[i].unit; i++) { if (nsec < table[i].base) continue; @@ -1626,11 +1632,179 @@ static void sort_contention_result(void) sort_result(); } -static void print_bpf_events(int total, struct lock_contention_fails *fails) +static void print_header_stdio(void) +{ + struct lock_key *key; + + list_for_each_entry(key, &lock_keys, list) + pr_info("%*s ", key->len, key->header); + + switch (aggr_mode) { + case LOCK_AGGR_TASK: + pr_info(" %10s %s\n\n", "pid", + show_lock_owner ? "owner" : "comm"); + break; + case LOCK_AGGR_CALLER: + pr_info(" %10s %s\n\n", "type", "caller"); + break; + case LOCK_AGGR_ADDR: + pr_info(" %16s %s\n\n", "address", "symbol"); + break; + default: + break; + } +} + +static void print_header_csv(const char *sep) +{ + struct lock_key *key; + + pr_info("# output: "); + list_for_each_entry(key, &lock_keys, list) + pr_info("%s%s ", key->header, sep); + + switch (aggr_mode) { + case LOCK_AGGR_TASK: + pr_info("%s%s %s\n", "pid", sep, + show_lock_owner ? "owner" : "comm"); + break; + case LOCK_AGGR_CALLER: + pr_info("%s%s %s", "type", sep, "caller"); + if (verbose > 0) + pr_info("%s %s", sep, "stacktrace"); + pr_info("\n"); + break; + case LOCK_AGGR_ADDR: + pr_info("%s%s %s%s %s\n", "address", sep, "symbol", sep, "type"); + break; + default: + break; + } +} + +static void print_header(void) +{ + if (!quiet) { + if (symbol_conf.field_sep) + print_header_csv(symbol_conf.field_sep); + else + print_header_stdio(); + } +} + +static void print_lock_stat_stdio(struct lock_contention *con, struct lock_stat *st) +{ + struct lock_key *key; + struct thread *t; + int pid; + + list_for_each_entry(key, &lock_keys, list) { + key->print(key, st); + pr_info(" "); + } + + switch (aggr_mode) { + case LOCK_AGGR_CALLER: + pr_info(" %10s %s\n", get_type_str(st->flags), st->name); + break; + case LOCK_AGGR_TASK: + pid = st->addr; + t = perf_session__findnew(session, pid); + pr_info(" %10d %s\n", + pid, pid == -1 ? "Unknown" : thread__comm_str(t)); + break; + case LOCK_AGGR_ADDR: + pr_info(" %016llx %s (%s)\n", (unsigned long long)st->addr, + st->name, get_type_name(st->flags)); + break; + default: + break; + } + + if (aggr_mode == LOCK_AGGR_CALLER && verbose > 0) { + struct map *kmap; + struct symbol *sym; + char buf[128]; + u64 ip; + + for (int i = 0; i < max_stack_depth; i++) { + if (!st->callstack || !st->callstack[i]) + break; + + ip = st->callstack[i]; + sym = machine__find_kernel_symbol(con->machine, ip, &kmap); + get_symbol_name_offset(kmap, sym, ip, buf, sizeof(buf)); + pr_info("\t\t\t%#lx %s\n", (unsigned long)ip, buf); + } + } +} + +static void print_lock_stat_csv(struct lock_contention *con, struct lock_stat *st, + const char *sep) +{ + struct lock_key *key; + struct thread *t; + int pid; + + list_for_each_entry(key, &lock_keys, list) { + key->print(key, st); + pr_info("%s ", sep); + } + + switch (aggr_mode) { + case LOCK_AGGR_CALLER: + pr_info("%s%s %s", get_type_str(st->flags), sep, st->name); + if (verbose <= 0) + pr_info("\n"); + break; + case LOCK_AGGR_TASK: + pid = st->addr; + t = perf_session__findnew(session, pid); + pr_info("%d%s %s\n", pid, sep, pid == -1 ? "Unknown" : thread__comm_str(t)); + break; + case LOCK_AGGR_ADDR: + pr_info("%llx%s %s%s %s\n", (unsigned long long)st->addr, sep, + st->name, sep, get_type_name(st->flags)); + break; + default: + break; + } + + if (aggr_mode == LOCK_AGGR_CALLER && verbose > 0) { + struct map *kmap; + struct symbol *sym; + char buf[128]; + u64 ip; + + for (int i = 0; i < max_stack_depth; i++) { + if (!st->callstack || !st->callstack[i]) + break; + + ip = st->callstack[i]; + sym = machine__find_kernel_symbol(con->machine, ip, &kmap); + get_symbol_name_offset(kmap, sym, ip, buf, sizeof(buf)); + pr_info("%s %#lx %s", i ? ":" : sep, (unsigned long) ip, buf); + } + pr_info("\n"); + } +} + +static void print_lock_stat(struct lock_contention *con, struct lock_stat *st) +{ + if (symbol_conf.field_sep) + print_lock_stat_csv(con, st, symbol_conf.field_sep); + else + print_lock_stat_stdio(con, st); +} + +static void print_footer_stdio(int total, int bad, struct lock_contention_fails *fails) { /* Output for debug, this have to be removed */ int broken = fails->task + fails->stack + fails->time + fails->data; + if (!use_bpf) + print_bad_events(bad, total); + if (quiet || total == 0 || (broken == 0 && verbose <= 0)) return; @@ -1646,38 +1820,53 @@ static void print_bpf_events(int total, struct lock_contention_fails *fails) pr_info(" %10s: %d\n", "data", fails->data); } +static void print_footer_csv(int total, int bad, struct lock_contention_fails *fails, + const char *sep) +{ + /* Output for debug, this have to be removed */ + if (use_bpf) + bad = fails->task + fails->stack + fails->time + fails->data; + + if (quiet || total == 0 || (bad == 0 && verbose <= 0)) + return; + + total += bad; + pr_info("# debug: total=%d%s bad=%d", total, sep, bad); + + if (use_bpf) { + pr_info("%s bad_%s=%d", sep, "task", fails->task); + pr_info("%s bad_%s=%d", sep, "stack", fails->stack); + pr_info("%s bad_%s=%d", sep, "time", fails->time); + pr_info("%s bad_%s=%d", sep, "data", fails->data); + } else { + int i; + const char *name[4] = { "acquire", "acquired", "contended", "release" }; + + for (i = 0; i < BROKEN_MAX; i++) + pr_info("%s bad_%s=%d", sep, name[i], bad_hist[i]); + } + pr_info("\n"); +} + +static void print_footer(int total, int bad, struct lock_contention_fails *fails) +{ + if (symbol_conf.field_sep) + print_footer_csv(total, bad, fails, symbol_conf.field_sep); + else + print_footer_stdio(total, bad, fails); +} + static void print_contention_result(struct lock_contention *con) { struct lock_stat *st; - struct lock_key *key; int bad, total, printed; - if (!quiet) { - list_for_each_entry(key, &lock_keys, list) - pr_info("%*s ", key->len, key->header); - - switch (aggr_mode) { - case LOCK_AGGR_TASK: - pr_info(" %10s %s\n\n", "pid", - show_lock_owner ? "owner" : "comm"); - break; - case LOCK_AGGR_CALLER: - pr_info(" %10s %s\n\n", "type", "caller"); - break; - case LOCK_AGGR_ADDR: - pr_info(" %16s %s\n\n", "address", "symbol"); - break; - default: - break; - } - } + if (!quiet) + print_header(); bad = total = printed = 0; while ((st = pop_from_result())) { - struct thread *t; - int pid; - total += use_bpf ? st->nr_contended : 1; if (st->broken) bad++; @@ -1685,45 +1874,7 @@ static void print_contention_result(struct lock_contention *con) if (!st->wait_time_total) continue; - list_for_each_entry(key, &lock_keys, list) { - key->print(key, st); - pr_info(" "); - } - - switch (aggr_mode) { - case LOCK_AGGR_CALLER: - pr_info(" %10s %s\n", get_type_str(st->flags), st->name); - break; - case LOCK_AGGR_TASK: - pid = st->addr; - t = perf_session__findnew(session, pid); - pr_info(" %10d %s\n", - pid, pid == -1 ? "Unknown" : thread__comm_str(t)); - break; - case LOCK_AGGR_ADDR: - pr_info(" %016llx %s (%s)\n", (unsigned long long)st->addr, - st->name, get_type_name(st->flags)); - break; - default: - break; - } - - if (aggr_mode == LOCK_AGGR_CALLER && verbose > 0) { - struct map *kmap; - struct symbol *sym; - char buf[128]; - u64 ip; - - for (int i = 0; i < max_stack_depth; i++) { - if (!st->callstack || !st->callstack[i]) - break; - - ip = st->callstack[i]; - sym = machine__find_kernel_symbol(con->machine, ip, &kmap); - get_symbol_name_offset(kmap, sym, ip, buf, sizeof(buf)); - pr_info("\t\t\t%#lx %s\n", (unsigned long)ip, buf); - } - } + print_lock_stat(con, st); if (++printed >= print_nr_entries) break; @@ -1740,10 +1891,7 @@ static void print_contention_result(struct lock_contention *con) /* some entries are collected but hidden by the callstack filter */ total += con->nr_filtered; - if (use_bpf) - print_bpf_events(total, &con->fails); - else - print_bad_events(bad, total); + print_footer(total, bad, &con->fails); } static bool force; @@ -1847,6 +1995,16 @@ static int check_lock_contention_options(const struct option *options, return -1; } + if (symbol_conf.field_sep) { + if (strstr(symbol_conf.field_sep, ":") || /* part of type flags */ + strstr(symbol_conf.field_sep, "+") || /* part of caller offset */ + strstr(symbol_conf.field_sep, ".")) { /* can be in a symbol name */ + pr_err("Cannot use the separator that is already used\n"); + parse_options_usage(usage, options, "x", 1); + return -1; + } + } + if (show_lock_owner) show_thread_stats = true; @@ -1962,6 +2120,15 @@ static int __cmd_contention(int argc, const char **argv) if (select_key(true)) goto out_delete; + if (symbol_conf.field_sep) { + int i; + struct lock_key *keys = contention_keys; + + /* do not align output in CSV format */ + for (i = 0; keys[i].name; i++) + keys[i].len = 0; + } + if (use_bpf) { lock_contention_start(); if (argc) @@ -2330,6 +2497,8 @@ int cmd_lock(int argc, const char **argv) OPT_CALLBACK('S', "callstack-filter", NULL, "NAMES", "Filter specific function in the callstack", parse_call_stack), OPT_BOOLEAN('o', "lock-owner", &show_lock_owner, "show lock owners instead of waiters"), + OPT_STRING_NOEMPTY('x', "field-separator", &symbol_conf.field_sep, "separator", + "print result in CSV format with custom separator"), OPT_PARENT(lock_options) }; From patchwork Wed Jun 28 20:01:40 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Namhyung Kim X-Patchwork-Id: 114039 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a59:994d:0:b0:3d9:f83d:47d9 with SMTP id k13csp9183566vqr; Wed, 28 Jun 2023 13:15:02 -0700 (PDT) X-Google-Smtp-Source: ACHHUZ4I36cQ3IIELhECnpZAyAeJFYpU+jB2KLMA7YlMJYyyJykMEasuXMQuXjvkdQ/mEeKl8SSt X-Received: by 2002:a05:6a20:7295:b0:111:fba0:bd3b with SMTP id o21-20020a056a20729500b00111fba0bd3bmr43317097pzk.1.1687983302049; Wed, 28 Jun 2023 13:15:02 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1687983302; cv=none; d=google.com; s=arc-20160816; b=lDaCIWyuBZAZeXid57KPeBG/FgU0b88zio0LHp6oyR0xql9TjCUxDtxzuA7CalSel+ IvFjpWnGRoRLpGe5naMh5u0qgiEN4aTJqLWoSguNGMXsAyS9xKuEHpCxfdCCFav/5yZw XzgaLngrNiKx7Y4JVOxMn99scK6RKqX+lYNdxpjGn/pBE+21UfvokgBRfQB6doEbr0OU 2ABfsHJ3amWM+VeF3nznMKS8/GuiWRqQB+qCEurLg2C9zsgF+72EHqW4RptH81NPCI6K lHohHsqYNLdQgRk0uTuLsOY9wv1Q5vvoZvearb89gTHzhbAIt1mlLvEb0T8AmRvrSNaY GSnQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:content-transfer-encoding:mime-version :references:in-reply-to:message-id:date:subject:cc:to:from:sender :dkim-signature; bh=PiWZYv4c06sxae6xC2ziSZRNA4QZoNeA1AhON9n731k=; fh=qg0XpHrrfjSy6nePy3ZLIayRkwEhRnO8Y6NeBhcC42U=; b=OrcB6HygWR+U/9xAuFFezqu5kSuGYcRLPlL4YOcVOATegAeesVEvQcU+mrDPghVT0W ooPii95uvKWvdu5rTVUrNr9i5IycCuWBNWcy198beF927bVidqvU4WnDBpkYIixIEWrI vXoH43BvDh6nXg+Nei5I9kg8SY4BQxd501kLDQcQk0ZLQjLgP4HsTNzVv7J5qAkf+xnZ EktIFmfZ3OSZ57hpJ7Jg8XCwgRmWkAo2ge/3Ep6PBa+EG4W7utMmLPHOUAFtz4Pwtvy3 06QYjveqGvxhVRxhlZUxrazMJGeCyVebpxWwoa8wVoekmDv0zd+ei3OLuHlgdPmz8HVn xhtA== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b="SIX1h/Jb"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id f28-20020a631f1c000000b005578a320ea6si9298285pgf.872.2023.06.28.13.14.49; Wed, 28 Jun 2023 13:15:02 -0700 (PDT) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b="SIX1h/Jb"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S231834AbjF1UCG (ORCPT + 99 others); Wed, 28 Jun 2023 16:02:06 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59418 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S231555AbjF1UBu (ORCPT ); Wed, 28 Jun 2023 16:01:50 -0400 Received: from mail-pf1-x42a.google.com (mail-pf1-x42a.google.com [IPv6:2607:f8b0:4864:20::42a]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id A8C782110; Wed, 28 Jun 2023 13:01:48 -0700 (PDT) Received: by mail-pf1-x42a.google.com with SMTP id d2e1a72fcca58-666eef03ebdso120917b3a.1; Wed, 28 Jun 2023 13:01:48 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20221208; t=1687982508; x=1690574508; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:from:to:cc:subject:date :message-id:reply-to; bh=PiWZYv4c06sxae6xC2ziSZRNA4QZoNeA1AhON9n731k=; b=SIX1h/Jb8fu5N1K7e7gJJ2kt0hKA0VSaJBNwxaPyNAghmGdX64yRxNgXqc145Gq6Zn Q7tUj7op8yPoFEb+GiHPkjHwso/tegnJuMh4Hndgwbhf1HkgYPQa+enWIvW7bM6QI+0z i7aHZhWjcFgphEb+wDE/izT1MGfuERMG/Sgj1KrykFeCFihlAH0ePbIAIFjkEThufgHy QpWq85mkEeX26kPCEDiQ724MDwkytXK0NW2DFa74Nl2ehLv4uW36WcwFqC7c7C8e8Ayd VZyUN2/25oS/QxrqWMtbFFzKSKw+soievxD3vRXjusM/yZ8XgtDN5mj7E34U1pGrdTFI YCKQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1687982508; x=1690574508; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:x-gm-message-state:from :to:cc:subject:date:message-id:reply-to; bh=PiWZYv4c06sxae6xC2ziSZRNA4QZoNeA1AhON9n731k=; b=fc3EdQUBpujJEsE4wACVFHoQf525mnZJnTuQrZ0DI5a8ONiD+c4P7Y1qJU8IqauvQO Ul5fQ4fIhdDBChdb3NgXjo2e2CDoOvGj9DqMdavA1drMkcy/Uklkk7neP5ZZQTcwvOAA lxCCl3uOW3t2xEJJCiew4nIch5je9UgrtyV6ryrSgkoQycdkk3mOzB6sxcKvLZx7hdMW 9qeudcnRhvwNaoaQ6KVQ2pYlFmM0DRJHQ2KBM4xJC45U7OCxObmh6+RFY3emxmMrciH7 xU2h/EJHNrV2kO2VBZ40iFgPRukVbzbUw63IiKBKmzr3vVdeHTc18+z8ZMHLnkSb2vKO Z4ig== X-Gm-Message-State: AC+VfDx1pvG4cG52kyidmrH3/m5dfyONtXnmP6Ws7zvNNxcLrTeKCRea HdYRovJqcsekhv3vMU7bkS4= X-Received: by 2002:a05:6a20:3c89:b0:124:eea9:668d with SMTP id b9-20020a056a203c8900b00124eea9668dmr17069108pzj.40.1687982507844; Wed, 28 Jun 2023 13:01:47 -0700 (PDT) Received: from bangji.corp.google.com ([2620:15c:2c0:5:fc6b:e50c:c8f0:b09b]) by smtp.gmail.com with ESMTPSA id f3-20020aa78b03000000b0065e154bac6dsm7340376pfd.133.2023.06.28.13.01.46 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 28 Jun 2023 13:01:47 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ian Rogers , Adrian Hunter , Peter Zijlstra , Ingo Molnar , LKML , linux-perf-users@vger.kernel.org, Song Liu , Hao Luo Subject: [PATCH 3/4] perf lock contention: Add --output option Date: Wed, 28 Jun 2023 13:01:40 -0700 Message-ID: <20230628200141.2739587-4-namhyung@kernel.org> X-Mailer: git-send-email 2.41.0.255.g8b1d071c50-goog In-Reply-To: <20230628200141.2739587-1-namhyung@kernel.org> References: <20230628200141.2739587-1-namhyung@kernel.org> MIME-Version: 1.0 X-Spam-Status: No, score=-1.5 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_EF,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE, SPF_PASS,T_SCC_BODY_TEXT_LINE,URIBL_BLOCKED autolearn=no autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?= X-GMAIL-THRID: =?utf-8?q?1769978778643233404?= X-GMAIL-MSGID: =?utf-8?q?1769978778643233404?= To avoid formatting failures for example in CSV output due to debug messages, add --output option to put the result in a file. Unfortunately the short -o option was taken by the --owner already. $ sudo ./perf lock con -ab --output lock-out.txt -v sleep 1 Looking at the vmlinux_path (8 entries long) symsrc__init: cannot get elf header. Using /proc/kcore for kernel data Using /proc/kallsyms for symbols $ head lock-out.txt contended total wait max wait avg wait type caller 3 76.79 us 26.89 us 25.60 us rwlock:R ep_poll_callback+0x2d 0xffffffff9a23f4b5 _raw_read_lock_irqsave+0x45 0xffffffff99bbd4dd ep_poll_callback+0x2d 0xffffffff999029f3 __wake_up_common+0x73 0xffffffff99902b82 __wake_up_common_lock+0x82 0xffffffff99fa5b1c sock_def_readable+0x3c 0xffffffff9a11521d unix_stream_sendmsg+0x18d 0xffffffff99f9fc9c sock_sendmsg+0x5c Suggested-by: Ian Rogers Signed-off-by: Namhyung Kim Acked-by: Ian Rogers --- tools/perf/Documentation/perf-lock.txt | 3 + tools/perf/builtin-lock.c | 140 +++++++++++++++---------- 2 files changed, 85 insertions(+), 58 deletions(-) diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentation/perf-lock.txt index d1efcbe7a470..30eea576721f 100644 --- a/tools/perf/Documentation/perf-lock.txt +++ b/tools/perf/Documentation/perf-lock.txt @@ -36,6 +36,9 @@ COMMON OPTIONS --input=:: Input file name. (default: perf.data unless stdin is a fifo) +--output=:: + Output file name for perf lock contention and report. + -v:: --verbose:: Be more verbose (show symbol address, etc). diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 98b0c0b1b307..c15386cb1033 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -27,6 +27,7 @@ #include "util/map.h" #include "util/util.h" +#include #include #include #include @@ -65,6 +66,8 @@ static int max_stack_depth = CONTENTION_STACK_DEPTH; static int stack_skip = CONTENTION_STACK_SKIP; static int print_nr_entries = INT_MAX / 2; static LIST_HEAD(callstack_filters); +static const char *output_name = NULL; +static FILE *lock_output; struct callstack_filter { struct list_head list; @@ -227,7 +230,7 @@ static void lock_stat_key_print_time(unsigned long long nsec, int len) /* for CSV output */ if (len == 0) { - pr_info("%llu", nsec); + fprintf(lock_output, "%llu", nsec); return; } @@ -235,18 +238,18 @@ static void lock_stat_key_print_time(unsigned long long nsec, int len) if (nsec < table[i].base) continue; - pr_info("%*.2f %s", len - 3, nsec / table[i].base, table[i].unit); + fprintf(lock_output, "%*.2f %s", len - 3, nsec / table[i].base, table[i].unit); return; } - pr_info("%*llu %s", len - 3, nsec, "ns"); + fprintf(lock_output, "%*llu %s", len - 3, nsec, "ns"); } #define PRINT_KEY(member) \ static void lock_stat_key_print_ ## member(struct lock_key *key, \ struct lock_stat *ls) \ { \ - pr_info("%*llu", key->len, (unsigned long long)ls->member); \ + fprintf(lock_output, "%*llu", key->len, (unsigned long long)ls->member);\ } #define PRINT_TIME(member) \ @@ -1335,12 +1338,12 @@ static void print_bad_events(int bad, int total) if (quiet || total == 0 || (broken == 0 && verbose <= 0)) return; - pr_info("\n=== output for debug ===\n\n"); - pr_info("bad: %d, total: %d\n", bad, total); - pr_info("bad rate: %.2f %%\n", (double)bad / (double)total * 100); - pr_info("histogram of events caused bad sequence\n"); + fprintf(lock_output, "\n=== output for debug ===\n\n"); + fprintf(lock_output, "bad: %d, total: %d\n", bad, total); + fprintf(lock_output, "bad rate: %.2f %%\n", (double)bad / (double)total * 100); + fprintf(lock_output, "histogram of events caused bad sequence\n"); for (i = 0; i < BROKEN_MAX; i++) - pr_info(" %10s: %d\n", name[i], bad_hist[i]); + fprintf(lock_output, " %10s: %d\n", name[i], bad_hist[i]); } /* TODO: various way to print, coloring, nano or milli sec */ @@ -1352,10 +1355,10 @@ static void print_result(void) int bad, total, printed; if (!quiet) { - pr_info("%20s ", "Name"); + fprintf(lock_output, "%20s ", "Name"); list_for_each_entry(key, &lock_keys, list) - pr_info("%*s ", key->len, key->header); - pr_info("\n\n"); + fprintf(lock_output, "%*s ", key->len, key->header); + fprintf(lock_output, "\n\n"); } bad = total = printed = 0; @@ -1380,7 +1383,7 @@ static void print_result(void) name = thread__comm_str(t); } - pr_info("%20s ", name); + fprintf(lock_output, "%20s ", name); } else { strncpy(cut_name, st->name, 16); cut_name[16] = '.'; @@ -1388,14 +1391,14 @@ static void print_result(void) cut_name[18] = '.'; cut_name[19] = '\0'; /* cut off name for saving output style */ - pr_info("%20s ", cut_name); + fprintf(lock_output, "%20s ", cut_name); } list_for_each_entry(key, &lock_keys, list) { key->print(key, st); - pr_info(" "); + fprintf(lock_output, " "); } - pr_info("\n"); + fprintf(lock_output, "\n"); if (++printed >= print_nr_entries) break; @@ -1412,13 +1415,13 @@ static void dump_threads(void) struct rb_node *node; struct thread *t; - pr_info("%10s: comm\n", "Thread ID"); + fprintf(lock_output, "%10s: comm\n", "Thread ID"); node = rb_first(&thread_stats); while (node) { st = container_of(node, struct thread_stat, rb); t = perf_session__findnew(session, st->tid); - pr_info("%10d: %s\n", st->tid, thread__comm_str(t)); + fprintf(lock_output, "%10d: %s\n", st->tid, thread__comm_str(t)); node = rb_next(node); thread__put(t); } @@ -1444,7 +1447,7 @@ static void dump_map(void) unsigned int i; struct lock_stat *st; - pr_info("Address of instance: name of class\n"); + fprintf(lock_output, "Address of instance: name of class\n"); for (i = 0; i < LOCKHASH_SIZE; i++) { hlist_for_each_entry(st, &lockhash_table[i], hash_entry) { insert_to_result(st, compare_maps); @@ -1452,7 +1455,7 @@ static void dump_map(void) } while ((st = pop_from_result())) - pr_info(" %#llx: %s\n", (unsigned long long)st->addr, st->name); + fprintf(lock_output, " %#llx: %s\n", (unsigned long long)st->addr, st->name); } static int dump_info(void) @@ -1637,18 +1640,18 @@ static void print_header_stdio(void) struct lock_key *key; list_for_each_entry(key, &lock_keys, list) - pr_info("%*s ", key->len, key->header); + fprintf(lock_output, "%*s ", key->len, key->header); switch (aggr_mode) { case LOCK_AGGR_TASK: - pr_info(" %10s %s\n\n", "pid", + fprintf(lock_output, " %10s %s\n\n", "pid", show_lock_owner ? "owner" : "comm"); break; case LOCK_AGGR_CALLER: - pr_info(" %10s %s\n\n", "type", "caller"); + fprintf(lock_output, " %10s %s\n\n", "type", "caller"); break; case LOCK_AGGR_ADDR: - pr_info(" %16s %s\n\n", "address", "symbol"); + fprintf(lock_output, " %16s %s\n\n", "address", "symbol"); break; default: break; @@ -1659,23 +1662,23 @@ static void print_header_csv(const char *sep) { struct lock_key *key; - pr_info("# output: "); + fprintf(lock_output, "# output: "); list_for_each_entry(key, &lock_keys, list) - pr_info("%s%s ", key->header, sep); + fprintf(lock_output, "%s%s ", key->header, sep); switch (aggr_mode) { case LOCK_AGGR_TASK: - pr_info("%s%s %s\n", "pid", sep, + fprintf(lock_output, "%s%s %s\n", "pid", sep, show_lock_owner ? "owner" : "comm"); break; case LOCK_AGGR_CALLER: - pr_info("%s%s %s", "type", sep, "caller"); + fprintf(lock_output, "%s%s %s", "type", sep, "caller"); if (verbose > 0) - pr_info("%s %s", sep, "stacktrace"); - pr_info("\n"); + fprintf(lock_output, "%s %s", sep, "stacktrace"); + fprintf(lock_output, "\n"); break; case LOCK_AGGR_ADDR: - pr_info("%s%s %s%s %s\n", "address", sep, "symbol", sep, "type"); + fprintf(lock_output, "%s%s %s%s %s\n", "address", sep, "symbol", sep, "type"); break; default: break; @@ -1700,21 +1703,21 @@ static void print_lock_stat_stdio(struct lock_contention *con, struct lock_stat list_for_each_entry(key, &lock_keys, list) { key->print(key, st); - pr_info(" "); + fprintf(lock_output, " "); } switch (aggr_mode) { case LOCK_AGGR_CALLER: - pr_info(" %10s %s\n", get_type_str(st->flags), st->name); + fprintf(lock_output, " %10s %s\n", get_type_str(st->flags), st->name); break; case LOCK_AGGR_TASK: pid = st->addr; t = perf_session__findnew(session, pid); - pr_info(" %10d %s\n", + fprintf(lock_output, " %10d %s\n", pid, pid == -1 ? "Unknown" : thread__comm_str(t)); break; case LOCK_AGGR_ADDR: - pr_info(" %016llx %s (%s)\n", (unsigned long long)st->addr, + fprintf(lock_output, " %016llx %s (%s)\n", (unsigned long long)st->addr, st->name, get_type_name(st->flags)); break; default: @@ -1734,7 +1737,7 @@ static void print_lock_stat_stdio(struct lock_contention *con, struct lock_stat ip = st->callstack[i]; sym = machine__find_kernel_symbol(con->machine, ip, &kmap); get_symbol_name_offset(kmap, sym, ip, buf, sizeof(buf)); - pr_info("\t\t\t%#lx %s\n", (unsigned long)ip, buf); + fprintf(lock_output, "\t\t\t%#lx %s\n", (unsigned long)ip, buf); } } } @@ -1748,22 +1751,23 @@ static void print_lock_stat_csv(struct lock_contention *con, struct lock_stat *s list_for_each_entry(key, &lock_keys, list) { key->print(key, st); - pr_info("%s ", sep); + fprintf(lock_output, "%s ", sep); } switch (aggr_mode) { case LOCK_AGGR_CALLER: - pr_info("%s%s %s", get_type_str(st->flags), sep, st->name); + fprintf(lock_output, "%s%s %s", get_type_str(st->flags), sep, st->name); if (verbose <= 0) - pr_info("\n"); + fprintf(lock_output, "\n"); break; case LOCK_AGGR_TASK: pid = st->addr; t = perf_session__findnew(session, pid); - pr_info("%d%s %s\n", pid, sep, pid == -1 ? "Unknown" : thread__comm_str(t)); + fprintf(lock_output, "%d%s %s\n", pid, sep, + pid == -1 ? "Unknown" : thread__comm_str(t)); break; case LOCK_AGGR_ADDR: - pr_info("%llx%s %s%s %s\n", (unsigned long long)st->addr, sep, + fprintf(lock_output, "%llx%s %s%s %s\n", (unsigned long long)st->addr, sep, st->name, sep, get_type_name(st->flags)); break; default: @@ -1783,9 +1787,9 @@ static void print_lock_stat_csv(struct lock_contention *con, struct lock_stat *s ip = st->callstack[i]; sym = machine__find_kernel_symbol(con->machine, ip, &kmap); get_symbol_name_offset(kmap, sym, ip, buf, sizeof(buf)); - pr_info("%s %#lx %s", i ? ":" : sep, (unsigned long) ip, buf); + fprintf(lock_output, "%s %#lx %s", i ? ":" : sep, (unsigned long) ip, buf); } - pr_info("\n"); + fprintf(lock_output, "\n"); } } @@ -1809,15 +1813,15 @@ static void print_footer_stdio(int total, int bad, struct lock_contention_fails return; total += broken; - pr_info("\n=== output for debug ===\n\n"); - pr_info("bad: %d, total: %d\n", broken, total); - pr_info("bad rate: %.2f %%\n", (double)broken / (double)total * 100); + fprintf(lock_output, "\n=== output for debug ===\n\n"); + fprintf(lock_output, "bad: %d, total: %d\n", broken, total); + fprintf(lock_output, "bad rate: %.2f %%\n", 100.0 * broken / total); - pr_info("histogram of failure reasons\n"); - pr_info(" %10s: %d\n", "task", fails->task); - pr_info(" %10s: %d\n", "stack", fails->stack); - pr_info(" %10s: %d\n", "time", fails->time); - pr_info(" %10s: %d\n", "data", fails->data); + fprintf(lock_output, "histogram of failure reasons\n"); + fprintf(lock_output, " %10s: %d\n", "task", fails->task); + fprintf(lock_output, " %10s: %d\n", "stack", fails->stack); + fprintf(lock_output, " %10s: %d\n", "time", fails->time); + fprintf(lock_output, " %10s: %d\n", "data", fails->data); } static void print_footer_csv(int total, int bad, struct lock_contention_fails *fails, @@ -1831,21 +1835,21 @@ static void print_footer_csv(int total, int bad, struct lock_contention_fails *f return; total += bad; - pr_info("# debug: total=%d%s bad=%d", total, sep, bad); + fprintf(lock_output, "# debug: total=%d%s bad=%d", total, sep, bad); if (use_bpf) { - pr_info("%s bad_%s=%d", sep, "task", fails->task); - pr_info("%s bad_%s=%d", sep, "stack", fails->stack); - pr_info("%s bad_%s=%d", sep, "time", fails->time); - pr_info("%s bad_%s=%d", sep, "data", fails->data); + fprintf(lock_output, "%s bad_%s=%d", sep, "task", fails->task); + fprintf(lock_output, "%s bad_%s=%d", sep, "stack", fails->stack); + fprintf(lock_output, "%s bad_%s=%d", sep, "time", fails->time); + fprintf(lock_output, "%s bad_%s=%d", sep, "data", fails->data); } else { int i; const char *name[4] = { "acquire", "acquired", "contended", "release" }; for (i = 0; i < BROKEN_MAX; i++) - pr_info("%s bad_%s=%d", sep, name[i], bad_hist[i]); + fprintf(lock_output, "%s bad_%s=%d", sep, name[i], bad_hist[i]); } - pr_info("\n"); + fprintf(lock_output, "\n"); } static void print_footer(int total, int bad, struct lock_contention_fails *fails) @@ -2427,10 +2431,29 @@ static int parse_call_stack(const struct option *opt __maybe_unused, const char return ret; } +static int parse_output(const struct option *opt __maybe_unused, const char *str, + int unset __maybe_unused) +{ + const char **name = (const char **)opt->value; + + if (str == NULL) + return -1; + + lock_output = fopen(str, "w"); + if (lock_output == NULL) { + pr_err("Cannot open %s\n", str); + return -1; + } + + *name = str; + return 0; +} + int cmd_lock(int argc, const char **argv) { const struct option lock_options[] = { OPT_STRING('i', "input", &input_name, "file", "input file name"), + OPT_CALLBACK(0, "output", &output_name, "file", "output file name", parse_output), OPT_INCR('v', "verbose", &verbose, "be more verbose (show symbol address, etc)"), OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, "dump raw trace in ASCII"), OPT_BOOLEAN('f', "force", &force, "don't complain, do it"), @@ -2530,6 +2553,7 @@ int cmd_lock(int argc, const char **argv) for (i = 0; i < LOCKHASH_SIZE; i++) INIT_HLIST_HEAD(lockhash_table + i); + lock_output = stderr; argc = parse_options_subcommand(argc, argv, lock_options, lock_subcommands, lock_usage, PARSE_OPT_STOP_AT_NON_OPTION); if (!argc) From patchwork Wed Jun 28 20:01:41 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Namhyung Kim X-Patchwork-Id: 114038 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a59:994d:0:b0:3d9:f83d:47d9 with SMTP id k13csp9182364vqr; Wed, 28 Jun 2023 13:12:33 -0700 (PDT) X-Google-Smtp-Source: ACHHUZ5v4CSMGUppK6TZ2ubIeCYK+6I4YfFW0V7Y2cOghLe1vo/iDHQToJiMKkBjBZuCmbesGKXp X-Received: by 2002:a05:6a20:4405:b0:11f:985e:ae2c with SMTP id ce5-20020a056a20440500b0011f985eae2cmr853721pzb.3.1687983153313; Wed, 28 Jun 2023 13:12:33 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1687983153; cv=none; d=google.com; s=arc-20160816; b=gaBtDNl3kyqJqD8S5/zevQs6xSXIrm1eEUk5VsZq0oZ7okVW6GdkYiXMdoMHr8Htgl Ey4DomDR6nfA6GMt3cwM0To/z4JYTn125EvO0YaTjHdwfb1B4le/w1aJsQJDuKlt2AXU zPyp09qvktCLV57o8czw9f1VWEA+x9+J30VkFdCWoRt90m+22W6h2cqWpWQ/tIcVeJV4 C9aHa3pfC23QwnsJoExBGmvfB6gyU2pAKh7//Bud0/R6bNMiO7IukweHuiTyohw98ZTt ev9X/KWv/jq9SiE2S0Bkeh9t6QQ3xwCcRIsn2KX/aVCmtM1n2NsXpfvBynfOeICDzQkI A6yQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:content-transfer-encoding:mime-version :references:in-reply-to:message-id:date:subject:cc:to:from:sender :dkim-signature; bh=BVELursx7ZDvBYQWp0incqgL1857WVtGQabwOfefQSc=; fh=qg0XpHrrfjSy6nePy3ZLIayRkwEhRnO8Y6NeBhcC42U=; b=kXYFdsOZgREpaud8dyt3rkNEqX7BK6QgMSKjmyhzWmE9XVPP9kVICiO0iQiT5/bFtS DRID4Ppy/a+X69wF5UqiUlp9MREX8zQ/szVInTScmqIOajgxxRabvHioDuo4SUQK1F81 ZbcNyNAuDjWvq0NMvk/TGt3Us7WqoyDd0SDSqt6Ief11aQALOhwzWtDLPcTiMD1/MoPL +OTyVb4g3qjw8IQR/+iabXA6OelvX33Tf5o76+FDbB/c2yrg1d0/yxdAYGYEbV+czaOH UpIrJPzObXZPmjtDJ2G0EaGaaDS9HbhilLPXb4verQ9z/lrp303Zu0PzjanQoA3F+NN9 Qh+g== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b="gN/lr8Ub"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id e192-20020a6369c9000000b00557531eafafsi9127193pgc.192.2023.06.28.13.12.20; Wed, 28 Jun 2023 13:12:33 -0700 (PDT) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; dkim=pass header.i=@gmail.com header.s=20221208 header.b="gN/lr8Ub"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S231614AbjF1UCJ (ORCPT + 99 others); Wed, 28 Jun 2023 16:02:09 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:59406 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S230260AbjF1UBu (ORCPT ); Wed, 28 Jun 2023 16:01:50 -0400 Received: from mail-pf1-x42a.google.com (mail-pf1-x42a.google.com [IPv6:2607:f8b0:4864:20::42a]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id C3FE51FE7; Wed, 28 Jun 2023 13:01:49 -0700 (PDT) Received: by mail-pf1-x42a.google.com with SMTP id d2e1a72fcca58-666ed230c81so151873b3a.0; Wed, 28 Jun 2023 13:01:49 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20221208; t=1687982509; x=1690574509; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:from:to:cc:subject:date :message-id:reply-to; bh=BVELursx7ZDvBYQWp0incqgL1857WVtGQabwOfefQSc=; b=gN/lr8UbwiJrrDE/KxtTTHGo8Y4o30+B6GIfeY7nBFzojGAOptzHMWWBaICsjeydhJ uJ4On3ApMAVXjXLmYWNeCIY9dBzWUCUxmdbq+N8FgOEPi/cTuMHmBxn7fqrrkcpSLIeC /0aVTVoQQMcEDP9htZcY1zQBA5Y6kO6Kc+4T62CICo69fcZd1TGuFxJ8yHttMopBfJty TRXh/CQWSyFbUY8RSiYh2k2zk9yWpLEsPds0cUB/xa4KivQlnO95lIuAXZyh0YlULULn VJTT+JM1xqEyFkhBgjmuGvd+7BegufSJ5JQW9mIr82B0g8dRnNLOIXVuDKNbTcOwOX1K XmCw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1687982509; x=1690574509; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:sender:x-gm-message-state:from :to:cc:subject:date:message-id:reply-to; bh=BVELursx7ZDvBYQWp0incqgL1857WVtGQabwOfefQSc=; b=lcPutIIZxIUUkr3zKNwLpHWI7AeckIOLv9w9qkQj0xn8Z+MgUS7lfjc5ZQV8R6NraF 8C6o/H+0RF5CLcUCKzoTKH4zBcpDrPEoADGt5eKGrl2TrVhqY9W9aSdxz0XSTLt/KKMn scGIPXXx85vpsXp3geM/UUCUZNOBdU1x2GJQ5wv8uS58+Diq6Br8QWGMw6qRQztiAf4/ ut99S5+uMKgYwjT/50CR22JFatOOhyCeYxRpKIJrH74yP6S2PmChMc0xoHjEhUj3fEJJ bGcun6p+KWQKnsleCeaYztqBJ8uQpS1e6VRJQKvaRVGE7X7Ebyf6uB7ubNSmsOvb33wR 1cxg== X-Gm-Message-State: AC+VfDxEfCLscvfZpm2kRGnz7WwnWkMeITe0zU0cs7tPlQuuYtn0hjoI RNTcRWmLZXdTDBoEwwo57Vj/lOi33VE= X-Received: by 2002:a05:6a00:1504:b0:668:7325:e184 with SMTP id q4-20020a056a00150400b006687325e184mr39037691pfu.16.1687982509139; Wed, 28 Jun 2023 13:01:49 -0700 (PDT) Received: from bangji.corp.google.com ([2620:15c:2c0:5:fc6b:e50c:c8f0:b09b]) by smtp.gmail.com with ESMTPSA id f3-20020aa78b03000000b0065e154bac6dsm7340376pfd.133.2023.06.28.13.01.48 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 28 Jun 2023 13:01:48 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ian Rogers , Adrian Hunter , Peter Zijlstra , Ingo Molnar , LKML , linux-perf-users@vger.kernel.org, Song Liu , Hao Luo Subject: [PATCH 4/4] perf test: Test perf lock contention CSV output Date: Wed, 28 Jun 2023 13:01:41 -0700 Message-ID: <20230628200141.2739587-5-namhyung@kernel.org> X-Mailer: git-send-email 2.41.0.255.g8b1d071c50-goog In-Reply-To: <20230628200141.2739587-1-namhyung@kernel.org> References: <20230628200141.2739587-1-namhyung@kernel.org> MIME-Version: 1.0 X-Spam-Status: No, score=-1.5 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_EF,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE, SPF_PASS,T_SCC_BODY_TEXT_LINE autolearn=no autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?= X-GMAIL-THRID: =?utf-8?q?1769978623304147728?= X-GMAIL-MSGID: =?utf-8?q?1769978623304147728?= To verify CSV output, just check the number of separators (",") using the tr and wc commands like this. grep -v "^#" ${result} | tr -d -c | wc -c Now it expects 6 columns (and 5 separators) in the output, but it may be changed later so count the field in the header first and compare it to the actual output lines. $ cat ${result} # output: contended, total wait, max wait, avg wait, type, caller 1, 28787, 28787, 28787, spinlock, raw_spin_rq_lock_nested+0x1b The test looks like below now: $ sudo ./perf test -v contention 86: kernel lock contention analysis test : --- start --- test child forked, pid 2705822 Testing perf lock record and perf lock contention Testing perf lock contention --use-bpf Testing perf lock record and perf lock contention at the same time Testing perf lock contention --threads Testing perf lock contention --lock-addr Testing perf lock contention --type-filter (w/ spinlock) Testing perf lock contention --lock-filter (w/ tasklist_lock) Testing perf lock contention --callstack-filter (w/ unix_stream) Testing perf lock contention --callstack-filter with task aggregation Testing perf lock contention CSV output test child finished with 0 ---- end ---- kernel lock contention analysis test: Ok Signed-off-by: Namhyung Kim Acked-by: Ian Rogers --- tools/perf/tests/shell/lock_contention.sh | 36 +++++++++++++++++++++++ 1 file changed, 36 insertions(+) diff --git a/tools/perf/tests/shell/lock_contention.sh b/tools/perf/tests/shell/lock_contention.sh index f2cc187b6186..4a194420416e 100755 --- a/tools/perf/tests/shell/lock_contention.sh +++ b/tools/perf/tests/shell/lock_contention.sh @@ -233,6 +233,41 @@ test_aggr_task_stack_filter() fi } +test_csv_output() +{ + echo "Testing perf lock contention CSV output" + perf lock contention -i ${perfdata} -E 1 -x , --output ${result} + # count the number of commas in the header + # it should have 5: contended, total-wait, max-wait, avg-wait, type, caller + header=$(grep "# output:" ${result} | tr -d -c , | wc -c) + if [ "${header}" != "5" ]; then + echo "[Fail] Recorded result does not have enough output columns: ${header} != 5" + err=1 + exit + fi + # count the number of commas in the output + output=$(grep -v "^#" ${result} | tr -d -c , | wc -c) + if [ "${header}" != "${output}" ]; then + echo "[Fail] Recorded result does not match the number of commas: ${header} != ${output}" + err=1 + exit + fi + + if ! perf lock con -b true > /dev/null 2>&1 ; then + echo "[Skip] No BPF support" + return + fi + + # the perf lock contention output goes to the stderr + perf lock con -a -b -E 1 -x , --output ${result} -- perf bench sched messaging > /dev/null 2>&1 + output=$(grep -v "^#" ${result} | tr -d -c , | wc -c) + if [ "${header}" != "${output}" ]; then + echo "[Fail] BPF result does not match the number of commas: ${header} != ${output}" + err=1 + exit + fi +} + check test_record @@ -244,5 +279,6 @@ test_type_filter test_lock_filter test_stack_filter test_aggr_task_stack_filter +test_csv_output exit ${err}