Messages in this thread | | | Date | Thu, 25 May 2023 10:23:41 +0800 | From | Masami Hiramatsu (Google) <> | Subject | Re: [RESEND][PATCH v2] tracing: Rename stacktrace field to common_stacktrace |
| |
On Tue, 23 May 2023 23:09:13 -0400 Steven Rostedt <rostedt@goodmis.org> wrote:
> From: "Steven Rostedt (Google)" <rostedt@goodmis.org> > > The histogram and synthetic events can use a pseudo event called > "stacktrace" that will create a stacktrace at the time of the event and > use it just like it was a normal field. We have other pseudo events such > as "common_cpu" and "common_timestamp". To stay consistent with that, > convert "stacktrace" to "common_stacktrace". As this was used in older > kernels, to keep backward compatibility, this will act just like > "common_cpu" did with "cpu". That is, "cpu" will be the same as > "common_cpu" unless the event has a "cpu" field. In which case, the > event's field is used. The same is true with "stacktrace". > > Also update the documentation to reflect this change. >
Looks good to me.
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Thanks,
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org> > --- > Resending to get rid of the junk I left at the top the first time. > > Changes since v1: https://lore.kernel.org/linux-trace-kernel/20230523221108.064a5d82@rorschach.local.home/ > - Update the tracefs README to use common_stacktrace instead of > just stacktrace > > Documentation/trace/histogram.rst | 64 +++++++++++++++---------------- > include/linux/trace_events.h | 1 + > kernel/trace/trace.c | 2 +- > kernel/trace/trace_events.c | 2 + > kernel/trace/trace_events_hist.c | 16 +++++--- > 5 files changed, 46 insertions(+), 39 deletions(-) > > diff --git a/Documentation/trace/histogram.rst b/Documentation/trace/histogram.rst > index 479c9eac6335..3c9b263de9c2 100644 > --- a/Documentation/trace/histogram.rst > +++ b/Documentation/trace/histogram.rst > @@ -35,7 +35,7 @@ Documentation written by Tom Zanussi > in place of an explicit value field - this is simply a count of > event hits. If 'values' isn't specified, an implicit 'hitcount' > value will be automatically created and used as the only value. > - Keys can be any field, or the special string 'stacktrace', which > + Keys can be any field, or the special string 'common_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 keywords > 'values', 'vals', or 'val' can be used to specify values. Compound > @@ -54,7 +54,7 @@ Documentation written by Tom Zanussi > 'compatible' if the fields named in the trigger share the same > number and type of fields and those fields also have the same names. > Note that any two events always share the compatible 'hitcount' and > - 'stacktrace' fields and can therefore be combined using those > + 'common_stacktrace' fields and can therefore be combined using those > fields, however pointless that may be. > > 'hist' triggers add a 'hist' file to each event's subdirectory. > @@ -547,9 +547,9 @@ Extended error information > 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_site. To do that, we simply use the special > - value 'stacktrace' for the key parameter:: > + value 'common_stacktrace' for the key parameter:: > > - # echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \ > + # echo 'hist:keys=common_stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \ > /sys/kernel/tracing/events/kmem/kmalloc/trigger > > The above trigger will use the kernel stack trace in effect when an > @@ -561,9 +561,9 @@ Extended error information > every callpath to a kmalloc for a kernel compile):: > > # cat /sys/kernel/tracing/events/kmem/kmalloc/hist > - # trigger info: hist:keys=stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active] > + # trigger info: hist:keys=common_stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active] > > - { stacktrace: > + { common_stacktrace: > __kmalloc_track_caller+0x10b/0x1a0 > kmemdup+0x20/0x50 > hidraw_report_event+0x8a/0x120 [hid] > @@ -581,7 +581,7 @@ Extended error information > cpu_startup_entry+0x315/0x3e0 > rest_init+0x7c/0x80 > } hitcount: 3 bytes_req: 21 bytes_alloc: 24 > - { stacktrace: > + { common_stacktrace: > __kmalloc_track_caller+0x10b/0x1a0 > kmemdup+0x20/0x50 > hidraw_report_event+0x8a/0x120 [hid] > @@ -596,7 +596,7 @@ Extended error information > do_IRQ+0x5a/0xf0 > ret_from_intr+0x0/0x30 > } hitcount: 3 bytes_req: 21 bytes_alloc: 24 > - { stacktrace: > + { common_stacktrace: > kmem_cache_alloc_trace+0xeb/0x150 > aa_alloc_task_context+0x27/0x40 > apparmor_cred_prepare+0x1f/0x50 > @@ -608,7 +608,7 @@ Extended error information > . > . > . > - { stacktrace: > + { common_stacktrace: > __kmalloc+0x11b/0x1b0 > i915_gem_execbuffer2+0x6c/0x2c0 [i915] > drm_ioctl+0x349/0x670 [drm] > @@ -616,7 +616,7 @@ Extended error information > SyS_ioctl+0x81/0xa0 > system_call_fastpath+0x12/0x6a > } hitcount: 17726 bytes_req: 13944120 bytes_alloc: 19593808 > - { stacktrace: > + { common_stacktrace: > __kmalloc+0x11b/0x1b0 > load_elf_phdrs+0x76/0xa0 > load_elf_binary+0x102/0x1650 > @@ -625,7 +625,7 @@ Extended error information > SyS_execve+0x3a/0x50 > return_from_execve+0x0/0x23 > } hitcount: 33348 bytes_req: 17152128 bytes_alloc: 20226048 > - { stacktrace: > + { common_stacktrace: > kmem_cache_alloc_trace+0xeb/0x150 > apparmor_file_alloc_security+0x27/0x40 > security_file_alloc+0x16/0x20 > @@ -636,7 +636,7 @@ Extended error information > SyS_open+0x1e/0x20 > system_call_fastpath+0x12/0x6a > } hitcount: 4766422 bytes_req: 9532844 bytes_alloc: 38131376 > - { stacktrace: > + { common_stacktrace: > __kmalloc+0x11b/0x1b0 > seq_buf_alloc+0x1b/0x50 > seq_read+0x2cc/0x370 > @@ -1026,7 +1026,7 @@ Extended error information > First we set up an initially paused stacktrace trigger on the > netif_receive_skb event:: > > - # echo 'hist:key=stacktrace:vals=len:pause' > \ > + # echo 'hist:key=common_stacktrace:vals=len:pause' > \ > /sys/kernel/tracing/events/net/netif_receive_skb/trigger > > Next, we set up an 'enable_hist' trigger on the sched_process_exec > @@ -1060,9 +1060,9 @@ Extended error information > $ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz > > # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist > - # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused] > + # trigger info: hist:keys=common_stacktrace:vals=len:sort=hitcount:size=2048 [paused] > > - { stacktrace: > + { common_stacktrace: > __netif_receive_skb_core+0x46d/0x990 > __netif_receive_skb+0x18/0x60 > netif_receive_skb_internal+0x23/0x90 > @@ -1079,7 +1079,7 @@ Extended error information > kthread+0xd2/0xf0 > ret_from_fork+0x42/0x70 > } hitcount: 85 len: 28884 > - { stacktrace: > + { common_stacktrace: > __netif_receive_skb_core+0x46d/0x990 > __netif_receive_skb+0x18/0x60 > netif_receive_skb_internal+0x23/0x90 > @@ -1097,7 +1097,7 @@ Extended error information > irq_thread+0x11f/0x150 > kthread+0xd2/0xf0 > } hitcount: 98 len: 664329 > - { stacktrace: > + { common_stacktrace: > __netif_receive_skb_core+0x46d/0x990 > __netif_receive_skb+0x18/0x60 > process_backlog+0xa8/0x150 > @@ -1115,7 +1115,7 @@ Extended error information > inet_sendmsg+0x64/0xa0 > sock_sendmsg+0x3d/0x50 > } hitcount: 115 len: 13030 > - { stacktrace: > + { common_stacktrace: > __netif_receive_skb_core+0x46d/0x990 > __netif_receive_skb+0x18/0x60 > netif_receive_skb_internal+0x23/0x90 > @@ -1142,14 +1142,14 @@ Extended error information > 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' >> \ > + # echo 'hist:key=common_stacktrace:vals=len:clear' >> \ > /sys/kernel/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/tracing/events/net/netif_receive_skb/hist > - # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused] > + # trigger info: hist:keys=common_stacktrace:vals=len:sort=hitcount:size=2048 [paused] > > Totals: > Hits: 0 > @@ -1485,12 +1485,12 @@ Extended error information > > And here's an example that shows how to combine histogram data from > any two events even if they don't share any 'compatible' fields > - other than 'hitcount' and 'stacktrace'. These commands create a > + other than 'hitcount' and 'common_stacktrace'. These commands create a > couple of triggers named 'bar' using those fields:: > > - # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \ > + # echo 'hist:name=bar:key=common_stacktrace:val=hitcount' > \ > /sys/kernel/tracing/events/sched/sched_process_fork/trigger > - # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \ > + # echo 'hist:name=bar:key=common_stacktrace:val=hitcount' > \ > /sys/kernel/tracing/events/net/netif_rx/trigger > > And displaying the output of either shows some interesting if > @@ -1501,16 +1501,16 @@ Extended error information > > # event histogram > # > - # trigger info: hist:name=bar:keys=stacktrace:vals=hitcount:sort=hitcount:size=2048 [active] > + # trigger info: hist:name=bar:keys=common_stacktrace:vals=hitcount:sort=hitcount:size=2048 [active] > # > > - { stacktrace: > + { common_stacktrace: > kernel_clone+0x18e/0x330 > kernel_thread+0x29/0x30 > kthreadd+0x154/0x1b0 > ret_from_fork+0x3f/0x70 > } hitcount: 1 > - { stacktrace: > + { common_stacktrace: > netif_rx_internal+0xb2/0xd0 > netif_rx_ni+0x20/0x70 > dev_loopback_xmit+0xaa/0xd0 > @@ -1528,7 +1528,7 @@ Extended error information > call_cpuidle+0x3b/0x60 > cpu_startup_entry+0x22d/0x310 > } hitcount: 1 > - { stacktrace: > + { common_stacktrace: > netif_rx_internal+0xb2/0xd0 > netif_rx_ni+0x20/0x70 > dev_loopback_xmit+0xaa/0xd0 > @@ -1543,7 +1543,7 @@ Extended error information > SyS_sendto+0xe/0x10 > entry_SYSCALL_64_fastpath+0x12/0x6a > } hitcount: 2 > - { stacktrace: > + { common_stacktrace: > netif_rx_internal+0xb2/0xd0 > netif_rx+0x1c/0x60 > loopback_xmit+0x6c/0xb0 > @@ -1561,7 +1561,7 @@ Extended error information > sock_sendmsg+0x38/0x50 > ___sys_sendmsg+0x14e/0x270 > } hitcount: 76 > - { stacktrace: > + { common_stacktrace: > netif_rx_internal+0xb2/0xd0 > netif_rx+0x1c/0x60 > loopback_xmit+0x6c/0xb0 > @@ -1579,7 +1579,7 @@ Extended error information > sock_sendmsg+0x38/0x50 > ___sys_sendmsg+0x269/0x270 > } hitcount: 77 > - { stacktrace: > + { common_stacktrace: > netif_rx_internal+0xb2/0xd0 > netif_rx+0x1c/0x60 > loopback_xmit+0x6c/0xb0 > @@ -1597,7 +1597,7 @@ Extended error information > sock_sendmsg+0x38/0x50 > SYSC_sendto+0xef/0x170 > } hitcount: 88 > - { stacktrace: > + { common_stacktrace: > kernel_clone+0x18e/0x330 > SyS_clone+0x19/0x20 > entry_SYSCALL_64_fastpath+0x12/0x6a > @@ -1949,7 +1949,7 @@ uninterruptible state:: > > # cd /sys/kernel/tracing > # echo 's:block_lat pid_t pid; u64 delta; unsigned long[] stack;' > dynamic_events > - # echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=stacktrace if prev_state == 2' >> events/sched/sched_switch/trigger > + # echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=common_stacktrace if prev_state == 2' >> events/sched/sched_switch/trigger > # echo 'hist:keys=prev_pid:delta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(block_lat,prev_pid,$delta,$s)' >> events/sched/sched_switch/trigger > # echo 1 > events/synthetic/block_lat/enable > # cat trace > diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h > index 0e373222a6df..7c4a0b72334e 100644 > --- a/include/linux/trace_events.h > +++ b/include/linux/trace_events.h > @@ -806,6 +806,7 @@ enum { > FILTER_TRACE_FN, > FILTER_COMM, > FILTER_CPU, > + FILTER_STACKTRACE, > }; > > extern int trace_event_raw_init(struct trace_event_call *call); > diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c > index ebc59781456a..81801dc31784 100644 > --- a/kernel/trace/trace.c > +++ b/kernel/trace/trace.c > @@ -5752,7 +5752,7 @@ static const char readme_msg[] = > "\t table using the key(s) and value(s) named, and the value of a\n" > "\t sum called 'hitcount' is incremented. Keys and values\n" > "\t correspond to fields in the event's format description. Keys\n" > - "\t can be any field, or the special string 'stacktrace'.\n" > + "\t can be any field, or the special string 'common_stacktrace'.\n" > "\t Compound keys consisting of up to two fields can be specified\n" > "\t by the 'keys' keyword. Values must correspond to numeric\n" > "\t fields. Sort keys consisting of up to two fields can be\n" > diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c > index 654ffa40457a..57e539d47989 100644 > --- a/kernel/trace/trace_events.c > +++ b/kernel/trace/trace_events.c > @@ -194,6 +194,8 @@ static int trace_define_generic_fields(void) > __generic_field(int, common_cpu, FILTER_CPU); > __generic_field(char *, COMM, FILTER_COMM); > __generic_field(char *, comm, FILTER_COMM); > + __generic_field(char *, stacktrace, FILTER_STACKTRACE); > + __generic_field(char *, STACKTRACE, FILTER_STACKTRACE); > > return ret; > } > diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c > index 543cb7dc84ad..b97d3ad832f1 100644 > --- a/kernel/trace/trace_events_hist.c > +++ b/kernel/trace/trace_events_hist.c > @@ -1364,7 +1364,7 @@ static const char *hist_field_name(struct hist_field *field, > if (field->field) > field_name = field->field->name; > else > - field_name = "stacktrace"; > + field_name = "common_stacktrace"; > } else if (field->flags & HIST_FIELD_FL_HITCOUNT) > field_name = "hitcount"; > > @@ -2367,7 +2367,7 @@ parse_field(struct hist_trigger_data *hist_data, struct trace_event_file *file, > hist_data->enable_timestamps = true; > if (*flags & HIST_FIELD_FL_TIMESTAMP_USECS) > hist_data->attrs->ts_in_usecs = true; > - } else if (strcmp(field_name, "stacktrace") == 0) { > + } else if (strcmp(field_name, "common_stacktrace") == 0) { > *flags |= HIST_FIELD_FL_STACKTRACE; > } else if (strcmp(field_name, "common_cpu") == 0) > *flags |= HIST_FIELD_FL_CPU; > @@ -2378,11 +2378,15 @@ parse_field(struct hist_trigger_data *hist_data, struct trace_event_file *file, > if (!field || !field->size) { > /* > * For backward compatibility, if field_name > - * was "cpu", then we treat this the same as > - * common_cpu. This also works for "CPU". > + * was "cpu" or "stacktrace", then we treat this > + * the same as common_cpu and common_stacktrace > + * respectively. This also works for "CPU", and > + * "STACKTRACE". > */ > if (field && field->filter_type == FILTER_CPU) { > *flags |= HIST_FIELD_FL_CPU; > + } else if (field && field->filter_type == FILTER_STACKTRACE) { > + *flags |= HIST_FIELD_FL_STACKTRACE; > } else { > hist_err(tr, HIST_ERR_FIELD_NOT_FOUND, > errpos(field_name)); > @@ -5394,7 +5398,7 @@ static void hist_trigger_print_key(struct seq_file *m, > if (key_field->field) > seq_printf(m, "%s.stacktrace", key_field->field->name); > else > - seq_puts(m, "stacktrace:\n"); > + seq_puts(m, "common_stacktrace:\n"); > hist_trigger_stacktrace_print(m, > key + key_field->offset, > HIST_STACKTRACE_DEPTH); > @@ -5977,7 +5981,7 @@ static int event_hist_trigger_print(struct seq_file *m, > if (field->field) > seq_printf(m, "%s.stacktrace", field->field->name); > else > - seq_puts(m, "stacktrace"); > + seq_puts(m, "common_stacktrace"); > } else > hist_field_print(m, field); > } > -- > 2.39.2 >
-- Masami Hiramatsu (Google) <mhiramat@kernel.org>
| |