From nobody Mon Apr 27 07:26:20 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 E4354CCA473 for ; Wed, 15 Jun 2022 16:32:47 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356403AbiFOQcr (ORCPT ); Wed, 15 Jun 2022 12:32:47 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35294 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1355065AbiFOQcd (ORCPT ); Wed, 15 Jun 2022 12:32:33 -0400 Received: from mail-pl1-x62a.google.com (mail-pl1-x62a.google.com [IPv6:2607:f8b0:4864:20::62a]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 4C759BD6; Wed, 15 Jun 2022 09:32:27 -0700 (PDT) Received: by mail-pl1-x62a.google.com with SMTP id o17so10860171pla.6; Wed, 15 Jun 2022 09:32:27 -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=699rWlf8ZBCdGGluADa4SdNzlDCHvmdVNZAg0YxDlWs=; b=ZTDKwDaMAWnsr2/N1QFyPRYGFPs4EJbumJ2reRI52uFklyqAbdigh50qx8bK5/e2aq kWa7Owy79RUVmEduAWHNqMBRUgf2sgtHiu75tzZ0zBQMKkohBi5K25K03YuVGtPN+2Bw RzNuBxyLu0kvvcp6FRDfAnki7C0vnOohH/MU0u5CoQpfDmOz6037QcdEveOBMqjAnKU6 4rxx8Cs//umKvFeGdAp/Dy7xlkg/oxUjMoVZTnXjkxOm9bt9OdLS5aeqWie7NqJCiRVK WSisroKXeSw5DZHMGpObAC9EwBMXsbLgDWXAX4qoKKq0Es9PtVWw7Z9qtIShogiAocr0 3wKA== 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=699rWlf8ZBCdGGluADa4SdNzlDCHvmdVNZAg0YxDlWs=; b=CyiJy/DhwoEsDmPybeK3MrpTHMB44PBp0OKHjLhFG1jTBrG4oZ3G3HXpDXR6qVF7i+ lf+5jHkqEg7jvjF2IO2r/1yj2b/7ACGKH2bOPG4RTyIxfE+lRUux9V0QsGOf4aM7lraA p1kTQYKxL1jl5YoEISbBetXT+K8ctxi86qIH0Co1tVfkLbQaTY6GTtpJxJGA5mFlRQg/ 9qelVSYGHLqG+dW6yi7ZLIbMqBFwXuZr11sK0xSxHBxTUmT7nAqPIjG2h359TrRBIBiC ctlG/GFkeeN91j2vx4W7v+F19t/rZjvSbCLeAvBLlhaDI+QR8gYDtNDVH9w62r4rv99N jz5Q== X-Gm-Message-State: AJIora8qKQZ8ulUggfdwh2+MhXxdIztGvb1mH36EfoYNaH0G0qov7FBV vvJMBRZiNxInQcK3kylU+Gs= X-Google-Smtp-Source: AGRyM1uWS8skkxtd2vlS3Xhu4R22mi0pWALn9RQ+8j+yzYv0Zpcx9PbgSkSQwXmpDuSHrsdrYHpkbQ== X-Received: by 2002:a17:902:dac3:b0:164:13b2:4914 with SMTP id q3-20020a170902dac300b0016413b24914mr565342plx.135.1655310747095; Wed, 15 Jun 2022 09:32:27 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.25 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:26 -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, 15 Jun 2022 09:32:16 -0700 Message-Id: <20220615163222.1275500-2-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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 Acked-by: Ian Rogers 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.476.g0c4daa206d-goog From nobody Mon Apr 27 07:26:20 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 156BFCCA47E for ; Wed, 15 Jun 2022 16:32:43 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356221AbiFOQcm (ORCPT ); Wed, 15 Jun 2022 12:32:42 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35226 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1348146AbiFOQcb (ORCPT ); Wed, 15 Jun 2022 12:32:31 -0400 Received: from mail-pj1-x102b.google.com (mail-pj1-x102b.google.com [IPv6:2607:f8b0:4864:20::102b]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 4CC33C7B; Wed, 15 Jun 2022 09:32:29 -0700 (PDT) Received: by mail-pj1-x102b.google.com with SMTP id g10-20020a17090a708a00b001ea8aadd42bso2575434pjk.0; Wed, 15 Jun 2022 09:32:29 -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=SEfnqww0vhMlkVHiAk0LS1yqqikkfJ8P8/TMa6OHIgk=; b=pVULSWm1v8HJ3x39vt+zJEuX905ymHetz97g76i4hkrDv1/vjIrq3kpEifIvu5MxOr 2qDZr6bOfE8kZzcabDhPJY7awFZMPOyNh91Icp1nuWhmPc+JhL/8Kt38VpattRAFDeOZ pki3VDAtDz7xopAMLTVSHOBm5LDoF02Rsvr2Q2L4zzwySfY9rA6iRlRkRNzLtk3f/U+6 3CD8YY17KL9JrG1Ph9j1oOb/1iIiknoU1kF7N/KJUhYlxhIL5GgqS+au2j3e/becV8XS SPpeoF7IDJTxNjv7OAkyvDIEmP0vd27vGataP6J5xrYGlGb3yQ2BlTo3Ji90zPy3OPwJ zfZQ== 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=SEfnqww0vhMlkVHiAk0LS1yqqikkfJ8P8/TMa6OHIgk=; b=k9DJVueNkKYV4000icyalB1Ob8WfuG3+Hny1SCurbVZWvzcojXMBQNpHkwD8h94hYa 57Yx71alRpx9n6CGTTsWRDzFKn5GmDTHpvxYwMN6fnihjRq7qUW9Cy5sNSlO73Kwb8Is tCm6+6ySC8zmElwCy/cEUMAVLRaOOzUCXp+AdmslKUXelAkifLuPzZYNEVY5m2VWDe59 VXUrDcSkP06sln6LDF4Ch3Bf1C+Cbuj7jgVmuePQ6duMgJC1us4dluHulAW5ykK/2Qaj CrOqxafH/5VU9yxRq3Vr37+jV5EZPnw/2GXn967WdkyMKCBjKxZysbirUU5Ys+90q2dB hHSg== X-Gm-Message-State: AJIora+bth/NXcvzNaWrFILuZfSlKyizae57UFSw1fhsMKI4RnA+M11l d9yBDeUhfMS2jUxmThVncBY= X-Google-Smtp-Source: AGRyM1vMDUaakpBkI+Ebb9s7inI0Xj0cvuVf8NoHbN/yu5jJHpwMj6mLO/Pb55P266slffVhpdLfUg== X-Received: by 2002:a17:90b:2241:b0:1e8:8ad8:5f22 with SMTP id hk1-20020a17090b224100b001e88ad85f22mr11104674pjb.73.1655310748910; Wed, 15 Jun 2022 09:32:28 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.27 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:28 -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, 15 Jun 2022 09:32:17 -0700 Message-Id: <20220615163222.1275500-3-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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.476.g0c4daa206d-goog From nobody Mon Apr 27 07:26:20 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 AB001C43334 for ; Wed, 15 Jun 2022 16:32:46 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356313AbiFOQco (ORCPT ); Wed, 15 Jun 2022 12:32:44 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35298 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1349676AbiFOQcd (ORCPT ); Wed, 15 Jun 2022 12:32:33 -0400 Received: from mail-pg1-x533.google.com (mail-pg1-x533.google.com [IPv6:2607:f8b0:4864:20::533]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id AEB1EE6C; Wed, 15 Jun 2022 09:32:30 -0700 (PDT) Received: by mail-pg1-x533.google.com with SMTP id 184so11818326pga.12; Wed, 15 Jun 2022 09:32:30 -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=duoHmKxuIzFJAlNO4QfNqtELx9hfbWCYoYDT4+R52Yw=; b=abTGZjIAm0tK/MttgJerHY1vYC4yNou74dFkyopcGMNJF9gmAyyNVIIkLq7cMtPQdO GDzPxCYJAYL9KttjKg8OG1JiuCD3UCGHiGKF0z7AHNQZ5slQjl2CJaPyXZgVA6uitZEu 4XD/lSuPicFJ3XeZ7l+fc5O4iPTE84aSmWIDuDVymnMSifuYBXUMuMSiAg1R5hBFcsOL 50P5I2HGmqTtvWWPabCc5OcYiWYIjTPmsKUwxB3t5k0A7S8w1SDlcsXhgCcf1TC8Cm+y IMDP8YvZ+qDDxpSWdRfJH+RbB5ziDaWIv+vf61HumclZWyqdrbKTKqlj83xjyypM+ZMX voxQ== 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=duoHmKxuIzFJAlNO4QfNqtELx9hfbWCYoYDT4+R52Yw=; b=ZqBbegQPdDRWOGcqpjGZTk35UTce574d5OtRtt0nawqb3LNCcSiGk8Evt2ZpmFx4UJ 892/Zuyd8g7S9CfXPYSjXT3VP5bgk+rSH3OUCNTNyOfSLxIinPigiQQtSaQ5iFO9Y/lQ 6sr4VH5xONryHqA3rNXCA0mUFAhaUTqTK6e37MeCrSq0bAlS7V6TeMSjVWJ8FTvfGBgB ZhL9cL5cAZ3hDEAZaohzpeSfIPuAEbuzCqb3/xwye0N1obK2nY3mYytzE7kjkCzT8Ffl HWnS6bYziFcdGoJqv7eQEpaAmNxEmncB3vECtIrgFHxztuRJpIhl1PE/4PmM6K6xGs7r KRSQ== X-Gm-Message-State: AJIora9aR53y+wkNeyCZd2c+745C+ypKeSlU5mOPkDYsMBFlQ94DSPDK dHv1Tl9wJIK0WeFEefuFP6M= X-Google-Smtp-Source: AGRyM1txCojo1d2022iToq/duTxSlUjTwLS6oZh6A4Zw9W50qHzeQPwyBjUq09+ewyhjDpgGX6zh1A== X-Received: by 2002:a05:6a00:b8b:b0:51b:eefc:7fd2 with SMTP id g11-20020a056a000b8b00b0051beefc7fd2mr437043pfj.74.1655310749924; Wed, 15 Jun 2022 09:32:29 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.29 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:29 -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, 15 Jun 2022 09:32:18 -0700 Message-Id: <20220615163222.1275500-4-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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.476.g0c4daa206d-goog From nobody Mon Apr 27 07:26:20 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 DF3FCC433EF for ; Wed, 15 Jun 2022 16:32:56 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356481AbiFOQcw (ORCPT ); Wed, 15 Jun 2022 12:32:52 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35292 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1355839AbiFOQce (ORCPT ); Wed, 15 Jun 2022 12:32:34 -0400 Received: from mail-pl1-x630.google.com (mail-pl1-x630.google.com [IPv6:2607:f8b0:4864:20::630]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 09A25F32; Wed, 15 Jun 2022 09:32:32 -0700 (PDT) Received: by mail-pl1-x630.google.com with SMTP id r1so10840198plo.10; Wed, 15 Jun 2022 09:32:32 -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=g0LEEWlXezf+DhFRy9/pJdwTKt3G7SKknYeUYVPZCxM=; b=gJuHVdi6Ti69f8k/SlQXnh47mkTQADBNZoRt93YNZljieaGute7CEd85HbP3/Lq0wS GqsGLEYp1+/OK+1q4dELM4L2DXm85LLmoqmB7Is7WHECpcbtHIcy2noI979okT4ye8MM rm5+FNM+xn/qpRbU6AQxBjoeHScabwaRtIUULaf7vuJFu+aA/PLvNgFEtk4wPFae790i ef75F3pH1dcExyVIMaHh/F+DpPhLLQQzqDYmgGOJXPI48TdP/RrenEf3dYvqkBBvsbJR dbLil3WXKCe0TQRqLwdsS6nsN+O4PXfzKGs2RFBZcPquIRlvbLYlrRBVCCkK7q7Q7wGR MJZg== 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=g0LEEWlXezf+DhFRy9/pJdwTKt3G7SKknYeUYVPZCxM=; b=W6OFexr2X6XdTjsbnOzJCIJfTgvUGQn6UqyetY8zeAcYrodqfiYMjg0Ws8i2Hu4jxn GZcqifDq0NzPOBDVQf3HAdw7lCOupC3olhRUrW0tBiRtCh/Ew9jUIYsKJ+t7qpHSeEhX LHPwya/Q89rwEjrlLF4pPL5IlYNsMnUy9kFsjjHLYFaUt1mQA5910GQs9Sgmky5seieV 8VIeFl3lrVL5pEj2h1ejg0CccfAeMq8VyyCIS0b4KE+7fmN124uyoBGI0tgVOLdnIGvV 4Lx2Pts7qXmmqWeWTRZgVv04Xx2qJwJfTu8mSU7in8CXgGLnE6G5iPNHcNDA6hPgahmj CEDg== X-Gm-Message-State: AJIora/95sCOTpFIKiV1I4leTXGAFM/G0xV3yi5dqduMmNswSAjTHASC oXByhGNttNPZNPicqnPxNqI= X-Google-Smtp-Source: AGRyM1tXYCUbi3hdkahvHXXQxj/n2yEqmpnM0U3PsQEJFkXZBmNM/Qv4llH5lWFX+IFFfRNBykY0Ag== X-Received: by 2002:a17:902:da88:b0:167:5b56:8edb with SMTP id j8-20020a170902da8800b001675b568edbmr455594plx.71.1655310751504; Wed, 15 Jun 2022 09:32:31 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.30 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:30 -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, 15 Jun 2022 09:32:19 -0700 Message-Id: <20220615163222.1275500-5-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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 | 76 +++++++++++++++++++++++++++++++++++---- 1 file changed, 69 insertions(+), 7 deletions(-) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 2337b09dd2cd..9e3b90cac505 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -516,17 +516,29 @@ 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_LOCKDEP && CONFIG_LOCK_STAT */ int (*acquired_event)(struct evsel *evsel, struct perf_sample *sample); =20 + /* it's used on CONFIG_LOCKDEP && 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); + + /* it's used when CONFIG_LOCKDEP is off */ + int (*contention_begin_event)(struct evsel *evsel, + struct perf_sample *sample); + + /* it's used when CONFIG_LOCKDEP is off */ + 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 +866,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 +1088,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 +1156,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 +1199,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.476.g0c4daa206d-goog From nobody Mon Apr 27 07:26:20 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 812E8C43334 for ; Wed, 15 Jun 2022 16:32:57 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356639AbiFOQc4 (ORCPT ); Wed, 15 Jun 2022 12:32:56 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35346 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1356085AbiFOQcg (ORCPT ); Wed, 15 Jun 2022 12:32:36 -0400 Received: from mail-pf1-x434.google.com (mail-pf1-x434.google.com [IPv6:2607:f8b0:4864:20::434]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 96F22CC0; Wed, 15 Jun 2022 09:32:33 -0700 (PDT) Received: by mail-pf1-x434.google.com with SMTP id z17so11904985pff.7; Wed, 15 Jun 2022 09:32:33 -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=8SkyHaY2ESEPTAByhn+IX0xpGHJKHXbmPFnrcF1ASi0=; b=lCT+U+Qf8LYIoflC2zGpkmB3Y97bo/boDaQ3TaXkc1vxGNJ4MFUfER6NetrVzbt1BI v+Vjpt4hNGWomAMvhzBwmiFGJYwXezL/ZVMULKtUlTHzScprp4gYqVXmJYJBa5uATn1y 2tTd7hHu2CfLilToJHN70ujht/yUt3+Cd5UGY7LyEpQ5/5+ytEf3ncoNSCdjfnbFSBAl PDN9lyyk55wH3UPuGMpR/dLPEbyj3nA9NvkDsKJnx/c3PLVtBxFI8SvyjOKTghxYHIb1 XGwGdmi8ANsRSVgrsF608bqhtMeKuHNfst8McG26DdrMzIhVSbimDX2X+5yRFkt0ET+r Jj8A== 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=8SkyHaY2ESEPTAByhn+IX0xpGHJKHXbmPFnrcF1ASi0=; b=HnIs1WnBzi21DH2OqXkmaFul73jfw8JYJfddWQW/Osus5r4n3WIfoPv1Oyx1dau9d4 OpeRvELjaRl4Lx2DHND/9C0y3HDA+w7lOyooL0hIiuzg4vFX7BoevUnuzkzkiBPAERZR +CpXnb2fBcTtJCxa2aJg15gW2ixIlpTqdMe7/ckedJtqiZWwtgkRushbHs0bJuBUuZ1+ 4Z13vQscxxuljre0yAVgON4svdELjLFEVN8HGZh4YPSnpUi/O/xwz0fwBy2EM5d+eiR3 FyF+zORovwgWypH61ESGYhz3UU6xz0mhuv0e8mOI/4bLq2qYy+eN1QXRTjEmDbNDaWrK MHtg== X-Gm-Message-State: AJIora+dYntTZpcmylgXw9ZH91551mBJDuOaLiX+qdn6SCZTjFZ3Ci7/ mJfijAhwhhSehcTJUaOu2KTY4Tet8bgrag== X-Google-Smtp-Source: AGRyM1teZ2alxYJQMbnnnMcxDdFWU6Nu9XInUyvXwwU61qLTE/qb+sdNDlTpHDwP4a/CRvuBp3HAiQ== X-Received: by 2002:a05:6a00:15c6:b0:51c:61bb:a62d with SMTP id o6-20020a056a0015c600b0051c61bba62dmr444558pfu.30.1655310752521; Wed, 15 Jun 2022 09:32:32 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.31 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:32 -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, 15 Jun 2022 09:32:20 -0700 Message-Id: <20220615163222.1275500-6-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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 | 137 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 137 insertions(+) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 9e3b90cac505..546dad1963c8 100644 --- a/tools/perf/builtin-lock.c +++ b/tools/perf/builtin-lock.c @@ -483,6 +483,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); @@ -827,6 +839,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_find(addr); + if (!ls) + return 0; + + ts =3D thread_stat_find(sample->tid); + if (!ts) + return 0; + + 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_ACQUIRED]++; + } + 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 { @@ -834,6 +964,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; @@ -1126,6 +1258,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.476.g0c4daa206d-goog From nobody Mon Apr 27 07:26:20 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 CF489C43334 for ; Wed, 15 Jun 2022 16:33:00 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356502AbiFOQc5 (ORCPT ); Wed, 15 Jun 2022 12:32:57 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35426 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1355873AbiFOQch (ORCPT ); Wed, 15 Jun 2022 12:32:37 -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 7F234639D; Wed, 15 Jun 2022 09:32:34 -0700 (PDT) Received: by mail-pf1-x42c.google.com with SMTP id c196so11923971pfb.1; Wed, 15 Jun 2022 09:32:34 -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=kdBujSJIuI5oTCt9ZNeAAGURO8zSMK1uyI+VIKFgR10=; b=dxhhk1OvgFuj0lplIBnl0vVS539Tg8JcDuiY/dnMJ9hBKz5Oj7yiFnskHv4qiQCzgZ QDB1rZtQ3XNUG773yoCgry9VVJDdqAUiDA0P9TFEejtR3xTBjfGjYCCzpckSBUDswUMp 8TqVKUSbg6DhdyvhP+xcefR8zcyS5up0LtR7hSB7YDeDBSIJR5CEF0jCoZo4Q6MVp3my Fh3aUcdEhJs+2UPG5fRWlkXTS5ILg17TzwimsKU/IdSW19y03vyNsaBK1NWAo9i8h/KU rJfrgOOIdnEiB1gf5Q9I9MqGfdeTkjPChOSZbsgdSAWhzUZYdYALcv33n2xgrmZ7KnqC tRUQ== 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=kdBujSJIuI5oTCt9ZNeAAGURO8zSMK1uyI+VIKFgR10=; b=sKDy65DRBS8tkLsgMwwrwCBwerxEvwGSrXZ23zgZ8jjVB2R6sIkU9xM+1Se7Ye5W0M IqUzEVTgqzNDo0Y8uXkfq0CWZlBKfX/ctzw9bIcizKRELXEY8Jc8/wPyDZxUvvB19WjV bnGkT051I5SQVgqPvKBKUPcL4QHdRySqEAV78/iawJ85FgV1Fnyhiw9JH7uXzZwzMqrF zgaFFJDHnZ0a7F736bKXtYZisyRFvWJSvQfM29jls1zjbi34hMxXpaTFaowr0OxnzvL2 Kg0CNy1i6Tr910+02AVNyc6jvwcnwlC88zjvrMI2gUgU60WbAZ18yet5njNEgEojJgkN UHvw== X-Gm-Message-State: AJIora+a2d/RjX7QcyQDk7gFA+Snxfz25P8uktvZzruYDk2akaibqIcy frAQp8w0NEptYnz6/o9wI10= X-Google-Smtp-Source: AGRyM1tgc8FswmVOQg38OQCqz090UxCEdxjFrf7i6UE0uhMiZlkUxz75ijG08Sufr729unT8xpip9A== X-Received: by 2002:a65:48c6:0:b0:403:aef0:bebe with SMTP id o6-20020a6548c6000000b00403aef0bebemr538435pgs.486.1655310754245; Wed, 15 Jun 2022 09:32:34 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.32 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:33 -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, 15 Jun 2022 09:32:21 -0700 Message-Id: <20220615163222.1275500-7-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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.476.g0c4daa206d-goog From nobody Mon Apr 27 07:26:20 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 726D3C43334 for ; Wed, 15 Jun 2022 16:33:05 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1356682AbiFOQdD (ORCPT ); Wed, 15 Jun 2022 12:33:03 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35428 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1356130AbiFOQch (ORCPT ); Wed, 15 Jun 2022 12:32:37 -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 9A0FA6574; Wed, 15 Jun 2022 09:32:36 -0700 (PDT) Received: by mail-pf1-x435.google.com with SMTP id i64so11910943pfc.8; Wed, 15 Jun 2022 09:32:36 -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=lEQiFQkN3hYWYIRpASWYdljxjRdSlfRPErOBQ95X4rY=; b=NSFoYeUiPpESb8t/o0bNmftJBHcM2trVMRpQwJfVOdHtBRNYZNX1D7o7tj4JENEJo0 NqeAuDYLWicCzCwItmdFcsqE/aFFSa/3zpYIfWJ2de78A1PBdZEkVghLoM3aBRoReoMW BK9teIegX5jFHPqhaKZrfyBg3t1cN8r8b7eDCUAHTDXH7repUXyHFcDwc7X5q+84OO0C LCxK3gX3suExDviIMjOWZrIUzo8itOV3PpmlgTYKCNPdugJEkS+IX2KYj9XUyhqNge3Z AH2kWbQBzQW7T7J0oJjbwSpP840Ij4jFzXYfeWFYbqOfKFHMPZzLCxOtp/DaqjXOysYW KfXA== 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=lEQiFQkN3hYWYIRpASWYdljxjRdSlfRPErOBQ95X4rY=; b=oTGCnTiR+Eg0JC1FmeuviiqIg7o8pPkBJ85gmqgvT7opFRCsWkiytw0KMfj9aEvkR0 Q0kkdEVz9pL5SLyWca7unwcFBvkl18ktcF5aKv05fSdSPQKVJbuXxD5y/vspIhtJXTNG IHQQ7NySAIU0d2RihT1hoBkx4SRDL8mqMIogvaZLAB+R0X5wNpwJZgjk5uEUkPq2TxHF QCX5CtZQ6WPIu8uKV8GyW1gcwjeztie6pDL7ov5K7YGWBympGdlPX0vAZhuA1G/bsTvO eJL4iruFuNraLiEkl4XsEv2U9SnUtYPReII0N2U+iTrglgZQQs1FLQNdE1Zj//TSCUMd 5Hqw== X-Gm-Message-State: AJIora8zNbx0N09uFVKqK262abTHAaOjRo1emeJvez0Bm1gIA5bf6lq6 jQM6zA3/7Dil02Jj7XIWQ2M= X-Google-Smtp-Source: AGRyM1vhiz4aVpfmIst+A4e/+gfGiZDWFm9hdMrdqTggjpl1Qecn1iX8tBSfGv267fl8hTK+3qaMAQ== X-Received: by 2002:a63:6885:0:b0:405:1d96:b671 with SMTP id d127-20020a636885000000b004051d96b671mr510297pgc.511.1655310756067; Wed, 15 Jun 2022 09:32:36 -0700 (PDT) Received: from balhae.corp.google.com ([2620:15c:2c1:200:6b99:92ca:1efa:c0fb]) by smtp.gmail.com with ESMTPSA id q23-20020a170902edd700b00168bffd39a1sm9583881plk.143.2022.06.15.09.32.34 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 15 Jun 2022 09:32:35 -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, 15 Jun 2022 09:32:22 -0700 Message-Id: <20220615163222.1275500-8-namhyung@kernel.org> X-Mailer: git-send-email 2.36.1.476.g0c4daa206d-goog In-Reply-To: <20220615163222.1275500-1-namhyung@kernel.org> References: <20220615163222.1275500-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 | 160 +++++++++++++++++++++++++++++++++++++- 1 file changed, 156 insertions(+), 4 deletions(-) diff --git a/tools/perf/builtin-lock.c b/tools/perf/builtin-lock.c index 546dad1963c8..c5ca34741561 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; @@ -839,6 +860,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) { @@ -850,9 +981,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) @@ -1233,6 +1373,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, }; @@ -1248,6 +1389,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")) @@ -1292,8 +1435,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 @@ -1318,8 +1465,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); @@ -1351,6 +1500,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.476.g0c4daa206d-goog