From nobody Tue Apr 7 13:28:35 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 C87E2ECAAD1 for ; Sat, 27 Aug 2022 04:03:26 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S236849AbiH0EDZ (ORCPT ); Sat, 27 Aug 2022 00:03:25 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:60748 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S232468AbiH0EDU (ORCPT ); Sat, 27 Aug 2022 00:03:20 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id C0579E3986 for ; Fri, 26 Aug 2022 21:03:19 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id 640E561DCF for ; Sat, 27 Aug 2022 04:03:19 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 9B6A7C433B5; Sat, 27 Aug 2022 04:03:17 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1661572998; bh=6h0q3HLOupjIluOvt0WI/JeaJ5DW/jOkFgt32sgYqnQ=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=JQXR+kXgSYH5qk8Eg/0CnOXI94pve9FpGWIbzbjntjQXG1/nd0Jg/oFndYtQ7IArO xGQQvT/OVioR3pFcK0VLu6uVIhFswZaE2J4ZcFYBKEF2IN2chGjUeJZpK8mL10inSh 1zb9GEFJFZZmr8C1bzSxCgpotUEy8wWNvPG4zr8S/KDVj2Y+iyZMLcl8zDa/b4tjtK 80GjR6TinlPKXJXID5OizEmBJvvCl2qCxDkXRd6TWCW+HweiOUiyyxI04xraGVGYb4 vb7ibFuJ8B5FRWr2Ss+tSdog6hwc8CO+kqNZ2J6sQ+eOUJEjB5zp4n9cOAZSqRMNXX gz1ciOD4wg20A== From: "Masami Hiramatsu (Google)" To: Steven Rostedt Cc: Tom Zanussi , Ingo Molnar , linux-kernel@vger.kernel.org Subject: [PATCH v4 1/5] tracing: Allow multiple hitcount values in histograms Date: Sat, 27 Aug 2022 13:03:15 +0900 Message-Id: <166157299482.348924.7718303119342203371.stgit@devnote2> X-Mailer: git-send-email 2.25.1 In-Reply-To: <166157298537.348924.2537162090505397377.stgit@devnote2> References: <166157298537.348924.2537162090505397377.stgit@devnote2> User-Agent: StGit/0.19 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Tom Zanussi The hitcount is treated specially in the histograms - since it's always expected to be there regardless of whether the user specified anything or not, it's always added as the first histogram value. Currently the code doesn't allow it to be added more than once as a value, which is inconsistent with all the other possible values. It would seem to be a pointless thing to want to do, but other features being added such as percent and graph modifiers don't work properly with the current hitcount restrictions. Fix this by allowing multiple hitcounts to be added. Signed-off-by: Tom Zanussi --- Changes in v4: - Initialize n_hitcount. --- kernel/trace/trace_events_hist.c | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_h= ist.c index 92fbd72b6408..e80a41e380bb 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -1356,6 +1356,8 @@ static const char *hist_field_name(struct hist_field = *field, field_name =3D field->name; } else if (field->flags & HIST_FIELD_FL_TIMESTAMP) field_name =3D "common_timestamp"; + else if (field->flags & HIST_FIELD_FL_HITCOUNT) + field_name =3D "hitcount"; =20 if (field_name =3D=3D NULL) field_name =3D ""; @@ -2328,6 +2330,8 @@ parse_field(struct hist_trigger_data *hist_data, stru= ct trace_event_file *file, hist_data->attrs->ts_in_usecs =3D true; } else if (strcmp(field_name, "common_cpu") =3D=3D 0) *flags |=3D HIST_FIELD_FL_CPU; + else if (strcmp(field_name, "hitcount") =3D=3D 0) + *flags |=3D HIST_FIELD_FL_HITCOUNT; else { field =3D trace_find_event_field(file->event_call, field_name); if (!field || !field->size) { @@ -4328,8 +4332,8 @@ static int create_var_field(struct hist_trigger_data = *hist_data, static int create_val_fields(struct hist_trigger_data *hist_data, struct trace_event_file *file) { + unsigned int i, j =3D 1, n_hitcount =3D 0; char *fields_str, *field_str; - unsigned int i, j =3D 1; int ret; =20 ret =3D create_hitcount_val(hist_data); @@ -4346,8 +4350,10 @@ static int create_val_fields(struct hist_trigger_dat= a *hist_data, if (!field_str) break; =20 - if (strcmp(field_str, "hitcount") =3D=3D 0) - continue; + if (strcmp(field_str, "hitcount") =3D=3D 0) { + if (!n_hitcount++) + continue; + } =20 ret =3D create_val_field(hist_data, j++, file, field_str); if (ret) From nobody Tue Apr 7 13:28:35 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 E4A1AECAAD1 for ; Sat, 27 Aug 2022 04:03:38 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S232468AbiH0EDf (ORCPT ); Sat, 27 Aug 2022 00:03:35 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:60932 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S237359AbiH0EDa (ORCPT ); Sat, 27 Aug 2022 00:03:30 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [IPv6:2604:1380:4641:c500::1]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 64253E3C03 for ; Fri, 26 Aug 2022 21:03:29 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id C82EE61E16 for ; Sat, 27 Aug 2022 04:03:28 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 0DAEBC433D6; Sat, 27 Aug 2022 04:03:26 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1661573008; bh=tu/uBFTcTkD8ciezaLIOud2OqZdulEjwj2vtD/px5uc=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=sOgO/3jr3dCmERi87hkG3jw3yqWXJRMOFDLMR8bRfcR7ryZdwafXXt8Z5rHLtZTFx uh/P4dgzsTRlhv7pQVKMmkwEJSHiMGBPD/2Ci0hqca8T9q1s935XHo3PfalUbLWU1I tD2nzUxCHmjoXLIV+ISm1AROjGYb4kUJnsqU2T+btP0WBFTBRO0BNfBS4I4Gi9ieUW xo4F9yFYUsF2kr77G8806cl/TXGuVmuS9ZU9YVv0heXB/9nbmSEtEhWuhPwFfqTPHy DiajW+Nvn1xAB0oS3Cy330pmQAcS8RgCbs3hAv6hH1HADfb5hN9T8zScIIb9Lz/IbG ZwHA85YqOIeuA== From: "Masami Hiramatsu (Google)" To: Steven Rostedt Cc: Tom Zanussi , Ingo Molnar , linux-kernel@vger.kernel.org Subject: [PATCH v4 2/5] tracing: Fix to check event_mutex is held while accessing trigger list Date: Sat, 27 Aug 2022 13:03:24 +0900 Message-Id: <166157300435.348924.14755234601275629058.stgit@devnote2> X-Mailer: git-send-email 2.25.1 In-Reply-To: <166157298537.348924.2537162090505397377.stgit@devnote2> References: <166157298537.348924.2537162090505397377.stgit@devnote2> User-Agent: StGit/0.19 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Masami Hiramatsu (Google) Since the check_user_trigger() is called outside of RCU read lock, this list_for_each_entry_rcu() caused a suspicious RCU usage warning. # echo hist:keys=3Dpid > events/sched/sched_stat_runtime/trigger # cat events/sched/sched_stat_runtime/trigger [ 43.167032] [ 43.167418] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D [ 43.167992] WARNING: suspicious RCU usage [ 43.168567] 5.19.0-rc5-00029-g19ebe4651abf #59 Not tainted [ 43.169283] ----------------------------- [ 43.169863] kernel/trace/trace_events_trigger.c:145 RCU-list traversed i= n non-reader section!! ... However, this file->triggers list is safe when it is accessed under event_mutex is held. To fix this warning, adds a lockdep_is_held check to the list_for_each_entry_rcu(). Fixes: 7491e2c44278 ("tracing: Add a probe that attaches to trace events") Signed-off-by: Masami Hiramatsu (Google) --- kernel/trace/trace_events_trigger.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/kernel/trace/trace_events_trigger.c b/kernel/trace/trace_event= s_trigger.c index cb866c3141af..918730d74932 100644 --- a/kernel/trace/trace_events_trigger.c +++ b/kernel/trace/trace_events_trigger.c @@ -142,7 +142,8 @@ static bool check_user_trigger(struct trace_event_file = *file) { struct event_trigger_data *data; =20 - list_for_each_entry_rcu(data, &file->triggers, list) { + list_for_each_entry_rcu(data, &file->triggers, list, + lockdep_is_held(&event_mutex)) { if (data->flags & EVENT_TRIGGER_FL_PROBE) continue; return true; From nobody Tue Apr 7 13:28:35 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 05B50ECAAD1 for ; Sat, 27 Aug 2022 04:03:52 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S239366AbiH0EDu (ORCPT ); Sat, 27 Aug 2022 00:03:50 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:60932 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S239818AbiH0EDj (ORCPT ); Sat, 27 Aug 2022 00:03:39 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [IPv6:2604:1380:4641:c500::1]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id B097AE3C36 for ; Fri, 26 Aug 2022 21:03:38 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id 3ABC361E10 for ; Sat, 27 Aug 2022 04:03:38 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 5FB8DC433C1; Sat, 27 Aug 2022 04:03:36 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1661573017; bh=Z/cNKmpFdYDoBjNtYCch9+5/pqpLwEDPB2B5qdUHBvw=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=IYPpJAnRjWkXpd+0lp7uZ1tn5WCPbzeHJE7vbS4F93ZmYqbQr3d0ZXqhhTi9Ux3W0 2YtMiw2S2f89JOkEiO1Hcgl+weM987ETFmY3ALoKK4YySura/FaMxT7k6t11fyzANM YJLlSCFFcVs5M0+vAjwG/N7F2hQNJHAQpcgmmXycdLBLY1IOmsIjVdmSSRUKeLdyZ4 M9aQYQY4hmwu0OC1kvSQsdUXLwXG2equehKjQ7h8dukuFkwszEyse8P5sFlfyXRbea zJ33t1e079+NsCXNyh/1v1diRAKc/npMuzsF7EpFg8Bu7g+wPfkAdUMER7pV2JKhsI bS/EGm61rMlLw== From: "Masami Hiramatsu (Google)" To: Steven Rostedt Cc: Tom Zanussi , Ingo Molnar , linux-kernel@vger.kernel.org Subject: [PATCH v4 3/5] tracing: Add .percent suffix option to histogram values Date: Sat, 27 Aug 2022 13:03:33 +0900 Message-Id: <166157301366.348924.3715744119667672294.stgit@devnote2> X-Mailer: git-send-email 2.25.1 In-Reply-To: <166157298537.348924.2537162090505397377.stgit@devnote2> References: <166157298537.348924.2537162090505397377.stgit@devnote2> User-Agent: StGit/0.19 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Masami Hiramatsu (Google) Add .percent suffix option to show the histogram values in percentage. This feature is useful when we need yo undersntand the overall trend for the histograms of large values. E.g. this shows the runtime percentage for each tasks. ------ # cd /sys/kernel/debug/tracing/ # echo hist:keys=3Dpid:vals=3Dhitcount,runtime.percent:sort=3Dpid > \ events/sched/sched_stat_runtime/trigger # sleep 10 # cat events/sched/sched_stat_runtime/hist # event histogram # # trigger info: hist:keys=3Dpid:vals=3Dhitcount,runtime.percent:sort=3Dpid= :size=3D2048 [active] # { pid: 8 } hitcount: 7 runtime (%): 4.14 { pid: 14 } hitcount: 5 runtime (%): 3.69 { pid: 16 } hitcount: 11 runtime (%): 3.41 { pid: 61 } hitcount: 41 runtime (%): 19.75 { pid: 65 } hitcount: 4 runtime (%): 1.48 { pid: 70 } hitcount: 6 runtime (%): 3.60 { pid: 72 } hitcount: 2 runtime (%): 1.10 { pid: 144 } hitcount: 10 runtime (%): 32.01 { pid: 151 } hitcount: 8 runtime (%): 22.66 { pid: 152 } hitcount: 2 runtime (%): 8.10 Totals: Hits: 96 Entries: 10 Dropped: 0 ----- Signed-off-by: Masami Hiramatsu (Google) --- Changes in v4: - Port on the Tom's hitcount patch. Changes in v3: - Show "(%)" in the field name. - Return div0 error only if the value is not zero. - Simplify the print code with hist_trigger_print_val(). - Show hitcount percentage correctly. Changes in v2: - Use div64_*(). - Show an error when failing to calculate the percentage. --- kernel/trace/trace.c | 3 + kernel/trace/trace_events_hist.c | 105 +++++++++++++++++++++++++++++++---= ---- 2 files changed, 88 insertions(+), 20 deletions(-) diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index d3005279165d..5e5efc550ac4 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -5700,7 +5700,8 @@ static const char readme_msg[] =3D "\t .syscall display a syscall id as a syscall name\n" "\t .log2 display log2 value rather than raw number\n" "\t .buckets=3Dsize display values in groups of size rather t= han raw number\n" - "\t .usecs display a common_timestamp in microseconds\n\n" + "\t .usecs display a common_timestamp in microseconds\n" + "\t .percent display a number of percentage value\n\n" "\t The 'pause' parameter can be used to pause an existing hist\n" "\t trigger or to start a hist trigger but not log any events\n" "\t until told to do so. 'continue' can be used to start or\n" diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_h= ist.c index e80a41e380bb..af6c140f85e6 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -506,6 +506,7 @@ enum hist_field_flags { HIST_FIELD_FL_ALIAS =3D 1 << 16, HIST_FIELD_FL_BUCKET =3D 1 << 17, HIST_FIELD_FL_CONST =3D 1 << 18, + HIST_FIELD_FL_PERCENT =3D 1 << 19, }; =20 struct var_defs { @@ -1707,6 +1708,8 @@ static const char *get_hist_field_flags(struct hist_f= ield *hist_field) flags_str =3D "buckets"; else if (hist_field->flags & HIST_FIELD_FL_TIMESTAMP_USECS) flags_str =3D "usecs"; + else if (hist_field->flags & HIST_FIELD_FL_PERCENT) + flags_str =3D "percent"; =20 return flags_str; } @@ -2315,6 +2318,10 @@ parse_field(struct hist_trigger_data *hist_data, str= uct trace_event_file *file, if (ret || !(*buckets)) goto error; *flags |=3D HIST_FIELD_FL_BUCKET; + } else if (strncmp(modifier, "percent", 7) =3D=3D 0) { + if (*flags & (HIST_FIELD_FL_VAR | HIST_FIELD_FL_KEY)) + goto error; + *flags |=3D HIST_FIELD_FL_PERCENT; } else { error: hist_err(tr, HIST_ERR_BAD_FIELD_MODIFIER, errpos(modifier)); @@ -4350,9 +4357,12 @@ static int create_val_fields(struct hist_trigger_dat= a *hist_data, if (!field_str) break; =20 - if (strcmp(field_str, "hitcount") =3D=3D 0) { - if (!n_hitcount++) - continue; + if (!n_hitcount++ && strncmp(field_str, "hitcount", 8) =3D=3D 0 && + (field_str[8] =3D=3D '.' || field_str[8] =3D=3D '\0')) { + if (strncmp(field_str + 8, ".percent", 8) =3D=3D 0) + hist_data->fields[HITCOUNT_IDX]->flags |=3D + HIST_FIELD_FL_PERCENT; + continue; } =20 ret =3D create_val_field(hist_data, j++, file, field_str); @@ -5288,33 +5298,69 @@ static void hist_trigger_print_key(struct seq_file = *m, seq_puts(m, "}"); } =20 +/* Get the 100 times of the percentage of @val in @total */ +static inline unsigned int __get_percentage(u64 val, u64 total) +{ + if (!total) + goto div0; + + if (val < (U64_MAX / 10000)) + return (unsigned int)div64_ul(val * 10000, total); + + total =3D div64_u64(total, 10000); + if (!total) + goto div0; + + return (unsigned int)div64_ul(val, total); +div0: + return val ? UINT_MAX : 0; +} + +static void hist_trigger_print_val(struct seq_file *m, unsigned int idx, + const char *field_name, unsigned long flags, + u64 *totals, struct tracing_map_elt *elt) +{ + u64 val =3D tracing_map_read_sum(elt, idx); + unsigned int pc; + + if (flags & HIST_FIELD_FL_PERCENT) { + pc =3D __get_percentage(val, totals[idx]); + if (pc =3D=3D UINT_MAX) + seq_printf(m, " %s (%%):[ERROR]", field_name); + else + seq_printf(m, " %s (%%): %3u.%02u", field_name, + pc / 100, pc % 100); + } else if (flags & HIST_FIELD_FL_HEX) { + seq_printf(m, " %s: %10llx", field_name, val); + } else { + seq_printf(m, " %s: %10llu", field_name, val); + } +} + static void hist_trigger_entry_print(struct seq_file *m, struct hist_trigger_data *hist_data, + u64 *totals, void *key, struct tracing_map_elt *elt) { const char *field_name; - unsigned int i; + unsigned int i =3D HITCOUNT_IDX; + unsigned long flags; =20 hist_trigger_print_key(m, hist_data, key, elt); =20 - seq_printf(m, " hitcount: %10llu", - tracing_map_read_sum(elt, HITCOUNT_IDX)); + flags =3D hist_data->fields[i]->flags; + hist_trigger_print_val(m, i, "hitcount", flags, totals, elt); =20 for (i =3D 1; i < hist_data->n_vals; i++) { field_name =3D hist_field_name(hist_data->fields[i], 0); + flags =3D hist_data->fields[i]->flags; =20 - if (hist_data->fields[i]->flags & HIST_FIELD_FL_VAR || - hist_data->fields[i]->flags & HIST_FIELD_FL_EXPR) + if (flags & HIST_FIELD_FL_VAR || flags & HIST_FIELD_FL_EXPR) continue; =20 - if (hist_data->fields[i]->flags & HIST_FIELD_FL_HEX) { - seq_printf(m, " %s: %10llx", field_name, - tracing_map_read_sum(elt, i)); - } else { - seq_printf(m, " %s: %10llu", field_name, - tracing_map_read_sum(elt, i)); - } + seq_puts(m, " "); + hist_trigger_print_val(m, i, field_name, flags, totals, elt); } =20 print_actions(m, hist_data, elt); @@ -5327,7 +5373,8 @@ static int print_entries(struct seq_file *m, { struct tracing_map_sort_entry **sort_entries =3D NULL; struct tracing_map *map =3D hist_data->map; - int i, n_entries; + int i, j, n_entries; + u64 *totals =3D NULL; =20 n_entries =3D tracing_map_sort_entries(map, hist_data->sort_keys, hist_data->n_sort_keys, @@ -5335,11 +5382,29 @@ static int print_entries(struct seq_file *m, if (n_entries < 0) return n_entries; =20 + for (j =3D 0; j < hist_data->n_vals; j++) { + if (!(hist_data->fields[j]->flags & HIST_FIELD_FL_PERCENT)) + continue; + if (!totals) { + totals =3D kcalloc(hist_data->n_vals, sizeof(u64), + GFP_KERNEL); + if (!totals) { + n_entries =3D -ENOMEM; + goto out; + } + } + for (i =3D 0; i < n_entries; i++) + totals[j] +=3D tracing_map_read_sum( + sort_entries[i]->elt, j); + } + for (i =3D 0; i < n_entries; i++) - hist_trigger_entry_print(m, hist_data, + hist_trigger_entry_print(m, hist_data, totals, sort_entries[i]->key, sort_entries[i]->elt); =20 + kfree(totals); +out: tracing_map_destroy_sort_entries(sort_entries, n_entries); =20 return n_entries; @@ -5759,9 +5824,11 @@ static int event_hist_trigger_print(struct seq_file = *m, continue; } =20 - if (i =3D=3D HITCOUNT_IDX) + if (i =3D=3D HITCOUNT_IDX) { seq_puts(m, "hitcount"); - else { + if (field->flags & HIST_FIELD_FL_PERCENT) + seq_puts(m, ".percent"); + } else { seq_puts(m, ","); hist_field_print(m, field); } From nobody Tue Apr 7 13:28:35 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 3DCDFECAAD1 for ; Sat, 27 Aug 2022 04:03:59 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S239818AbiH0EDz (ORCPT ); Sat, 27 Aug 2022 00:03:55 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:32956 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S232408AbiH0EDw (ORCPT ); Sat, 27 Aug 2022 00:03:52 -0400 Received: from sin.source.kernel.org (sin.source.kernel.org [145.40.73.55]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id E9F6BE3C05 for ; Fri, 26 Aug 2022 21:03:50 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by sin.source.kernel.org (Postfix) with ESMTPS id 21C49CE29C0 for ; Sat, 27 Aug 2022 04:03:49 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id C4566C433D6; Sat, 27 Aug 2022 04:03:45 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1661573027; bh=OOmpaaDy9ShZc/kMESeHiG2wVIE56UJPU3LZ7EpPjls=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=uSv3u/R8ZwpqM+tn3ceEmJptDLmcGihQuX0qHw9xuuWvLo70s3gHwDxSKaZ07t11m hRlVxKZwedI4XqF3wO6BR53NC0FS/d4Gh1WLEF+3dJ+oBjo3GFLeQM1AmaK3Tmo7Sm zigKlcf1UvwQStvqvU98r1rG4uPtSb9wvXuUTjmN5855Vx9R8bF9ILquOUonPF3X7O S355ryvTo/CwMAtHqFnlEc8IqHMHeIrAZw7Hx+U9ZP74CXWoUgBGS2IkxQbR9rNe6h L0zfbrlpc4nxHiCY57UbCLe+NxXYy/urZpjI4ncbnK1rZWh6uFcEkEx6y7PIyvgiH3 tljYkrzskNyOQ== From: "Masami Hiramatsu (Google)" To: Steven Rostedt Cc: Tom Zanussi , Ingo Molnar , linux-kernel@vger.kernel.org Subject: [PATCH v4 4/5] tracing: Add .graph suffix option to histogram value Date: Sat, 27 Aug 2022 13:03:43 +0900 Message-Id: <166157302302.348924.9998983489821621084.stgit@devnote2> X-Mailer: git-send-email 2.25.1 In-Reply-To: <166157298537.348924.2537162090505397377.stgit@devnote2> References: <166157298537.348924.2537162090505397377.stgit@devnote2> User-Agent: StGit/0.19 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Masami Hiramatsu (Google) Add the .graph suffix which shows the bar graph of the histogram value. For example, the below example shows that the bar graph of the histogram of the runtime for each tasks. ------ # cd /sys/kernel/debug/tracing/ # echo hist:keys=3Dpid:vals=3Druntime.graph:sort=3Dpid > \ events/sched/sched_stat_runtime/trigger # sleep 10 # cat events/sched/sched_stat_runtime/hist # event histogram # # trigger info: hist:keys=3Dpid:vals=3Dhitcount,runtime.graph:sort=3Dpid:s= ize=3D2048 [active] # { pid: 14 } hitcount: 2 runtime: { pid: 16 } hitcount: 8 runtime: { pid: 26 } hitcount: 1 runtime: { pid: 57 } hitcount: 3 runtime: { pid: 61 } hitcount: 20 runtime: ### { pid: 66 } hitcount: 2 runtime: { pid: 70 } hitcount: 3 runtime: { pid: 72 } hitcount: 2 runtime: { pid: 145 } hitcount: 14 runtime: #################### { pid: 152 } hitcount: 5 runtime: ####### { pid: 153 } hitcount: 2 runtime: #### Totals: Hits: 62 Entries: 11 Dropped: 0 ------- Signed-off-by: Masami Hiramatsu (Google) --- Changes in v3: - Show hitcount.graph in trigger info correctly. - Show both hitcount.percent and hitcount.graph on the same histogram. Changes in v2: - Show an error when failing to calculate the percentage. --- kernel/trace/trace_events_hist.c | 82 +++++++++++++++++++++++++++++++---= ---- 1 file changed, 66 insertions(+), 16 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_h= ist.c index af6c140f85e6..fceea784fded 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -507,6 +507,7 @@ enum hist_field_flags { HIST_FIELD_FL_BUCKET =3D 1 << 17, HIST_FIELD_FL_CONST =3D 1 << 18, HIST_FIELD_FL_PERCENT =3D 1 << 19, + HIST_FIELD_FL_GRAPH =3D 1 << 20, }; =20 struct var_defs { @@ -1710,6 +1711,8 @@ static const char *get_hist_field_flags(struct hist_f= ield *hist_field) flags_str =3D "usecs"; else if (hist_field->flags & HIST_FIELD_FL_PERCENT) flags_str =3D "percent"; + else if (hist_field->flags & HIST_FIELD_FL_GRAPH) + flags_str =3D "graph"; =20 return flags_str; } @@ -2322,6 +2325,10 @@ parse_field(struct hist_trigger_data *hist_data, str= uct trace_event_file *file, if (*flags & (HIST_FIELD_FL_VAR | HIST_FIELD_FL_KEY)) goto error; *flags |=3D HIST_FIELD_FL_PERCENT; + } else if (strncmp(modifier, "graph", 5) =3D=3D 0) { + if (*flags & (HIST_FIELD_FL_VAR | HIST_FIELD_FL_KEY)) + goto error; + *flags |=3D HIST_FIELD_FL_GRAPH; } else { error: hist_err(tr, HIST_ERR_BAD_FIELD_MODIFIER, errpos(modifier)); @@ -4362,6 +4369,9 @@ static int create_val_fields(struct hist_trigger_data= *hist_data, if (strncmp(field_str + 8, ".percent", 8) =3D=3D 0) hist_data->fields[HITCOUNT_IDX]->flags |=3D HIST_FIELD_FL_PERCENT; + if (strncmp(field_str + 8, ".graph", 8) =3D=3D 0) + hist_data->fields[HITCOUNT_IDX]->flags |=3D + HIST_FIELD_FL_GRAPH; continue; } =20 @@ -5316,20 +5326,52 @@ static inline unsigned int __get_percentage(u64 val= , u64 total) return val ? UINT_MAX : 0; } =20 +#define BAR_CHAR '#' + +static inline const char *__fill_bar_str(char *buf, int size, u64 val, u64= max) +{ + unsigned int len =3D __get_percentage(val, max); + int i; + + if (len =3D=3D UINT_MAX) { + snprintf(buf, size, "[ERROR]"); + return buf; + } + + len =3D len * size / 10000; + for (i =3D 0; i < len && i < size; i++) + buf[i] =3D BAR_CHAR; + while (i < size) + buf[i++] =3D ' '; + buf[size] =3D '\0'; + + return buf; +} + +struct hist_val_stat { + u64 max; + u64 total; +}; + static void hist_trigger_print_val(struct seq_file *m, unsigned int idx, const char *field_name, unsigned long flags, - u64 *totals, struct tracing_map_elt *elt) + struct hist_val_stat *stats, + struct tracing_map_elt *elt) { u64 val =3D tracing_map_read_sum(elt, idx); unsigned int pc; + char bar[21]; =20 if (flags & HIST_FIELD_FL_PERCENT) { - pc =3D __get_percentage(val, totals[idx]); + pc =3D __get_percentage(val, stats[idx].total); if (pc =3D=3D UINT_MAX) seq_printf(m, " %s (%%):[ERROR]", field_name); else seq_printf(m, " %s (%%): %3u.%02u", field_name, pc / 100, pc % 100); + } else if (flags & HIST_FIELD_FL_GRAPH) { + seq_printf(m, " %s: %20s", field_name, + __fill_bar_str(bar, 20, val, stats[idx].max)); } else if (flags & HIST_FIELD_FL_HEX) { seq_printf(m, " %s: %10llx", field_name, val); } else { @@ -5339,7 +5381,7 @@ static void hist_trigger_print_val(struct seq_file *m= , unsigned int idx, =20 static void hist_trigger_entry_print(struct seq_file *m, struct hist_trigger_data *hist_data, - u64 *totals, + struct hist_val_stat *stats, void *key, struct tracing_map_elt *elt) { @@ -5350,7 +5392,7 @@ static void hist_trigger_entry_print(struct seq_file = *m, hist_trigger_print_key(m, hist_data, key, elt); =20 flags =3D hist_data->fields[i]->flags; - hist_trigger_print_val(m, i, "hitcount", flags, totals, elt); + hist_trigger_print_val(m, i, "hitcount", flags, stats, elt); =20 for (i =3D 1; i < hist_data->n_vals; i++) { field_name =3D hist_field_name(hist_data->fields[i], 0); @@ -5360,7 +5402,7 @@ static void hist_trigger_entry_print(struct seq_file = *m, continue; =20 seq_puts(m, " "); - hist_trigger_print_val(m, i, field_name, flags, totals, elt); + hist_trigger_print_val(m, i, field_name, flags, stats, elt); } =20 print_actions(m, hist_data, elt); @@ -5374,7 +5416,8 @@ static int print_entries(struct seq_file *m, struct tracing_map_sort_entry **sort_entries =3D NULL; struct tracing_map *map =3D hist_data->map; int i, j, n_entries; - u64 *totals =3D NULL; + struct hist_val_stat *stats =3D NULL; + u64 val; =20 n_entries =3D tracing_map_sort_entries(map, hist_data->sort_keys, hist_data->n_sort_keys, @@ -5382,28 +5425,33 @@ static int print_entries(struct seq_file *m, if (n_entries < 0) return n_entries; =20 + /* Calculate the max and the total for each field if needed. */ for (j =3D 0; j < hist_data->n_vals; j++) { - if (!(hist_data->fields[j]->flags & HIST_FIELD_FL_PERCENT)) + if (!(hist_data->fields[j]->flags & + (HIST_FIELD_FL_PERCENT | HIST_FIELD_FL_GRAPH))) continue; - if (!totals) { - totals =3D kcalloc(hist_data->n_vals, sizeof(u64), - GFP_KERNEL); - if (!totals) { + if (!stats) { + stats =3D kcalloc(hist_data->n_vals, sizeof(*stats), + GFP_KERNEL); + if (!stats) { n_entries =3D -ENOMEM; goto out; } } - for (i =3D 0; i < n_entries; i++) - totals[j] +=3D tracing_map_read_sum( - sort_entries[i]->elt, j); + for (i =3D 0; i < n_entries; i++) { + val =3D tracing_map_read_sum(sort_entries[i]->elt, j); + stats[j].total +=3D val; + if (stats[j].max < val) + stats[j].max =3D val; + } } =20 for (i =3D 0; i < n_entries; i++) - hist_trigger_entry_print(m, hist_data, totals, + hist_trigger_entry_print(m, hist_data, stats, sort_entries[i]->key, sort_entries[i]->elt); =20 - kfree(totals); + kfree(stats); out: tracing_map_destroy_sort_entries(sort_entries, n_entries); =20 @@ -5828,6 +5876,8 @@ static int event_hist_trigger_print(struct seq_file *= m, seq_puts(m, "hitcount"); if (field->flags & HIST_FIELD_FL_PERCENT) seq_puts(m, ".percent"); + else if (field->flags & HIST_FIELD_FL_GRAPH) + seq_puts(m, ".graph"); } else { seq_puts(m, ","); hist_field_print(m, field); From nobody Tue Apr 7 13:28:35 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 4FFCDECAAD5 for ; Sat, 27 Aug 2022 04:04:09 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S232408AbiH0EEI (ORCPT ); Sat, 27 Aug 2022 00:04:08 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:33348 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S240971AbiH0EEE (ORCPT ); Sat, 27 Aug 2022 00:04:04 -0400 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 2E06AE42F9 for ; Fri, 26 Aug 2022 21:03:57 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dfw.source.kernel.org (Postfix) with ESMTPS id BE62861E0E for ; Sat, 27 Aug 2022 04:03:56 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 02BDDC433C1; Sat, 27 Aug 2022 04:03:54 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1661573036; bh=f9mXihupzTDK1250qHChyNfWYWBi2D+NT5drxWfjNVM=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=iEmwtVBod0GbmaXmMPKNucuW/S2OBHMTPsQoSnR2YoQK6xZ0HK/kbX5+qFTlLHT+i gNW0DlqV2nvg4ux8OrMj/2tHiTApgJ+rtDk44SSdaIFUrgzAG6x7CykljFQTQXx4ps C/a/f3tbG+XE0LHRwxpT2YYLXrCv3Iyohq/z8gGwpfI2w9e6gUGp94G+a6X0YlvCN5 lUFtwYHDOkQxJJDGWJPwqZ+4VncIxdMhcMyZ0mc8XvtC80j9uWLEJSF2duhulBPqh1 ZGLlYD7WJzc20+nAHnIusE4XIIylMzubBdwya1Y6d6A/8uJS/sfw4Le4T8M6/iGa75 hyWKWzbULsqew== From: "Masami Hiramatsu (Google)" To: Steven Rostedt Cc: Tom Zanussi , Ingo Molnar , linux-kernel@vger.kernel.org Subject: [PATCH v4 5/5] tracing: Show hitcount value only when specified Date: Sat, 27 Aug 2022 13:03:52 +0900 Message-Id: <166157303240.348924.7493529171143320258.stgit@devnote2> X-Mailer: git-send-email 2.25.1 In-Reply-To: <166157298537.348924.2537162090505397377.stgit@devnote2> References: <166157298537.348924.2537162090505397377.stgit@devnote2> User-Agent: StGit/0.19 MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Masami Hiramatsu (Google) Show the hitcount value only when it is specified explicitly or no value is specified. # cd /sys/kernel/debug/tracing/ # echo hist:keys=3Dpid:vals=3Druntime.percent,runtime.graph:sort=3Dpid > \ events/sched/sched_stat_runtime/trigger # sleep 10 # cat events/sched/sched_stat_runtime/hist # event histogram # # trigger info: hist:keys=3Dpid:vals=3Druntime.percent,runtime.graph:sort= =3Dpid:size=3D2048 [active] # { pid: 14 } runtime (%): 0.97 runtime: { pid: 16 } runtime (%): 1.74 runtime: { pid: 26 } runtime (%): 0.13 runtime: { pid: 57 } runtime (%): 7.06 runtime: ### { pid: 61 } runtime (%): 11.06 runtime: ##### { pid: 65 } runtime (%): 0.75 runtime: { pid: 70 } runtime (%): 0.98 runtime: { pid: 77 } runtime (%): 0.10 runtime: { pid: 125 } runtime (%): 0.56 runtime: { pid: 146 } runtime (%): 37.53 runtime: #################### { pid: 152 } runtime (%): 23.67 runtime: ############ { pid: 153 } runtime (%): 15.39 runtime: ######## Signed-off-by: Masami Hiramatsu (Google) --- kernel/trace/trace_events_hist.c | 33 +++++++++++++++++++-------------- 1 file changed, 19 insertions(+), 14 deletions(-) diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_h= ist.c index fceea784fded..35feeea84a38 100644 --- a/kernel/trace/trace_events_hist.c +++ b/kernel/trace/trace_events_hist.c @@ -508,6 +508,7 @@ enum hist_field_flags { HIST_FIELD_FL_CONST =3D 1 << 18, HIST_FIELD_FL_PERCENT =3D 1 << 19, HIST_FIELD_FL_GRAPH =3D 1 << 20, + HIST_FIELD_FL_VAL =3D 1 << 21, }; =20 struct var_defs { @@ -4204,7 +4205,8 @@ static int create_val_field(struct hist_trigger_data = *hist_data, if (WARN_ON(val_idx >=3D TRACING_MAP_VALS_MAX)) return -EINVAL; =20 - return __create_val_field(hist_data, val_idx, file, NULL, field_str, 0); + return __create_val_field(hist_data, val_idx, file, NULL, field_str, + HIST_FIELD_FL_VAL); } =20 static const char no_comm[] =3D "(no comm)"; @@ -4355,8 +4357,11 @@ static int create_val_fields(struct hist_trigger_dat= a *hist_data, goto out; =20 fields_str =3D hist_data->attrs->vals_str; - if (!fields_str) + if (!fields_str) { + /* If there is no value, use hitcount as a value */ + hist_data->fields[HITCOUNT_IDX]->flags |=3D HIST_FIELD_FL_VAL; goto out; + } =20 for (i =3D 0, j =3D 1; i < TRACING_MAP_VALS_MAX && j < TRACING_MAP_VALS_MAX; i++) { @@ -4372,6 +4377,8 @@ static int create_val_fields(struct hist_trigger_data= *hist_data, if (strncmp(field_str + 8, ".graph", 8) =3D=3D 0) hist_data->fields[HITCOUNT_IDX]->flags |=3D HIST_FIELD_FL_GRAPH; + hist_data->fields[HITCOUNT_IDX]->flags |=3D + HIST_FIELD_FL_VAL; continue; } =20 @@ -5392,13 +5399,13 @@ static void hist_trigger_entry_print(struct seq_fil= e *m, hist_trigger_print_key(m, hist_data, key, elt); =20 flags =3D hist_data->fields[i]->flags; - hist_trigger_print_val(m, i, "hitcount", flags, stats, elt); + if (flags & HIST_FIELD_FL_VAL) + hist_trigger_print_val(m, i, "hitcount", flags, stats, elt); =20 for (i =3D 1; i < hist_data->n_vals; i++) { field_name =3D hist_field_name(hist_data->fields[i], 0); flags =3D hist_data->fields[i]->flags; - - if (flags & HIST_FIELD_FL_VAR || flags & HIST_FIELD_FL_EXPR) + if (!(flags & HIST_FIELD_FL_VAL)) continue; =20 seq_puts(m, " "); @@ -5842,6 +5849,7 @@ static int event_hist_trigger_print(struct seq_file *= m, struct hist_trigger_data *hist_data =3D data->private_data; struct hist_field *field; bool have_var =3D false; + bool show_val =3D false; unsigned int i; =20 seq_puts(m, HIST_PREFIX); @@ -5872,16 +5880,13 @@ static int event_hist_trigger_print(struct seq_file= *m, continue; } =20 - if (i =3D=3D HITCOUNT_IDX) { - seq_puts(m, "hitcount"); - if (field->flags & HIST_FIELD_FL_PERCENT) - seq_puts(m, ".percent"); - else if (field->flags & HIST_FIELD_FL_GRAPH) - seq_puts(m, ".graph"); - } else { + if (!(field->flags & HIST_FIELD_FL_VAL)) + continue; + + if (show_val) seq_puts(m, ","); - hist_field_print(m, field); - } + hist_field_print(m, field); + show_val =3D true; } =20 if (have_var) {