From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id A71A5C43334 for ; Thu, 9 Jun 2022 05:57:01 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S237848AbiFIF47 (ORCPT ); Thu, 9 Jun 2022 01:56:59 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50288 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S236830AbiFIF45 (ORCPT ); Thu, 9 Jun 2022 01:56:57 -0400 Received: from mail-pf1-x429.google.com (mail-pf1-x429.google.com [IPv6:2607:f8b0:4864:20::429]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 332122AC5B; Wed, 8 Jun 2022 22:56:56 -0700 (PDT) Received: by mail-pf1-x429.google.com with SMTP id y196so20200250pfb.6; Wed, 08 Jun 2022 22:56:56 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=m0eyMgwIk3CPtPFDkJwbRK4xZhRS0F0NmwDS3qIiC7U=; b=TzgG5VqfYuCYVvUCv6XhOkxOnAu75fHbbbLfYh4fbXKwGqbZtZSdzN+wLtCKGd32YJ aay+C94a8bsfv8u3ZwTMlPn17tjTBQAskqkqAcRjiXvWsKzdKItc41yUUEa2MpKNyDNj Fg97Rcb5ardzecWBV7k3C1HlX/+7bkrlUyhps/s9msTEWvOrLkaxSMQGwdZaQKm77fqn 3j49U3hbvj4Dip1+pszEDaufA6/bKG1bIpjpMcJ62cUvgzl94QD7IjTJ/k+r4BpSOQ0C Wttde7cuQ7q8C9CzErM797sQgVw7nEfOVNpp+o92CF071foYrjMQu2jq/rJzVOhV7WMa YOqQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=m0eyMgwIk3CPtPFDkJwbRK4xZhRS0F0NmwDS3qIiC7U=; b=JZxAFDwb40AgYCvEGzT9LSvFMf6fqmmy4wfT1EUCIC1eIdv3yZzEQFR2MBa4r5Djlj PIL1rJw7IY/aQ0XOX4OGIZdRrEunErGUkE/+k3B6Qli3q5RpUYiChbg0YLERqHJqkqs+ KKGIpQlR/OZ5BDM3C4t/wUDHHLtT804IWUdxQU7cscMkq+B2jQt1fmzYTTP6jeK88J4M WOffdQI7SLPjU7nh1A2KkNbY7td38eBcJk2JRMLTM1Nu+oYs4o6ZIDEDZbH+/Jmc4UDV 513/y2SyV4OF5nFsO8Ph+MIoHgZnWcvsb1LD9pXMzCei6wCldHaJ1WojlCKiuPqY0FYh /D/g== X-Gm-Message-State: AOAM532nn5HU5MxZDnnW30oKgOKF6IFKTDdMKn5TF9avVKE959Eu5bSl oRWb4Yiusr35wWBHQdcEsYWgJuuohPYqow== X-Google-Smtp-Source: ABdhPJxS1vEgV2iXzVy2mU3BLc4te2TrAxkypg1G+0tcT/wXmqVzkDCXIDqewKFHi2IjRyNNH2MkKg== X-Received: by 2002:a05:6a00:855:b0:51c:27dc:b5c0 with SMTP id q21-20020a056a00085500b0051c27dcb5c0mr16768481pfk.47.1654754215606; Wed, 08 Jun 2022 22:56:55 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.56.54 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:56:55 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 1/7] perf lock: Print wait times with unit Date: Wed, 8 Jun 2022 22:56:46 -0700 Message-Id: <20220609055652.938821-2-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" Currently it only prints the time in nsec but it's a bit hard to read and takes longer in the screen. We can change it to use different units and keep the number small to save the space. Before: $ perf lock report Name acquired contended avg wait (ns) total wait (ns) = max wait (ns) min wait (ns) jiffies_lock 433 32 2778 88908 = 13570 692 &lruvec->lru_lock 747 5 11254 56272 = 18317 1412 slock-AF_INET6 7 1 23543 23543 = 23543 23543 &newf->file_lock 706 15 1025 15388 = 2279 618 slock-AF_INET6 8 1 10379 10379 = 10379 10379 &rq->__lock 2143 5 2037 10185 = 3462 939 After: Name acquired contended avg wait total wait ma= x wait min wait jiffies_lock 433 32 2.78 us 88.91 us 13= .57 us 692 ns &lruvec->lru_lock 747 5 11.25 us 56.27 us 18= .32 us 1.41 us slock-AF_INET6 7 1 23.54 us 23.54 us 23= .54 us 23.54 us &newf->file_lock 706 15 1.02 us 15.39 us 2= .28 us 618 ns slock-AF_INET6 8 1 10.38 us 10.38 us 10= .38 us 10.38 us &rq->__lock 2143 5 2.04 us 10.19 us 3= .46 us 939 ns Signed-off-by: Namhyung Kim --- tools/perf/builtin-lock.c | 48 ++++++++++++++++++++++++++++++++------- 1 file changed, 40 insertions(+), 8 deletions(-) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 23a33ac15e68..57e396323d05 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -251,6 +251,31 @@ struct lock_key { struct list_head list; }; =20 +static void lock_stat_key_print_time(unsigned long long nsec, int len) +{ + static const struct { + float base; + const char *unit; + } table[] =3D { + { 1e9 * 3600, "h " }, + { 1e9 * 60, "m " }, + { 1e9, "s " }, + { 1e6, "ms" }, + { 1e3, "us" }, + { 0, NULL }, + }; + + for (int i =3D 0; table[i].unit; i++) { + if (nsec < table[i].base) + continue; + + pr_info("%*.2f %s", len - 3, nsec / table[i].base, table[i].unit); + return; + } + + pr_info("%*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) \ @@ -258,11 +283,18 @@ static void lock_stat_key_print_ ## member(struct loc= k_key *key, \ pr_info("%*llu", key->len, (unsigned long long)ls->member); \ } =20 +#define PRINT_TIME(member) \ +static void lock_stat_key_print_ ## member(struct lock_key *key, \ + struct lock_stat *ls) \ +{ \ + lock_stat_key_print_time((unsigned long long)ls->member, key->len); \ +} + PRINT_KEY(nr_acquired) PRINT_KEY(nr_contended) -PRINT_KEY(avg_wait_time) -PRINT_KEY(wait_time_total) -PRINT_KEY(wait_time_max) +PRINT_TIME(avg_wait_time) +PRINT_TIME(wait_time_total) +PRINT_TIME(wait_time_max) =20 static void lock_stat_key_print_wait_time_min(struct lock_key *key, struct lock_stat *ls) @@ -272,7 +304,7 @@ static void lock_stat_key_print_wait_time_min(struct lo= ck_key *key, if (wait_time =3D=3D ULLONG_MAX) wait_time =3D 0; =20 - pr_info("%*"PRIu64, key->len, wait_time); + lock_stat_key_print_time(wait_time, key->len); } =20 =20 @@ -291,10 +323,10 @@ static const char *output_fields; struct lock_key keys[] =3D { DEF_KEY_LOCK(acquired, "acquired", nr_acquired, 10), DEF_KEY_LOCK(contended, "contended", nr_contended, 10), - DEF_KEY_LOCK(avg_wait, "avg wait (ns)", avg_wait_time, 15), - DEF_KEY_LOCK(wait_total, "total wait (ns)", wait_time_total, 15), - DEF_KEY_LOCK(wait_max, "max wait (ns)", wait_time_max, 15), - DEF_KEY_LOCK(wait_min, "min wait (ns)", wait_time_min, 15), + DEF_KEY_LOCK(avg_wait, "avg wait", avg_wait_time, 12), + DEF_KEY_LOCK(wait_total, "total wait", wait_time_total, 12), + DEF_KEY_LOCK(wait_max, "max wait", wait_time_max, 12), + DEF_KEY_LOCK(wait_min, "min wait", wait_time_min, 12), =20 /* extra comparisons much complicated should be here */ { } --=20 2.36.1.255.ge46751e96f-goog From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 2969FC43334 for ; Thu, 9 Jun 2022 05:57:09 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S238612AbiFIF5I (ORCPT ); Thu, 9 Jun 2022 01:57:08 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50322 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S230157AbiFIF46 (ORCPT ); Thu, 9 Jun 2022 01:56:58 -0400 Received: from mail-pl1-x62c.google.com (mail-pl1-x62c.google.com [IPv6:2607:f8b0:4864:20::62c]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 2889C23BE4; Wed, 8 Jun 2022 22:56:57 -0700 (PDT) Received: by mail-pl1-x62c.google.com with SMTP id r1so2207526plo.10; Wed, 08 Jun 2022 22:56:57 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=wmb76XFaytNa5GMenz/Iq3bisUs3tEEphpm082+YSy8=; b=mmoLHQHn6q9tnQoEFtbD5bA1Q4oFUIj4+9TCOiDkIAftRVzLuW9SU7sTZY/1zcBCkP FKzd7URLYshYZhCWyEGguaxF/cl2aqGMeUj1OiiPnnuErji/6KSK0lgi/Bsgu6FN0Quf h/ldtpyhhYWaIcrIiWQl+f7RHe7jf2nuqYRaTobL9VvliqpWQqADN6XEXafdYUhpf4T+ 4M7iBpKWPL2LJ4wA4BdCWV5RIzGml1lvBqEd1yp88GBk1ITUZUiUHXpZIQmfBiAnxbLZ f/KCeR6m5y3v3KlGbED/z66XQX8lZeCAarDSuLxqZE6s/bURjf2mJSisp5jknUAMkKG4 F0BQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=wmb76XFaytNa5GMenz/Iq3bisUs3tEEphpm082+YSy8=; b=qTr3sYfTmbMG5MZZ7j2jhjO+dWwKA52C539MvmrPsAk5++SX1tHvDhmPBAbit3/bfd vxm0wPQTrNVT98qGal/LDC6PqiIyi1cL1lUp1XRRTmkuUXTzs7ULlaF7GwExLpiLmAmP XIEKcI8/s1heefmNIN6ZBV/uEpK/BbbqV7bBl5NnlojFGP2OpdqkMrcHuIoWBX6PK4fu z6XH6VcFEB5+y03zrxrJ9T3TcsrytATORIsDt8U9nvJD30g3K9UFmAyK0BwS2ZmZhO7d tdEYQyUoX0Lxw2j0ZjPJt2QuzDB+qnFjQ+BObJkUo59dXJ3BavXASh2ZCPpRErqZH2ze N03w== X-Gm-Message-State: AOAM5330rkkOQMG9e7mR0siwiGfUgD5jSJ9PN9FjlPHTpJCjeGIH1S/d SJsj0jIDes6h31knr3FVXtw= X-Google-Smtp-Source: ABdhPJweNR4OXPCwmodeqUi9IIO7Z+w4wu9MAza14JvumyYSPkJUntwwFTFIvu+QvKILkv4qKcVMsw== X-Received: by 2002:a17:90b:1d06:b0:1e6:7a84:3c6e with SMTP id on6-20020a17090b1d0600b001e67a843c6emr1788728pjb.202.1654754216640; Wed, 08 Jun 2022 22:56:56 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.56.55 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:56:56 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 2/7] perf lock: Allow to use different kernel symbols Date: Wed, 8 Jun 2022 22:56:47 -0700 Message-Id: <20220609055652.938821-3-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" Add --vmlinux and --kallsyms options to support data file from different kernels. Signed-off-by: Namhyung Kim --- tools/perf/Documentation/perf-lock.txt | 7 +++++++ tools/perf/builtin-lock.c | 4 ++++ 2 files changed, 11 insertions(+) diff --git a/tools/perf/Documentation/perf-lock.txt b/tools/perf/Documentat= ion/perf-lock.txt index 656b537b2fba..4b8568f0c53b 100644 --- a/tools/perf/Documentation/perf-lock.txt +++ b/tools/perf/Documentation/perf-lock.txt @@ -46,6 +46,13 @@ COMMON OPTIONS --force:: Don't complain, do it. =20 +--vmlinux=3D:: + vmlinux pathname + +--kallsyms=3D:: + kallsyms pathname + + REPORT OPTIONS -------------- =20 diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 57e396323d05..118a036a81fb 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -1162,6 +1162,10 @@ int cmd_lock(int argc, const char **argv) 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"), + OPT_STRING(0, "vmlinux", &symbol_conf.vmlinux_name, + "file", "vmlinux pathname"), + OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name, + "file", "kallsyms pathname"), OPT_END() }; =20 --=20 2.36.1.255.ge46751e96f-goog From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 62802C433EF for ; Thu, 9 Jun 2022 05:57:13 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S238692AbiFIF5L (ORCPT ); Thu, 9 Jun 2022 01:57:11 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50390 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229809AbiFIF47 (ORCPT ); Thu, 9 Jun 2022 01:56:59 -0400 Received: from mail-pg1-x531.google.com (mail-pg1-x531.google.com [IPv6:2607:f8b0:4864:20::531]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 38D3425294; Wed, 8 Jun 2022 22:56:58 -0700 (PDT) Received: by mail-pg1-x531.google.com with SMTP id e66so20892353pgc.8; Wed, 08 Jun 2022 22:56:58 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=t48NqpUqoX4+gRVwc3DRxSnbCSJD7GJFMSilwwZgUm0=; b=WQhGB9ZxhV5t0rqaftv19+LNiY9Y5xKvfh5magNXEKUBPWNTbILVWGSOBOPfqAZlNw 58GPqT2ZiYR/3OZqzD2bcibKhtlMe/uhEJv64qXKGmKApRvbeIWjYgd+rXYYUGD5bvo1 Wkh7FP/XjOoEC/f/qB4+bYM7CH8uBJFbSi4IV9Adl8jWMRYMivp0rvr0CSfM2OiXKzwU DBRJSceXAxSII12KVvc6effc6KtGGptAbrRviLKam5AeROScTVfLlYLnhYezyroGV+S2 07nLlZkCi9oCBnYKUuJPPXIwSNBWLLAAYP3cP8ga13+EHLowFZwL30FzlOX8O+vNHe2a 6QjA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=t48NqpUqoX4+gRVwc3DRxSnbCSJD7GJFMSilwwZgUm0=; b=TJFO5cWabFU1knAEZ79Czecy2D7DewFzoapyT7F1lt0/W7oRHD4KYrEsA+YjCpiIBo mXN8Ajq0nWIGjmGPoT4RdxdS+e/wpL812W06mHUxZHUCTOKZnGvTbR9dSl81BRoh/ir1 ZHHTaO945Bu0B3RDIMukjADJHFigWGsGc3o2ncZfBvLC4oIDa4mGyL+EFzZPFQamuhBf yssy1vHz9moHjk5HeRGRwNvcyazjKv+xfzcHdEKf64ukAPaVuIjvJMP8hpl0rD/WmoEL E8+hrxzPwr9CDBxRU3IxQy0oCYLg5flC6CClJFBBP0SwD3pHGd78kWJsymxBED3fmC5a aaTg== X-Gm-Message-State: AOAM530j4x6beG0EWL8DW2JlMeWSK6hqz8JJpvIv9fWLTD07jb2J5bZd 1acRRyTGaURAAf52qbbiTvhHxGncLt2YFA== X-Google-Smtp-Source: ABdhPJzXvP2CcXNegnXk5ORsR37Jima8zVuRU34SrrY7ZQB+amBeuEZwzjnolsU9wG0PduGjRZ747w== X-Received: by 2002:a05:6a00:24cc:b0:50d:58bf:5104 with SMTP id d12-20020a056a0024cc00b0050d58bf5104mr38607423pfv.36.1654754217725; Wed, 08 Jun 2022 22:56:57 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.56.56 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:56:57 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 3/7] perf lock: Skip print_bad_events() if nothing bad Date: Wed, 8 Jun 2022 22:56:48 -0700 Message-Id: <20220609055652.938821-4-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The debug output is meaningful when there are bad lock sequences. Skip it unless there's one or -v option is given. Signed-off-by: Namhyung Kim --- tools/perf/builtin-lock.c | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 118a036a81fb..2337b09dd2cd 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -858,9 +858,16 @@ static void print_bad_events(int bad, int total) { /* Output for debug, this have to be removed */ int i; + int broken =3D 0; const char *name[4] =3D { "acquire", "acquired", "contended", "release" }; =20 + for (i =3D 0; i < BROKEN_MAX; i++) + broken +=3D bad_hist[i]; + + if (broken =3D=3D 0 && !verbose) + return; + pr_info("\n=3D=3D=3D output for debug=3D=3D=3D\n\n"); pr_info("bad: %d, total: %d\n", bad, total); pr_info("bad rate: %.2f %%\n", (double)bad / (double)total * 100); --=20 2.36.1.255.ge46751e96f-goog From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 010E1C43334 for ; Thu, 9 Jun 2022 05:57:25 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S238695AbiFIF5W (ORCPT ); Thu, 9 Jun 2022 01:57:22 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50480 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S238557AbiFIF5A (ORCPT ); Thu, 9 Jun 2022 01:57:00 -0400 Received: from mail-pf1-x42d.google.com (mail-pf1-x42d.google.com [IPv6:2607:f8b0:4864:20::42d]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 3958828733; Wed, 8 Jun 2022 22:56:59 -0700 (PDT) Received: by mail-pf1-x42d.google.com with SMTP id j6so20169917pfe.13; Wed, 08 Jun 2022 22:56:59 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=+fAQAu3R4tRVZ7vW7DjEw1aerx7t4qGkXj4hQ6RBGyw=; b=KLfpmjlHernPBNccU93rloiN/vAGD+fHH2nWE/9bBlI7lFtsMCQ1i5LtMhFJLRGkg4 HgafSmoOwaSmiKSEew2Zv6Wcx0f3he8tNJTSwAiwXGyU8I0RK8FNOUp6nGMpgGh3zV1i ypuj6PyucdRPzrN+11xX+l4nAhm+m6k7vh/uHS4GdX1i/GngcVcbJsR/UWBQDlmWnRfQ MVtT/GP8uj2WayviBYDV0kfzIndZz9Ij1qRi2sNHuWw2nusy9Cd6t21Jv1ZetsQZaLzs +0/RN2AsPkzwpTlE9/farDil3Iz14zuCItC1qHfVrgYkvjef4UQYtyoutbRri7Rw40ez wi0w== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=+fAQAu3R4tRVZ7vW7DjEw1aerx7t4qGkXj4hQ6RBGyw=; b=ExDRxpdGwvs1sIzDEfA45dM5cdN23zfZqT/H3hEmOdjELiOfEii+MxxXP7/MpdZQZ9 Eh16HEoG5X7o3AwAhvMJgH0sEkpeRtr9GAnp66SSFOriamKUCSWuNXxy1meB0ighhtEz CAD5B35B2WoJf4nqjHo36bLC3aULvjXNTQ09I6XZzzVAIZfGwoyjV1M4ejdp65Trqe7L LjtIn53PFpDUCKogQqA6iNsiy3YvyXOXdYAHxIQTdXMywQ3nO0CpIyLgkN0ZyeiEJAZu EWmQ1KcI2MIHhT1lhLkDXyE53TQgTmE/2EKAjXZBo7GvNwcbNTJcb619oc/Uy47H426w er3g== X-Gm-Message-State: AOAM533dObazI63BWL1nU+bXJWs3X9365YF7Gtj3bFYpwllpaLH4XTqe 1LYEz93rOcA5zVt/C+0L1CGkLdabqUpvSA== X-Google-Smtp-Source: ABdhPJzkZvdLkaMWgBdukltQgNaAPbbIGh8w5PSupFwbVZaGVXon5byHTeZkWKsWiZl8KWqfBrfjwQ== X-Received: by 2002:a05:6a00:2450:b0:4f7:bf07:c063 with SMTP id d16-20020a056a00245000b004f7bf07c063mr104299026pfj.51.1654754218741; Wed, 08 Jun 2022 22:56:58 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.56.57 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:56:58 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 4/7] perf lock: Add lock contention tracepoints record support Date: Wed, 8 Jun 2022 22:56:49 -0700 Message-Id: <20220609055652.938821-5-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" When LOCKDEP and LOCK_STAT events are not available, it falls back to record the new lock contention tracepoints. Signed-off-by: Namhyung Kim --- tools/perf/builtin-lock.c | 74 +++++++++++++++++++++++++++++++++++---- 1 file changed, 67 insertions(+), 7 deletions(-) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 2337b09dd2cd..7df182a8443b 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -516,17 +516,27 @@ static struct lock_stat *lock_stat_findnew(u64 addr, = const char *name) } =20 struct trace_lock_handler { + /* it's used on CONFIG_LOCKDEP */ int (*acquire_event)(struct evsel *evsel, struct perf_sample *sample); =20 + /* it's used on CONFIG_LOCK_STAT */ int (*acquired_event)(struct evsel *evsel, struct perf_sample *sample); =20 + /* it's used on CONFIG_LOCK_STAT */ int (*contended_event)(struct evsel *evsel, struct perf_sample *sample); =20 + /* it's used on CONFIG_LOCKDEP */ int (*release_event)(struct evsel *evsel, struct perf_sample *sample); + + int (*contention_begin_event)(struct evsel *evsel, + struct perf_sample *sample); + + int (*contention_end_event)(struct evsel *evsel, + struct perf_sample *sample); }; =20 static struct lock_seq_stat *get_seq(struct thread_stat *ts, u64 addr) @@ -854,6 +864,20 @@ static int evsel__process_lock_release(struct evsel *e= vsel, struct perf_sample * return 0; } =20 +static int evsel__process_contention_begin(struct evsel *evsel, struct per= f_sample *sample) +{ + if (trace_handler->contention_begin_event) + return trace_handler->contention_begin_event(evsel, sample); + return 0; +} + +static int evsel__process_contention_end(struct evsel *evsel, struct perf_= sample *sample) +{ + if (trace_handler->contention_end_event) + return trace_handler->contention_end_event(evsel, sample); + return 0; +} + static void print_bad_events(int bad, int total) { /* Output for debug, this have to be removed */ @@ -1062,6 +1086,11 @@ static const struct evsel_str_handler lock_tracepoin= ts[] =3D { { "lock:lock_release", evsel__process_lock_release, }, /* CONFIG_LOCKD= EP */ }; =20 +static const struct evsel_str_handler contention_tracepoints[] =3D { + { "lock:contention_begin", evsel__process_contention_begin, }, + { "lock:contention_end", evsel__process_contention_end, }, +}; + static bool force; =20 static int __cmd_report(bool display_info) @@ -1125,20 +1154,41 @@ static int __cmd_record(int argc, const char **argv) "record", "-R", "-m", "1024", "-c", "1", "--synth", "task", }; unsigned int rec_argc, i, j, ret; + unsigned int nr_tracepoints; const char **rec_argv; + bool has_lock_stat =3D true; =20 for (i =3D 0; i < ARRAY_SIZE(lock_tracepoints); i++) { if (!is_valid_tracepoint(lock_tracepoints[i].name)) { - pr_err("tracepoint %s is not enabled. " - "Are CONFIG_LOCKDEP and CONFIG_LOCK_STAT enabled?\n", - lock_tracepoints[i].name); - return 1; + pr_debug("tracepoint %s is not enabled. " + "Are CONFIG_LOCKDEP and CONFIG_LOCK_STAT enabled?\n", + lock_tracepoints[i].name); + has_lock_stat =3D false; + break; + } + } + + if (has_lock_stat) + goto setup_args; + + for (i =3D 0; i < ARRAY_SIZE(contention_tracepoints); i++) { + if (!is_valid_tracepoint(contention_tracepoints[i].name)) { + pr_err("tracepoint %s is not enabled.\n", + contention_tracepoints[i].name); + return 1; } } =20 +setup_args: rec_argc =3D ARRAY_SIZE(record_args) + argc - 1; + + if (has_lock_stat) + nr_tracepoints =3D ARRAY_SIZE(lock_tracepoints); + else + nr_tracepoints =3D ARRAY_SIZE(contention_tracepoints); + /* factor of 2 is for -e in front of each tracepoint */ - rec_argc +=3D 2 * ARRAY_SIZE(lock_tracepoints); + rec_argc +=3D 2 * nr_tracepoints; =20 rec_argv =3D calloc(rec_argc + 1, sizeof(char *)); if (!rec_argv) @@ -1147,9 +1197,19 @@ static int __cmd_record(int argc, const char **argv) for (i =3D 0; i < ARRAY_SIZE(record_args); i++) rec_argv[i] =3D strdup(record_args[i]); =20 - for (j =3D 0; j < ARRAY_SIZE(lock_tracepoints); j++) { + for (j =3D 0; j < nr_tracepoints; j++) { + const char *ev_name; + + if (has_lock_stat) + ev_name =3D strdup(lock_tracepoints[j].name); + else + ev_name =3D strdup(contention_tracepoints[j].name); + + if (!ev_name) + return -ENOMEM; + rec_argv[i++] =3D "-e"; - rec_argv[i++] =3D strdup(lock_tracepoints[j].name); + rec_argv[i++] =3D ev_name; } =20 for (j =3D 1; j < (unsigned int)argc; j++, i++) --=20 2.36.1.255.ge46751e96f-goog From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 53C3DCCA481 for ; Thu, 9 Jun 2022 05:57:18 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S238126AbiFIF5P (ORCPT ); Thu, 9 Jun 2022 01:57:15 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50482 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S238556AbiFIF5A (ORCPT ); Thu, 9 Jun 2022 01:57:00 -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 4F4862CE27; Wed, 8 Jun 2022 22:57:00 -0700 (PDT) Received: by mail-pf1-x435.google.com with SMTP id c196so20228028pfb.1; Wed, 08 Jun 2022 22:57:00 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=DB/q3LbGIH2sCkq4UxdF4IbkyINeo0jgyAU9j8AQqfQ=; b=DN99daR+lbGinfbUQ65qKxXxZGv/ebltW69xe2onBUFEHDBLnYsDOHYDojWvFIZ9Os 0pm7zmbKdMDquwyQ5y2JStPl8B81tZEZrOya+paoQTSVe1/EUBCbSa26j0MQFZyY7XcV 4KdYgrM5T+n8KJ24abNKQoix5vPdVRsY1qo2Ak03pxvhL/RfCDAUVWYnA2gw80E0XjYf 9iIJ8TrXYUR2TPy60o/Rmj6AMkt0bqOvlln5r21SdJZX5Q/ZJsv8tgX9cyZrhrWFOfCW PXgU/SnRygM61KCR9FH+y/jXHVfUdr6xNSGy3sBzth/35FUdrW/FELhsW9x/qjMl8coa JvLA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=DB/q3LbGIH2sCkq4UxdF4IbkyINeo0jgyAU9j8AQqfQ=; b=FbzAD345mjmMoct6fsfAJqusoAvoZb/NeRBcgB8nevJO+Z3t6I10WyfHsTE+g/skce Nm4fIMHXhssOyROb2lIpbAaWjMosW0p3jbDy6wBjLD/r44WXKgTomYNu6P3xChoBVwTf AafAL6J5oTe7sgEcMuAvpAYfNLeIDMbfQ5lbF9k3W5IIa5s4G+dCOIu+yp+g0OVQTGRK e99sNRl3KIiR959QMy9RAam/46L5FnopIkKr/h34NqDRQ9n1vzUu7IzExRp2JkTTU3H7 v3/+KCICuyYHu2tWX21ghThyN+eMPvlyVyhhvikqy7IIYCfve/h13KBGh8OcEsU9XJm/ bQkg== X-Gm-Message-State: AOAM530qzhFcCz8jQRpAX7q8sJ1+EA5BqzgDiqXidLP0TNx9yKP20m1S EXIELKIeeeKoYqupU9w5sUK56J0qTJOeHA== X-Google-Smtp-Source: ABdhPJyvKKEye6Vw5jfKi/ukcUK1IGHuku+ZkMT7WpwZQaQ/1hpTg4JAuHjsys3/OkO0ZWgmzSkzXw== X-Received: by 2002:a05:6a00:b8c:b0:51c:2d3d:4595 with SMTP id g12-20020a056a000b8c00b0051c2d3d4595mr15346276pfj.80.1654754219742; Wed, 08 Jun 2022 22:56:59 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.56.58 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:56:59 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 5/7] perf lock: Handle lock contention tracepoints Date: Wed, 8 Jun 2022 22:56:50 -0700 Message-Id: <20220609055652.938821-6-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" When the lock contention events are used, there's no tracking of acquire and release. So the state machine is simplified to use UNINITIALIZED -> CONTENDED -> ACQUIRED only. Note that CONTENDED state is re-entrant since mutex locks can hit two or more consecutive contention_begin events for optimistic spinning and sleep. Acked-by: Ian Rogers Signed-off-by: Namhyung Kim --- tools/perf/builtin-lock.c | 125 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 125 insertions(+) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 7df182a8443b..a677ad9507c3 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -825,6 +825,124 @@ static int report_lock_release_event(struct evsel *ev= sel, return 0; } =20 +static int report_lock_contention_begin_event(struct evsel *evsel, + struct perf_sample *sample) +{ + struct lock_stat *ls; + struct thread_stat *ts; + struct lock_seq_stat *seq; + u64 addr =3D evsel__intval(evsel, sample, "lock_addr"); + + if (show_thread_stats) + addr =3D sample->tid; + + ls =3D lock_stat_findnew(addr, "No name"); + if (!ls) + return -ENOMEM; + + ts =3D thread_stat_findnew(sample->tid); + if (!ts) + return -ENOMEM; + + seq =3D get_seq(ts, addr); + if (!seq) + return -ENOMEM; + + switch (seq->state) { + case SEQ_STATE_UNINITIALIZED: + case SEQ_STATE_ACQUIRED: + break; + case SEQ_STATE_CONTENDED: + /* + * It can have nested contention begin with mutex spinning, + * then we would use the original contention begin event and + * ignore the second one. + */ + goto end; + case SEQ_STATE_ACQUIRING: + case SEQ_STATE_READ_ACQUIRED: + case SEQ_STATE_RELEASED: + /* broken lock sequence */ + if (!ls->broken) { + ls->broken =3D 1; + bad_hist[BROKEN_CONTENDED]++; + } + list_del_init(&seq->list); + free(seq); + goto end; + default: + BUG_ON("Unknown state of lock sequence found!\n"); + break; + } + + if (seq->state !=3D SEQ_STATE_CONTENDED) { + seq->state =3D SEQ_STATE_CONTENDED; + seq->prev_event_time =3D sample->time; + ls->nr_contended++; + } +end: + return 0; +} + +static int report_lock_contention_end_event(struct evsel *evsel, + struct perf_sample *sample) +{ + struct lock_stat *ls; + struct thread_stat *ts; + struct lock_seq_stat *seq; + u64 contended_term; + u64 addr =3D evsel__intval(evsel, sample, "lock_addr"); + + if (show_thread_stats) + addr =3D sample->tid; + + ls =3D lock_stat_findnew(addr, "No name"); + if (!ls) + return -ENOMEM; + + ts =3D thread_stat_findnew(sample->tid); + if (!ts) + return -ENOMEM; + + seq =3D get_seq(ts, addr); + if (!seq) + return -ENOMEM; + + switch (seq->state) { + case SEQ_STATE_UNINITIALIZED: + goto end; + case SEQ_STATE_CONTENDED: + contended_term =3D sample->time - seq->prev_event_time; + ls->wait_time_total +=3D contended_term; + if (contended_term < ls->wait_time_min) + ls->wait_time_min =3D contended_term; + if (ls->wait_time_max < contended_term) + ls->wait_time_max =3D contended_term; + break; + case SEQ_STATE_ACQUIRING: + case SEQ_STATE_ACQUIRED: + case SEQ_STATE_READ_ACQUIRED: + case SEQ_STATE_RELEASED: + /* broken lock sequence */ + if (!ls->broken) { + ls->broken =3D 1; + bad_hist[BROKEN_CONTENDED]++; + } + list_del_init(&seq->list); + free(seq); + goto end; + default: + BUG_ON("Unknown state of lock sequence found!\n"); + break; + } + + seq->state =3D SEQ_STATE_ACQUIRED; + ls->nr_acquired++; + ls->avg_wait_time =3D ls->wait_time_total/ls->nr_acquired; +end: + return 0; +} + /* lock oriented handlers */ /* TODO: handlers for CPU oriented, thread oriented */ static struct trace_lock_handler report_lock_ops =3D { @@ -832,6 +950,8 @@ static struct trace_lock_handler report_lock_ops =3D { .acquired_event =3D report_lock_acquired_event, .contended_event =3D report_lock_contended_event, .release_event =3D report_lock_release_event, + .contention_begin_event =3D report_lock_contention_begin_event, + .contention_end_event =3D report_lock_contention_end_event, }; =20 static struct trace_lock_handler *trace_handler; @@ -1124,6 +1244,11 @@ static int __cmd_report(bool display_info) goto out_delete; } =20 + if (perf_session__set_tracepoints_handlers(session, contention_tracepoint= s)) { + pr_err("Initializing perf session tracepoint handlers failed\n"); + goto out_delete; + } + if (setup_output_field(output_fields)) goto out_delete; =20 --=20 2.36.1.255.ge46751e96f-goog From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id F37E4C43334 for ; Thu, 9 Jun 2022 05:57:36 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S238732AbiFIF5f (ORCPT ); Thu, 9 Jun 2022 01:57:35 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50626 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S230414AbiFIF5D (ORCPT ); Thu, 9 Jun 2022 01:57:03 -0400 Received: from mail-pg1-x52d.google.com (mail-pg1-x52d.google.com [IPv6:2607:f8b0:4864:20::52d]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 6B4F42DD5E; Wed, 8 Jun 2022 22:57:01 -0700 (PDT) Received: by mail-pg1-x52d.google.com with SMTP id r71so20954559pgr.0; Wed, 08 Jun 2022 22:57:01 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=CWHqqF01MR1hRCUv+JftvZxTCLeuaSF/IGUn/jKBQVI=; b=JawKMh1AJPHwaPnySc/7xgifRxG+g42ouAQQnHKQJLUdMPPOjY6Ccpvw5vsgS6pR0a Jf3OVc3Ip3TvljYNOt6PFuOEBX5bnWpoBljrfTUSDBcBH7LW/dZ84psWzF37vb7JJDRP /+W3AOJ0pBkeKzi90SET4+Bi5obxbaXr8lTdCvYZmZmEwSJfrbytgBpuSYvs7S+RmrLX Qdc/URP5EdArHaPh5P7MsoA7ro1CiO/7fGkN0YpHesKmKLju8kQcqnn453Y6ejHGiDz8 wcD2QOxsfStmMoZ5lhn/ylFNHe/So2Jn/kcon5IXMg36RtZeJ10N+Z/vQ75OtVkUjZQY Q0aQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=CWHqqF01MR1hRCUv+JftvZxTCLeuaSF/IGUn/jKBQVI=; b=fz0N22ZD+xbvA7wn+TTZnpAF/MANQCaQc2cTvhOlXfwM8NzihMCpHlEF8VZuLDxyuZ OMfPH0bbDcrxDdSS2mAr6MWPW+AgeEXrajf+yzoXYtWSnmQjOPqByEwQjI8EFF8zCMhO mbaFq4xKBZQv7Faju5EizCWGpcxtCQdBKY9fmBQPGfkri/8GQc8B5KcUHfCrPipxnPlf jNVQ4ob1CyF9hH6hAjl/rxklg7MJkWZIilw/wdo7XuH0V8PRDUTi8u5RJAClSiI6rEtw 7k1bdV94t17RxkIK95skrnc8/YyQMN5EYna52gzpAj0tS0V+xrFY67Uyo/PhsnK9FWZa WLzQ== X-Gm-Message-State: AOAM530k0xsXJ77JiTp4J5gupJ032CXYY77oYx7gTk4SLGIKPzRnrq1o TpU5kLQUByaQ8evQyPWeSls= X-Google-Smtp-Source: ABdhPJz2rS8RAd8uReNPfKoijBt8DHgC+S5Snksv2PfXynfJ75ijza012kXYSdVLft3IYry+vz6gIg== X-Received: by 2002:a05:6a00:2390:b0:51c:21e1:782 with SMTP id f16-20020a056a00239000b0051c21e10782mr18035223pfc.21.1654754220882; Wed, 08 Jun 2022 22:57:00 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.56.59 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:57:00 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 6/7] perf record: Allow to specify max stack depth of fp callchain Date: Wed, 8 Jun 2022 22:56:51 -0700 Message-Id: <20220609055652.938821-7-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" Currently it has no interface to specify the max stack depth for perf record. Extend the command line parameter to accept a number after 'fp' to specify the depth like '--call-graph fp,32'. Signed-off-by: Namhyung Kim --- tools/perf/Documentation/perf-record.txt | 5 +++++ tools/perf/util/callchain.c | 18 ++++++++++++------ 2 files changed, 17 insertions(+), 6 deletions(-) diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Document= ation/perf-record.txt index cf8ad50f3de1..772777c2a52e 100644 --- a/tools/perf/Documentation/perf-record.txt +++ b/tools/perf/Documentation/perf-record.txt @@ -275,6 +275,11 @@ OPTIONS User can change the size by passing the size after comma like "--call-graph dwarf,4096". =20 + When "fp" recording is used, perf tries to save stack enties + up to the number specified in sysctl.kernel.perf_event_max_stack + by default. User can change the number by passing it after comma + like "--call-graph fp,32". + -q:: --quiet:: Don't print any message, useful for scripting. diff --git a/tools/perf/util/callchain.c b/tools/perf/util/callchain.c index 5c27a4b2e7a7..7e663673f79f 100644 --- a/tools/perf/util/callchain.c +++ b/tools/perf/util/callchain.c @@ -31,6 +31,7 @@ #include "callchain.h" #include "branch.h" #include "symbol.h" +#include "util.h" #include "../perf.h" =20 #define CALLCHAIN_PARAM_DEFAULT \ @@ -266,12 +267,17 @@ int parse_callchain_record(const char *arg, struct ca= llchain_param *param) do { /* Framepointer style */ if (!strncmp(name, "fp", sizeof("fp"))) { - if (!strtok_r(NULL, ",", &saveptr)) { - param->record_mode =3D CALLCHAIN_FP; - ret =3D 0; - } else - pr_err("callchain: No more arguments " - "needed for --call-graph fp\n"); + ret =3D 0; + param->record_mode =3D CALLCHAIN_FP; + + tok =3D strtok_r(NULL, ",", &saveptr); + if (tok) { + unsigned long size; + + size =3D strtoul(tok, &name, 0); + if (size < (unsigned) sysctl__max_stack()) + param->max_stack =3D size; + } break; =20 /* Dwarf style */ --=20 2.36.1.255.ge46751e96f-goog From nobody Mon Apr 27 23:53:52 2026 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id A933DC433EF for ; Thu, 9 Jun 2022 05:57:45 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S238809AbiFIF5o (ORCPT ); Thu, 9 Jun 2022 01:57:44 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:50634 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S231255AbiFIF5D (ORCPT ); Thu, 9 Jun 2022 01:57:03 -0400 Received: from mail-pg1-x531.google.com (mail-pg1-x531.google.com [IPv6:2607:f8b0:4864:20::531]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 6BBFD2DD70; Wed, 8 Jun 2022 22:57:02 -0700 (PDT) Received: by mail-pg1-x531.google.com with SMTP id e66so20892353pgc.8; Wed, 08 Jun 2022 22:57:02 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=sender:from:to:cc:subject:date:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=GPdbfLYebrSBilu4sWHrQjj3Z3ds+OW3q529cekCEq0=; b=ghJFVwLTXC9Sx4QQRLpAqC3ILtqsxIc9WRRU11ZKPYBCYqtAn4Y+h3qZsYsrQCBdpB JcqmIb7RfIQKwO9Z+U2OzpMYGoy1cRndGrayHZ2BLczOyt1hHaejSch4AWmE3XpfTIei yrWHax6cSVCHCwhlt2s8MTzhsCm9x/DETzAY9JOot3mdQGkVykhcADzaUxh96ZhjiNyJ NCT7ejZhGQyj9RyNtjqNHogfPTHAvyyB3+UExgPX0GLh6u4igAuTaerATzbd55Kh5Bjb jlqhMbcCMQE8v+s3givQ9zAyaVoUo5ONkedy/06HGAFJnwuEwbbsqCe/HxdoVnVxkOEQ 8Kig== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id :in-reply-to:references:mime-version:content-transfer-encoding; bh=GPdbfLYebrSBilu4sWHrQjj3Z3ds+OW3q529cekCEq0=; b=w/NHAqfaELqcpyjFH1pkoWgeb60W7OSqRmeqA0ND/UfvPGGu1b17lOMXBJAgsubp5j UvmWPgmxN+9TjQDuqdSwymVxBn419UjQ05TYVxbb5IS/5WYHbfPQoawaVLAtxCG1U7NJ pxlOZEZZPOHhWE4++BqO3oGBV3+Oe8fJF9lupwYL0H+20+2FZ7bvneniOvbKikV6UJcW sLatYq5xF7lANzMqyLjwc6pt02dcX7fL91NLuUBM701TUA9QY2UT++fP9kVXItGYCyVl rlnpcyZU01YjzbRS5FJAaSzMHifu/pySuaoKVfH2U0vabEOVOK9eTMvwC8g2prTywrqq WXCw== X-Gm-Message-State: AOAM532IWVQu9rWOKCRVpL87DjbuX7qvqNqw/UmXFEAaEfXuKHXk4wXx 2mIQVQBpcH6bP/aMgmqX0FA= X-Google-Smtp-Source: ABdhPJwWDYRZURQ7qmJEJHlCO0ZPtptTumIXmIJxiqyr4VJ64alsmbHwN4bNstpmBKdoU2ypCqDV9g== X-Received: by 2002:aa7:88c6:0:b0:51c:6e36:fad7 with SMTP id k6-20020aa788c6000000b0051c6e36fad7mr5798989pff.2.1654754222108; Wed, 08 Jun 2022 22:57:02 -0700 (PDT) Received: from balhae.hsd1.ca.comcast.net ([2601:647:6780:cb0:2c32:ceaf:ea06:c5de]) by smtp.gmail.com with ESMTPSA id w22-20020a1709026f1600b0016196bcf743sm9502413plk.275.2022.06.08.22.57.01 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 08 Jun 2022 22:57:01 -0700 (PDT) Sender: Namhyung Kim From: Namhyung Kim To: Arnaldo Carvalho de Melo , Jiri Olsa Cc: Ingo Molnar , Peter Zijlstra , LKML , Ian Rogers , linux-perf-users@vger.kernel.org, Will Deacon , Waiman Long , Boqun Feng , Davidlohr Bueso Subject: [PATCH 7/7] perf lock: Look up callchain for the contended locks Date: Wed, 8 Jun 2022 22:56:52 -0700 Message-Id: <20220609055652.938821-8-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.255.ge46751e96f-goog In-Reply-To: <20220609055652.938821-1-namhyung@kernel.org> References: <20220609055652.938821-1-namhyung@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Type: text/plain; charset="utf-8" The lock contention tracepoints don't provide lock names. All we can do is to get stack traces and show the caller instead. To minimize the overhead it's limited to up to 8 stack traces and display the first non-lock function symbol name as a caller. $ perf lock report -F acquired,contended,avg_wait,wait_total Name acquired contended avg wait total wait update_blocked_a... 40 40 3.61 us 144.45 us kernfs_fop_open+... 5 5 3.64 us 18.18 us _nohz_idle_balance 3 3 2.65 us 7.95 us tick_do_update_j... 1 1 6.04 us 6.04 us ep_scan_ready_list 1 1 3.93 us 3.93 us ... Acked-by: Ian Rogers Signed-off-by: Namhyung Kim --- tools/perf/builtin-lock.c | 172 +++++++++++++++++++++++++++++++++++++- 1 file changed, 168 insertions(+), 4 deletions(-) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index a677ad9507c3..93e958a7f844 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -9,6 +9,7 @@ #include "util/symbol.h" #include "util/thread.h" #include "util/header.h" +#include "util/callchain.h" =20 #include #include @@ -19,6 +20,7 @@ #include "util/tool.h" #include "util/data.h" #include "util/string2.h" +#include "util/map.h" =20 #include #include @@ -32,6 +34,7 @@ #include #include #include +#include =20 static struct perf_session *session; =20 @@ -120,6 +123,24 @@ static struct rb_root thread_stats; static bool combine_locks; static bool show_thread_stats; =20 +/* + * CONTENTION_STACK_DEPTH + * Number of stack trace entries to find callers + */ +#define CONTENTION_STACK_DEPTH 8 + +/* + * CONTENTION_STACK_SKIP + * Number of stack trace entries to skip when finding callers. + * The first few entries belong to the locking implementation itself. + */ +#define CONTENTION_STACK_SKIP 3 + +static u64 sched_text_start; +static u64 sched_text_end; +static u64 lock_text_start; +static u64 lock_text_end; + static struct thread_stat *thread_stat_find(u32 tid) { struct rb_node *node; @@ -483,6 +504,18 @@ static struct lock_stat *pop_from_result(void) return container_of(node, struct lock_stat, rb); } =20 +static struct lock_stat *lock_stat_find(u64 addr) +{ + struct hlist_head *entry =3D lockhashentry(addr); + struct lock_stat *ret; + + hlist_for_each_entry(ret, entry, hash_entry) { + if (ret->addr =3D=3D addr) + return ret; + } + return NULL; +} + static struct lock_stat *lock_stat_findnew(u64 addr, const char *name) { struct hlist_head *entry =3D lockhashentry(addr); @@ -825,6 +858,116 @@ static int report_lock_release_event(struct evsel *ev= sel, return 0; } =20 +static bool is_lock_function(u64 addr) +{ + if (!sched_text_start) { + struct machine *machine =3D &session->machines.host; + struct map *kmap; + struct symbol *sym; + + sym =3D machine__find_kernel_symbol_by_name(machine, + "__sched_text_start", + &kmap); + if (!sym) { + /* to avoid retry */ + sched_text_start =3D 1; + return false; + } + + sched_text_start =3D kmap->unmap_ip(kmap, sym->start); + + /* should not fail from here */ + sym =3D machine__find_kernel_symbol_by_name(machine, + "__sched_text_end", + &kmap); + sched_text_end =3D kmap->unmap_ip(kmap, sym->start); + + sym =3D machine__find_kernel_symbol_by_name(machine, + "__lock_text_start", + &kmap); + lock_text_start =3D kmap->unmap_ip(kmap, sym->start); + + sym =3D machine__find_kernel_symbol_by_name(machine, + "__lock_text_end", + &kmap); + lock_text_start =3D kmap->unmap_ip(kmap, sym->start); + } + + /* failed to get kernel symbols */ + if (sched_text_start =3D=3D 1) + return false; + + /* mutex and rwsem functions are in sched text section */ + if (sched_text_start <=3D addr && addr < sched_text_end) + return true; + + /* spinlock functions are in lock text section */ + if (lock_text_start <=3D addr && addr < lock_text_end) + return true; + + return false; +} + +static int lock_contention_caller(struct evsel *evsel, struct perf_sample = *sample, + char *buf, int size) +{ + struct thread *thread; + struct callchain_cursor *cursor =3D &callchain_cursor; + struct symbol *sym; + int skip =3D 0; + int ret; + + /* lock names will be replaced to task name later */ + if (show_thread_stats) + return -1; + + thread =3D machine__findnew_thread(&session->machines.host, + -1, sample->pid); + if (thread =3D=3D NULL) + return -1; + + /* use caller function name from the callchain */ + ret =3D thread__resolve_callchain(thread, cursor, evsel, sample, + NULL, NULL, CONTENTION_STACK_DEPTH); + if (ret !=3D 0) { + thread__put(thread); + return -1; + } + + callchain_cursor_commit(cursor); + thread__put(thread); + + while (true) { + struct callchain_cursor_node *node; + + node =3D callchain_cursor_current(cursor); + if (node =3D=3D NULL) + break; + + /* skip first few entries - for lock functions */ + if (++skip <=3D CONTENTION_STACK_SKIP) + goto next; + + sym =3D node->ms.sym; + if (sym && !is_lock_function(node->ip)) { + struct map *map =3D node->ms.map; + u64 offset; + + offset =3D map->map_ip(map, node->ip) - sym->start; + + if (offset) + scnprintf(buf, size, "%s+%#lx", sym->name, offset); + else + strlcpy(buf, sym->name, size); + return 0; + } + +next: + callchain_cursor_advance(cursor); + } + return -1; +} + static int report_lock_contention_begin_event(struct evsel *evsel, struct perf_sample *sample) { @@ -836,9 +979,18 @@ static int report_lock_contention_begin_event(struct e= vsel *evsel, if (show_thread_stats) addr =3D sample->tid; =20 - ls =3D lock_stat_findnew(addr, "No name"); - if (!ls) - return -ENOMEM; + ls =3D lock_stat_find(addr); + if (!ls) { + char buf[128]; + const char *caller =3D buf; + + if (lock_contention_caller(evsel, sample, buf, sizeof(buf)) < 0) + caller =3D "Unknown"; + + ls =3D lock_stat_findnew(addr, caller); + if (!ls) + return -ENOMEM; + } =20 ts =3D thread_stat_findnew(sample->tid); if (!ts) @@ -1219,6 +1371,7 @@ static int __cmd_report(bool display_info) struct perf_tool eops =3D { .sample =3D process_sample_event, .comm =3D perf_event__process_comm, + .mmap =3D perf_event__process_mmap, .namespaces =3D perf_event__process_namespaces, .ordered_events =3D true, }; @@ -1234,6 +1387,8 @@ static int __cmd_report(bool display_info) return PTR_ERR(session); } =20 + /* for lock function check */ + symbol_conf.sort_by_name =3D true; symbol__init(&session->header.env); =20 if (!perf_session__has_traces(session, "lock record")) @@ -1278,8 +1433,12 @@ static int __cmd_record(int argc, const char **argv) const char *record_args[] =3D { "record", "-R", "-m", "1024", "-c", "1", "--synth", "task", }; + const char *callgraph_args[] =3D { + "--call-graph", "fp," __stringify(CONTENTION_STACK_DEPTH), + }; unsigned int rec_argc, i, j, ret; unsigned int nr_tracepoints; + unsigned int nr_callgraph_args =3D 0; const char **rec_argv; bool has_lock_stat =3D true; =20 @@ -1304,8 +1463,10 @@ static int __cmd_record(int argc, const char **argv) } } =20 + nr_callgraph_args =3D ARRAY_SIZE(callgraph_args); + setup_args: - rec_argc =3D ARRAY_SIZE(record_args) + argc - 1; + rec_argc =3D ARRAY_SIZE(record_args) + nr_callgraph_args + argc - 1; =20 if (has_lock_stat) nr_tracepoints =3D ARRAY_SIZE(lock_tracepoints); @@ -1337,6 +1498,9 @@ static int __cmd_record(int argc, const char **argv) rec_argv[i++] =3D ev_name; } =20 + for (j =3D 0; j < nr_callgraph_args; j++, i++) + rec_argv[i] =3D callgraph_args[j]; + for (j =3D 1; j < (unsigned int)argc; j++, i++) rec_argv[i] =3D argv[j]; =20 --=20 2.36.1.255.ge46751e96f-goog