Re: [PATCH 13/18] tracing: Add array type to function based events
From: Masami Hiramatsu
Date: Sat Feb 03 2018 - 09:03:44 EST
On Fri, 02 Feb 2018 18:05:11 -0500
Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
> 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
This idea looks good for kprobe events too.
I'll try to implement same one :)
Thank you,
>
> 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 206114f192be..64e2d7dcfd18 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,
> @@ -289,6 +293,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;
>
> @@ -339,6 +344,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)
> @@ -350,14 +359,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] != ']')
> @@ -453,6 +485,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;
> @@ -474,6 +510,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,
> @@ -520,7 +571,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,
> @@ -571,6 +625,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)
> @@ -582,6 +655,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;
>
> @@ -598,20 +672,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);
> @@ -634,11 +704,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;
> }
> @@ -729,7 +802,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);
> @@ -741,19 +814,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
>
>
--
Masami Hiramatsu <mhiramat@xxxxxxxxxx>