[PATCH v13 24/29] tracing: Add support for multiple hist triggers per event
From: Tom Zanussi
Date: Thu Dec 10 2015 - 13:52:21 EST
Allow users to define any number of hist triggers per trace event.
Any number of hist triggers may be added for a given event, which may
differ by key, value, or filter.
Reading the event's 'hist' file will display the output of all the
hist triggers defined on an event concatenated in the order they were
defined.
Signed-off-by: Tom Zanussi <tom.zanussi@xxxxxxxxxxxxxxx>
Tested-by: Masami Hiramatsu <masami.hiramatsu.pt@xxxxxxxxxxx>
Reviewed-by: Namhyung Kim <namhyung@xxxxxxxxxx>
---
Documentation/trace/events.txt | 154 +++++++++++++++++++++++++++++++++--
kernel/trace/trace.c | 8 +-
kernel/trace/trace_events_hist.c | 172 +++++++++++++++++++++++++++++++--------
3 files changed, 293 insertions(+), 41 deletions(-)
diff --git a/Documentation/trace/events.txt b/Documentation/trace/events.txt
index db223e8..cc02167 100644
--- a/Documentation/trace/events.txt
+++ b/Documentation/trace/events.txt
@@ -550,12 +550,14 @@ The following commands are supported:
'hist' triggers add a 'hist' file to each event's subdirectory.
Reading the 'hist' file for the event will dump the hash table in
- its entirety to stdout. Each printed hash table entry is a simple
- list of the keys and values comprising the entry; keys are printed
- first and are delineated by curly braces, and are followed by the
- set of value fields for the entry. By default, numeric fields are
- displayed as base-10 integers. This can be modified by appending
- any of the following modifiers to the field name:
+ its entirety to stdout. If there are multiple hist triggers
+ attached to an event, there will be a table for each trigger in the
+ output. Each printed hash table entry is a simple list of the keys
+ and values comprising the entry; keys are printed first and are
+ delineated by curly braces, and are followed by the set of value
+ fields for the entry. By default, numeric fields are displayed as
+ base-10 integers. This can be modified by appending any of the
+ following modifiers to the field name:
.hex display a number as a hex value
.sym display an address as a symbol
@@ -1667,3 +1669,143 @@ The following commands are supported:
.
.
.
+
+ The following example demonstrates how multiple hist triggers can be
+ attached to a given event. This capability can be useful for
+ creating a set of different summaries derived from the same set of
+ events, or for comparing the effects of different filters, among
+ other things.
+
+ # echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
+ /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ # echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
+ /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ # echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
+ /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ # echo 'hist:keys=skbaddr.hex:vals=len' >> \
+ /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+ # echo 'hist:keys=len:vals=common_preempt_count' >> \
+ /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+
+ The above set of commands create four triggers differing only in
+ their filters, along with a completely different though fairly
+ nonsensical trigger. Note that in order to append multiple hist
+ triggers to the same file, you should use the '>>' operator to
+ append them ('>' will also add the new hist trigger, but will remove
+ any existing hist triggers beforehand).
+
+ Displaying the contents of the 'hist' file for the event shows the
+ contents of all five histograms:
+
+ # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
+
+ # event histogram
+ #
+ # trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active]
+ #
+
+ { len: 176 } hitcount: 1 common_preempt_count: 0
+ { len: 223 } hitcount: 1 common_preempt_count: 0
+ { len: 4854 } hitcount: 1 common_preempt_count: 0
+ { len: 395 } hitcount: 1 common_preempt_count: 0
+ { len: 177 } hitcount: 1 common_preempt_count: 0
+ { len: 446 } hitcount: 1 common_preempt_count: 0
+ { len: 1601 } hitcount: 1 common_preempt_count: 0
+ .
+ .
+ .
+ { len: 1280 } hitcount: 66 common_preempt_count: 0
+ { len: 116 } hitcount: 81 common_preempt_count: 40
+ { len: 708 } hitcount: 112 common_preempt_count: 0
+ { len: 46 } hitcount: 221 common_preempt_count: 0
+ { len: 1264 } hitcount: 458 common_preempt_count: 0
+
+ Totals:
+ Hits: 1428
+ Entries: 147
+ Dropped: 0
+
+
+ # event histogram
+ #
+ # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
+ #
+
+ { skbaddr: ffff8800baee5e00 } hitcount: 1 len: 130
+ { skbaddr: ffff88005f3d5600 } hitcount: 1 len: 1280
+ { skbaddr: ffff88005f3d4900 } hitcount: 1 len: 1280
+ { skbaddr: ffff88009fed6300 } hitcount: 1 len: 115
+ { skbaddr: ffff88009fe0ad00 } hitcount: 1 len: 115
+ { skbaddr: ffff88008cdb1900 } hitcount: 1 len: 46
+ { skbaddr: ffff880064b5ef00 } hitcount: 1 len: 118
+ { skbaddr: ffff880044e3c700 } hitcount: 1 len: 60
+ { skbaddr: ffff880100065900 } hitcount: 1 len: 46
+ { skbaddr: ffff8800d46bd500 } hitcount: 1 len: 116
+ { skbaddr: ffff88005f3d5f00 } hitcount: 1 len: 1280
+ { skbaddr: ffff880100064700 } hitcount: 1 len: 365
+ { skbaddr: ffff8800badb6f00 } hitcount: 1 len: 60
+ .
+ .
+ .
+ { skbaddr: ffff88009fe0be00 } hitcount: 27 len: 24677
+ { skbaddr: ffff88009fe0a400 } hitcount: 27 len: 23052
+ { skbaddr: ffff88009fe0b700 } hitcount: 31 len: 25589
+ { skbaddr: ffff88009fe0b600 } hitcount: 32 len: 27326
+ { skbaddr: ffff88006a462800 } hitcount: 68 len: 71678
+ { skbaddr: ffff88006a463700 } hitcount: 70 len: 72678
+ { skbaddr: ffff88006a462b00 } hitcount: 71 len: 77589
+ { skbaddr: ffff88006a463600 } hitcount: 73 len: 71307
+ { skbaddr: ffff88006a462200 } hitcount: 81 len: 81032
+
+ Totals:
+ Hits: 1451
+ Entries: 318
+ Dropped: 0
+
+
+ # event histogram
+ #
+ # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len == 256 [active]
+ #
+
+
+ Totals:
+ Hits: 0
+ Entries: 0
+ Dropped: 0
+
+
+ # event histogram
+ #
+ # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [active]
+ #
+
+ { skbaddr: ffff88009fd2c300 } hitcount: 1 len: 7212
+ { skbaddr: ffff8800d2bcce00 } hitcount: 1 len: 7212
+ { skbaddr: ffff8800d2bcd700 } hitcount: 1 len: 7212
+ { skbaddr: ffff8800d2bcda00 } hitcount: 1 len: 21492
+ { skbaddr: ffff8800ae2e2d00 } hitcount: 1 len: 7212
+ { skbaddr: ffff8800d2bcdb00 } hitcount: 1 len: 7212
+ { skbaddr: ffff88006a4df500 } hitcount: 1 len: 4854
+ { skbaddr: ffff88008ce47b00 } hitcount: 1 len: 18636
+ { skbaddr: ffff8800ae2e2200 } hitcount: 1 len: 12924
+ { skbaddr: ffff88005f3e1000 } hitcount: 1 len: 4356
+ { skbaddr: ffff8800d2bcdc00 } hitcount: 2 len: 24420
+ { skbaddr: ffff8800d2bcc200 } hitcount: 2 len: 12996
+
+ Totals:
+ Hits: 14
+ Entries: 12
+ Dropped: 0
+
+
+ # event histogram
+ #
+ # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active]
+ #
+
+
+ Totals:
+ Hits: 0
+ Entries: 0
+ Dropped: 0
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 8b9424d..f1ec156 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -3847,9 +3847,11 @@ static const char readme_msg[] =
"\t sort field. The 'size' parameter can be used to specify more\n"
"\t or fewer than the default 2048 entries for the hashtable size.\n\n"
"\t Reading the 'hist' file for the event will dump the hash\n"
- "\t table in its entirety to stdout. The default format used to\n"
- "\t display a given field can be modified by appending any of the\n"
- "\t following modifiers to the field name, as applicable:\n\n"
+ "\t table in its entirety to stdout. If there are multiple hist\n"
+ "\t triggers attached to an event, there will be a table for each\n"
+ "\t trigger in the output. The default format used to display a\n"
+ "\t given field can be modified by appending any of the following\n"
+ "\t modifiers to the field name, as applicable:\n\n"
"\t .hex display a number as a hex value\n"
"\t .sym display an address as a symbol\n"
"\t .sym-offset display an address as a symbol and offset\n"
diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index 63fceab..37ad970 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -1016,33 +1016,18 @@ static int print_entries(struct seq_file *m,
return n_entries;
}
-static int hist_show(struct seq_file *m, void *v)
+static void hist_trigger_show(struct seq_file *m,
+ struct event_trigger_data *data, int n)
{
- struct event_trigger_data *test, *data = NULL;
- struct trace_event_file *event_file;
struct hist_trigger_data *hist_data;
int n_entries, ret = 0;
- mutex_lock(&event_mutex);
-
- event_file = event_file_data(m->private);
- if (unlikely(!event_file)) {
- ret = -ENODEV;
- goto out_unlock;
- }
-
- list_for_each_entry_rcu(test, &event_file->triggers, list) {
- if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) {
- data = test;
- break;
- }
- }
- if (!data)
- goto out_unlock;
+ if (n > 0)
+ seq_puts(m, "\n\n");
seq_puts(m, "# event histogram\n#\n# trigger info: ");
data->ops->print(m, data->ops, data);
- seq_puts(m, "\n");
+ seq_puts(m, "#\n\n");
hist_data = data->private_data;
n_entries = print_entries(m, hist_data);
@@ -1054,6 +1039,27 @@ static int hist_show(struct seq_file *m, void *v)
seq_printf(m, "\nTotals:\n Hits: %llu\n Entries: %u\n Dropped: %llu\n",
(u64)atomic64_read(&hist_data->map->hits),
n_entries, (u64)atomic64_read(&hist_data->map->drops));
+}
+
+static int hist_show(struct seq_file *m, void *v)
+{
+ struct event_trigger_data *data;
+ struct trace_event_file *event_file;
+ int n = 0, ret = 0;
+
+ mutex_lock(&event_mutex);
+
+ event_file = event_file_data(m->private);
+ if (unlikely(!event_file)) {
+ ret = -ENODEV;
+ goto out_unlock;
+ }
+
+ list_for_each_entry_rcu(data, &event_file->triggers, list) {
+ if (data->cmd_ops->trigger_type == ETT_EVENT_HIST)
+ hist_trigger_show(m, data, n++);
+ }
+
out_unlock:
mutex_unlock(&event_mutex);
@@ -1214,6 +1220,54 @@ static void hist_clear(struct event_trigger_data *data)
data->paused = paused;
}
+static bool hist_trigger_match(struct event_trigger_data *data,
+ struct event_trigger_data *data_test)
+{
+ struct tracing_map_sort_key *sort_key, *sort_key_test;
+ struct hist_trigger_data *hist_data, *hist_data_test;
+ struct hist_field *key_field, *key_field_test;
+ unsigned int i;
+
+ hist_data = data->private_data;
+ hist_data_test = data_test->private_data;
+
+ if (hist_data->n_vals != hist_data_test->n_vals ||
+ hist_data->n_fields != hist_data_test->n_fields ||
+ hist_data->n_sort_keys != hist_data_test->n_sort_keys)
+ return false;
+
+ if ((data->filter_str && !data_test->filter_str) ||
+ (!data->filter_str && data_test->filter_str))
+ return false;
+
+ for_each_hist_field(i, hist_data) {
+ key_field = hist_data->fields[i];
+ key_field_test = hist_data_test->fields[i];
+
+ if (key_field->flags != key_field_test->flags)
+ return false;
+ if (key_field->field != key_field_test->field)
+ return false;
+ if (key_field->offset != key_field_test->offset)
+ return false;
+ }
+
+ for (i = 0; i < hist_data->n_sort_keys; i++) {
+ sort_key = &hist_data->sort_keys[i];
+ sort_key_test = &hist_data_test->sort_keys[i];
+
+ if (sort_key->field_idx != sort_key_test->field_idx ||
+ sort_key->descending != sort_key_test->descending)
+ return false;
+ }
+
+ if (data->filter_str &&
+ strcmp(data->filter_str, data_test->filter_str))
+ return false;
+
+ return true;
+}
+
static int hist_register_trigger(char *glob, struct event_trigger_ops *ops,
struct event_trigger_data *data,
struct trace_event_file *file)
@@ -1224,6 +1278,8 @@ static int hist_register_trigger(char *glob, struct event_trigger_ops *ops,
list_for_each_entry_rcu(test, &file->triggers, list) {
if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) {
+ if (!hist_trigger_match(data, test))
+ continue;
if (hist_data->attrs->pause)
test->paused = true;
else if (hist_data->attrs->cont)
@@ -1263,6 +1319,44 @@ static int hist_register_trigger(char *glob, struct event_trigger_ops *ops,
return ret;
}
+static void hist_unregister_trigger(char *glob, struct event_trigger_ops *ops,
+ struct event_trigger_data *data,
+ struct trace_event_file *file)
+{
+ struct event_trigger_data *test;
+ bool unregistered = false;
+
+ list_for_each_entry_rcu(test, &file->triggers, list) {
+ if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) {
+ if (!hist_trigger_match(data, test))
+ continue;
+ unregistered = true;
+ list_del_rcu(&test->list);
+ trace_event_trigger_enable_disable(file, 0);
+ update_cond_flag(file);
+ break;
+ }
+ }
+
+ if (unregistered && test->ops->free)
+ test->ops->free(test->ops, test);
+}
+
+static void hist_unreg_all(struct trace_event_file *file)
+{
+ struct event_trigger_data *test;
+
+ list_for_each_entry_rcu(test, &file->triggers, list) {
+ if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) {
+ list_del_rcu(&test->list);
+ trace_event_trigger_enable_disable(file, 0);
+ update_cond_flag(file);
+ if (test->ops->free)
+ test->ops->free(test->ops, test);
+ }
+ }
+}
+
static int event_hist_trigger_func(struct event_command *cmd_ops,
struct trace_event_file *file,
char *glob, char *cmd, char *param)
@@ -1312,22 +1406,19 @@ static int event_hist_trigger_func(struct event_command *cmd_ops,
trigger_data->private_data = hist_data;
+ /* if param is non-empty, it's supposed to be a filter */
+ if (param && cmd_ops->set_filter) {
+ ret = cmd_ops->set_filter(param, trigger_data, file);
+ if (ret < 0)
+ goto out_free;
+ }
+
if (glob[0] == '!') {
cmd_ops->unreg(glob+1, trigger_ops, trigger_data, file);
ret = 0;
goto out_free;
}
- if (!param) /* if param is non-empty, it's supposed to be a filter */
- goto out_reg;
-
- if (!cmd_ops->set_filter)
- goto out_reg;
-
- ret = cmd_ops->set_filter(param, trigger_data, file);
- if (ret < 0)
- goto out_free;
- out_reg:
ret = cmd_ops->reg(glob, trigger_ops, trigger_data, file);
/*
* The above returns on success the # of triggers registered,
@@ -1360,7 +1451,8 @@ static struct event_command trigger_hist_cmd = {
.needs_rec = true,
.func = event_hist_trigger_func,
.reg = hist_register_trigger,
- .unreg = unregister_trigger,
+ .unreg = hist_unregister_trigger,
+ .unreg_all = hist_unreg_all,
.get_trigger_ops = event_hist_get_trigger_ops,
.set_filter = set_trigger_filter,
};
@@ -1387,7 +1479,6 @@ hist_enable_trigger(struct event_trigger_data *data, void *rec)
test->paused = false;
else
test->paused = true;
- break;
}
}
}
@@ -1450,12 +1541,28 @@ hist_enable_get_trigger_ops(char *cmd, char *param)
return ops;
}
+static void hist_enable_unreg_all(struct trace_event_file *file)
+{
+ struct event_trigger_data *test;
+
+ list_for_each_entry_rcu(test, &file->triggers, list) {
+ if (test->cmd_ops->trigger_type == ETT_HIST_ENABLE) {
+ list_del_rcu(&test->list);
+ update_cond_flag(file);
+ trace_event_trigger_enable_disable(file, 0);
+ if (test->ops->free)
+ test->ops->free(test->ops, test);
+ }
+ }
+}
+
static struct event_command trigger_hist_enable_cmd = {
.name = ENABLE_HIST_STR,
.trigger_type = ETT_HIST_ENABLE,
.func = event_enable_trigger_func,
.reg = event_enable_register_trigger,
.unreg = event_enable_unregister_trigger,
+ .unreg_all = hist_enable_unreg_all,
.get_trigger_ops = hist_enable_get_trigger_ops,
.set_filter = set_trigger_filter,
};
@@ -1466,6 +1573,7 @@ static struct event_command trigger_hist_disable_cmd = {
.func = event_enable_trigger_func,
.reg = event_enable_register_trigger,
.unreg = event_enable_unregister_trigger,
+ .unreg_all = hist_enable_unreg_all,
.get_trigger_ops = hist_enable_get_trigger_ops,
.set_filter = set_trigger_filter,
};
--
1.9.3
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/