[PATCH 13/20 v2] tracing: Add array type to function based events

[Steven Rostedt]

From: "Steven Rostedt (VMware)" <rostedt@xxxxxxxxxxx>

Add syntex to allow the user to create an array type. Brackets after the
type field will denote that this is an array type. For example:

 # echo 'SyS_open(x8[32] buf, x32 flags, x32 mode)' > function_events

Will make the first argument of the sys_open function call an array of
32 bytes.

The array type can also be used in conjunction with the indirect offset
brackets as well. For example to get the interrupt stack of regs in do_IRQ()
for x86_64.

 # echo 'do_IRQ(x64[5] regs[16])' > function_events

Signed-off-by: Steven Rostedt (VMware) <rostedt@xxxxxxxxxxx>
---
 Documentation/trace/function-based-events.rst |  22 +++-
 kernel/trace/trace_event_ftrace.c             | 157 +++++++++++++++++++++-----
 2 files changed, 151 insertions(+), 28 deletions(-)

diff --git a/Documentation/trace/function-based-events.rst b/Documentation/trace/function-based-events.rst
index b0e6725f3032..4a8a6fb16a0a 100644
--- a/Documentation/trace/function-based-events.rst
+++ b/Documentation/trace/function-based-events.rst
@@ -93,7 +93,7 @@ as follows:
 
  ARG := TYPE FIELD | TYPE <name> '=' ADDR | TYPE ADDR | ARG '|' ARG
 
- TYPE := ATOM | 'unsigned' ATOM
+ TYPE := ATOM | ATOM '[' <number> ']' | 'unsigned' TYPE
 
  ATOM := 'u8' | 'u16' | 'u32' | 'u64' |
          's8' | 's16' | 's32' | 's64' |
@@ -305,3 +305,23 @@ Is the same as
     <idle>-0     [003] d..3   655.823498: ret_from_intr->do_IRQ(total_forks=1504, regs=tick_nohz_idle_enter+0x4c/0x50)
     <idle>-0     [003] d..3   655.954096: ret_from_intr->do_IRQ(total_forks=1504, regs=cpuidle_enter_state+0xb1/0x330)
 
+
+Array types
+===========
+
+If there's a case where you want to see an array of a type, then you can
+declare a type as an array by adding '[' number ']' after the type.
+
+To get the net_device perm_addr, from the dev parameter.
+
+ (gdb) printf "%d\n", &((struct net_device *)0)->perm_addr
+558
+
+ # echo 'ip_rcv(x64 skb, x8[6] perm_addr+558)' > function_events
+
+ # echo 1 > events/functions/ip_rcv/enable
+ # cat trace
+    <idle>-0     [003] ..s3   219.813582: __netif_receive_skb_core->ip_rcv(skb=ffff880118195e00, perm_addr=b4,b5,2f,ce,18,65)
+    <idle>-0     [003] ..s3   219.813595: __netif_receive_skb_core->ip_rcv(skb=ffff880118195e00, perm_addr=b4,b5,2f,ce,18,65)
+    <idle>-0     [003] ..s3   220.115053: __netif_receive_skb_core->ip_rcv(skb=ffff880118195c00, perm_addr=b4,b5,2f,ce,18,65)
+    <idle>-0     [003] ..s3   220.115293: __netif_receive_skb_core->ip_rcv(skb=ffff880118195c00, perm_addr=b4,b5,2f,ce,18,65)
diff --git a/kernel/trace/trace_event_ftrace.c b/kernel/trace/trace_event_ftrace.c
index 97748edc8bcb..f62bd6a2ea87 100644
--- a/kernel/trace/trace_event_ftrace.c
+++ b/kernel/trace/trace_event_ftrace.c
@@ -20,6 +20,7 @@ struct func_arg {
 	char				*name;
 	long				indirect;
 	long				index;
+	short				array;
 	short				offset;
 	short				size;
 	s8				arg;
@@ -68,6 +69,9 @@ enum func_states {
 	FUNC_STATE_PIPE,
 	FUNC_STATE_PLUS,
 	FUNC_STATE_TYPE,
+	FUNC_STATE_ARRAY,
+	FUNC_STATE_ARRAY_SIZE,
+	FUNC_STATE_ARRAY_END,
 	FUNC_STATE_VAR,
 	FUNC_STATE_COMMA,
 	FUNC_STATE_END,
@@ -291,6 +295,7 @@ process_event(struct func_event *fevent, const char *token, enum func_states sta
 	static bool update_arg;
 	static int unsign;
 	unsigned long val;
+	char *type;
 	int ret;
 	int i;
 
@@ -341,6 +346,10 @@ process_event(struct func_event *fevent, const char *token, enum func_states sta
 		return FUNC_STATE_TYPE;
 
 	case FUNC_STATE_TYPE:
+		if (token[0] == '[')
+			return FUNC_STATE_ARRAY;
+		/* Fall through */
+	case FUNC_STATE_ARRAY_END:
 		if (WARN_ON(!fevent->last_arg))
 			break;
 		if (update_arg_name(fevent, token) < 0)
@@ -352,14 +361,37 @@ process_event(struct func_event *fevent, const char *token, enum func_states sta
 		update_arg = true;
 		return FUNC_STATE_VAR;
 
+	case FUNC_STATE_ARRAY:
 	case FUNC_STATE_BRACKET:
-		WARN_ON(!fevent->last_arg);
+		if (WARN_ON(!fevent->last_arg))
+			break;
 		ret = kstrtoul(token, 0, &val);
 		if (ret)
 			break;
-		val *= fevent->last_arg->size;
-		fevent->last_arg->indirect = val ^ INDIRECT_FLAG;
-		return FUNC_STATE_INDIRECT;
+		if (state == FUNC_STATE_BRACKET) {
+			val *= fevent->last_arg->size;
+			fevent->last_arg->indirect = val ^ INDIRECT_FLAG;
+			return FUNC_STATE_INDIRECT;
+		}
+		if (val <= 0)
+			break;
+		fevent->last_arg->array = val;
+		type = kasprintf(GFP_KERNEL, "%s[%d]", fevent->last_arg->type, (unsigned)val);
+		if (!type)
+			break;
+		kfree(fevent->last_arg->type);
+		fevent->last_arg->type = type;
+		/*
+		 * arg_offset has already been updated once by size.
+		 * This update needs to account for that (hence the "- 1").
+		 */
+		fevent->arg_offset += fevent->last_arg->size * (fevent->last_arg->array - 1);
+		return FUNC_STATE_ARRAY_SIZE;
+
+	case FUNC_STATE_ARRAY_SIZE:
+		if (token[0] != ']')
+			break;
+		return FUNC_STATE_ARRAY_END;
 
 	case FUNC_STATE_INDIRECT:
 		if (token[0] != ']')
@@ -455,6 +487,10 @@ static long long get_arg(struct func_arg *arg, unsigned long val)
 
 	val = val + (arg->indirect ^ INDIRECT_FLAG);
 
+	/* Arrays do their own indirect reads */
+	if (arg->array)
+		return val;
+
 	ret = probe_kernel_read(buf, (void *)val, arg->size);
 	if (ret)
 		return 0;
@@ -476,6 +512,21 @@ static long long get_arg(struct func_arg *arg, unsigned long val)
 	return val;
 }
 
+static void get_array(void *dst, struct func_arg *arg, unsigned long val)
+{
+	void *ptr = (void *)val;
+	int ret;
+	int i;
+
+	for (i = 0; i < arg->array; i++) {
+		ret = probe_kernel_read(dst, ptr, arg->size);
+		if (ret)
+			memset(dst, 0, arg->size);
+		ptr += arg->size;
+		dst += arg->size;
+	}
+}
+
 static void func_event_trace(struct trace_event_file *trace_file,
 			     struct func_event *func_event,
 			     unsigned long ip, unsigned long parent_ip,
@@ -522,7 +573,10 @@ static void func_event_trace(struct trace_event_file *trace_file,
 				val = get_arg(arg, args[arg->arg]);
 		} else
 			val = 0;
-		memcpy(&entry->data[arg->offset], &val, arg->size);
+		if (arg->array)
+			get_array(&entry->data[arg->offset], arg, val);
+		else
+			memcpy(&entry->data[arg->offset], &val, arg->size);
 	}
 
 	event_trigger_unlock_commit_regs(trace_file, buffer, event,
@@ -577,6 +631,25 @@ static void make_fmt(struct func_arg *arg, char *fmt)
 	fmt[c++] = '\0';
 }
 
+static void write_data(struct trace_seq *s, const struct func_arg *arg, const char *fmt,
+		       const void *data)
+{
+	switch (arg->size) {
+	case 8:
+		trace_seq_printf(s, fmt, *(unsigned long long *)data);
+		break;
+	case 4:
+		trace_seq_printf(s, fmt, *(unsigned *)data);
+		break;
+	case 2:
+		trace_seq_printf(s, fmt, *(unsigned short *)data);
+		break;
+	case 1:
+		trace_seq_printf(s, fmt, *(unsigned char *)data);
+		break;
+	}
+}
+
 static enum print_line_t
 func_event_print(struct trace_iterator *iter, int flags,
 		 struct trace_event *event)
@@ -588,6 +661,7 @@ func_event_print(struct trace_iterator *iter, int flags,
 	char fmt[FMT_SIZE];
 	void *data;
 	bool comma = false;
+	int a;
 
 	entry = (struct func_event_hdr *)iter->ent;
 
@@ -604,20 +678,16 @@ func_event_print(struct trace_iterator *iter, int flags,
 
 		make_fmt(arg, fmt);
 
-		switch (arg->size) {
-		case 8:
-			trace_seq_printf(s, fmt, *(unsigned long long *)data);
-			break;
-		case 4:
-			trace_seq_printf(s, fmt, *(unsigned *)data);
-			break;
-		case 2:
-			trace_seq_printf(s, fmt, *(unsigned short *)data);
-			break;
-		case 1:
-			trace_seq_printf(s, fmt, *(unsigned char *)data);
-			break;
-		}
+		if (arg->array) {
+			comma = false;
+			for (a = 0; a < arg->array; a++, data += arg->size) {
+				if (comma)
+					trace_seq_putc(s, ',');
+				comma = true;
+				write_data(s, arg, fmt, data);
+			}
+		} else
+			write_data(s, arg, fmt, data);
 	}
 	trace_seq_puts(s, ")\n");
 	return trace_handle_return(s);
@@ -640,11 +710,14 @@ static int func_event_define_fields(struct trace_event_call *event_call)
 	DEFINE_FIELD(unsigned long, parent_ip, "__ip", 0);
 
 	list_for_each_entry(arg, &fevent->args, list) {
+		int size = arg->size;
+
+		if (arg->array)
+			size *= arg->array;
 		ret = trace_define_field(event_call, arg->type,
 					 arg->name,
 					 sizeof(field) + arg->offset,
-					 arg->size, arg->sign,
-					 FILTER_OTHER);
+					 size, arg->sign, FILTER_OTHER);
 		if (ret < 0)
 			return ret;
 	}
@@ -735,7 +808,7 @@ static int __set_print_fmt(struct func_event *func_event,
 	const char *fmt_start = "\"%pS->%pS(";
 	const char *fmt_end = ")\", REC->__ip, REC->__parent_ip";
 	char fmt[FMT_SIZE];
-	int r, i;
+	int r, i, a;
 	bool comma = false;
 
 	r = snprintf(buf, len, "%s", fmt_start);
@@ -747,19 +820,49 @@ static int __set_print_fmt(struct func_event *func_event,
 			len = update_len(len, i);
 		}
 		comma = true;
-		make_fmt(arg, fmt);
-		i = snprintf(buf + r, len, "%s=%s", arg->name, fmt);
+
+		i = snprintf(buf + r, len, "%s=", arg->name);
 		r += i;
 		len = update_len(len, i);
+
+		make_fmt(arg, fmt);
+
+		if (arg->array) {
+			bool colon = false;
+
+			for (a = 0; a < arg->array; a++) {
+				if (colon) {
+					i = snprintf(buf + r, len, ":");
+					r += i;
+					len = update_len(len, i);
+				}
+				colon = true;
+				i = snprintf(buf + r, len, "%s", fmt);
+				r += i;
+				len = update_len(len, i);
+			}
+		} else {
+			i = snprintf(buf + r, len, "%s", fmt);
+			r += i;
+			len = update_len(len, i);
+		}
 	}
 	i = snprintf(buf + r, len, "%s", fmt_end);
 	r += i;
 	len = update_len(len, i);
 
 	list_for_each_entry(arg, &func_event->args, list) {
-		i = snprintf(buf + r, len, ", REC->%s", arg->name);
-		r += i;
-		len = update_len(len, i);
+		if (arg->array) {
+			for (a = 0; a < arg->array; a++) {
+				i = snprintf(buf + r, len, ", REC->%s[%d]", arg->name, a);
+				r += i;
+				len = update_len(len, i);
+			}
+		} else {
+			i = snprintf(buf + r, len, ", REC->%s", arg->name);
+			r += i;
+			len = update_len(len, i);
+		}
 	}
 
 	return r;
-- 
2.15.1