From: "Steven Rostedt (VMware)" Add a "string" type that will create a dynamic length string for the event, this is the same as the __string() field in normal TRACE_EVENTS. [ missing 'static' found by Fengguang Wu's kbuild test robot ] Signed-off-by: Steven Rostedt (VMware) --- Documentation/trace/function-based-events.rst | 19 ++- kernel/trace/trace_event_ftrace.c | 183 +++++++++++++++++++++++--- 2 files changed, 181 insertions(+), 21 deletions(-) diff --git a/Documentation/trace/function-based-events.rst b/Documentation/trace/function-based-events.rst index 99ae77cd59e6..6c643ea749e7 100644 --- a/Documentation/trace/function-based-events.rst +++ b/Documentation/trace/function-based-events.rst @@ -99,7 +99,7 @@ as follows: 's8' | 's16' | 's32' | 's64' | 'x8' | 'x16' | 'x32' | 'x64' | 'char' | 'short' | 'int' | 'long' | 'size_t' | - 'symbol' + 'symbol' | 'string' FIELD := | INDEX | OFFSET | OFFSET INDEX @@ -342,3 +342,20 @@ the format "%s". If a nul is found, the output will stop. Use another type bash-1470 [003] ...2 980.678715: path_openat->link_path_walk(name=/lib64/ld-linux-x86-64.so.2) bash-1470 [003] ...2 980.678721: path_openat->link_path_walk(name=ld-2.24.so) bash-1470 [003] ...2 980.678978: path_lookupat->link_path_walk(name=/etc/ld.so.preload) + + +Dynamic strings +=============== + +Static strings are fine, but they can waste a lot of memory in the ring buffer. +The above allocated 64 bytes for a character array, but most of the output was +less than 20 characters. Not wanting to truncate strings or waste space on +the ring buffer, the dynamic string can help. + +Use the "string" type for strings that have a large range in size. The max +size that will be recorded is 512 bytes. If a string is larger than that, then +it will be truncated. + + # echo 'link_path_walk(string name)' > function_events + +Gives the same result as above, but does not waste buffer space. diff --git a/kernel/trace/trace_event_ftrace.c b/kernel/trace/trace_event_ftrace.c index dd24b840329d..273c5838a8e2 100644 --- a/kernel/trace/trace_event_ftrace.c +++ b/kernel/trace/trace_event_ftrace.c @@ -39,6 +39,7 @@ struct func_event { struct func_arg *last_arg; int arg_cnt; int arg_offset; + int has_strings; }; struct func_file { @@ -83,6 +84,8 @@ typedef u32 x32; typedef u16 x16; typedef u8 x8; typedef void * symbol; +/* 2 byte offset, 2 byte length */ +typedef u32 string; #define TYPE_TUPLE(type) \ { #type, sizeof(type), is_signed_type(type) } @@ -105,7 +108,8 @@ typedef void * symbol; TYPE_TUPLE(u8), \ TYPE_TUPLE(s8), \ TYPE_TUPLE(x8), \ - TYPE_TUPLE(symbol) + TYPE_TUPLE(symbol), \ + TYPE_TUPLE(string) static struct func_type { char *name; @@ -124,6 +128,16 @@ enum { FUNC_TYPE_MAX }; +#define MAX_STR 512 + +/* Two contexts, normal and NMI, hence the " * 2" */ +struct func_string { + char buf[MAX_STR * 2]; +}; + +static struct func_string __percpu *str_buffer; +static int nr_strings; + /** * arch_get_func_args - retrieve function arguments via pt_regs * @regs: The registers at the moment the function is called @@ -163,6 +177,23 @@ int __weak arch_get_func_args(struct pt_regs *regs, return 0; } +static void free_arg(struct func_arg *arg) +{ + list_del(&arg->list); + if (arg->func_type == FUNC_TYPE_string) { + nr_strings--; + if (WARN_ON(nr_strings < 0)) + nr_strings = 0; + if (!nr_strings) { + free_percpu(str_buffer); + str_buffer = NULL; + } + } + kfree(arg->name); + kfree(arg->type); + kfree(arg); +} + static void free_func_event(struct func_event *func_event) { struct func_arg *arg, *n; @@ -171,10 +202,7 @@ static void free_func_event(struct func_event *func_event) return; list_for_each_entry_safe(arg, n, &func_event->args, list) { - list_del(&arg->list); - kfree(arg->name); - kfree(arg->type); - kfree(arg); + free_arg(arg); } ftrace_free_filter(&func_event->ops); kfree(func_event->call.print_fmt); @@ -255,6 +283,17 @@ static int add_arg(struct func_event *fevent, int ftype, int unsign) list_add_tail(&arg->list, &fevent->args); fevent->last_arg = arg; + if (ftype == FUNC_TYPE_string) { + fevent->has_strings++; + nr_strings++; + if (nr_strings == 1) { + str_buffer = alloc_percpu(struct func_string); + if (!str_buffer) { + free_arg(arg); + return -ENOMEM; + } + } + } return 0; } @@ -344,8 +383,19 @@ process_event(struct func_event *fevent, const char *token, enum func_states sta return FUNC_STATE_TYPE; case FUNC_STATE_TYPE: - if (token[0] == '[') + if (token[0] == '[') { + /* Strings are already arrays */ + if (fevent->last_arg->func_type == FUNC_TYPE_string) + break; return FUNC_STATE_ARRAY; + } + if (fevent->last_arg->func_type == FUNC_TYPE_string) { + type = kstrdup("__data_loc char[]", GFP_KERNEL); + if (!type) + break; + kfree(fevent->last_arg->type); + fevent->last_arg->type = type; + } /* Fall through */ case FUNC_STATE_ARRAY_END: if (WARN_ON(!fevent->last_arg)) @@ -473,7 +523,7 @@ process_event(struct func_event *fevent, const char *token, enum func_states sta return FUNC_STATE_END; } -static long long get_arg(struct func_arg *arg, unsigned long val) +static long long __get_arg(struct func_arg *arg, unsigned long val) { char buf[8]; int ret; @@ -485,8 +535,8 @@ 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) + /* Arrays and strings do their own indirect reads */ + if (arg->array || arg->func_type == FUNC_TYPE_string) return val; ret = probe_kernel_read(buf, (void *)val, arg->size); @@ -510,6 +560,15 @@ static long long get_arg(struct func_arg *arg, unsigned long val) return val; } +static long long get_arg(struct func_arg *arg, long *args) +{ + /* Is arg an address and not a parameter? */ + if (arg->arg < 0) + return __get_arg(arg, 0); + else + return __get_arg(arg, args[arg->arg]); +} + static void get_array(void *dst, struct func_arg *arg, unsigned long val) { void *ptr = (void *)val; @@ -525,6 +584,67 @@ static void get_array(void *dst, struct func_arg *arg, unsigned long val) } } +static int read_string(char *str, unsigned long addr) +{ + unsigned long flags; + struct func_string *strbuf; + char *ptr = (void *)addr; + char *buf; + int ret; + + if (!str_buffer) + return 0; + + strbuf = this_cpu_ptr(str_buffer); + buf = &strbuf->buf[0]; + + if (in_nmi()) + buf += MAX_STR; + + local_irq_save(flags); + ret = strncpy_from_unsafe(buf, ptr, MAX_STR); + if (ret < 0) + ret = 0; + if (ret > 0 && str) + memcpy(str, buf, ret); + local_irq_restore(flags); + + return ret; +} + +static int calculate_strings(struct func_event *func_event, int nr_args, long *args) +{ + struct func_arg *arg; + unsigned long val; + int str_count = 0; + int size = 0; + + list_for_each_entry(arg, &func_event->args, list) { + if (arg->func_type != FUNC_TYPE_string) + continue; + if (arg->arg < nr_args) + val = get_arg(arg, args); + else + goto skip; + size += read_string(NULL, val); + skip: + if (++str_count >= func_event->has_strings) + return size; + } + return size; +} + +static int get_string(unsigned long addr, unsigned int idx, + unsigned int *info, char *data) +{ + int len; + + len = read_string(data, addr); + *info = len << 16 | idx; + + return len; +} + static void func_event_trace(struct trace_event_file *trace_file, struct func_event *func_event, unsigned long ip, unsigned long parent_ip, @@ -538,6 +658,8 @@ static void func_event_trace(struct trace_event_file *trace_file, long args[func_event->arg_cnt]; long long val = 1; unsigned long irq_flags; + int str_offset; + int str_idx = 0; int nr_args = 0; int size; int pc; @@ -550,6 +672,12 @@ static void func_event_trace(struct trace_event_file *trace_file, size = func_event->arg_offset + sizeof(*entry); + if (func_event->arg_cnt) + nr_args = arch_get_func_args(pt_regs, 0, func_event->arg_cnt, args); + + if (func_event->has_strings) + size += calculate_strings(func_event, nr_args, args); + event = trace_event_buffer_lock_reserve(&buffer, trace_file, call->event.type, size, irq_flags, pc); @@ -559,21 +687,22 @@ static void func_event_trace(struct trace_event_file *trace_file, entry = ring_buffer_event_data(event); entry->ip = ip; entry->parent_ip = parent_ip; - if (func_event->arg_cnt) - nr_args = arch_get_func_args(pt_regs, 0, func_event->arg_cnt, args); list_for_each_entry(arg, &func_event->args, list) { - if (arg->arg < nr_args) { - /* Is arg an address and not a parameter? */ - if (arg->arg < 0) - val = get_arg(arg, 0); - else - val = get_arg(arg, args[arg->arg]); - } else + if (arg->arg < nr_args) + val = get_arg(arg, args); + else val = 0; if (arg->array) get_array(&entry->data[arg->offset], arg, val); - else + else if (arg->func_type == FUNC_TYPE_string) { + str_offset = sizeof(struct func_event_hdr) + + func_event->arg_offset; + + str_idx += get_string(val, str_offset + str_idx, + (unsigned int *)&entry->data[arg->offset], + &entry->data[func_event->arg_offset + str_idx]); + } else memcpy(&entry->data[arg->offset], &val, arg->size); } @@ -610,6 +739,11 @@ static void make_fmt(struct func_arg *arg, char *fmt) fmt[c++] = '%'; + if (arg->func_type == FUNC_TYPE_string) { + fmt[c++] = 's'; + goto out; + } + if (arg->func_type == FUNC_TYPE_char) { if (arg->array) fmt[c++] = 's'; @@ -667,6 +801,7 @@ func_event_print(struct trace_iterator *iter, int flags, char fmt[FMT_SIZE]; void *data; bool comma = false; + int info; int a; entry = (struct func_event_hdr *)iter->ent; @@ -692,6 +827,11 @@ func_event_print(struct trace_iterator *iter, int flags, comma = true; write_data(s, arg, fmt, data); } + } else if (arg->func_type == FUNC_TYPE_string) { + info = *(unsigned int *)data; + info = (info & 0xffff) - sizeof(struct func_event_hdr); + data = &entry->data[info]; + trace_seq_printf(s, fmt, data); } else write_data(s, arg, fmt, data); } @@ -866,7 +1006,10 @@ static int __set_print_fmt(struct func_event *func_event, len = update_len(len, i); } } else { - i = snprintf(buf + r, len, ", REC->%s", arg->name); + if (arg->func_type == FUNC_TYPE_string) + i = snprintf(buf + r, len, ", __get_str(%s)", arg->name); + else + i = snprintf(buf + r, len, ", REC->%s", arg->name); r += i; len = update_len(len, i); } -- 2.15.1