2022-08-27 04:26:38

by Masami Hiramatsu

[permalink] [raw]
Subject: [PATCH v4 0/5] tracing/hist: Add percentage histogram suffixes

Hi,

Here is the 4th version of .percent and .graph suffixes for histogram
trigger to show the value in percentage and in bar-graph respectively.

I've rebased on Tom's hitcount patch[1/5] on the series and added a patch
for supressing display of hitcount[5/5] in this version.

This will help us to check the trend of the histogram instantly
without any post processing tool.

Here shows an example of the percentage and the bar graph of
the hitcount of the running tasks.

# cd /sys/kernel/debug/tracing/
# echo hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid > \
events/sched/sched_stat_runtime/trigger
# sleep 10
# cat events/sched/sched_stat_runtime/hist
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid:size=2048 [active]
#

{ pid: 14 } hitcount (%): 4.68 hitcount: ###
{ pid: 16 } hitcount (%): 17.18 hitcount: ###########
{ pid: 57 } hitcount (%): 7.81 hitcount: #####
{ pid: 61 } hitcount (%): 31.25 hitcount: ####################
{ pid: 70 } hitcount (%): 4.68 hitcount: ###
{ pid: 77 } hitcount (%): 1.56 hitcount: #
{ pid: 145 } hitcount (%): 18.75 hitcount: ############
{ pid: 151 } hitcount (%): 9.37 hitcount: ######
{ pid: 152 } hitcount (%): 4.68 hitcount: ###

Totals:
Hits: 64
Entries: 9
Dropped: 0

Of course if you explicitly specify the hitcount, it can show the
hitcount as below;

# cd /sys/kernel/debug/tracing/
# echo hist:keys=pid:vals=hitcount,runtime:sort=pid > \
events/sched/sched_stat_runtime/trigger
# sleep 10
# cat events/sched/sched_stat_runtime/hist
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount,runtime:sort=pid:size=2048 [active]
#

{ pid: 14 } hitcount: 2 runtime: 304876
{ pid: 16 } hitcount: 8 runtime: 300574
{ pid: 26 } hitcount: 2 runtime: 15578
{ pid: 32 } hitcount: 2 runtime: 219186
{ pid: 57 } hitcount: 3 runtime: 506003
{ pid: 61 } hitcount: 20 runtime: 1681473
{ pid: 69 } hitcount: 3 runtime: 201785
{ pid: 70 } hitcount: 4 runtime: 360608
{ pid: 77 } hitcount: 8 runtime: 4146935
{ pid: 145 } hitcount: 13 runtime: 7537994
{ pid: 155 } hitcount: 4 runtime: 2511937
{ pid: 156 } hitcount: 2 runtime: 1398886

Totals:
Hits: 71
Entries: 12
Dropped: 0


Thank you,

---

Masami Hiramatsu (Google) (4):
tracing: Fix to check event_mutex is held while accessing trigger list
tracing: Add .percent suffix option to histogram values
tracing: Add .graph suffix option to histogram value
tracing: Show hitcount value only when specified

Tom Zanussi (1):
tracing: Allow multiple hitcount values in histograms


kernel/trace/trace.c | 3 -
kernel/trace/trace_events_hist.c | 176 ++++++++++++++++++++++++++++++-----
kernel/trace/trace_events_trigger.c | 3 -
3 files changed, 156 insertions(+), 26 deletions(-)

--
Masami Hiramatsu (Google) <[email protected]>


2022-08-27 04:38:12

by Masami Hiramatsu

[permalink] [raw]
Subject: [PATCH v4 4/5] tracing: Add .graph suffix option to histogram value

From: Masami Hiramatsu (Google) <[email protected]>

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=pid:vals=runtime.graph:sort=pid > \
events/sched/sched_stat_runtime/trigger
# sleep 10
# cat events/sched/sched_stat_runtime/hist
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount,runtime.graph:sort=pid:size=2048 [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) <[email protected]>
---
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_hist.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 = 1 << 17,
HIST_FIELD_FL_CONST = 1 << 18,
HIST_FIELD_FL_PERCENT = 1 << 19,
+ HIST_FIELD_FL_GRAPH = 1 << 20,
};

struct var_defs {
@@ -1710,6 +1711,8 @@ static const char *get_hist_field_flags(struct hist_field *hist_field)
flags_str = "usecs";
else if (hist_field->flags & HIST_FIELD_FL_PERCENT)
flags_str = "percent";
+ else if (hist_field->flags & HIST_FIELD_FL_GRAPH)
+ flags_str = "graph";

return flags_str;
}
@@ -2322,6 +2325,10 @@ parse_field(struct hist_trigger_data *hist_data, struct trace_event_file *file,
if (*flags & (HIST_FIELD_FL_VAR | HIST_FIELD_FL_KEY))
goto error;
*flags |= HIST_FIELD_FL_PERCENT;
+ } else if (strncmp(modifier, "graph", 5) == 0) {
+ if (*flags & (HIST_FIELD_FL_VAR | HIST_FIELD_FL_KEY))
+ goto error;
+ *flags |= 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) == 0)
hist_data->fields[HITCOUNT_IDX]->flags |=
HIST_FIELD_FL_PERCENT;
+ if (strncmp(field_str + 8, ".graph", 8) == 0)
+ hist_data->fields[HITCOUNT_IDX]->flags |=
+ HIST_FIELD_FL_GRAPH;
continue;
}

@@ -5316,20 +5326,52 @@ static inline unsigned int __get_percentage(u64 val, u64 total)
return val ? UINT_MAX : 0;
}

+#define BAR_CHAR '#'
+
+static inline const char *__fill_bar_str(char *buf, int size, u64 val, u64 max)
+{
+ unsigned int len = __get_percentage(val, max);
+ int i;
+
+ if (len == UINT_MAX) {
+ snprintf(buf, size, "[ERROR]");
+ return buf;
+ }
+
+ len = len * size / 10000;
+ for (i = 0; i < len && i < size; i++)
+ buf[i] = BAR_CHAR;
+ while (i < size)
+ buf[i++] = ' ';
+ buf[size] = '\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 = tracing_map_read_sum(elt, idx);
unsigned int pc;
+ char bar[21];

if (flags & HIST_FIELD_FL_PERCENT) {
- pc = __get_percentage(val, totals[idx]);
+ pc = __get_percentage(val, stats[idx].total);
if (pc == 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,

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);

flags = 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);

for (i = 1; i < hist_data->n_vals; i++) {
field_name = hist_field_name(hist_data->fields[i], 0);
@@ -5360,7 +5402,7 @@ static void hist_trigger_entry_print(struct seq_file *m,
continue;

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);
}

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 = NULL;
struct tracing_map *map = hist_data->map;
int i, j, n_entries;
- u64 *totals = NULL;
+ struct hist_val_stat *stats = NULL;
+ u64 val;

n_entries = 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;

+ /* Calculate the max and the total for each field if needed. */
for (j = 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 = kcalloc(hist_data->n_vals, sizeof(u64),
- GFP_KERNEL);
- if (!totals) {
+ if (!stats) {
+ stats = kcalloc(hist_data->n_vals, sizeof(*stats),
+ GFP_KERNEL);
+ if (!stats) {
n_entries = -ENOMEM;
goto out;
}
}
- for (i = 0; i < n_entries; i++)
- totals[j] += tracing_map_read_sum(
- sort_entries[i]->elt, j);
+ for (i = 0; i < n_entries; i++) {
+ val = tracing_map_read_sum(sort_entries[i]->elt, j);
+ stats[j].total += val;
+ if (stats[j].max < val)
+ stats[j].max = val;
+ }
}

for (i = 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);

- kfree(totals);
+ kfree(stats);
out:
tracing_map_destroy_sort_entries(sort_entries, n_entries);

@@ -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);

2022-08-27 04:38:40

by Masami Hiramatsu

[permalink] [raw]
Subject: [PATCH v4 5/5] tracing: Show hitcount value only when specified

From: Masami Hiramatsu (Google) <[email protected]>

Show the hitcount value only when it is specified explicitly or
no value is specified.

# cd /sys/kernel/debug/tracing/
# echo hist:keys=pid:vals=runtime.percent,runtime.graph:sort=pid > \
events/sched/sched_stat_runtime/trigger
# sleep 10
# cat events/sched/sched_stat_runtime/hist
# event histogram
#
# trigger info: hist:keys=pid:vals=runtime.percent,runtime.graph:sort=pid:size=2048 [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) <[email protected]>
---
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_hist.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 = 1 << 18,
HIST_FIELD_FL_PERCENT = 1 << 19,
HIST_FIELD_FL_GRAPH = 1 << 20,
+ HIST_FIELD_FL_VAL = 1 << 21,
};

struct var_defs {
@@ -4204,7 +4205,8 @@ static int create_val_field(struct hist_trigger_data *hist_data,
if (WARN_ON(val_idx >= TRACING_MAP_VALS_MAX))
return -EINVAL;

- 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);
}

static const char no_comm[] = "(no comm)";
@@ -4355,8 +4357,11 @@ static int create_val_fields(struct hist_trigger_data *hist_data,
goto out;

fields_str = 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 |= HIST_FIELD_FL_VAL;
goto out;
+ }

for (i = 0, j = 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) == 0)
hist_data->fields[HITCOUNT_IDX]->flags |=
HIST_FIELD_FL_GRAPH;
+ hist_data->fields[HITCOUNT_IDX]->flags |=
+ HIST_FIELD_FL_VAL;
continue;
}

@@ -5392,13 +5399,13 @@ static void hist_trigger_entry_print(struct seq_file *m,
hist_trigger_print_key(m, hist_data, key, elt);

flags = 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);

for (i = 1; i < hist_data->n_vals; i++) {
field_name = hist_field_name(hist_data->fields[i], 0);
flags = hist_data->fields[i]->flags;
-
- if (flags & HIST_FIELD_FL_VAR || flags & HIST_FIELD_FL_EXPR)
+ if (!(flags & HIST_FIELD_FL_VAL))
continue;

seq_puts(m, " ");
@@ -5842,6 +5849,7 @@ static int event_hist_trigger_print(struct seq_file *m,
struct hist_trigger_data *hist_data = data->private_data;
struct hist_field *field;
bool have_var = false;
+ bool show_val = false;
unsigned int i;

seq_puts(m, HIST_PREFIX);
@@ -5872,16 +5880,13 @@ static int event_hist_trigger_print(struct seq_file *m,
continue;
}

- if (i == 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 = true;
}

if (have_var) {

2022-08-31 21:52:53

by Tom Zanussi

[permalink] [raw]
Subject: Re: [PATCH v4 0/5] tracing/hist: Add percentage histogram suffixes

Hi Masami,

On Sat, 2022-08-27 at 13:03 +0900, Masami Hiramatsu (Google) wrote:
> Hi,
>
> Here is the 4th version of .percent and .graph suffixes for histogram
> trigger to show the value in percentage and in bar-graph
> respectively.
>
> I've rebased on Tom's hitcount patch[1/5] on the series and added a
> patch
> for supressing display of hitcount[5/5] in this version.

This is a very nice patchset overall - the only question I have
concerns patch 5 for suppressing the hitcount. I actually think the
patch is fine and does what it says nicely (and probably should have
been done that way to begin with) but it looks like it would cause
problems for anyone already doing postprocessing and whose scripts
would be expecting the hitcount to be there. So changing the default
behavior would require their scripts to change, and also now that I
look at it, the example output in Documentation/ as well.

How about adding an option like 'nohitcount' and having that patch do
what it does but only if that option is set?

Anyway, for the other ones, patches 2-4,

Signed-off-by: Tom Zanussi <[email protected]>
Tested-by: Tom Zanussi <[email protected]

Thanks!

Tom

>
> This will help us to check the trend of the histogram instantly
> without any post processing tool.
>
> Here shows an example of the percentage and the bar graph of
> the hitcount of the running tasks.
>
>   # cd /sys/kernel/debug/tracing/
>   # echo hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid
> > \
>         events/sched/sched_stat_runtime/trigger
>   # sleep 10
>   # cat events/sched/sched_stat_runtime/hist
>  # event histogram
>  #
>  # trigger info:
> hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid:size=2048
> [active]
>  #
>
>  { pid:         14 } hitcount (%):   4.68  hitcount:
> ###                
>  { pid:         16 } hitcount (%):  17.18  hitcount:
> ###########        
>  { pid:         57 } hitcount (%):   7.81  hitcount:
> #####              
>  { pid:         61 } hitcount (%):  31.25  hitcount:
> ####################
>  { pid:         70 } hitcount (%):   4.68  hitcount:
> ###                
>  { pid:         77 } hitcount (%):   1.56  hitcount:
> #                  
>  { pid:        145 } hitcount (%):  18.75  hitcount:
> ############       
>  { pid:        151 } hitcount (%):   9.37  hitcount:
> ######             
>  { pid:        152 } hitcount (%):   4.68  hitcount:
> ###                
>
>  Totals:
>      Hits: 64
>      Entries: 9
>      Dropped: 0
>
> Of course if you explicitly specify the hitcount, it can show the
> hitcount as below;
>
>   # cd /sys/kernel/debug/tracing/
>   # echo hist:keys=pid:vals=hitcount,runtime:sort=pid > \
>         events/sched/sched_stat_runtime/trigger
>   # sleep 10
>   # cat events/sched/sched_stat_runtime/hist
>  # event histogram
>  #
>  # trigger info:
> hist:keys=pid:vals=hitcount,runtime:sort=pid:size=2048 [active]
>  #
>
>  { pid:         14 } hitcount:          2  runtime:     304876
>  { pid:         16 } hitcount:          8  runtime:     300574
>  { pid:         26 } hitcount:          2  runtime:      15578
>  { pid:         32 } hitcount:          2  runtime:     219186
>  { pid:         57 } hitcount:          3  runtime:     506003
>  { pid:         61 } hitcount:         20  runtime:    1681473
>  { pid:         69 } hitcount:          3  runtime:     201785
>  { pid:         70 } hitcount:          4  runtime:     360608
>  { pid:         77 } hitcount:          8  runtime:    4146935
>  { pid:        145 } hitcount:         13  runtime:    7537994
>  { pid:        155 } hitcount:          4  runtime:    2511937
>  { pid:        156 } hitcount:          2  runtime:    1398886
>
>  Totals:
>      Hits: 71
>      Entries: 12
>      Dropped: 0
>
>
> Thank you,
>
> ---
>
> Masami Hiramatsu (Google) (4):
>       tracing: Fix to check event_mutex is held while accessing
> trigger list
>       tracing: Add .percent suffix option to histogram values
>       tracing: Add .graph suffix option to histogram value
>       tracing: Show hitcount value only when specified
>
> Tom Zanussi (1):
>       tracing: Allow multiple hitcount values in histograms
>
>
>  kernel/trace/trace.c                |    3 -
>  kernel/trace/trace_events_hist.c    |  176
> ++++++++++++++++++++++++++++++-----
>  kernel/trace/trace_events_trigger.c |    3 -
>  3 files changed, 156 insertions(+), 26 deletions(-)
>
> --
> Masami Hiramatsu (Google) <[email protected]>

2022-08-31 23:53:12

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v4 0/5] tracing/hist: Add percentage histogram suffixes

On Wed, 31 Aug 2022 16:35:25 -0500
Tom Zanussi <[email protected]> wrote:

> Hi Masami,
>
> On Sat, 2022-08-27 at 13:03 +0900, Masami Hiramatsu (Google) wrote:
> > Hi,
> >
> > Here is the 4th version of .percent and .graph suffixes for histogram
> > trigger to show the value in percentage and in bar-graph
> > respectively.
> >
> > I've rebased on Tom's hitcount patch[1/5] on the series and added a
> > patch
> > for supressing display of hitcount[5/5] in this version.
>
> This is a very nice patchset overall - the only question I have
> concerns patch 5 for suppressing the hitcount. I actually think the
> patch is fine and does what it says nicely (and probably should have
> been done that way to begin with) but it looks like it would cause
> problems for anyone already doing postprocessing and whose scripts
> would be expecting the hitcount to be there. So changing the default
> behavior would require their scripts to change, and also now that I
> look at it, the example output in Documentation/ as well.

Good catch! Yeah, this type of change will need to update the docs.
I missed that.

>
> How about adding an option like 'nohitcount' and having that patch do
> what it does but only if that option is set?

Agreed. So something like this?

echo hist:keys=pid:vals=runtime.graph:nohitcount (or NOHC for short)

Maybe we can also add an option under <tracefs/>options/

>
> Anyway, for the other ones, patches 2-4,
>
> Signed-off-by: Tom Zanussi <[email protected]>
> Tested-by: Tom Zanussi <[email protected]

Thank you!

>
> Thanks!
>
> Tom
>
> >
> > This will help us to check the trend of the histogram instantly
> > without any post processing tool.
> >
> > Here shows an example of the percentage and the bar graph of
> > the hitcount of the running tasks.
> >
> >   # cd /sys/kernel/debug/tracing/
> >   # echo hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid
> > > \
> >         events/sched/sched_stat_runtime/trigger
> >   # sleep 10
> >   # cat events/sched/sched_stat_runtime/hist
> >  # event histogram
> >  #
> >  # trigger info:
> > hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid:size=2048
> > [active]
> >  #
> >
> >  { pid:         14 } hitcount (%):   4.68  hitcount:
> > ###                
> >  { pid:         16 } hitcount (%):  17.18  hitcount:
> > ###########        
> >  { pid:         57 } hitcount (%):   7.81  hitcount:
> > #####              
> >  { pid:         61 } hitcount (%):  31.25  hitcount:
> > ####################
> >  { pid:         70 } hitcount (%):   4.68  hitcount:
> > ###                
> >  { pid:         77 } hitcount (%):   1.56  hitcount:
> > #                  
> >  { pid:        145 } hitcount (%):  18.75  hitcount:
> > ############       
> >  { pid:        151 } hitcount (%):   9.37  hitcount:
> > ######             
> >  { pid:        152 } hitcount (%):   4.68  hitcount:
> > ###                
> >
> >  Totals:
> >      Hits: 64
> >      Entries: 9
> >      Dropped: 0
> >
> > Of course if you explicitly specify the hitcount, it can show the
> > hitcount as below;
> >
> >   # cd /sys/kernel/debug/tracing/
> >   # echo hist:keys=pid:vals=hitcount,runtime:sort=pid > \
> >         events/sched/sched_stat_runtime/trigger
> >   # sleep 10
> >   # cat events/sched/sched_stat_runtime/hist
> >  # event histogram
> >  #
> >  # trigger info:
> > hist:keys=pid:vals=hitcount,runtime:sort=pid:size=2048 [active]
> >  #
> >
> >  { pid:         14 } hitcount:          2  runtime:     304876
> >  { pid:         16 } hitcount:          8  runtime:     300574
> >  { pid:         26 } hitcount:          2  runtime:      15578
> >  { pid:         32 } hitcount:          2  runtime:     219186
> >  { pid:         57 } hitcount:          3  runtime:     506003
> >  { pid:         61 } hitcount:         20  runtime:    1681473
> >  { pid:         69 } hitcount:          3  runtime:     201785
> >  { pid:         70 } hitcount:          4  runtime:     360608
> >  { pid:         77 } hitcount:          8  runtime:    4146935
> >  { pid:        145 } hitcount:         13  runtime:    7537994
> >  { pid:        155 } hitcount:          4  runtime:    2511937
> >  { pid:        156 } hitcount:          2  runtime:    1398886
> >
> >  Totals:
> >      Hits: 71
> >      Entries: 12
> >      Dropped: 0
> >
> >
> > Thank you,
> >
> > ---
> >
> > Masami Hiramatsu (Google) (4):
> >       tracing: Fix to check event_mutex is held while accessing
> > trigger list
> >       tracing: Add .percent suffix option to histogram values
> >       tracing: Add .graph suffix option to histogram value
> >       tracing: Show hitcount value only when specified
> >
> > Tom Zanussi (1):
> >       tracing: Allow multiple hitcount values in histograms
> >
> >
> >  kernel/trace/trace.c                |    3 -
> >  kernel/trace/trace_events_hist.c    |  176
> > ++++++++++++++++++++++++++++++-----
> >  kernel/trace/trace_events_trigger.c |    3 -
> >  3 files changed, 156 insertions(+), 26 deletions(-)
> >
> > --
> > Masami Hiramatsu (Google) <[email protected]>
>


--
Masami Hiramatsu (Google) <[email protected]>

2022-09-01 21:23:15

by Tom Zanussi

[permalink] [raw]
Subject: Re: [PATCH v4 0/5] tracing/hist: Add percentage histogram suffixes

On Thu, 2022-09-01 at 08:02 +0900, Masami Hiramatsu wrote:
> On Wed, 31 Aug 2022 16:35:25 -0500
> Tom Zanussi <[email protected]> wrote:
>
> > Hi Masami,
> >
> > On Sat, 2022-08-27 at 13:03 +0900, Masami Hiramatsu (Google) wrote:
> > > Hi,
> > >
> > > Here is the 4th version of .percent and .graph suffixes for
> > > histogram
> > > trigger to show the value in percentage and in bar-graph
> > > respectively.
> > >
> > > I've rebased on Tom's hitcount patch[1/5] on the series and added
> > > a
> > > patch
> > > for supressing display of hitcount[5/5] in this version.
> >
> > This is a very nice patchset overall - the only question I have
> > concerns patch 5 for suppressing the hitcount.  I actually think
> > the
> > patch is fine and does what it says nicely (and probably should
> > have
> > been done that way to begin with) but it looks like it would cause
> > problems for anyone already doing postprocessing and whose scripts
> > would be expecting the hitcount to be there.  So changing the
> > default
> > behavior would require their scripts to change, and also now that I
> > look at it, the example output in Documentation/ as well.
>
> Good catch! Yeah, this type of change will need to update the docs.
> I missed that.
>
> >
> > How about adding an option like 'nohitcount' and having that patch
> > do
> > what it does but only if that option is set?
>
> Agreed. So something like this?
>
> echo hist:keys=pid:vals=runtime.graph:nohitcount (or NOHC for short)
>
> Maybe we can also add an option under <tracefs/>options/

Yeah, makes sense to me.

Thanks,

Tom

>
> >
> > Anyway, for the other ones, patches 2-4,
> >
> >   Signed-off-by: Tom Zanussi <[email protected]>
> >   Tested-by: Tom Zanussi <[email protected]
>
> Thank you!
>
> >
> > Thanks!
> >
> > Tom
> >
> > >
> > > This will help us to check the trend of the histogram instantly
> > > without any post processing tool.
> > >
> > > Here shows an example of the percentage and the bar graph of
> > > the hitcount of the running tasks.
> > >
> > >   # cd /sys/kernel/debug/tracing/
> > >   # echo
> > > hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid
> > > > \
> > >         events/sched/sched_stat_runtime/trigger
> > >   # sleep 10
> > >   # cat events/sched/sched_stat_runtime/hist
> > >  # event histogram
> > >  #
> > >  # trigger info:
> > > hist:keys=pid:vals=hitcount.percent,hitcount.graph:sort=pid:size=
> > > 2048
> > > [active]
> > >  #
> > >
> > >  { pid:         14 } hitcount (%):   4.68  hitcount:
> > > ###                
> > >  { pid:         16 } hitcount (%):  17.18  hitcount:
> > > ###########        
> > >  { pid:         57 } hitcount (%):   7.81  hitcount:
> > > #####              
> > >  { pid:         61 } hitcount (%):  31.25  hitcount:
> > > ####################
> > >  { pid:         70 } hitcount (%):   4.68  hitcount:
> > > ###                
> > >  { pid:         77 } hitcount (%):   1.56  hitcount:
> > > #                  
> > >  { pid:        145 } hitcount (%):  18.75  hitcount:
> > > ############       
> > >  { pid:        151 } hitcount (%):   9.37  hitcount:
> > > ######             
> > >  { pid:        152 } hitcount (%):   4.68  hitcount:
> > > ###                
> > >
> > >  Totals:
> > >      Hits: 64
> > >      Entries: 9
> > >      Dropped: 0
> > >
> > > Of course if you explicitly specify the hitcount, it can show the
> > > hitcount as below;
> > >
> > >   # cd /sys/kernel/debug/tracing/
> > >   # echo hist:keys=pid:vals=hitcount,runtime:sort=pid > \
> > >         events/sched/sched_stat_runtime/trigger
> > >   # sleep 10
> > >   # cat events/sched/sched_stat_runtime/hist
> > >  # event histogram
> > >  #
> > >  # trigger info:
> > > hist:keys=pid:vals=hitcount,runtime:sort=pid:size=2048 [active]
> > >  #
> > >
> > >  { pid:         14 } hitcount:          2  runtime:     304876
> > >  { pid:         16 } hitcount:          8  runtime:     300574
> > >  { pid:         26 } hitcount:          2  runtime:      15578
> > >  { pid:         32 } hitcount:          2  runtime:     219186
> > >  { pid:         57 } hitcount:          3  runtime:     506003
> > >  { pid:         61 } hitcount:         20  runtime:    1681473
> > >  { pid:         69 } hitcount:          3  runtime:     201785
> > >  { pid:         70 } hitcount:          4  runtime:     360608
> > >  { pid:         77 } hitcount:          8  runtime:    4146935
> > >  { pid:        145 } hitcount:         13  runtime:    7537994
> > >  { pid:        155 } hitcount:          4  runtime:    2511937
> > >  { pid:        156 } hitcount:          2  runtime:    1398886
> > >
> > >  Totals:
> > >      Hits: 71
> > >      Entries: 12
> > >      Dropped: 0
> > >
> > >
> > > Thank you,
> > >
> > > ---
> > >
> > > Masami Hiramatsu (Google) (4):
> > >       tracing: Fix to check event_mutex is held while accessing
> > > trigger list
> > >       tracing: Add .percent suffix option to histogram values
> > >       tracing: Add .graph suffix option to histogram value
> > >       tracing: Show hitcount value only when specified
> > >
> > > Tom Zanussi (1):
> > >       tracing: Allow multiple hitcount values in histograms
> > >
> > >
> > >  kernel/trace/trace.c                |    3 -
> > >  kernel/trace/trace_events_hist.c    |  176
> > > ++++++++++++++++++++++++++++++-----
> > >  kernel/trace/trace_events_trigger.c |    3 -
> > >  3 files changed, 156 insertions(+), 26 deletions(-)
> > >
> > > --
> > > Masami Hiramatsu (Google) <[email protected]>
> >
>
>