tracing: 'hist' triggers

PATCH Superseded Tom Zanussi 4 participants 25 messages Mar 2, 2015 – Mar 3, 2015

Subsystems (9)

Memory management Documentation BPF MM core +5 more subsystems

lore

Share & tools

lore

Tom Zanussi

author

2015-03-02 16:01 UTC #0 lore raw

v2 cover tracing: 'hist' triggers

This is v2 of my previously posted 'hashtriggers' patchset [1], but renamed to 'hist triggers' following feedback from v1.

Since then, the kernel has gained a tracing map implementation in the form of bpf_map, which this patchset makes a bit more generic, exports and uses (as tracing_map_*, still in the bpf syscall file however).

A large part of the initial hash triggers implementation was devoted to a map implementation and general-purpose hashing functions, which have now been subsumed by the bpf maps. I've completely redone the trigger patches themselves to work on top of tracing_map. The result is a much simpler and easier-to-review patchset that's able to focus more directly on the problem at hand.

The new version addresses all the comments from the previous review, including changing the name from hash->hist, adding separate 'hist' files for the output, and moving the examples into Documentation.

This patchset also includes a couple other new and related triggers, enable_hist and disable_hist, very similar to the existing enable_event/disable_event triggers used to automatically enable and disable events based on a triggering condition, but in this case allowing hist triggers to be enabled and disabled in the same way.

The only problem with using the bpf_map implementation for this is that it uses kmalloc internally, which causes problems when trying to trace kmalloc itself. I'm guessing the ebpf tracing code would also share this problem e.g. when using bpf_maps from probes on kmalloc(). This patchset attempts a solution to that problem (by adding a gfp_flag and changing the kmem memory allocation tracepoints to conditional variants) for checking for it in for but I'm not sure it's the best way to address it.

There are a couple of important bits of functionality that were present in v1 but dropped in v2 mainly because I'm still trying to figure out the best way to accomplish those things using the bpf_map implementation.

The first is support for compound keys. Currently, maps can only be keyed on a single event field, whereas in v1 they could be keyed on multiple keys. With support for compound keys, you can create much more interesting output, such as for example per-pid lists of syscalls or read counts e.g.:

  # echo 'hist:keys=common_pid.execname,id.syscall:vals=hitcount' > \
        /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger

  # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist

key: common_pid:bash[3112], id:sys_write vals: count:69
key: common_pid:bash[3112], id:sys_rt_sigprocmask vals: count:218

key: common_pid:update-notifier[3164], id:sys_poll vals: count:37
key: common_pid:update-notifier[3164], id:sys_recvfrom vals: count:118

key: common_pid:deja-dup-monito[3194], id:sys_sendto vals: count:1
key: common_pid:deja-dup-monito[3194], id:sys_read vals: count:4
key: common_pid:deja-dup-monito[3194], id:sys_poll vals: count:8
key: common_pid:deja-dup-monito[3194], id:sys_recvmsg vals: count:8
key: common_pid:deja-dup-monito[3194], id:sys_getegid vals: count:8

key: common_pid:emacs[3275], id:sys_fsync vals: count:1
key: common_pid:emacs[3275], id:sys_open vals: count:1
key: common_pid:emacs[3275], id:sys_symlink vals: count:2
key: common_pid:emacs[3275], id:sys_poll vals: count:23
key: common_pid:emacs[3275], id:sys_select vals: count:23
key: common_pid:emacs[3275], id:unknown_syscall vals: count:34
key: common_pid:emacs[3275], id:sys_ioctl vals: count:60
key: common_pid:emacs[3275], id:sys_rt_sigprocmask vals: count:116

key: common_pid:cat[3323], id:sys_munmap vals: count:1
key: common_pid:cat[3323], id:sys_fadvise64 vals: count:1

Related to that is support for sorting on multiple fields. Currently, you can sort using only a primary key. Being able to sort on multiple or at least a secondary key is indispensible for seeing trends when displaying multiple values.

[1] http://thread.gmane.org/gmane.linux.kernel/1673551

Changes from v1:
- completely rewritten on top of tracing_map (renamed and exported bpf_map)
- added map clearing and client ops to tracing_map
- changed the name from 'hash' triggers to 'hist' triggers
- added new trigger 'pause' feature
- added new enable_hist and disable_hist triggers
- added usage for hist/enable_hist/disable hist to tracing/README
- moved examples into Documentation/trace/event.txt
- added ___GFP_NOTRACE, kmalloc/kfree macros, and conditional kmem tracepoints

The following changes since commit 49058038a12cfd9044146a1bf4b286781268d5c9:

ring-buffer: Do not wake up a splice waiter when page is not full (2015-02-24 14:00:41 -0600)

are available in the git repository at:

git://git.yoctoproject.org/linux-yocto-contrib.git tzanussi/hist-triggers-v2
http://git.yoctoproject.org/cgit/cgit.cgi/linux-yocto-contrib/log/?h=tzanussi/hist-triggers-v2

Tom Zanussi (15):
tracing: Make ftrace_event_field checking functions available
tracing: Add event record param to trigger_ops.func()
tracing: Add get_syscall_name()
bpf: Export bpf map functionality as trace_map_*
bpf: Export a map-clearing function
bpf: Add tracing_map client ops
mm: Add ___GFP_NOTRACE
tracing: Make kmem memory allocation tracepoints conditional
tracing: Add kmalloc/kfree macros
bpf: Make tracing_map use kmalloc/kfree_notrace()
tracing: Add a per-event-trigger 'paused' field
tracing: Add 'hist' event trigger command
tracing: Add sorting to hist triggers
tracing: Add enable_hist/disable_hist triggers
tracing: Add 'hist' trigger Documentation

 Documentation/trace/events.txt      |  870 +++++++++++++++++++++
 include/linux/bpf.h                 |   15 +
 include/linux/ftrace_event.h        |    9 +-
 include/linux/gfp.h                 |    3 +-
 include/linux/slab.h                |   61 +-
 include/trace/events/kmem.h         |   28 +-
 kernel/bpf/arraymap.c               |   16 +
 kernel/bpf/hashtab.c                |   39 +-
 kernel/bpf/syscall.c                |  193 ++++-
 kernel/trace/trace.c                |   48 ++
 kernel/trace/trace.h                |   25 +-
 kernel/trace/trace_events.c         |    3 +
 kernel/trace/trace_events_filter.c  |   15 +-
 kernel/trace/trace_events_trigger.c | 1466 ++++++++++++++++++++++++++++++++++-
 kernel/trace/trace_syscalls.c       |   11 +
 mm/slab.c                           |   45 +-
 mm/slob.c                           |   45 +-
 mm/slub.c                           |   47 +-
 18 files changed, 2795 insertions(+), 144 deletions(-)

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:06 UTC #1 lore raw

PATCH v2 1/15 tracing: Make ftrace_event_field checking functions available

Make is_string_field() and is_function_field() accessible outside of trace_event_filters.c for other users of ftrace_event_fields.

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

---
 kernel/trace/trace.h               | 12 ++++++++++++
 kernel/trace/trace_events_filter.c | 12 ------------
 2 files changed, 12 insertions(+), 12 deletions(-)

kernel/trace/trace.h +12 -0

index d951ded..6177486 100644
@@ -1050,6 +1050,18 @@ struct filter_pred {
 	unsigned short		right;
 };
 
+static inline bool is_string_field(struct ftrace_event_field *field)
+{
+	return field->filter_type == FILTER_DYN_STRING ||
+	       field->filter_type == FILTER_STATIC_STRING ||
+	       field->filter_type == FILTER_PTR_STRING;
+}
+
+static inline bool is_function_field(struct ftrace_event_field *field)
+{
+	return field->filter_type == FILTER_TRACE_FN;
+}
+
 extern enum regex_type
 filter_parse_regex(char *buff, int len, char **search, int *not);
 extern void print_event_filter(struct ftrace_event_file *file,

kernel/trace/trace_events_filter.c +0 ~~-12~~

index ced69da..aa8ab85 100644
@@ -917,18 +917,6 @@ int filter_assign_type(const char *type)
 	return FILTER_OTHER;
 }
 
-static bool is_function_field(struct ftrace_event_field *field)
-{
-	return field->filter_type == FILTER_TRACE_FN;
-}
-
-static bool is_string_field(struct ftrace_event_field *field)
-{
-	return field->filter_type == FILTER_DYN_STRING ||
-	       field->filter_type == FILTER_STATIC_STRING ||
-	       field->filter_type == FILTER_PTR_STRING;
-}
-
 static int is_legal_op(struct ftrace_event_field *field, int op)
 {
 	if (is_string_field(field) &&

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:01 UTC #2 lore raw

PATCH v2 2/15 tracing: Add event record param to trigger_ops.func()

In reply to Tom Zanussi

Some triggers may need access to the trace event, so pass it in. Also fix up the existing trigger funcs and their callers.

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

---
 include/linux/ftrace_event.h        |  7 ++++---
 kernel/trace/trace.h                |  6 ++++--
 kernel/trace/trace_events_trigger.c | 35 ++++++++++++++++++-----------------
 3 files changed, 26 insertions(+), 22 deletions(-)

include/linux/ftrace_event.h +4 -3

index 5aa4a92..c967526 100644
@@ -429,7 +429,8 @@ extern int call_filter_check_discard(struct ftrace_event_call *call, void *rec,
 extern enum event_trigger_type event_triggers_call(struct ftrace_event_file *file,
 						   void *rec);
 extern void event_triggers_post_call(struct ftrace_event_file *file,
-				     enum event_trigger_type tt);
+				     enum event_trigger_type tt,
+				     void *rec);
 
 /**
  * ftrace_trigger_soft_disabled - do triggers and test if soft disabled

@@ -512,7 +513,7 @@ event_trigger_unlock_commit(struct ftrace_event_file *file,
 		trace_buffer_unlock_commit(buffer, event, irq_flags, pc);
 
 	if (tt)
-		event_triggers_post_call(file, tt);
+		event_triggers_post_call(file, tt, entry);
 }
 
 /**

@@ -545,7 +546,7 @@ event_trigger_unlock_commit_regs(struct ftrace_event_file *file,
 						irq_flags, pc, regs);
 
 	if (tt)
-		event_triggers_post_call(file, tt);
+		event_triggers_post_call(file, tt, entry);
 }
 
 enum {

kernel/trace/trace.h +4 -2

index 6177486..89dd87a 100644
@@ -1125,7 +1125,8 @@ struct event_trigger_data {
  * @func: The trigger 'probe' function called when the triggering
  *	event occurs.  The data passed into this callback is the data
  *	that was supplied to the event_command @reg() function that
- *	registered the trigger (see struct event_command).
+ *	registered the trigger (see struct event_command) along with
+ *	the trace record, rec.
  *
  * @init: An optional initialization function called for the trigger
  *	when the trigger is registered (via the event_command reg()

@@ -1150,7 +1151,8 @@ struct event_trigger_data {
  *	(see trace_event_triggers.c).
  */
 struct event_trigger_ops {
-	void			(*func)(struct event_trigger_data *data);
+	void			(*func)(struct event_trigger_data *data,
+					void *rec);
 	int			(*init)(struct event_trigger_ops *ops,
 					struct event_trigger_data *data);
 	void			(*free)(struct event_trigger_ops *ops,

kernel/trace/trace_events_trigger.c +18 ~~-17~~

index 8712df9..a8dfd4e 100644
@@ -74,7 +74,7 @@ event_triggers_call(struct ftrace_event_file *file, void *rec)
 
 	list_for_each_entry_rcu(data, &file->triggers, list) {
 		if (!rec) {
-			data->ops->func(data);
+			data->ops->func(data, rec);
 			continue;
 		}
 		filter = rcu_dereference_sched(data->filter);

@@ -84,7 +84,7 @@ event_triggers_call(struct ftrace_event_file *file, void *rec)
 			tt |= data->cmd_ops->trigger_type;
 			continue;
 		}
-		data->ops->func(data);
+		data->ops->func(data, rec);
 	}
 	return tt;
 }

@@ -104,13 +104,14 @@ EXPORT_SYMBOL_GPL(event_triggers_call);
  */
 void
 event_triggers_post_call(struct ftrace_event_file *file,
-			 enum event_trigger_type tt)
+			 enum event_trigger_type tt,
+			 void *rec)
 {
 	struct event_trigger_data *data;
 
 	list_for_each_entry_rcu(data, &file->triggers, list) {
 		if (data->cmd_ops->trigger_type & tt)
-			data->ops->func(data);
+			data->ops->func(data, rec);
 	}
 }
 EXPORT_SYMBOL_GPL(event_triggers_post_call);

@@ -751,7 +752,7 @@ static int set_trigger_filter(char *filter_str,
 }
 
 static void
-traceon_trigger(struct event_trigger_data *data)
+traceon_trigger(struct event_trigger_data *data, void *rec)
 {
 	if (tracing_is_on())
 		return;

@@ -760,7 +761,7 @@ traceon_trigger(struct event_trigger_data *data)
 }
 
 static void
-traceon_count_trigger(struct event_trigger_data *data)
+traceon_count_trigger(struct event_trigger_data *data, void *rec)
 {
 	if (tracing_is_on())
 		return;

@@ -775,7 +776,7 @@ traceon_count_trigger(struct event_trigger_data *data)
 }
 
 static void
-traceoff_trigger(struct event_trigger_data *data)
+traceoff_trigger(struct event_trigger_data *data, void *rec)
 {
 	if (!tracing_is_on())
 		return;

@@ -784,7 +785,7 @@ traceoff_trigger(struct event_trigger_data *data)
 }
 
 static void
-traceoff_count_trigger(struct event_trigger_data *data)
+traceoff_count_trigger(struct event_trigger_data *data, void *rec)
 {
 	if (!tracing_is_on())
 		return;

@@ -880,13 +881,13 @@ static struct event_command trigger_traceoff_cmd = {
 
 #ifdef CONFIG_TRACER_SNAPSHOT
 static void
-snapshot_trigger(struct event_trigger_data *data)
+snapshot_trigger(struct event_trigger_data *data, void *rec)
 {
 	tracing_snapshot();
 }
 
 static void
-snapshot_count_trigger(struct event_trigger_data *data)
+snapshot_count_trigger(struct event_trigger_data *data, void *rec)
 {
 	if (!data->count)
 		return;

@@ -894,7 +895,7 @@ snapshot_count_trigger(struct event_trigger_data *data)
 	if (data->count != -1)
 		(data->count)--;
 
-	snapshot_trigger(data);
+	snapshot_trigger(data, rec);
 }
 
 static int

@@ -973,13 +974,13 @@ static __init int register_trigger_snapshot_cmd(void) { return 0; }
 #define STACK_SKIP 3
 
 static void
-stacktrace_trigger(struct event_trigger_data *data)
+stacktrace_trigger(struct event_trigger_data *data, void *rec)
 {
 	trace_dump_stack(STACK_SKIP);
 }
 
 static void
-stacktrace_count_trigger(struct event_trigger_data *data)
+stacktrace_count_trigger(struct event_trigger_data *data, void *rec)
 {
 	if (!data->count)
 		return;

@@ -987,7 +988,7 @@ stacktrace_count_trigger(struct event_trigger_data *data)
 	if (data->count != -1)
 		(data->count)--;
 
-	stacktrace_trigger(data);
+	stacktrace_trigger(data, rec);
 }
 
 static int

@@ -1058,7 +1059,7 @@ struct enable_trigger_data {
 };
 
 static void
-event_enable_trigger(struct event_trigger_data *data)
+event_enable_trigger(struct event_trigger_data *data, void *rec)
 {
 	struct enable_trigger_data *enable_data = data->private_data;

@@ -1069,7 +1070,7 @@ event_enable_trigger(struct event_trigger_data *data)
 }
 
 static void
-event_enable_count_trigger(struct event_trigger_data *data)
+event_enable_count_trigger(struct event_trigger_data *data, void *rec)
 {
 	struct enable_trigger_data *enable_data = data->private_data;

@@ -1083,7 +1084,7 @@ event_enable_count_trigger(struct event_trigger_data *data)
 	if (data->count != -1)
 		(data->count)--;
 
-	event_enable_trigger(data);
+	event_enable_trigger(data, rec);
 }
 
 static int

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:01 UTC #3 lore raw

PATCH v2 3/15 tracing: Add get_syscall_name()

In reply to Tom Zanussi

Add a utility function to grab the syscall name from the syscall metadata, given a syscall id.

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

---
 kernel/trace/trace.h          |  5 +++++
 kernel/trace/trace_syscalls.c | 11 +++++++++++
 2 files changed, 16 insertions(+)

kernel/trace/trace.h +5 -0

index 89dd87a..3d38c2e 100644
@@ -1317,8 +1317,13 @@ int perf_ftrace_event_register(struct ftrace_event_call *call,
 
 #ifdef CONFIG_FTRACE_SYSCALLS
 void init_ftrace_syscalls(void);
+const char *get_syscall_name(int syscall);
 #else
 static inline void init_ftrace_syscalls(void) { }
+static inline const char *get_syscall_name(int syscall)
+{
+	return NULL;
+}
 #endif
 
 #ifdef CONFIG_EVENT_TRACING

kernel/trace/trace_syscalls.c +11 -0

index c6ee36f..35dfcf3 100644
@@ -106,6 +106,17 @@ static struct syscall_metadata *syscall_nr_to_meta(int nr)
 	return syscalls_metadata[nr];
 }
 
+const char *get_syscall_name(int syscall)
+{
+	struct syscall_metadata *entry;
+
+	entry = syscall_nr_to_meta(syscall);
+	if (!entry)
+		return NULL;
+
+	return entry->name;
+}
+
 static enum print_line_t
 print_syscall_enter(struct trace_iterator *iter, int flags,
 		    struct trace_event *event)

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:01 UTC #4 lore raw

PATCH v2 4/15 bpf: Export bpf map functionality as trace_map_*

In reply to Tom Zanussi

Make the bpf map implementation available outside of kernel/bpf - as a general-purpose map implementation for tracing, it should be available to any tracing facility that can make use of it, not just the bpf syscall.

Create a set of exported tracing_map_* functions and have the bpf implementation use them.

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

---
 include/linux/bpf.h  |   7 +++
 kernel/bpf/syscall.c | 173 ++++++++++++++++++++++++++++++++++++++++++++++-----
 2 files changed, 163 insertions(+), 17 deletions(-)

include/linux/bpf.h +7 -0

index bbfceb7..900405bf 100644
@@ -142,4 +142,11 @@ extern struct bpf_func_proto bpf_map_lookup_elem_proto;
 extern struct bpf_func_proto bpf_map_update_elem_proto;
 extern struct bpf_func_proto bpf_map_delete_elem_proto;
 
+struct bpf_map *tracing_map_create(union bpf_attr *attr);
+void tracing_map_destroy(struct bpf_map *map);
+int tracing_map_update_elem(struct bpf_map *map, void *key, void *value,
+			    union bpf_attr *attr);
+int tracing_map_lookup_elem(struct bpf_map *map, void *key, void *uvalue);
+int tracing_map_delete_elem(struct bpf_map *map, void *key);
+int tracing_map_get_next_key(struct bpf_map *map, void *key, void *next_key);
 #endif /* _LINUX_BPF_H */

kernel/bpf/syscall.c +156 ~~-17~~

240 lines not on this page · raw message

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:01 UTC #5 lore raw

PATCH v2 5/15 bpf: Export a map-clearing function

In reply to Tom Zanussi

Add a new map_clear() function to bpf_map_ops along with a tracing_map_clear() export for external users.

Map implementations that it makes sense for should implement it, otherwise it's not required. The bpf hashtab implementation does implement a clear operation, but since it doesn't make sense for bpf arraymaps, the arraymap implementation doesn't.

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

---
 include/linux/bpf.h  |  2 ++
 kernel/bpf/hashtab.c |  8 ++++++++
 kernel/bpf/syscall.c | 17 +++++++++++++++++
 3 files changed, 27 insertions(+)

include/linux/bpf.h +2 -0

index 900405bf..f7f95d7 100644
@@ -18,6 +18,7 @@ struct bpf_map_ops {
 	/* funcs callable from userspace (via syscall) */
 	struct bpf_map *(*map_alloc)(union bpf_attr *attr);
 	void (*map_free)(struct bpf_map *);
+	void (*map_clear)(struct bpf_map *);
 	int (*map_get_next_key)(struct bpf_map *map, void *key, void *next_key);
 
 	/* funcs callable from userspace and from eBPF programs */

@@ -144,6 +145,7 @@ extern struct bpf_func_proto bpf_map_delete_elem_proto;
 
 struct bpf_map *tracing_map_create(union bpf_attr *attr);
 void tracing_map_destroy(struct bpf_map *map);
+void tracing_map_clear(struct bpf_map *map);
 int tracing_map_update_elem(struct bpf_map *map, void *key, void *value,
 			    union bpf_attr *attr);
 int tracing_map_lookup_elem(struct bpf_map *map, void *key, void *uvalue);

kernel/bpf/hashtab.c +8 -0

index b3ba436..addf3a8 100644
@@ -325,6 +325,13 @@ static void delete_all_elements(struct bpf_htab *htab)
 	}
 }
 
+static void htab_map_clear(struct bpf_map *map)
+{
+	struct bpf_htab *htab = container_of(map, struct bpf_htab, map);
+
+	delete_all_elements(htab);
+}
+
 /* Called when map->refcnt goes to zero, either from workqueue or from syscall */
 static void htab_map_free(struct bpf_map *map)
 {

@@ -348,6 +355,7 @@ static void htab_map_free(struct bpf_map *map)
 static struct bpf_map_ops htab_ops = {
 	.map_alloc = htab_map_alloc,
 	.map_free = htab_map_free,
+	.map_clear = htab_map_clear,
 	.map_get_next_key = htab_map_get_next_key,
 	.map_lookup_elem = htab_map_lookup_elem,
 	.map_update_elem = htab_map_update_elem,

kernel/bpf/syscall.c +17 -0

index cac8df6..0f28904 100644
@@ -362,6 +362,23 @@ int tracing_map_delete_elem(struct bpf_map *map, void *key)
 }
 EXPORT_SYMBOL_GPL(tracing_map_delete_elem);
 
+/**
+ * tracing_map_clear - Clear a bpf_map
+ * @map: The bpf_map to clear
+ *
+ * Clear the bpf_map.
+ *
+ * Return: nothing, map clearing always succeeds
+ */
+void tracing_map_clear(struct bpf_map *map)
+{
+	rcu_read_lock();
+	if (map->ops->map_clear)
+		map->ops->map_clear(map);
+	rcu_read_unlock();
+}
+EXPORT_SYMBOL_GPL(tracing_map_clear);
+
 #define BPF_MAP_DELETE_ELEM_LAST_FIELD key
 
 static int map_delete_elem(union bpf_attr *attr)

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:01 UTC #6 lore raw

PATCH v2 6/15 bpf: Add tracing_map client ops

In reply to Tom Zanussi

External users of the tracing_map API may customize their map usage and need to be notified of certain events occuring during the lifetime of a map.

One example would be element deletion - if private data has been associated with an element's value, the client should be notified when that element is being deleted in order to give it a chance to delete the private data.

struct bpf_map_client_ops defines a set of client callbacks, a pointer to an instance of which can be passed by the client to tracing_map_create().

Initially, the only callback defined is free_elem(), which is called when a map element is freed and gives clients the opportunity to free app-specific elements. Other callbacks such as a client-defined sort() function are anticipated, however, which is why it's not a standalone op.

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

---
 include/linux/bpf.h   |  8 +++++++-
 kernel/bpf/arraymap.c | 16 ++++++++++++++++
 kernel/bpf/hashtab.c  | 12 ++++++++++++
 kernel/bpf/syscall.c  |  7 +++++--
 4 files changed, 40 insertions(+), 3 deletions(-)

include/linux/bpf.h +7 -1

index f7f95d7..09095ec 100644
@@ -27,6 +27,10 @@ struct bpf_map_ops {
 	int (*map_delete_elem)(struct bpf_map *map, void *key);
 };
 
+struct bpf_map_client_ops {
+	void (*free_elem)(void *value);
+};
+
 struct bpf_map {
 	atomic_t refcnt;
 	enum bpf_map_type map_type;

@@ -35,6 +39,7 @@ struct bpf_map {
 	u32 max_entries;
 	struct bpf_map_ops *ops;
 	struct work_struct work;
+	struct bpf_map_client_ops *client_ops;
 };
 
 struct bpf_map_type_list {

@@ -143,7 +148,8 @@ extern struct bpf_func_proto bpf_map_lookup_elem_proto;
 extern struct bpf_func_proto bpf_map_update_elem_proto;
 extern struct bpf_func_proto bpf_map_delete_elem_proto;
 
-struct bpf_map *tracing_map_create(union bpf_attr *attr);
+struct bpf_map *tracing_map_create(union bpf_attr *attr,
+				   struct bpf_map_client_ops *client_ops);
 void tracing_map_destroy(struct bpf_map *map);
 void tracing_map_clear(struct bpf_map *map);
 int tracing_map_update_elem(struct bpf_map *map, void *key, void *value,

kernel/bpf/arraymap.c +16 -0

index 9eb4d8a..333c959 100644
@@ -119,6 +119,20 @@ static int array_map_delete_elem(struct bpf_map *map, void *key)
 	return -EINVAL;
 }
 
+static void free_client_elems(struct bpf_array *array)
+{
+	void *val;
+	u32 index;
+
+	if (!array->map.client_ops || !array->map.client_ops->free_elem)
+		return;
+
+	for (index = 0; index < array->map.max_entries; index++) {
+		val = array->value + array->elem_size * index;
+		array->map.client_ops->free_elem(val);
+	}
+}
+
 /* Called when map->refcnt goes to zero, either from workqueue or from syscall */
 static void array_map_free(struct bpf_map *map)
 {

@@ -131,6 +145,8 @@ static void array_map_free(struct bpf_map *map)
 	 */
 	synchronize_rcu();
 
+	free_client_elems(array);
+
 	kvfree(array);
 }

kernel/bpf/hashtab.c +12 -0

index addf3a8..6f349ad 100644
@@ -275,6 +275,16 @@ err:
 	return ret;
 }
 
+static void free_client_elem(struct bpf_htab *htab, struct htab_elem *l)
+{
+	void *val;
+
+	if (htab->map.client_ops && htab->map.client_ops->free_elem) {
+		val = l->key + round_up(htab->map.key_size, 8);
+		htab->map.client_ops->free_elem(val);
+	}
+}
+
 /* Called from syscall or from eBPF program */
 static int htab_map_delete_elem(struct bpf_map *map, void *key)
 {

@@ -298,6 +308,7 @@ static int htab_map_delete_elem(struct bpf_map *map, void *key)
 	l = lookup_elem_raw(head, hash, key, key_size);
 
 	if (l) {
+		free_client_elem(htab, l);
 		hlist_del_rcu(&l->hash_node);
 		htab->count--;
 		kfree_rcu(l, rcu);

@@ -318,6 +329,7 @@ static void delete_all_elements(struct bpf_htab *htab)
 		struct htab_elem *l;
 
 		hlist_for_each_entry_safe(l, n, head, hash_node) {
+			free_client_elem(htab, l);
 			hlist_del_rcu(&l->hash_node);
 			htab->count--;
 			kfree(l);

kernel/bpf/syscall.c +5 -2

index 0f28904..85735e6 100644
@@ -110,7 +110,8 @@ static const struct file_operations bpf_map_fops = {
  *
  * Return: the map created on success, ERR_PTR otherwise
  */
-struct bpf_map *tracing_map_create(union bpf_attr *attr)
+struct bpf_map *tracing_map_create(union bpf_attr *attr,
+				   struct bpf_map_client_ops *client_ops)
 {
 	struct bpf_map *map;

@@ -119,6 +120,8 @@ struct bpf_map *tracing_map_create(union bpf_attr *attr)
 	if (!IS_ERR(map))
 		atomic_set(&map->refcnt, 1);
 
+	map->client_ops = client_ops;
+
 	return map;
 }
 EXPORT_SYMBOL_GPL(tracing_map_create);

@@ -133,7 +136,7 @@ static int map_create(union bpf_attr *attr)
 	if (err)
 		return -EINVAL;
 
-	map = tracing_map_create(attr);
+	map = tracing_map_create(attr, NULL);
 	if (IS_ERR(map))
 		return PTR_ERR(map);

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:05 UTC #7 lore raw

PATCH v2 7/15 mm: Add ___GFP_NOTRACE

In reply to Tom Zanussi

Add a gfp flag that allows kmalloc() et al to be used in tracing functions.

The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().

With this flag, tracing code could use a special version of kmalloc() that sets __GFP_NOTRACE on every allocation it does, while leaving the normal kmalloc() path untouched.

This would allow any tracepoint in the kmalloc path to be avoided via DEFINE_EVENT_CONDITION() redefinitions of those events, which check for ___GFP_NOTRACE immediately in their execution and break if set, thereby avoiding the recursion.

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

---
 include/linux/gfp.h | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

include/linux/gfp.h +2 -1

index b840e3b..acbbc7c 100644
@@ -34,6 +34,7 @@ struct vm_area_struct;
 #define ___GFP_NO_KSWAPD	0x400000u
 #define ___GFP_OTHER_NODE	0x800000u
 #define ___GFP_WRITE		0x1000000u
+#define ___GFP_NOTRACE		0x2000000u
 /* If the above are modified, __GFP_BITS_SHIFT may need updating */
 
 /*

@@ -97,7 +98,7 @@ struct vm_area_struct;
  */
 #define __GFP_NOTRACK_FALSE_POSITIVE (__GFP_NOTRACK)
 
-#define __GFP_BITS_SHIFT 25	/* Room for N __GFP_FOO bits */
+#define __GFP_BITS_SHIFT 26	/* Room for N __GFP_FOO bits */
 #define __GFP_BITS_MASK ((__force gfp_t)((1 << __GFP_BITS_SHIFT) - 1))
 
 /* This equals 0, but use constants in case they ever change */

Signature · 1 line

1.9.3

Steven Rostedt

maintainer

2015-03-02 16:37 UTC #8 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

Quoted 7 lines · On Mon, 2 Mar 2015 10:01:00 -0600 Tom Zanussi <[email protected]>…

Add a gfp flag that allows kmalloc() et al to be used in tracing functions.
The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().

This part I don't like at all. Why can't the memory be preallocated when the hist is created (the echo 'hist:...')?

kmalloc must never be called from any tracepoint callback.

This change is currently a showstopper.

-- Steve

Quoted 10 lines

With this flag, tracing code could use a special version of kmalloc() that sets __GFP_NOTRACE on every allocation it does, while leaving the normal kmalloc() path untouched.
This would allow any tracepoint in the kmalloc path to be avoided via DEFINE_EVENT_CONDITION() redefinitions of those events, which check for ___GFP_NOTRACE immediately in their execution and break if set, thereby avoiding the recursion.

Tom Zanussi

author

2015-03-02 16:46 UTC #9 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

Quoted 6 lines · Steven Rostedt

Quoted 3 lines · On Mon, 2 Mar 2015 10:01:00 -0600 Tom Zanussi <[email protected]>…
Add a gfp flag that allows kmalloc() et al to be used in tracing functions.

Quoted 8 lines

Quoted 4 lines
The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().
This part I don't like at all. Why can't the memory be preallocated when the hist is created (the echo 'hist:...')?

Yeah, I didn't like it either. My original version did exactly what you suggest and preallocated an array of entries to 'allocate' from in order to avoid the problem.

But I wanted to attempt to use the bpf_map directly, which already uses kmalloc internally. My fallback in case this wouldn't fly, which it obviously won't, would be to add an option to have the bpf_map code preallocate a maximum number of entries or pass in a client-owned array for the purpose. I'll do that if I don't hear any better ideas..

Tom

Quoted 17 lines

kmalloc must never be called from any tracepoint callback.
This change is currently a showstopper.
-- Steve
Quoted 10 lines
With this flag, tracing code could use a special version of kmalloc() that sets __GFP_NOTRACE on every allocation it does, while leaving the normal kmalloc() path untouched.
This would allow any tracepoint in the kmalloc path to be avoided via DEFINE_EVENT_CONDITION() redefinitions of those events, which check for ___GFP_NOTRACE immediately in their execution and break if set, thereby avoiding the recursion.

Alexei Starovoitov

2015-03-02 17:58 UTC #10 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

Quoted 20 lines · Tom Zanussi

Quoted 6 lines · Steven Rostedt
Quoted 3 lines · On Mon, 2 Mar 2015 10:01:00 -0600 Tom Zanussi <[email protected]>…
Add a gfp flag that allows kmalloc() et al to be used in tracing functions.
Quoted 8 lines
Quoted 4 lines
The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().
This part I don't like at all. Why can't the memory be preallocated when the hist is created (the echo 'hist:...')?
Yeah, I didn't like it either. My original version did exactly what you suggest and preallocated an array of entries to 'allocate' from in order to avoid the problem.

Quoted 5 lines

But I wanted to attempt to use the bpf_map directly, which already uses kmalloc internally. My fallback in case this wouldn't fly, which it obviously won't, would be to add an option to have the bpf_map code preallocate a maximum number of entries or pass in a client-owned array for the purpose. I'll do that if I don't hear any better ideas..

Tom, I'm still reading through the patch set.
Quick comment for the above.
Currently there are two map types: array and hash. array type is pre-allocating all memory at map creation time. hash is allocating on demand.

Tom Zanussi

author

2015-03-02 18:03 UTC #11 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

Quoted 27 lines · Alexei Starovoitov

Quoted 20 lines · Tom Zanussi
Quoted 6 lines · Steven Rostedt
Quoted 3 lines · On Mon, 2 Mar 2015 10:01:00 -0600 Tom Zanussi <[email protected]>…
Add a gfp flag that allows kmalloc() et al to be used in tracing functions.
Quoted 8 lines
Quoted 4 lines
The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().
This part I don't like at all. Why can't the memory be preallocated when the hist is created (the echo 'hist:...')?
Yeah, I didn't like it either. My original version did exactly what you suggest and preallocated an array of entries to 'allocate' from in order to avoid the problem.
Quoted 5 lines
But I wanted to attempt to use the bpf_map directly, which already uses kmalloc internally. My fallback in case this wouldn't fly, which it obviously won't, would be to add an option to have the bpf_map code preallocate a maximum number of entries or pass in a client-owned array for the purpose. I'll do that if I don't hear any better ideas..

Quoted 5 lines

Tom, I'm still reading through the patch set.
Quick comment for the above.
Currently there are two map types: array and hash. array type is pre-allocating all memory at map creation time. hash is allocating on demand.

OK, so would it make sense to do the same for the hash type, or at least add an option that does that?

Tom

Alexei Starovoitov

2015-03-02 18:12 UTC #12 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

Quoted 28 lines · Tom Zanussi

Quoted 27 lines · Alexei Starovoitov
Quoted 25 lines · Tom Zanussi
Quoted 6 lines · Steven Rostedt
Quoted 3 lines · On Mon, 2 Mar 2015 10:01:00 -0600 Tom Zanussi <[email protected]>…
Add a gfp flag that allows kmalloc() et al to be used in tracing functions.
Quoted 8 lines
Quoted 4 lines
The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().
This part I don't like at all. Why can't the memory be preallocated when the hist is created (the echo 'hist:...')?
Yeah, I didn't like it either. My original version did exactly what you suggest and preallocated an array of entries to 'allocate' from in order to avoid the problem.
But I wanted to attempt to use the bpf_map directly, which already uses kmalloc internally. My fallback in case this wouldn't fly, which it obviously won't, would be to add an option to have the bpf_map code preallocate a maximum number of entries or pass in a client-owned array for the purpose. I'll do that if I don't hear any better ideas..

Quoted 8 lines

Quoted 5 lines
Tom, I'm still reading through the patch set.
Quick comment for the above.
Currently there are two map types: array and hash. array type is pre-allocating all memory at map creation time. hash is allocating on demand.
OK, so would it make sense to do the same for the hash type, or at least add an option that does that?

I'm not sure what would be the meaning of hash map that has all elements pre-allocated...
As I'm reading your cover letter, I agree, we need to find a way to call kmalloc_notrace-like from tracepoints.
Not sure that patch 8 style of duplicating the functions is clean. Can we keep kmalloc/kfree as-is and do something like if (in_tracepoint()) check inside ftrace_raw_kmalloc* ? so that kmalloc will be traced but calls to kmalloc from inside tracepoints will be automatically suppressed ?

Tom Zanussi

author

2015-03-02 18:25 UTC #13 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

Quoted 36 lines · Alexei Starovoitov

Quoted 34 lines · Tom Zanussi
Quoted 32 lines · Alexei Starovoitov
Quoted 20 lines · Tom Zanussi
Quoted 6 lines · Steven Rostedt
Quoted 3 lines · On Mon, 2 Mar 2015 10:01:00 -0600 Tom Zanussi <[email protected]>…
Add a gfp flag that allows kmalloc() et al to be used in tracing functions.
Quoted 8 lines
Quoted 4 lines
The problem with using kmalloc for tracing is that the tracing subsystem should be able to trace kmalloc itself, which it can't do directly because of paths like kmalloc()->trace_kmalloc()->kmalloc() or kmalloc()->trace_mm_page_alloc()->kmalloc().
This part I don't like at all. Why can't the memory be preallocated when the hist is created (the echo 'hist:...')?
Yeah, I didn't like it either. My original version did exactly what you suggest and preallocated an array of entries to 'allocate' from in order to avoid the problem.
Quoted 5 lines
But I wanted to attempt to use the bpf_map directly, which already uses kmalloc internally. My fallback in case this wouldn't fly, which it obviously won't, would be to add an option to have the bpf_map code preallocate a maximum number of entries or pass in a client-owned array for the purpose. I'll do that if I don't hear any better ideas..
Tom, I'm still reading through the patch set.
Quick comment for the above.
Currently there are two map types: array and hash. array type is pre-allocating all memory at map creation time. hash is allocating on demand.

Quoted 5 lines

Quoted 2 lines
OK, so would it make sense to do the same for the hash type, or at least add an option that does that?
I'm not sure what would be the meaning of hash map that has all elements pre-allocated...

The idea would be that instead of getting your individually kmalloc'ed elements on-demand from kmalloc while in the handler, you'd get them from a pool you've pre-allocated when you set up the table. This could be from a list of individual entries you've already kmalloc'ed ahead of time, or from an array of n * sizeof(entry).

This would also allow you to avoid GFP_ATOMIC for those.

Quoted 3 lines

As I'm reading your cover letter, I agree, we need to find a way to call kmalloc_notrace-like from tracepoints.
Not sure that patch 8 style of duplicating the functions is clean.

No, it's horrible, but it does the job without changing the normal path at all.

Quoted 2 lines

Can we keep kmalloc/kfree as-is and do something like if (in_tracepoint()) check inside ftrace_raw_kmalloc* ?

Yeah, that's essentially what TP_CONDITION() in patch 8 (Make kmem memory allocation tracepoints conditional) does.

Tom

Quoted 2 lines

so that kmalloc will be traced but calls to kmalloc from inside tracepoints will be automatically suppressed ?

Steven Rostedt

maintainer

2015-03-02 18:43 UTC #14 lore raw

Re: [PATCH 07/15] mm: Add ___GFP_NOTRACE

In reply to Alexei Starovoitov

Quoted 7 lines · On Mon, 2 Mar 2015 10:12:32 -0800 Alexei Starovoitov <[email protected]> wrote:

I'm not sure what would be the meaning of hash map that has all elements pre-allocated...
As I'm reading your cover letter, I agree, we need to find a way to call kmalloc_notrace-like from tracepoints.
Not sure that patch 8 style of duplicating the functions is clean. Can we keep kmalloc/kfree as-is and do something like if (in_tracepoint()) check inside ftrace_raw_kmalloc* ?

I'm strongly against this. You should not be doing anything in a tracepoint that you can't do from NMI context. And calling kmalloc happens to be one of them.

Not to mention, kmalloc is a hot path, and tracing must not have any impact on it (no extra if statements).

-- Steve

Quoted 2 lines

so that kmalloc will be traced but calls to kmalloc from inside tracepoints will be automatically suppressed ?

Tom Zanussi

author

2015-03-02 16:02 UTC #15 lore raw

PATCH v2 8/15 tracing: Make kmem memory allocation tracepoints conditional

In reply to Tom Zanussi

Making the memory allocation tracepoints conditional allows those events to be traced using the functions containing them e.g. the kmalloc_trace() handler can itself use kmalloc() in the trace path, which otherwise wouldn't be possible.

The TP_CONDITION simply tests gfp_flags for the newly introduced ___GFP_NOTRACE and if true, the tracepoint simply returns without tracing.

This allows _notrace versions of the memory allocation functions to be defined, which do the same thing as the normal versions but in addition set the ___GFP_NOTRACE flag, and thus avoid the (possibly indirect) recursive calls to themselves.

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

---
 include/trace/events/kmem.h | 28 +++++++++++++++++++---------
 1 file changed, 19 insertions(+), 9 deletions(-)

include/trace/events/kmem.h +19 -9

index aece134..6d34eed 100644
@@ -42,20 +42,24 @@ DECLARE_EVENT_CLASS(kmem_alloc,
 		show_gfp_flags(__entry->gfp_flags))
 );
 
-DEFINE_EVENT(kmem_alloc, kmalloc,
+DEFINE_EVENT_CONDITION(kmem_alloc, kmalloc,
 
 	TP_PROTO(unsigned long call_site, const void *ptr,
 		 size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags),
 
-	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags)
+	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags),
+
+	TP_CONDITION(!(gfp_flags & ___GFP_NOTRACE))
 );
 
-DEFINE_EVENT(kmem_alloc, kmem_cache_alloc,
+DEFINE_EVENT_CONDITION(kmem_alloc, kmem_cache_alloc,
 
 	TP_PROTO(unsigned long call_site, const void *ptr,
 		 size_t bytes_req, size_t bytes_alloc, gfp_t gfp_flags),
 
-	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags)
+	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags),
+
+	TP_CONDITION(!(gfp_flags & ___GFP_NOTRACE))
 );
 
 DECLARE_EVENT_CLASS(kmem_alloc_node,

@@ -96,22 +100,26 @@ DECLARE_EVENT_CLASS(kmem_alloc_node,
 		__entry->node)
 );
 
-DEFINE_EVENT(kmem_alloc_node, kmalloc_node,
+DEFINE_EVENT_CONDITION(kmem_alloc_node, kmalloc_node,
 
 	TP_PROTO(unsigned long call_site, const void *ptr,
 		 size_t bytes_req, size_t bytes_alloc,
 		 gfp_t gfp_flags, int node),
 
-	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node)
+	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node),
+
+	TP_CONDITION(!(gfp_flags & ___GFP_NOTRACE))
 );
 
-DEFINE_EVENT(kmem_alloc_node, kmem_cache_alloc_node,
+DEFINE_EVENT_CONDITION(kmem_alloc_node, kmem_cache_alloc_node,
 
 	TP_PROTO(unsigned long call_site, const void *ptr,
 		 size_t bytes_req, size_t bytes_alloc,
 		 gfp_t gfp_flags, int node),
 
-	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node)
+	TP_ARGS(call_site, ptr, bytes_req, bytes_alloc, gfp_flags, node),
+
+	TP_CONDITION(!(gfp_flags & ___GFP_NOTRACE))
 );
 
 DECLARE_EVENT_CLASS(kmem_free,

@@ -191,13 +199,15 @@ TRACE_EVENT(mm_page_free_batched,
 			__entry->cold)
 );
 
-TRACE_EVENT(mm_page_alloc,
+TRACE_EVENT_CONDITION(mm_page_alloc,
 
 	TP_PROTO(struct page *page, unsigned int order,
 			gfp_t gfp_flags, int migratetype),
 
 	TP_ARGS(page, order, gfp_flags, migratetype),
 
+	TP_CONDITION(!(gfp_flags & ___GFP_NOTRACE)),
+
 	TP_STRUCT__entry(
 		__field(	struct page *,	page		)
 		__field(	unsigned int,	order		)

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:01 UTC #16 lore raw

PATCH v2 9/15 tracing: Add kmalloc/kfree macros

In reply to Tom Zanussi

Make the kmalloc function in slab.h into a macro, and define a normal and a _notrace version.

The _notrace version is for tracing code that wants to be able to use kmalloc for its purposes but at the same time be able to trace kmalloc and friends. Examples would be the bpf map and hist triggers code.

The reason for doing this is as a macro is so that we can avoid any change at all to the normal kmalloc since its performance is obviously critical. It allows us to define a _notrace version that reuses the kmalloc code but additionally sets the ___GFP_NOTRACE flag. This allows any downstream call to a tracepoint function to be avoided, as the DEFINE_EVENT_CONDITION() TP_CONDITION will simply cause the trace call to exit when it sees the ___GFP_NOTRACE_FLAG.

Because the #ifdef CONFIG_SLOB in the original causes problems if it's inside a macro, it was explicitly broken out into two different macros for those cases.

Though it doesn't suffer from the same recursion problems that motivate the kmalloc macro, we also need to define _notrace versions of kfree() as well, in order to allow for proper accounting. Users of kmalloc_notrace() should use kfree_notrace() to make sure the kfrees corresponding to the untraced kmallocs don't appear in the trace stream.

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

---
 include/linux/slab.h | 61 ++++++++++++++++++++++++++++++++++++++--------------
 mm/slab.c            | 45 ++++++++++++++++++++++----------------
 mm/slob.c            | 45 ++++++++++++++++++++++----------------
 mm/slub.c            | 47 +++++++++++++++++++++++-----------------
 4 files changed, 124 insertions(+), 74 deletions(-)

include/linux/slab.h +45 ~~-16~~

index 9a139b6..7519aaa 100644
@@ -142,6 +142,7 @@ void kmem_cache_free(struct kmem_cache *, void *);
 void * __must_check __krealloc(const void *, size_t, gfp_t);
 void * __must_check krealloc(const void *, size_t, gfp_t);
 void kfree(const void *);
+void kfree_notrace(const void *);
 void kzfree(const void *);
 size_t ksize(const void *);

@@ -409,25 +410,53 @@ static __always_inline void *kmalloc_large(size_t size, gfp_t flags)
  * for general use, and so are not documented here. For a full list of
  * potential flags, always refer to linux/gfp.h.
  */
-static __always_inline void *kmalloc(size_t size, gfp_t flags)
-{
-	if (__builtin_constant_p(size)) {
-		if (size > KMALLOC_MAX_CACHE_SIZE)
-			return kmalloc_large(size, flags);
-#ifndef CONFIG_SLOB
-		if (!(flags & GFP_DMA)) {
-			int index = kmalloc_index(size);
 
-			if (!index)
-				return ZERO_SIZE_PTR;
+#define set_gfp_notrace_flag(flags)
+#define set_gfp_notrace_flag_notrace(flags) (flags |= ___GFP_NOTRACE)
 
-			return kmem_cache_alloc_trace(kmalloc_caches[index],
-					flags, size);
-		}
-#endif
-	}
-	return __kmalloc(size, flags);
+#ifndef CONFIG_SLOB
+#define DEFINE_KMALLOC(_suffix)						\
+static __always_inline void *kmalloc##_suffix(size_t size, gfp_t flags)	\
+{									\
+	set_gfp_notrace_flag##_suffix(flags);				\
+									\
+	if (__builtin_constant_p(size)) {				\
+		if (size > KMALLOC_MAX_CACHE_SIZE)			\
+			return kmalloc_large(size, flags);		\
+									\
+		if (!(flags & GFP_DMA)) {				\
+			int index = kmalloc_index(size);		\
+									\
+			if (!index)					\
+				return ZERO_SIZE_PTR;			\
+									\
+			return kmem_cache_alloc_trace(kmalloc_caches[index],\
+					flags, size);			\
+		}							\
+	}								\
+	return __kmalloc(size, flags);					\
 }
+#else
+#define DEFINE_KMALLOC(_suffix)						\
+static __always_inline void *kmalloc##_suffix(size_t size, gfp_t flags)	\
+{									\
+	set_gfp_notrace_flag##_suffix(flags);				\
+									\
+	if (__builtin_constant_p(size)) {				\
+		if (size > KMALLOC_MAX_CACHE_SIZE)			\
+			return kmalloc_large(size, flags);		\
+	}								\
+	return __kmalloc(size, flags);					\
+}
+#endif /* !CONFIG_SLOB */
+
+DEFINE_KMALLOC()
+#ifdef CONFIG_TRACING
+DEFINE_KMALLOC(_notrace)
+#else
+#define kmalloc_notrace kmalloc
+#define kfree_notrace kfree
+#endif
 
 /*
  * Determine size used for the nth kmalloc cache.

mm/slab.c +26 ~~-19~~

51 lines not on this page · raw message

mm/slob.c +26 ~~-19~~

51 lines not on this page · raw message

mm/slub.c +27 ~~-20~~

53 lines not on this page · raw message

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:05 UTC #17 lore raw

PATCH v2 10/15 bpf: Make tracing_map use kmalloc/kfree_notrace()

In reply to Tom Zanussi

We need to prevent any kmallocs that could be invoked from within a tracepoint handler from being traced, in order to prevent recursion.

For tracing maps, this means the allocation of the map elements (maps themselves along with their associated buckets, etc, are never allocated in the context of a tracepoint handler, so we don't need to worry about them).

We also want the matching kfrees to remain untraced as well.

With this, we should be able to use maps when tracing kmalloc, which otherwise would lock up the machine.

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

---
 kernel/bpf/hashtab.c | 19 ++++++++++++++-----
 1 file changed, 14 insertions(+), 5 deletions(-)

kernel/bpf/hashtab.c +14 -5

index 6f349ad..308ef47 100644
@@ -200,6 +200,15 @@ find_first_elem:
 	return -ENOENT;
 }
 
+/* Use this instead of kfree_rcu() for notrace-kfreeing
+ * kmalloc_notrace()'d elements, to avoid creating a
+ * kfree_rcu_notrace() */
+static void kfree_htab_elem(struct rcu_head *head)
+{
+	struct htab_elem *elem = container_of(head, struct htab_elem, rcu);
+	kfree_notrace(elem);
+}
+
 /* Called from syscall or from eBPF program */
 static int htab_map_update_elem(struct bpf_map *map, void *key, void *value,
 				u64 map_flags)

@@ -218,7 +227,7 @@ static int htab_map_update_elem(struct bpf_map *map, void *key, void *value,
 	WARN_ON_ONCE(!rcu_read_lock_held());
 
 	/* allocate new element outside of lock */
-	l_new = kmalloc(htab->elem_size, GFP_ATOMIC);
+	l_new = kmalloc_notrace(htab->elem_size, GFP_ATOMIC);
 	if (!l_new)
 		return -ENOMEM;

@@ -262,7 +271,7 @@ static int htab_map_update_elem(struct bpf_map *map, void *key, void *value,
 	hlist_add_head_rcu(&l_new->hash_node, head);
 	if (l_old) {
 		hlist_del_rcu(&l_old->hash_node);
-		kfree_rcu(l_old, rcu);
+		call_rcu(&l_old->rcu, kfree_htab_elem);
 	} else {
 		htab->count++;
 	}

@@ -271,7 +280,7 @@ static int htab_map_update_elem(struct bpf_map *map, void *key, void *value,
 	return 0;
 err:
 	spin_unlock_irqrestore(&htab->lock, flags);
-	kfree(l_new);
+	kfree_notrace(l_new);
 	return ret;
 }

@@ -311,7 +320,7 @@ static int htab_map_delete_elem(struct bpf_map *map, void *key)
 		free_client_elem(htab, l);
 		hlist_del_rcu(&l->hash_node);
 		htab->count--;
-		kfree_rcu(l, rcu);
+		call_rcu(&l->rcu, kfree_htab_elem);
 		ret = 0;
 	}

@@ -332,7 +341,7 @@ static void delete_all_elements(struct bpf_htab *htab)
 			free_client_elem(htab, l);
 			hlist_del_rcu(&l->hash_node);
 			htab->count--;
-			kfree(l);
+			kfree_notrace(l);
 		}
 	}
 }

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:04 UTC #18 lore raw

PATCH v2 11/15 tracing: Add a per-event-trigger 'paused' field

In reply to Tom Zanussi

Add a simple per-trigger 'paused' flag, allowing individual triggers to pause. We could leave it to individual triggers that need this functionality to do it themselves, but we also want to allow other events to control pausing, so add it to the trigger data.

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

---
 kernel/trace/trace.h                | 1 +
 kernel/trace/trace_events_trigger.c | 4 ++++
 2 files changed, 5 insertions(+)

kernel/trace/trace.h +1 -0

index 3d38c2e..5bc1752 100644
@@ -1110,6 +1110,7 @@ struct event_trigger_data {
 	struct event_filter __rcu	*filter;
 	char				*filter_str;
 	void				*private_data;
+	bool				paused;
 	struct list_head		list;
 };

kernel/trace/trace_events_trigger.c +4 -0

index a8dfd4e..010ce30 100644
@@ -73,6 +73,8 @@ event_triggers_call(struct ftrace_event_file *file, void *rec)
 		return tt;
 
 	list_for_each_entry_rcu(data, &file->triggers, list) {
+		if (data->paused)
+			continue;
 		if (!rec) {
 			data->ops->func(data, rec);
 			continue;

@@ -110,6 +112,8 @@ event_triggers_post_call(struct ftrace_event_file *file,
 	struct event_trigger_data *data;
 
 	list_for_each_entry_rcu(data, &file->triggers, list) {
+		if (data->paused)
+			continue;
 		if (data->cmd_ops->trigger_type & tt)
 			data->ops->func(data, rec);
 	}

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:05 UTC #19 lore raw

PATCH v2 12/15 tracing: Add 'hist' event trigger command

In reply to Tom Zanussi

'hist' triggers allow users to continually aggregate trace events, which can then be viewed afterwards by simply reading a 'hist' file containing the aggregation in a human-readable format.

The basic idea is very simple and boils down to a mechanism whereby trace events, rather than being exhaustively dumped in raw form and viewed directly, are automatically 'compressed' into meaningful tables completely defined by the user.

This is done strictly via single-line command-line commands and without the aid of any kind of programming language or interpreter.

A surprising number of typical use cases can be accomplished by users via this simple mechanism. In fact, a large number of the tasks that users typically do using the more complicated script-based tracing tools, at least during the initial stages of an investigation, can be accomplished by simply specifying a set of keys and values to be used in the creation of a hash table.

The Linux kernel trace event subsystem happens to provide an extensive list of keys and values ready-made for such a purpose in the form of the event format files associated with each trace event. By simply consulting the format file for field names of interest and by plugging them into the hist trigger command, users can create an endless number of useful aggregations to help with investigating various properties of the system. See Documentation/trace/events.txt for examples.

hist triggers are implemented on top of the existing event trigger infrastructure, and as such are consistent with the existing triggers from a user's perspective as well.

The basic syntax follows the existing trigger syntax. Users start an aggregation by writing a 'hist' trigger to the event of interest's trigger file:

  # echo hist:keys=xxx:values=yyy [ if filter] > event/trigger

Once a hist trigger has been set up, by default it continually aggregates every matching event into a hash table using the event key and value fields specified.

To view the aggregation at any point in time, simply read the 'hist' file in the same directory as the 'trigger' file:

  # cat event/hist

The detailed syntax provides additional options for user control, and is described exhaustively in Documentation/trace/events.txt and in the virtual tracing/README file in the tracing subsystem.

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

---
 include/linux/ftrace_event.h        |    1 +
 kernel/trace/trace.c                |   39 ++
 kernel/trace/trace.h                |    1 +
 kernel/trace/trace_events.c         |    3 +
 kernel/trace/trace_events_filter.c  |    3 +-
 kernel/trace/trace_events_trigger.c | 1014 +++++++++++++++++++++++++++++++++++
 6 files changed, 1060 insertions(+), 1 deletion(-)

include/linux/ftrace_event.h +1 -0

index c967526..483e011 100644
@@ -416,6 +416,7 @@ enum event_trigger_type {
 	ETT_SNAPSHOT		= (1 << 1),
 	ETT_STACKTRACE		= (1 << 2),
 	ETT_EVENT_ENABLE	= (1 << 3),
+	ETT_EVENT_HIST		= (1 << 4),
 };
 
 extern int filter_match_preds(struct event_filter *filter, void *rec);

kernel/trace/trace.c +39 -0

index 60fa9e1..683048f 100644
@@ -3730,6 +3730,7 @@ static const char readme_msg[] =
 #ifdef CONFIG_TRACER_SNAPSHOT
 	"\t\t    snapshot\n"
 #endif
+	"\t\t    hist (see below)\n"
 	"\t   example: echo traceoff > events/block/block_unplug/trigger\n"
 	"\t            echo traceoff:3 > events/block/block_unplug/trigger\n"
 	"\t            echo 'enable_event:kmem:kmalloc:3 if nr_rq > 1' > \\\n"

@@ -3745,6 +3746,44 @@ static const char readme_msg[] =
 	"\t   To remove a trigger with a count:\n"
 	"\t     echo '!<trigger>:0 > <system>/<event>/trigger\n"
 	"\t   Filters can be ignored when removing a trigger.\n"
+	"      hist trigger\t- If set, event hits are aggregated into a hash table\n"
+	"\t    Format: hist:keys=<field1>:values=<field1[,field2,...]>\n"
+	"\t            [:size=#entries][:sort=field1][:pause][:continue]\n"
+	"\t            [:clear] [if <filter>]\n\n"
+	"\t    When a matching event is hit, an entry is added to a hash\n"
+	"\t    table using the key(s) and value(s) named.  Keys and values\n"
+	"\t    correspond to fields in the event's format description.\n"
+	"\t    Values must correspond to numeric fields - on an event hit,\n"
+	"\t    the value(s) will be added to a sum kept for that field.\n"
+	"\t    The special string 'hitcount' can be used in place of an\n"
+	"\t    explicit value field - this is simply a count of event hits.\n"
+	"\t    Keys can be any field, or the special string 'stacktrace',\n"
+	"\t    which will use the event's kernel stacktrace as the key.\n\n"
+	"\t    Reading the 'hist' file for the event will dump the hash\n"
+	"\t    table in its entirety to stdout.  By default, numeric fields\n"
+	"\t    are displayed as base-10 integers.  This can be modified by\n"
+	"\t    appending any of the following modifiers to the field name:\n\n"
+	"\t            .hex       display a number as a hex value\n"
+	"\t            .sym       display an address as a symbol\n"
+	"\t            .syscall   display a syscall id as a system call name\n"
+	"\t            .execname  display a common_pid as a program name\n\n"
+	"\t    By default, the size of the hash table is 2048 entries.  The\n"
+	"\t    'size' param can be used to specify more or fewer than that.\n"
+	"\t    The units are in terms of hashtable entries - if a run uses\n"
+	"\t    more entries than specified, the results will show the number\n"
+	"\t    of 'drops', the number of hits that were ignored.  The size\n"
+	"\t    should be a power of 2 between 128 and 131072 (any non-\n"
+	"\t    power-of-2 number specified will be rounded up).\n\n"
+	"\t    The 'sort' param can be used to specify a value field to sort\n"
+	"\t    on.  The default if unspecified is 'hitcount' and the.\n"
+	"\t    default sort order is 'ascending'.  To sort in the opposite\n"
+	"\t    direction, append .descending' to the sort key.\n"
+	"\t    The 'pause' param 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"
+	"\t    restart a paused hist trigger.\n\n"
+	"\t    The 'clear' param will clear the contents of a running hist\n"
+	"\t    trigger and leave its current paused/active state.\n"
 ;
 
 static ssize_t

kernel/trace/trace.h +1 -0

index 5bc1752..f2efd6a 100644
@@ -1098,6 +1098,7 @@ extern struct mutex event_mutex;
 extern struct list_head ftrace_events;
 
 extern const struct file_operations event_trigger_fops;
+extern const struct file_operations event_hist_fops;
 
 extern int register_trigger_cmds(void);
 extern void clear_event_triggers(struct trace_array *tr);

kernel/trace/trace_events.c +3 -0

index 0d2e473..b906f40 100644
@@ -1621,6 +1621,9 @@ event_create_dir(struct dentry *parent, struct ftrace_event_file *file)
 	trace_create_file("trigger", 0644, file->dir, file,
 			  &event_trigger_fops);
 
+	trace_create_file("hist", 0444, file->dir, file,
+			  &event_hist_fops);
+
 	trace_create_file("format", 0444, file->dir, call,
 			  &ftrace_event_format_fops);

kernel/trace/trace_events_filter.c +2 -1

index aa8ab85..15b1ffa 100644
@@ -911,7 +911,8 @@ int filter_assign_type(const char *type)
 	if (strstr(type, "__data_loc") && strstr(type, "char"))
 		return FILTER_DYN_STRING;
 
-	if (strchr(type, '[') && strstr(type, "char"))
+	if (strchr(type, '[') &&
+	    (strstr(type, "char") || strstr(type, "u8")))
 		return FILTER_STATIC_STRING;
 
 	return FILTER_OTHER;

kernel/trace/trace_events_trigger.c +1014 -0

1,044 lines not on this page · raw message

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:04 UTC #20 lore raw

PATCH v2 13/15 tracing: Add sorting to hist triggers

In reply to Tom Zanussi

Add support for sorting to hist triggers, which without this will display entries in hash order, which is to say randomly.

Currently, support is implemented for just a primary sort key which is by default ascending.

To specify the sort key for a trigger, append ':sort=<sort_key>', where sort_key can be any value specified in the values= param, or the special value 'hitcount', which is a sum of the number of times each entry in the hashtable was hit.

With these changes, even if the user doesn't explicitly specify a sort key, the table will be sorted ascending on hitcount. To sort in descending order, append the .descending modifier to the sort field, as such:

':sort=<sort_key>.descending'

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

---
 kernel/trace/trace.c                |   2 +-
 kernel/trace/trace_events_trigger.c | 279 +++++++++++++++++++++++++++++++++++-
 2 files changed, 278 insertions(+), 3 deletions(-)

kernel/trace/trace.c +1 -1

index 683048f..2fa41ef 100644
@@ -3777,7 +3777,7 @@ static const char readme_msg[] =
 	"\t    The 'sort' param can be used to specify a value field to sort\n"
 	"\t    on.  The default if unspecified is 'hitcount' and the.\n"
 	"\t    default sort order is 'ascending'.  To sort in the opposite\n"
-	"\t    direction, append .descending' to the sort key.\n"
+	"\t    direction, append .descending' to the sort key.\n\n"
 	"\t    The 'pause' param 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"

kernel/trace/trace_events_trigger.c +277 -2

360 lines not on this page · raw message

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:02 UTC #21 lore raw

PATCH v2 14/15 tracing: Add enable_hist/disable_hist triggers

In reply to Tom Zanussi

Similar to enable_event/disable_event triggers, these triggers enable and disable the aggregation of events into maps rather than enabling and disabling their writing into the trace buffer.

They can be used to automatically start and stop hist triggers based on a matching filter condition.

If there's a paused hist trigger on system:event, the following would start it when the filter condition was hit:

  # echo enable_hist:system:event [ if filter] > event/trigger

And the following would disable a running system:event hist trigger:

  # echo disable_hist:system:event [ if filter] > event/trigger

See Documentation/trace/events.txt for real examples.

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

---
 include/linux/ftrace_event.h        |   1 +
 kernel/trace/trace.c                |  11 ++-
 kernel/trace/trace_events_trigger.c | 138 +++++++++++++++++++++++++++++++++++-
 3 files changed, 146 insertions(+), 4 deletions(-)

include/linux/ftrace_event.h +1 -0

index 483e011..8679996 100644
@@ -417,6 +417,7 @@ enum event_trigger_type {
 	ETT_STACKTRACE		= (1 << 2),
 	ETT_EVENT_ENABLE	= (1 << 3),
 	ETT_EVENT_HIST		= (1 << 4),
+	ETT_HIST_ENABLE		= (1 << 5),
 };
 
 extern int filter_match_preds(struct event_filter *filter, void *rec);

kernel/trace/trace.c +10 -1

index 2fa41ef..b537a37 100644
@@ -3724,6 +3724,8 @@ static const char readme_msg[] =
 	"\t   trigger: traceon, traceoff\n"
 	"\t            enable_event:<system>:<event>\n"
 	"\t            disable_event:<system>:<event>\n"
+	"\t            enable_hist:<system>:<event>\n"
+	"\t            disable_hist:<system>:<event>\n"
 #ifdef CONFIG_STACKTRACE
 	"\t\t    stacktrace\n"
 #endif

@@ -3783,7 +3785,14 @@ static const char readme_msg[] =
 	"\t    until told to do so.  'continue' can be used to start or\n"
 	"\t    restart a paused hist trigger.\n\n"
 	"\t    The 'clear' param will clear the contents of a running hist\n"
-	"\t    trigger and leave its current paused/active state.\n"
+	"\t    trigger and leave its current paused/active state.\n\n"
+	"\t    The enable_hist and disable_hist triggers can be used to\n"
+	"\t    have one event conditionally start and stop another event's\n"
+	"\t    already-attached hist trigger.  Any number of enable_hist\n"
+	"\t    and disable_hist triggers can be attached to a given event,\n"
+	"\t    allowing that event to kick off and stop aggregations on\n"
+	"\t    a host of other events.  See Documentation/trace/events.txt\n"
+	"\t    for examples.\n"
 ;
 
 static ssize_t

kernel/trace/trace_events_trigger.c +135 -3

202 lines not on this page · raw message

Signature · 1 line

1.9.3

Tom Zanussi

author

2015-03-02 16:02 UTC #22 lore raw

PATCH v2 15/15 tracing: Add 'hist' trigger Documentation

In reply to Tom Zanussi

Add documentation and usage examples for 'hist' triggers.

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

---
 Documentation/trace/events.txt | 870 +++++++++++++++++++++++++++++++++++++++++
 1 file changed, 870 insertions(+)

Documentation/trace/events.txt +870 -0

index 75d25a1..0e7a27f 100644
@@ -494,3 +494,873 @@ The following commands are supported:
 
   Note that there can be only one traceon or traceoff trigger per
   triggering event.
+
+- hist
+
+  This command aggregates event hits into a hash table keyed on a
+  trace event format fields (or stacktrace) and a set of running
+  totals derived from one or more trace event format fields and/or
+  event counts (hitcount).
+
+  The format of a hist trigger is as follows:
+
+        hist:keys=<field1>:values=<field1[,field2,...]>
+          [:size=#entries][:sort=field1][:pause][:continue]
+          [:clear] [if <filter>]
+
+  When a matching event is hit, an entry is added to a hash table
+  using the key(s) and value(s) named.  Keys and values correspond to
+  fields in the event's format description.  Values must correspond to
+  numeric fields - on an event hit, the value(s) will be added to a
+  sum kept for that field.  The special string 'hitcount' can be used
+  in place of an explicit value field - this is simply a count of
+  event hits.  Keys can be any field, or the special string
+  'stacktrace', which will use the event's kernel stacktrace as the
+  key.  The keywords 'keys' or 'key' can be used to specify keys, and
+  the keyworks 'values', 'vals', or 'val' can be used to specify
+  values.  For the time being, only a single key can be used -
+  compound keys aren't yet 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.  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
+	.syscall   display a syscall id as a system call name
+	.execname  display a common_pid as a program name
+
+  A typical usage scenario would be the following to enable a hist
+  trigger, read its current contents, and then turn it off:
+
+  # echo 'hist:keys=skbaddr.hex:vals=len' > \
+    /sys/kernel/debug/tracing/events/net/netif_rx/trigger
+
+  # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
+
+  # echo '!hist:keys=skbaddr.hex:vals=len' > \
+    /sys/kernel/debug/tracing/events/net/netif_rx/trigger
+
+  The trigger file itself can be read to show the details of the
+  currently attached hist trigger.  This information is also displayed
+  at the top of the 'hist' file when read.
+
+  By default, the size of the hash table is 2048 entries.  The 'size'
+  param can be used to specify more or fewer than that.  The units are
+  in terms of hashtable entries - if a run uses more entries than
+  specified, the results will show the number of 'drops', the number
+  of hits that were ignored.  The size should be a power of 2 between
+  128 and 131072 (any non- power-of-2 number specified will be rounded
+  up).
+
+  The 'sort' param can be used to specify a value field to sort on.
+  The default if unspecified is 'hitcount' and the default sort order
+  is 'ascending'.  To sort in the opposite direction, append
+  .descending' to the sort key.
+
+  The 'pause' param can be used to pause an existing hist trigger or
+  to start a hist trigger but not log any events until told to do so.
+  'continue' or 'cont' can be used to start or restart a paused hist
+  trigger.
+
+  The 'clear' param will clear the contents of a running hist trigger
+  and leave its current paused/active state.
+
+- enable_hist/disable_hist
+
+  The enable_hist and disable_hist triggers can be used to have one
+  event conditionally start and stop another event's already-attached
+  hist trigger.  Any number of enable_hist and disable_hist triggers
+  can be attached to a given event, allowing that event to kick off
+  and stop aggregations on a host of other events.
+
+  The format is very similar to the enable/disable_event triggers:
+
+      enable_hist:<system>:<event>[:count]
+      disable_hist:<system>:<event>[:count]
+
+  Instead of enabling or disabling the tracing of the target event
+  into the trace buffer as the enable/disable_event triggers do, the
+  enable/disable_hist triggers enable or disable the aggregation of
+  the target event into a hash table.
+
+  A typical usage scenario for the enable_hist/disable_hist triggers
+  would be to first set up a paused hist trigger on some event,
+  followed by an enable_hist/disable_hist pair that turns the hist
+  aggregation on and off when conditions of interest are hit:
+
+  # echo 'hist:keys=skbaddr.hex:vals=len:pause' > \
+    /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+
+  # echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
+    /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+
+  # echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
+    /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+
+  The above sets up an initially paused hist trigger which is unpaused
+  and starts aggregating events when a given program is executed, and
+  which stops aggregating when the process exits and the hist trigger
+  is paused again.
+
+  The examples below provide a more concrete illustration of the
+  concepts and typical usage patterns discussed above.
+
+
+6.2 'hist' trigger examples
+---------------------------
+
+  The first set of examples creates aggregations using the kmalloc
+  event.  The fields that can be used for the hist trigger are listed
+  in the kmalloc event's format file:
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format
+    name: kmalloc
+    ID: 374
+    format:
+	field:unsigned short common_type;	offset:0;	size:2;	signed:0;
+	field:unsigned char common_flags;	offset:2;	size:1;	signed:0;
+	field:unsigned char common_preempt_count;		offset:3;	size:1;	signed:0;
+	field:int common_pid;					offset:4;	size:4;	signed:1;
+
+	field:unsigned long call_site;				offset:8;	size:8;	signed:0;
+	field:const void * ptr;					offset:16;	size:8;	signed:0;
+	field:size_t bytes_req;					offset:24;	size:8;	signed:0;
+	field:size_t bytes_alloc;				offset:32;	size:8;	signed:0;
+	field:gfp_t gfp_flags;					offset:40;	size:4;	signed:0;
+
+  We'll start by creating a hist trigger that generates a simple table
+  that lists the total number of bytes requested for each function in
+  the kernel that made one or more calls to kmalloc:
+
+    # echo 'hist:key=call_site:val=bytes_req' > \
+            /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+  This tells the tracing system to create a 'hist' trigger using the
+  call_site field of the kmalloc event as the key for the table, which
+  just means that each unique call_site address will have an entry
+  created for it in the table.  The 'val=bytes_req' parameter tells
+  the hist trigger that for each unique entry (call_site) in the
+  table, it should keep a running total of the number of bytes
+  requested by that call_site.
+
+  We'll let it run for awhile and then dump the contents of the 'hist'
+  file in the kmalloc event's subdirectory (for readability, a number
+  of entries have been omitted):
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+    trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
+
+    call_site: 18446744071581750326 hitcount:          1  bytes_req:         24
+    call_site: 18446744071583151255 hitcount:          1  bytes_req:         32
+    call_site: 18446744071582443167 hitcount:          1  bytes_req:        264
+    call_site: 18446744072104099935 hitcount:          2  bytes_req:        464
+    call_site: 18446744071579323550 hitcount:          3  bytes_req:        168
+    call_site: 18446744071580558850 hitcount:          4  bytes_req:      65536
+    .
+    .
+    .
+    call_site: 18446744072101362738 hitcount:       4115  bytes_req:     362120
+    call_site: 18446744072103235682 hitcount:       4115  bytes_req:     427960
+    call_site: 18446744072102962280 hitcount:       4342  bytes_req:    1637584
+    call_site: 18446744072102962328 hitcount:       4973  bytes_req:     360624
+    call_site: 18446744072101400062 hitcount:       6465  bytes_req:     258600
+    call_site: 18446744071582063959 hitcount:       7818  bytes_req:      15636
+    call_site: 18446744072102968908 hitcount:       9315  bytes_req:    8912400
+    call_site: 18446744072103122419 hitcount:       9315  bytes_req:     819720
+    call_site: 18446744072101402850 hitcount:      10240  bytes_req:     573440
+    call_site: 18446744072099471334 hitcount:      23820  bytes_req:     476512
+
+    Totals:
+        Hits: 109976
+        Entries: 76
+        Dropped: 0
+
+  The output displays a line for each entry, beginning with the key
+  specified in the trigger, followed by the value(s) also specified in
+  the trigger.  At the beginning of the output is a line that displays
+  the trigger info, which can also be displayed by reading the
+  'trigger' file:
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+    hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
+
+  At the end of the output are a few lines that display the overall
+  totals for the run.  The 'Hits' field shows the total number of
+  times the event trigger was hit, the 'Entries' fields shows the
+  total number of used entries in the hash table, and the 'Dropped'
+  field shows the number of hits that were dropped because the number
+  of used entries for the run exceeded the maximum number of entries
+  allowed for the table (normally 0, but if not a hint that you may
+  want to increase the size of the table using the 'size' param).
+
+  Notice in the above output that there's an extra field, 'hitcount',
+  that wasn't specified in the trigger.  Also notice that in the
+  trigger info a param,'sort=hitcount', which wasn't specified in the
+  trigger either.  The reason is that every trigger implicitly keeps a
+  count of the total number of hits attributed to a given entry,
+  called the 'hitcount', and that in the absence of a user-specified
+  sort param, the hitcount is used as the default sort field.
+
+  The value 'hitcount' can be used in place of an explicit value in
+  the 'values' param if you don't really need to have any particular
+  field summed and are mainly interested in hit frequencies.
+
+  To turn the hist trigger off, simply call up the trigger in command
+  history and re-execute it with a '!' prepended:
+
+    # echo '!hist:key=call_site:val=bytes_req' > \
+           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+  Finally, notice that the call_site as displayed in the output above
+  isn't really very useful.  It's an address, but normally addresses
+  are displayed in hex.  To have a numeric field displayed as hex
+  values, simply append '.hex' to the field name in the trigger:
+
+    # echo 'hist:key=call_site.hex:val=bytes_req' > \
+           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+    trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
+
+    call_site: ffffffffa04e85cb hitcount:          1  bytes_req:        511
+    call_site: ffffffff810a66a9 hitcount:          1  bytes_req:       1024
+    call_site: ffffffff8152db82 hitcount:          1  bytes_req:          8
+    call_site: ffffffffa008829e hitcount:          1  bytes_req:          7
+    call_site: ffffffffa0087d6a hitcount:          1  bytes_req:          7
+    call_site: ffffffffa02eb7e1 hitcount:          1  bytes_req:        433
+    call_site: ffffffff8152cbde hitcount:          1  bytes_req:        192
+    call_site: ffffffff811a2602 hitcount:          2  bytes_req:      32768
+    .
+    .
+    .
+    call_site: ffffffffa0419062 hitcount:        724  bytes_req:      75296
+    call_site: ffffffffa024fc32 hitcount:        724  bytes_req:      63712
+    call_site: ffffffffa03d6468 hitcount:        852  bytes_req:     416736
+    call_site: ffffffffa03d6498 hitcount:        944  bytes_req:      70984
+    call_site: ffffffff81311d57 hitcount:        961  bytes_req:       1922
+    call_site: ffffffffa0258dfe hitcount:       1429  bytes_req:      57160
+    call_site: ffffffffa03fd5f3 hitcount:       1796  bytes_req:     158048
+    call_site: ffffffffa03d7e4c hitcount:       1796  bytes_req:    2206848
+    call_site: ffffffffa02598e2 hitcount:       3196  bytes_req:     178976
+    call_site: ffffffffa0081fe6 hitcount:       9529  bytes_req:     190584
+
+    Totals:
+        Hits: 24542
+        Entries: 60
+        Dropped: 0
+
+  Even that's only marginally more useful - while hex values do look
+  more like addresses, what users are typically more interested in
+  when looking at text addresses are the corresponding symbols
+  instead.  To have an address displayed as symbolic value instead,
+  simply append '.sym' to the field name in the trigger:
+
+    # echo 'hist:key=call_site.sym:val=bytes_req' > \
+           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+    trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
+
+    call_site: [ffffffff8152db82] usb_control_msg                     hitcount:          1  bytes_req:          8
+    call_site: [ffffffffa04e85cb] __ieee80211_start_scan              hitcount:          1  bytes_req:        511
+    call_site: [ffffffff815d7f6b] sk_prot_alloc                       hitcount:          1  bytes_req:        976
+    call_site: [ffffffff8152cbde] usb_alloc_urb                       hitcount:          1  bytes_req:        192
+    call_site: [ffffffff815d2c1b] sock_alloc_inode                    hitcount:          1  bytes_req:         64
+    call_site: [ffffffffa02eb7e1] nl80211_trigger_scan                hitcount:          1  bytes_req:        433
+    call_site: [ffffffffa0087d6a] hidraw_report_event                 hitcount:          1  bytes_req:          7
+    call_site: [ffffffff810a66a9] syslog_print_all                    hitcount:          1  bytes_req:       1024
+    call_site: [ffffffffa008829e] hidraw_send_report                  hitcount:          1  bytes_req:          7
+    call_site: [ffffffff811f1316] mounts_open_common                  hitcount:          2  bytes_req:        368
+    call_site: [ffffffff811d0825] alloc_fdtable                       hitcount:          2  bytes_req:         96
+    call_site: [ffffffffa042106f] __intel_framebuffer_create          hitcount:          3  bytes_req:        432
+    .
+    .
+    .
+    call_site: [ffffffff8136b079] sg_kmalloc                          hitcount:        461  bytes_req:     153696
+    call_site: [ffffffffa03dbc5e] i915_gem_obj_lookup_or_create_vma   hitcount:        462  bytes_req:      92400
+    call_site: [ffffffffa03e213a] i915_gem_object_get_pages_gtt       hitcount:        462  bytes_req:       7392
+    call_site: [ffffffffa03d6498] i915_gem_do_execbuffer.isra.22      hitcount:        697  bytes_req:      52064
+    call_site: [ffffffff81311d57] apparmor_file_alloc_security        hitcount:        926  bytes_req:       1852
+    call_site: [ffffffffa0258dfe] drm_vma_node_allow                  hitcount:       1050  bytes_req:      42000
+    call_site: [ffffffffa03fd5f3] intel_ring_begin                    hitcount:       1116  bytes_req:      98208
+    call_site: [ffffffffa03d7e4c] i915_gem_execbuffer2                hitcount:       1116  bytes_req:     956984
+    call_site: [ffffffffa02598e2] drm_modeset_lock_crtc               hitcount:       2055  bytes_req:     115080
+    call_site: [ffffffffa0081fe6] hid_report_raw_event                hitcount:       6433  bytes_req:     128664
+
+    Totals:
+        Hits: 17384
+        Entries: 62
+        Dropped: 0
+
+  Because the default sort key above is 'hitcount', the above shows a
+  the list of call_sites by increasing hitcount, so that at the bottom
+  we see the functions that made the most kmalloc calls during the
+  run.  If instead we we wanted to see the top kmalloc callers in
+  terms of the number of bytes requested rather than the number of
+  calls, and we wanted the top caller to appear at the top, we can use
+  the 'sort' param, along with the 'descending' modifier:
+
+    # echo 'hist:key=call_site.sym:val=bytes_req:sort=bytes_req.descending' > \
+           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+    trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req:size=2048 [active]
+
+    call_site: [ffffffffa03d7e4c] i915_gem_execbuffer2                hitcount:        682  bytes_req:     766360
+    call_site: [ffffffff811d6c3b] seq_buf_alloc                       hitcount:         46  bytes_req:     186176
+    call_site: [ffffffffa03d6468] i915_gem_do_execbuffer.isra.22      hitcount:        377  bytes_req:     142808
+    call_site: [ffffffffa02598e2] drm_modeset_lock_crtc               hitcount:       1107  bytes_req:      61992
+    call_site: [ffffffffa03fd5f3] intel_ring_begin                    hitcount:        682  bytes_req:      60016
+    call_site: [ffffffffa0081fe6] hid_report_raw_event                hitcount:       2993  bytes_req:      59864
+    call_site: [ffffffff8136b079] sg_kmalloc                          hitcount:        206  bytes_req:      48096
+    call_site: [ffffffffa03dbc5e] i915_gem_obj_lookup_or_create_vma   hitcount:        206  bytes_req:      41200
+    call_site: [ffffffff811a2602] __kmalloc                           hitcount:          2  bytes_req:      32768
+    call_site: [ffffffffa0419062] intel_crtc_page_flip                hitcount:        305  bytes_req:      31720
+    call_site: [ffffffffa024fc32] drm_mode_page_flip_ioctl            hitcount:        305  bytes_req:      26840
+    call_site: [ffffffffa0258dfe] drm_vma_node_allow                  hitcount:        603  bytes_req:      24120
+    call_site: [ffffffffa03d6498] i915_gem_do_execbuffer.isra.22      hitcount:        305  bytes_req:      23072
+    call_site: [ffffffff812775da] ext4_find_extent                    hitcount:         79  bytes_req:       7584
+    .
+    .
+    .
+    call_site: [ffffffff811f3b07] inotify_handle_event                hitcount:          2  bytes_req:         96
+    call_site: [ffffffff811bfb6e] vfs_rename                          hitcount:          6  bytes_req:         66
+    call_site: [ffffffff815d2c1b] sock_alloc_inode                    hitcount:          1  bytes_req:         64
+    call_site: [ffffffff811d0825] alloc_fdtable                       hitcount:          1  bytes_req:         48
+    call_site: [ffffffff81220376] proc_self_follow_link               hitcount:          2  bytes_req:         24
+    call_site: [ffffffff8112e1ec] hist_show                           hitcount:          2  bytes_req:         16
+    call_site: [ffffffff8112e1d0] hist_show                           hitcount:          2  bytes_req:         16
+    call_site: [ffffffff8152db82] usb_control_msg                     hitcount:          1  bytes_req:          8
+    call_site: [ffffffffa008829e] hidraw_send_report                  hitcount:          1  bytes_req:          7
+    call_site: [ffffffffa0087d6a] hidraw_report_event                 hitcount:          1  bytes_req:          7
+
+    Totals:
+        Hits: 9331
+        Entries: 57
+        Dropped: 0
+
+  We can also add multiple fields to the 'values' param.  For example,
+  we might want to see the total number of bytes allocated alongside
+  bytes requested, and display the result sorted by bytes allocated in
+  a descending order:
+
+    # echo 'hist:keys=call_site.sym:values=bytes_req,bytes_alloc:sort=bytes_alloc.descending' > \
+           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+    trigger info: hist:keys=call_site.sym:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active]
+
+    call_site: [ffffffffa03d7e4c] i915_gem_execbuffer2                hitcount:       4427  bytes_req:    4190032  bytes_alloc:    5967744
+    call_site: [ffffffff811d6c3b] seq_buf_alloc                       hitcount:        427  bytes_req:    1706768  bytes_alloc:    1765376
+    call_site: [ffffffffa03d6468] i915_gem_do_execbuffer.isra.22      hitcount:       1978  bytes_req:     765936  bytes_alloc:    1434304
+    call_site: [ffffffffa03fd5f3] intel_ring_begin                    hitcount:       4427  bytes_req:     389576  bytes_alloc:     424992
+    call_site: [ffffffff8136b079] sg_kmalloc                          hitcount:        993  bytes_req:     305824  bytes_alloc:     376576
+    call_site: [ffffffffa02598e2] drm_modeset_lock_crtc               hitcount:       4319  bytes_req:     241864  bytes_alloc:     276416
+    call_site: [ffffffffa03dbc5e] i915_gem_obj_lookup_or_create_vma   hitcount:        993  bytes_req:     198600  bytes_alloc:     254208
+    call_site: [ffffffffa0419062] intel_crtc_page_flip                hitcount:       1806  bytes_req:     187824  bytes_alloc:     231168
+    call_site: [ffffffff81424d78] __tty_buffer_request_room           hitcount:         61  bytes_req:     128928  bytes_alloc:     229376
+    call_site: [ffffffffa0081fe6] hid_report_raw_event                hitcount:       9550  bytes_req:     191024  bytes_alloc:     210160
+    call_site: [ffffffffa03d6498] i915_gem_do_execbuffer.isra.22      hitcount:       2449  bytes_req:     184720  bytes_alloc:     209216
+    call_site: [ffffffffa0258dfe] drm_vma_node_allow                  hitcount:       3256  bytes_req:     130240  bytes_alloc:     208384
+    .
+    .
+    .
+    call_site: [ffffffffa04e85cb] __ieee80211_start_scan              hitcount:          3  bytes_req:       1533  bytes_alloc:       1536
+    call_site: [ffffffffa02eb7e1] nl80211_trigger_scan                hitcount:          3  bytes_req:       1299  bytes_alloc:       1536
+    call_site: [ffffffff8152cbde] usb_alloc_urb                       hitcount:          6  bytes_req:       1152  bytes_alloc:       1152
+    call_site: [ffffffff811f3b07] inotify_handle_event                hitcount:         14  bytes_req:        744  bytes_alloc:        896
+    call_site: [ffffffff81206b81] load_elf_binary                     hitcount:         24  bytes_req:        672  bytes_alloc:        768
+    call_site: [ffffffff811bfb6e] vfs_rename                          hitcount:         38  bytes_req:        436  bytes_alloc:        640
+    call_site: [ffffffff81220376] proc_self_follow_link               hitcount:         24  bytes_req:        288  bytes_alloc:        384
+    call_site: [ffffffff815d2c1b] sock_alloc_inode                    hitcount:          5  bytes_req:        320  bytes_alloc:        320
+    call_site: [ffffffff811d0825] alloc_fdtable                       hitcount:          4  bytes_req:        192  bytes_alloc:        256
+    call_site: [ffffffffa04ec05f] ieee80211_start_tx_ba_session       hitcount:          1  bytes_req:        232  bytes_alloc:        256
+    call_site: [ffffffffa0244701] drm_vm_open_locked                  hitcount:          5  bytes_req:        160  bytes_alloc:        160
+    call_site: [ffffffff8112e1d0] hist_show                           hitcount:         10  bytes_req:         80  bytes_alloc:         80
+    call_site: [ffffffff8112e1ec] hist_show                           hitcount:         10  bytes_req:         80  bytes_alloc:         80
+    call_site: [ffffffff81074c9e] kthread_create_on_node              hitcount:          1  bytes_req:         56  bytes_alloc:         64
+    call_site: [ffffffff8152db82] usb_control_msg                     hitcount:          6  bytes_req:         48  bytes_alloc:         48
+    call_site: [ffffffffa008829e] hidraw_send_report                  hitcount:          6  bytes_req:         42  bytes_alloc:         48
+    call_site: [ffffffffa0087d6a] hidraw_report_event                 hitcount:          6  bytes_req:         42  bytes_alloc:         48
+
+    Totals:
+        Hits: 45576
+        Entries: 66
+        Dropped: 0
+
+  Finally, to finish off our kmalloc example, instead of simply having
+  the hist trigger display symbolic call_sites, we can have the hist
+  trigger additionally display the complete set of kernel stack traces
+  that led to each call_sites.  To do that, we simply use the special
+  value 'stacktrace' for the key param:
+
+    # echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \
+           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
+
+  The above trigger will use the kernel stack trace in effect when an
+  event is triggered as the key for the hash table.  This allows the
+  enumeration of every kernel callpath that led up to a particular
+  event, along with a running total of any of the event fields for
+  that event.  Here we tally bytes requested and bytes allocated for
+  every callpath in the system that led up to a kmalloc (in this case
+  every callpath to a kmalloc for a kernel compile):
+
+    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
+    trigger info: hist:keys=stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active]
+
+    stacktrace:
+         __kmalloc_track_caller+0x10b/0x190
+         kstrdup+0x35/0x70
+         __kernfs_new_node+0x34/0xf0
+         kernfs_new_node+0x26/0x50
+         kernfs_create_dir_ns+0x29/0x80
+         sysfs_create_dir_ns+0x40/0xa0
+         kobject_add_internal+0xbd/0x3a0
+         kobject_add+0x60/0xb0
+         device_add+0xff/0x5a0
+         device_register+0x1e/0x30
+         usb_create_ep_devs+0x81/0xd0
+         usb_new_device+0x357/0x410
+         hub_event+0xd68/0x11a0
+         process_one_work+0x149/0x3d0
+         worker_thread+0x121/0x4a0
+         kthread+0xd2/0xf0
+     hitcount:          1  bytes_req:          6  bytes_alloc:          8
+    stacktrace:
+         kmem_cache_alloc_trace+0xfb/0x160
+         usb_control_msg+0x42/0x110
+         hub_port_status+0x84/0x120
+         hub_port_reset+0x263/0x430
+         hub_port_init+0x77/0xbb0
+         hub_event+0x944/0x11a0
+         process_one_work+0x149/0x3d0
+         worker_thread+0x121/0x4a0
+         kthread+0xd2/0xf0
+         ret_from_fork+0x7c/0xb0
+     hitcount:          1  bytes_req:          8  bytes_alloc:          8
+    .
+    .
+    .
+    stacktrace:
+         __kmalloc+0x11b/0x1a0
+         load_elf_phdrs+0x76/0xa0
+         load_elf_binary+0x102/0x1780
+         search_binary_handler+0x97/0x1d0
+         do_execveat_common.isra.32+0x551/0x6e0
+         SyS_execve+0x3a/0x50
+         stub_execve+0x69/0xa0
+     hitcount:     131791  bytes_req:   67822944  bytes_alloc:   80279552
+    stacktrace:
+         __kmalloc+0x11b/0x1a0
+         i915_gem_execbuffer2+0x6c/0x2c0 [i915]
+         drm_ioctl+0x1a4/0x630 [drm]
+         do_vfs_ioctl+0x2f0/0x4f0
+         SyS_ioctl+0x81/0xa0
+         system_call_fastpath+0x12/0x17
+     hitcount:     164540  bytes_req:  134464456  bytes_alloc:  167693376
+    stacktrace:
+         kmem_cache_alloc_trace+0xfb/0x160
+         apparmor_file_alloc_security+0x27/0x40
+         security_file_alloc+0x16/0x20
+         get_empty_filp+0x93/0x1c0
+         path_openat+0x31/0x620
+         do_filp_open+0x3a/0x90
+         do_sys_open+0x128/0x220
+         SyS_open+0x1e/0x20
+         system_call_fastpath+0x12/0x17
+     hitcount:   22118413  bytes_req:   44236888  bytes_alloc:  176947328
+    stacktrace:
+         __kmalloc+0x11b/0x1a0
+         seq_buf_alloc+0x1b/0x50
+         seq_read+0x2cc/0x370
+         proc_reg_read+0x3d/0x80
+         __vfs_read+0x18/0x50
+         vfs_read+0x86/0x140
+         SyS_read+0x46/0xb0
+         system_call_fastpath+0x12/0x17
+     hitcount:      66168  bytes_req:  271015944  bytes_alloc:  271015952
+
+    Totals:
+        Hits: 26780801
+        Entries: 633
+        Dropped: 0
+
+  If you key a hist trigger on pid, for example, to gather and display
+  sorted totals for each process, you can use the special .execname
+  modifier to display the executable names for the processes in the
+  table rather than raw pids.  The example below keeps a per-process
+  sum of total bytes read:
+
+    # echo 'hist:key=common_pid.execname:val=count:sort=count.descending' > \
+           /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
+
+    # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/hist
+    trigger info: hist:keys=common_pid.execname:vals=count:sort=count:size=2048 [active]
+
+    common_pid: Xorg            [18446612132314219843] hitcount:        166  count:     159744
+    common_pid: gnome-terminal  [18446612132314221635] hitcount:         44  count:     113321
+    common_pid: compiz          [18446612132314221491] hitcount:         13  count:      81968
+    common_pid: bash            [18446612132314231931] hitcount:          3  count:      66369
+    common_pid: gdbus           [18446612132314221135] hitcount:         91  count:       1456
+    common_pid: acpid           [18446612132314219701] hitcount:         48  count:       1152
+    common_pid: ibus-daemon     [18446612132314221129] hitcount:         71  count:       1136
+    common_pid: gdbus           [18446612132314221638] hitcount:         42  count:        672
+    common_pid: gdbus           [18446612132314221345] hitcount:         42  count:        672
+    common_pid: ibus-engine-sim [18446612132314221344] hitcount:         14  count:        224
+    common_pid: gdbus           [18446612132314221262] hitcount:         12  count:        192
+    common_pid: gdbus           [18446612132314221249] hitcount:          6  count:         96
+    common_pid: ibus-ui-gtk3    [18446612132314221245] hitcount:          6  count:         96
+    common_pid: gdbus           [18446612132314221504] hitcount:          5  count:         80
+    common_pid: unity-panel-ser [18446612132314221243] hitcount:          3  count:         48
+    common_pid: postgres        [18446612132314220339] hitcount:          1  count:         16
+    common_pid: gdbus           [18446612132314221395] hitcount:          1  count:         16
+    common_pid: rtkit-daemon    [18446612132314220509] hitcount:          1  count:          8
+    common_pid: upstart-dbus-br [18446612132314221100] hitcount:          4  count:          4
+    common_pid: bash            [18446612132314221924] hitcount:          4  count:          4
+    common_pid: firefox         [18446612132314222258] hitcount:          1  count:          1
+
+    Totals:
+        Hits: 578
+        Entries: 21
+        Dropped: 0
+
+
+  Similarly, if you key a hist trigger on syscall id, for example to
+  gather and display a list of systemwide syscall hits, you can use
+  the special .syscall modifier to display the syscall names rather
+  than raw ids.  The example below keeps a running total of syscall
+  counts for the system during the run:
+
+    # echo 'hist:key=id.syscall:val=hitcount' > \
+           /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
+
+    # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
+    trigger info: hist:keys=id.syscall:vals=:sort=hitcount:size=2048 [active]
+
+    id: sys_fadvise64                  hitcount:          1
+    id: sys_bind                       hitcount:          1
+    id: sys_fsync                      hitcount:          1
+    id: sys_getsockname                hitcount:          1
+    id: sys_readlink                   hitcount:          3
+    id: sys_set_tid_address            hitcount:          4
+    .
+    .
+    .
+    id: sys_mprotect                   hitcount:         57
+    id: sys_waitid                     hitcount:         64
+    id: sys_rt_sigaction               hitcount:        121
+    id: sys_inotify_add_watch          hitcount:        234
+    id: sys_mmap                       hitcount:        258
+    id: sys_nanosleep                  hitcount:        310
+    id: sys_close                      hitcount:        323
+    id: sys_rt_sigprocmask             hitcount:       3520
+    id: sys_futex                      hitcount:       4819
+    id: sys_write                      hitcount:       8907
+    id: sys_setitimer                  hitcount:      39039
+    id: sys_writev                     hitcount:      64528
+    id: sys_poll                       hitcount:      77493
+    id: sys_recvmsg                    hitcount:     168240
+    id: sys_ioctl                      hitcount:     448946
+
+    Totals:
+        Hits: 869971
+        Entries: 75
+        Dropped: 0
+
+  The next example uses a string field as the hash key and
+  demonstrates how you can manually pause and continue a hist trigger.
+  In this example, we'll aggregate fork counts and don't expect a
+  large number of entries in the hash table, so we'll drop it to a
+  much smaller number, say 256:
+
+    # echo 'hist:key=child_comm:val=hitcount:size=256' > \
+           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+
+    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
+    trigger info: hist:keys=child_comm:vals=:sort=hitcount:size=256 [active]
+
+    child_comm: gdbus                               hitcount:          1
+    child_comm: smbd                                hitcount:          1
+    child_comm: ibus-daemon                         hitcount:          1
+    child_comm: Cache2 I/O                          hitcount:          1
+    child_comm: dconf worker                        hitcount:          1
+    child_comm: postgres                            hitcount:          1
+    child_comm: unity-panel-ser                     hitcount:          2
+    child_comm: compiz                              hitcount:          3
+    child_comm: bash                                hitcount:          3
+    child_comm: firefox                             hitcount:         60
+
+    Totals:
+        Hits: 74
+        Entries: 10
+        Dropped: 0
+
+    # echo 'hist:key=child_comm:val=hitcount:size=256:pause' > \
+           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+
+  If we want to pause the hist trigger, we can simply append :pause to
+  the command that started the trigger.  Notice that the trigger info
+  displays as [paused]:
+
+    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
+    trigger info: hist:keys=child_comm:vals=:sort=hitcount:size=256 [paused]
+
+    child_comm: dconf worker                        hitcount:          1
+    child_comm: gdbus                               hitcount:          1
+    child_comm: Cache2 I/O                          hitcount:          1
+    child_comm: ibus-daemon                         hitcount:          1
+    child_comm: unity-panel-ser                     hitcount:          2
+    child_comm: smbd                                hitcount:          2
+    child_comm: postgres                            hitcount:          3
+    child_comm: compiz                              hitcount:          3
+    child_comm: bash                                hitcount:          3
+    child_comm: emacs                               hitcount:          8
+    child_comm: firefox                             hitcount:         60
+
+    Totals:
+        Hits: 85
+        Entries: 11
+        Dropped: 0
+
+  To manually continue having the trigger aggregate events, append
+  :cont instead.  Notice that the trigger info displays as [active]
+  again, and the data has changed:
+
+    # echo 'hist:key=child_comm:val=hitcount:size=256:cont' >
+           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
+
+    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
+    trigger info: hist:keys=child_comm:vals=:sort=hitcount:size=256 [active]
+
+    child_comm: Cache2 I/O                          hitcount:          1
+    child_comm: ibus-daemon                         hitcount:          1
+    child_comm: kthreadd                            hitcount:          1
+    child_comm: gdbus                               hitcount:          1
+    child_comm: dconf worker                        hitcount:          1
+    child_comm: unity-panel-ser                     hitcount:          2
+    child_comm: smbd                                hitcount:          2
+    child_comm: compiz                              hitcount:          3
+    child_comm: postgres                            hitcount:          4
+    child_comm: bash                                hitcount:          4
+    child_comm: emacs                               hitcount:          8
+    child_comm: firefox                             hitcount:         60
+
+    Totals:
+        Hits: 88
+        Entries: 12
+        Dropped: 0
+
+  The previous example showed how to start and stop a hist trigger by
+  appending 'pause' and 'continue' to the hist trigger command.  A
+  hist trigger can also be started in a paused state by initially
+  starting the trigger with ':pause' appended.  This allows you to
+  start the trigger only when you're ready to start collecting data
+  and not before.  For example, start the trigger in a paused state,
+  then unpause it and do something you want to measure, then pause the
+  trigger when done.
+
+  Of course, doing this manually can be difficult and error-prone, but
+  it is possible to automatically start and stop a hist trigger based
+  on some condition, via the enable_hist and disable_hist triggers.
+
+  For example, suppose we wanted to take a look at the relative
+  weights in terms of skb length for each callpath that leads to a
+  netif_receieve_skb event when downloading a decent-sized file using
+  wget.
+
+  First we set up an initially paused stacktrace trigger on the
+  netif_receive_skb event:
+
+    # echo 'hist:key=stacktrace:vals=len:pause' > \
+           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+
+  Next, we set up an 'enable_hist' trigger on the sched_process_exec
+  event, with an 'if filename==/usr/bin/wget' filter.  The effect of
+  this new trigger is that it will 'unpause' the hist trigger we just
+  set up on netif_receive_skb if and only if it sees a
+  sched_proces_exec event with a filename of '/usr/bin/wget'.  When
+  that happens, all netif_receive_skb events are aggregated into a
+  hash table keyed on stacktrace:
+
+    # echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
+           /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+
+  The aggregation continues until the netif_receive_skb is paused
+  again, which is what the following disable_hist event does by
+  creating a similar setup on the sched_process_exit event, using the
+  filter 'comm==wget':
+
+    # echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
+           /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+
+  Whenever a process exits and the comm field of the disable_hist
+  trigger filter matches 'comm==wget', the netif_receive_skb hist
+  trigger is disabled.
+
+  The overall effect is that netif_received_skb events are aggregated
+  into the hash table for only the duration of the wget.  Executing a
+  wget command and then listing the 'hist' file will display the
+  output generated by the wget command:
+
+    $ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
+
+    # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
+    trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
+
+    stacktrace:
+         __netif_receive_skb_core+0x4ad/0x780
+         __netif_receive_skb+0x18/0x60
+         process_backlog+0xa8/0x150
+         net_rx_action+0x15d/0x340
+         __do_softirq+0x114/0x2c0
+         do_softirq_own_stack+0x1c/0x30
+         do_softirq+0x65/0x70
+         __local_bh_enable_ip+0xb5/0xc0
+         ip_finish_output+0x1f4/0x810
+         ip_output+0x68/0xa0
+         ip_local_out_sk+0x30/0x40
+         ip_send_skb+0x1a/0x50
+         udp_send_skb+0x173/0x2a0
+         udp_sendmsg+0x2bf/0x9f0
+         inet_sendmsg+0x63/0xb0
+         do_sock_sendmsg+0x8c/0x100
+     hitcount:          4  len:        388
+    stacktrace:
+         __netif_receive_skb_core+0x4ad/0x780
+         __netif_receive_skb+0x18/0x60
+         netif_receive_skb_internal+0x23/0x90
+         napi_gro_receive+0xc8/0x100
+         ieee80211_deliver_skb+0xba/0x250 [mac80211]
+         ieee80211_rx_handlers+0xcc5/0x2240 [mac80211]
+         ieee80211_prepare_and_rx_handle+0x4e7/0xc30 [mac80211]
+         ieee80211_rx+0x31d/0x920 [mac80211]
+         iwlagn_rx_reply_rx+0x3db/0x6f0 [iwldvm]
+         iwl_rx_dispatch+0x8e/0xf0 [iwldvm]
+         iwl_pcie_irq_handler+0xe1c/0x12c0 [iwlwifi]
+         irq_thread_fn+0x20/0x50
+         irq_thread+0x11f/0x150
+         kthread+0xd2/0xf0
+         ret_from_fork+0x7c/0xb0
+     hitcount:         35  len:      17415
+    stacktrace:
+         __netif_receive_skb_core+0x4ad/0x780
+         __netif_receive_skb+0x18/0x60
+         netif_receive_skb_internal+0x23/0x90
+         napi_gro_complete+0xa4/0xe0
+         dev_gro_receive+0x233/0x360
+         napi_gro_receive+0x30/0x100
+         ieee80211_deliver_skb+0xba/0x250 [mac80211]
+         ieee80211_rx_handlers+0xcc5/0x2240 [mac80211]
+         ieee80211_prepare_and_rx_handle+0x4e7/0xc30 [mac80211]
+         ieee80211_rx+0x31d/0x920 [mac80211]
+         iwlagn_rx_reply_rx+0x3db/0x6f0 [iwldvm]
+         iwl_rx_dispatch+0x8e/0xf0 [iwldvm]
+         iwl_pcie_irq_handler+0xe1c/0x12c0 [iwlwifi]
+         irq_thread_fn+0x20/0x50
+         irq_thread+0x11f/0x150
+         kthread+0xd2/0xf0
+     hitcount:        155  len:     636342
+    stacktrace:
+         __netif_receive_skb_core+0x4ad/0x780
+         __netif_receive_skb+0x18/0x60
+         netif_receive_skb_internal+0x23/0x90
+         napi_gro_complete+0xa4/0xe0
+         napi_gro_flush+0x6d/0x90
+         iwl_pcie_irq_handler+0x90f/0x12c0 [iwlwifi]
+         irq_thread_fn+0x20/0x50
+         irq_thread+0x11f/0x150
+         kthread+0xd2/0xf0
+         ret_from_fork+0x7c/0xb0
+     hitcount:       1013  len:    5531908
+
+    Totals:
+        Hits: 1207
+        Entries: 4
+        Dropped: 0
+
+  The above shows all the netif_receive_skb callpaths and their total
+  lengths for the duration of the wget command.
+
+  The 'clear' hist trigger param can be used to clear the hash table.
+  Suppose we wanted to try another run of the previous example but
+  this time also wanted to see the complete list of events that went
+  into the histogram.  In order to avoid having to set everything up
+  again, we can just clear the histogram first:
+
+    # echo 'hist:key=stacktrace:vals=len:clear' > \
+           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
+
+  Just to verify that it is in fact cleared, here's what we now see in
+  the hist file:
+
+    # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
+    trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
+
+    Totals:
+        Hits: 0
+        Entries: 0
+        Dropped: 0
+
+  Since we want to see the detailed list of every netif_receive_skb
+  event occurring during the new run, which are in fact same events
+  being aggregated into the hash table, we add some additional
+  'enable_event' events the triggering sched_process_exec and
+  sched_process_exit events as such:
+
+    # echo 'enable_event:net:netif_receive_skb if filename==/usr/bin/wget' > \
+           /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+
+    # echo 'disable_event:net:netif_receive_skb if comm==wget' > \
+           /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+
+  If you read the trigger files for the sched_process_exec and
+  sched_process_exit triggers, you should see two triggers for each:
+  one enabling/disabling the hist aggregation and the other
+  enabling/disabling the logging of events:
+
+    # cat /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
+    enable_event:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
+    enable_hist:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
+
+    # cat /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
+    enable_event:net:netif_receive_skb:unlimited if comm==wget
+    disable_hist:net:netif_receive_skb:unlimited if comm==wget
+
+  In other words, whever either of the sched_process_exec or
+  sched_process_exit events is hit and matches 'wget', it enables or
+  disables both the histogram and the event log, and what you end up
+  with is a hash table and set of events just covering the specified
+  duration.
+
+  Displaying the 'hist' file should show something similar to what you
+  saw in the last run, but this time you should also see the
+  individual events in the trace file:
+
+    # cat /sys/kernel/debug/tracing/trace
+    # tracer: nop
+    #
+    # entries-in-buffer/entries-written: 183/1426   #P:4
+    #
+    #                              _-----=> irqs-off
+    #                             / _----=> need-resched
+    #                            | / _---=> hardirq/softirq
+    #                            || / _--=> preempt-depth
+    #                            ||| /     delay
+    #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
+    #              | |       |   ||||       |         |
+                wget-15108 [000] ..s1 31769.606929: netif_receive_skb: dev=lo skbaddr=ffff88009c353100 len=60
+                wget-15108 [000] ..s1 31769.606999: netif_receive_skb: dev=lo skbaddr=ffff88009c353200 len=60
+             dnsmasq-1382  [000] ..s1 31769.677652: netif_receive_skb: dev=lo skbaddr=ffff88009c352b00 len=130
+             dnsmasq-1382  [000] ..s1 31769.685917: netif_receive_skb: dev=lo skbaddr=ffff88009c352200 len=138
+    ##### CPU 2 buffer started ####
+      irq/29-iwlwifi-559   [002] ..s. 31772.031529: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433d00 len=2948
+      irq/29-iwlwifi-559   [002] ..s. 31772.031572: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432200 len=1500
+      irq/29-iwlwifi-559   [002] ..s. 31772.032196: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433100 len=2948
+      irq/29-iwlwifi-559   [002] ..s. 31772.032761: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433000 len=2948
+      irq/29-iwlwifi-559   [002] ..s. 31772.033220: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432e00 len=1500
+    .
+    .
+    .

Signature · 1 line

1.9.3

Masami Hiramatsu

2015-03-03 02:25 UTC #23 lore raw

In reply to Tom Zanussi

Quoted 2 lines · Tom Zanussi

This is v2 of my previously posted 'hashtriggers' patchset [1], but renamed to 'hist triggers' following feedback from v1.

This is what I need :) The trigger interface gives us better flexibility for environment. With this series I believe the 80% use of "scripting tracing" can be replaced with just "echo'ing tracing" via tracefs :)

Quoted 22 lines

Since then, the kernel has gained a tracing map implementation in the form of bpf_map, which this patchset makes a bit more generic, exports and uses (as tracing_map_*, still in the bpf syscall file however).
A large part of the initial hash triggers implementation was devoted to a map implementation and general-purpose hashing functions, which have now been subsumed by the bpf maps. I've completely redone the trigger patches themselves to work on top of tracing_map. The result is a much simpler and easier-to-review patchset that's able to focus more directly on the problem at hand.
The new version addresses all the comments from the previous review, including changing the name from hash->hist, adding separate 'hist' files for the output, and moving the examples into Documentation.
This patchset also includes a couple other new and related triggers, enable_hist and disable_hist, very similar to the existing enable_event/disable_event triggers used to automatically enable and disable events based on a triggering condition, but in this case allowing hist triggers to be enabled and disabled in the same way.

Quoted 8 lines

The only problem with using the bpf_map implementation for this is that it uses kmalloc internally, which causes problems when trying to trace kmalloc itself. I'm guessing the ebpf tracing code would also share this problem e.g. when using bpf_maps from probes on kmalloc(). This patchset attempts a solution to that problem (by adding a gfp_flag and changing the kmem memory allocation tracepoints to conditional variants) for checking for it in for but I'm not sure it's the best way to address it.

That is not a solution for kprobe-based events, nor the events on interrupt context.
Can we reserve some amount of memory for bpf_map? and If it is exceeded the reserved memory we can choose (A) disable hist or (B) continue to do with kmalloc.

Quoted 38 lines

There are a couple of important bits of functionality that were present in v1 but dropped in v2 mainly because I'm still trying to figure out the best way to accomplish those things using the bpf_map implementation.
The first is support for compound keys. Currently, maps can only be keyed on a single event field, whereas in v1 they could be keyed on multiple keys. With support for compound keys, you can create much more interesting output, such as for example per-pid lists of syscalls or read counts e.g.:
  # echo 'hist:keys=common_pid.execname,id.syscall:vals=hitcount' > \
        /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
  # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
key: common_pid:bash[3112], id:sys_write vals: count:69
key: common_pid:bash[3112], id:sys_rt_sigprocmask vals: count:218
key: common_pid:update-notifier[3164], id:sys_poll vals: count:37
key: common_pid:update-notifier[3164], id:sys_recvfrom vals: count:118
key: common_pid:deja-dup-monito[3194], id:sys_sendto vals: count:1
key: common_pid:deja-dup-monito[3194], id:sys_read vals: count:4
key: common_pid:deja-dup-monito[3194], id:sys_poll vals: count:8
key: common_pid:deja-dup-monito[3194], id:sys_recvmsg vals: count:8
key: common_pid:deja-dup-monito[3194], id:sys_getegid vals: count:8
key: common_pid:emacs[3275], id:sys_fsync vals: count:1
key: common_pid:emacs[3275], id:sys_open vals: count:1
key: common_pid:emacs[3275], id:sys_symlink vals: count:2
key: common_pid:emacs[3275], id:sys_poll vals: count:23
key: common_pid:emacs[3275], id:sys_select vals: count:23
key: common_pid:emacs[3275], id:unknown_syscall vals: count:34
key: common_pid:emacs[3275], id:sys_ioctl vals: count:60
key: common_pid:emacs[3275], id:sys_rt_sigprocmask vals: count:116

Quoted 2 lines

key: common_pid:cat[3323], id:sys_munmap vals: count:1
key: common_pid:cat[3323], id:sys_fadvise64 vals: count:1

Very impressive! :)

Thank you,

Quoted 64 lines

Related to that is support for sorting on multiple fields. Currently, you can sort using only a primary key. Being able to sort on multiple or at least a secondary key is indispensible for seeing trends when displaying multiple values.
[1] http://thread.gmane.org/gmane.linux.kernel/1673551
Changes from v1:
- completely rewritten on top of tracing_map (renamed and exported bpf_map)
- added map clearing and client ops to tracing_map
- changed the name from 'hash' triggers to 'hist' triggers
- added new trigger 'pause' feature
- added new enable_hist and disable_hist triggers
- added usage for hist/enable_hist/disable hist to tracing/README
- moved examples into Documentation/trace/event.txt
- added ___GFP_NOTRACE, kmalloc/kfree macros, and conditional kmem tracepoints
The following changes since commit 49058038a12cfd9044146a1bf4b286781268d5c9:
ring-buffer: Do not wake up a splice waiter when page is not full (2015-02-24 14:00:41 -0600)
are available in the git repository at:
git://git.yoctoproject.org/linux-yocto-contrib.git tzanussi/hist-triggers-v2
http://git.yoctoproject.org/cgit/cgit.cgi/linux-yocto-contrib/log/?h=tzanussi/hist-triggers-v2
Tom Zanussi (15):
tracing: Make ftrace_event_field checking functions available
tracing: Add event record param to trigger_ops.func()
tracing: Add get_syscall_name()
bpf: Export bpf map functionality as trace_map_*
bpf: Export a map-clearing function
bpf: Add tracing_map client ops
mm: Add ___GFP_NOTRACE
tracing: Make kmem memory allocation tracepoints conditional
tracing: Add kmalloc/kfree macros
bpf: Make tracing_map use kmalloc/kfree_notrace()
tracing: Add a per-event-trigger 'paused' field
tracing: Add 'hist' event trigger command
tracing: Add sorting to hist triggers
tracing: Add enable_hist/disable_hist triggers
tracing: Add 'hist' trigger Documentation
 Documentation/trace/events.txt      |  870 +++++++++++++++++++++
 include/linux/bpf.h                 |   15 +
 include/linux/ftrace_event.h        |    9 +-
 include/linux/gfp.h                 |    3 +-
 include/linux/slab.h                |   61 +-
 include/trace/events/kmem.h         |   28 +-
 kernel/bpf/arraymap.c               |   16 +
 kernel/bpf/hashtab.c                |   39 +-
 kernel/bpf/syscall.c                |  193 ++++-
 kernel/trace/trace.c                |   48 ++
 kernel/trace/trace.h                |   25 +-
 kernel/trace/trace_events.c         |    3 +
 kernel/trace/trace_events_filter.c  |   15 +-
 kernel/trace/trace_events_trigger.c | 1466 ++++++++++++++++++++++++++++++++++-
 kernel/trace/trace_syscalls.c       |   11 +
 mm/slab.c                           |   45 +-
 mm/slob.c                           |   45 +-
 mm/slub.c                           |   47 +-
 18 files changed, 2795 insertions(+), 144 deletions(-)

Signature · 4 lines

Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: [email protected]

Tom Zanussi

author

2015-03-03 14:47 UTC #24 lore raw

Quoted 8 lines · Masami Hiramatsu

Quoted 2 lines · Tom Zanussi
This is v2 of my previously posted 'hashtriggers' patchset [1], but renamed to 'hist triggers' following feedback from v1.
This is what I need :) The trigger interface gives us better flexibility for environment. With this series I believe the 80% use of "scripting tracing" can be replaced with just "echo'ing tracing" via tracefs :)

Glad you like it, thanks!

Quoted 31 lines

Quoted 22 lines
Since then, the kernel has gained a tracing map implementation in the form of bpf_map, which this patchset makes a bit more generic, exports and uses (as tracing_map_*, still in the bpf syscall file however).
A large part of the initial hash triggers implementation was devoted to a map implementation and general-purpose hashing functions, which have now been subsumed by the bpf maps. I've completely redone the trigger patches themselves to work on top of tracing_map. The result is a much simpler and easier-to-review patchset that's able to focus more directly on the problem at hand.
The new version addresses all the comments from the previous review, including changing the name from hash->hist, adding separate 'hist' files for the output, and moving the examples into Documentation.
This patchset also includes a couple other new and related triggers, enable_hist and disable_hist, very similar to the existing enable_event/disable_event triggers used to automatically enable and disable events based on a triggering condition, but in this case allowing hist triggers to be enabled and disabled in the same way.
Quoted 8 lines
The only problem with using the bpf_map implementation for this is that it uses kmalloc internally, which causes problems when trying to trace kmalloc itself. I'm guessing the ebpf tracing code would also share this problem e.g. when using bpf_maps from probes on kmalloc(). This patchset attempts a solution to that problem (by adding a gfp_flag and changing the kmem memory allocation tracepoints to conditional variants) for checking for it in for but I'm not sure it's the best way to address it.

Quoted 6 lines

That is not a solution for kprobe-based events, nor the events on interrupt context.
Can we reserve some amount of memory for bpf_map? and If it is exceeded the reserved memory we can choose (A) disable hist or (B) continue to do with kmalloc.

Yeah, the non-bpf_map v1 did (A) with reserved memory. I'll take a look at doing that again for the next version.

Quoted 38 lines

Quoted 38 lines
There are a couple of important bits of functionality that were present in v1 but dropped in v2 mainly because I'm still trying to figure out the best way to accomplish those things using the bpf_map implementation.
The first is support for compound keys. Currently, maps can only be keyed on a single event field, whereas in v1 they could be keyed on multiple keys. With support for compound keys, you can create much more interesting output, such as for example per-pid lists of syscalls or read counts e.g.:
  # echo 'hist:keys=common_pid.execname,id.syscall:vals=hitcount' > \
        /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
  # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
key: common_pid:bash[3112], id:sys_write vals: count:69
key: common_pid:bash[3112], id:sys_rt_sigprocmask vals: count:218
key: common_pid:update-notifier[3164], id:sys_poll vals: count:37
key: common_pid:update-notifier[3164], id:sys_recvfrom vals: count:118
key: common_pid:deja-dup-monito[3194], id:sys_sendto vals: count:1
key: common_pid:deja-dup-monito[3194], id:sys_read vals: count:4
key: common_pid:deja-dup-monito[3194], id:sys_poll vals: count:8
key: common_pid:deja-dup-monito[3194], id:sys_recvmsg vals: count:8
key: common_pid:deja-dup-monito[3194], id:sys_getegid vals: count:8
key: common_pid:emacs[3275], id:sys_fsync vals: count:1
key: common_pid:emacs[3275], id:sys_open vals: count:1
key: common_pid:emacs[3275], id:sys_symlink vals: count:2
key: common_pid:emacs[3275], id:sys_poll vals: count:23
key: common_pid:emacs[3275], id:sys_select vals: count:23
key: common_pid:emacs[3275], id:unknown_syscall vals: count:34
key: common_pid:emacs[3275], id:sys_ioctl vals: count:60
key: common_pid:emacs[3275], id:sys_rt_sigprocmask vals: count:116

Quoted 5 lines

Quoted 2 lines
key: common_pid:cat[3323], id:sys_munmap vals: count:1
key: common_pid:cat[3323], id:sys_fadvise64 vals: count:1
Very impressive! :)

Thanks!

Tom

Quoted 68 lines

Thank you,
Quoted 64 lines
Related to that is support for sorting on multiple fields. Currently, you can sort using only a primary key. Being able to sort on multiple or at least a secondary key is indispensible for seeing trends when displaying multiple values.
[1] http://thread.gmane.org/gmane.linux.kernel/1673551
Changes from v1:
- completely rewritten on top of tracing_map (renamed and exported bpf_map)
- added map clearing and client ops to tracing_map
- changed the name from 'hash' triggers to 'hist' triggers
- added new trigger 'pause' feature
- added new enable_hist and disable_hist triggers
- added usage for hist/enable_hist/disable hist to tracing/README
- moved examples into Documentation/trace/event.txt
- added ___GFP_NOTRACE, kmalloc/kfree macros, and conditional kmem tracepoints
The following changes since commit 49058038a12cfd9044146a1bf4b286781268d5c9:
ring-buffer: Do not wake up a splice waiter when page is not full (2015-02-24 14:00:41 -0600)
are available in the git repository at:
git://git.yoctoproject.org/linux-yocto-contrib.git tzanussi/hist-triggers-v2
http://git.yoctoproject.org/cgit/cgit.cgi/linux-yocto-contrib/log/?h=tzanussi/hist-triggers-v2
Tom Zanussi (15):
tracing: Make ftrace_event_field checking functions available
tracing: Add event record param to trigger_ops.func()
tracing: Add get_syscall_name()
bpf: Export bpf map functionality as trace_map_*
bpf: Export a map-clearing function
bpf: Add tracing_map client ops
mm: Add ___GFP_NOTRACE
tracing: Make kmem memory allocation tracepoints conditional
tracing: Add kmalloc/kfree macros
bpf: Make tracing_map use kmalloc/kfree_notrace()
tracing: Add a per-event-trigger 'paused' field
tracing: Add 'hist' event trigger command
tracing: Add sorting to hist triggers
tracing: Add enable_hist/disable_hist triggers
tracing: Add 'hist' trigger Documentation
 Documentation/trace/events.txt      |  870 +++++++++++++++++++++
 include/linux/bpf.h                 |   15 +
 include/linux/ftrace_event.h        |    9 +-
 include/linux/gfp.h                 |    3 +-
 include/linux/slab.h                |   61 +-
 include/trace/events/kmem.h         |   28 +-
 kernel/bpf/arraymap.c               |   16 +
 kernel/bpf/hashtab.c                |   39 +-
 kernel/bpf/syscall.c                |  193 ++++-
 kernel/trace/trace.c                |   48 ++
 kernel/trace/trace.h                |   25 +-
 kernel/trace/trace_events.c         |    3 +
 kernel/trace/trace_events_filter.c  |   15 +-
 kernel/trace/trace_events_trigger.c | 1466 ++++++++++++++++++++++++++++++++++-
 kernel/trace/trace_syscalls.c       |   11 +
 mm/slab.c                           |   45 +-
 mm/slob.c                           |   45 +-
 mm/slub.c                           |   47 +-
 18 files changed, 2795 insertions(+), 144 deletions(-)