* [PATCH] trace: Add migrate-disabled counter to tracing output. @ 2021-08-06 16:49 Sebastian Andrzej Siewior 2021-08-06 17:51 ` Steven Rostedt 0 siblings, 1 reply; 10+ messages in thread From: Sebastian Andrzej Siewior @ 2021-08-06 16:49 UTC (permalink / raw) To: linux-kernel; +Cc: Steven Rostedt, Ingo Molnar, Thomas Gleixner, Peter Zijlstra From: Thomas Gleixner <tglx@linutronix.de> migrate_disable() forbids task migration to another CPU. It is available since v5.11 and has already users such as highmem or BPF. It is useful to observe this task state in tracing which already has other states like the preemption counter. Add the migrate-disable counter to the trace entry so it shows up in the trace. Due to the users mentioned above, it is already possible to observe it: | bash-1108 [000] ...21 73.950578: rss_stat: mm_id=2213312838 curr=0 type=MM_ANONPAGES size=8192B | bash-1108 [000] d..31 73.951222: irq_disable: caller=flush_tlb_mm_range+0x115/0x130 parent=ptep_clear_flush+0x42/0x50 | bash-1108 [000] d..31 73.951222: tlb_flush: pages:1 reason:local mm shootdown (3) The last value is the migrate-disable counter. Signed-off-by: Thomas Gleixner <tglx@linutronix.de> [bigeasy: patch description.] Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> --- include/linux/trace_events.h | 2 ++ kernel/trace/trace.c | 26 +++++++++++++++++++------- kernel/trace/trace_events.c | 1 + kernel/trace/trace_output.c | 5 +++++ 4 files changed, 27 insertions(+), 7 deletions(-) diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index ad413b382a3ca..7c4280b4c6be7 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -69,6 +69,7 @@ struct trace_entry { unsigned char flags; unsigned char preempt_count; int pid; + unsigned char migrate_disable; }; #define TRACE_EVENT_TYPE_MAX \ @@ -157,6 +158,7 @@ static inline void tracing_generic_entry_update(struct trace_entry *entry, unsigned int trace_ctx) { entry->preempt_count = trace_ctx & 0xff; + entry->migrate_disable = (trace_ctx >> 8) & 0xff; entry->pid = current->pid; entry->type = type; entry->flags = trace_ctx >> 16; diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index c59dd35a6da5c..936b683c81c7a 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -2603,6 +2603,15 @@ enum print_line_t trace_handle_return(struct trace_seq *s) } EXPORT_SYMBOL_GPL(trace_handle_return); +static unsigned short migration_disable_value(void) +{ +#if defined(CONFIG_SMP) + return current->migration_disabled; +#else + return 0; +#endif +} + unsigned int tracing_gen_ctx_irq_test(unsigned int irqs_status) { unsigned int trace_flags = irqs_status; @@ -2621,7 +2630,8 @@ unsigned int tracing_gen_ctx_irq_test(unsigned int irqs_status) trace_flags |= TRACE_FLAG_NEED_RESCHED; if (test_preempt_need_resched()) trace_flags |= TRACE_FLAG_PREEMPT_RESCHED; - return (trace_flags << 16) | (pc & 0xff); + return (trace_flags << 16) | (pc & 0xff) | + (migration_disable_value() & 0xff) << 8; } struct ring_buffer_event * @@ -4177,9 +4187,10 @@ static void print_lat_help_header(struct seq_file *m) "# | / _----=> need-resched \n" "# || / _---=> hardirq/softirq \n" "# ||| / _--=> preempt-depth \n" - "# |||| / delay \n" - "# cmd pid ||||| time | caller \n" - "# \\ / ||||| \\ | / \n"); + "# |||| / _-=> migrate-disable \n" + "# ||||| / delay \n" + "# cmd pid |||||| time | caller \n" + "# \\ / |||||| \\ | / \n"); } static void print_event_info(struct array_buffer *buf, struct seq_file *m) @@ -4217,9 +4228,10 @@ static void print_func_help_header_irq(struct array_buffer *buf, struct seq_file seq_printf(m, "# %.*s / _----=> need-resched\n", prec, space); seq_printf(m, "# %.*s| / _---=> hardirq/softirq\n", prec, space); seq_printf(m, "# %.*s|| / _--=> preempt-depth\n", prec, space); - seq_printf(m, "# %.*s||| / delay\n", prec, space); - seq_printf(m, "# TASK-PID %.*s CPU# |||| TIMESTAMP FUNCTION\n", prec, " TGID "); - seq_printf(m, "# | | %.*s | |||| | |\n", prec, " | "); + seq_printf(m, "# %.*s||| / _-=> migrate-disable\n", prec, space); + seq_printf(m, "# %.*s|||| / delay\n", prec, space); + seq_printf(m, "# TASK-PID %.*s CPU# ||||| TIMESTAMP FUNCTION\n", prec, " TGID "); + seq_printf(m, "# | | %.*s | ||||| | |\n", prec, " | "); } void diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c index 80e96989770ed..80b09956d5a0f 100644 --- a/kernel/trace/trace_events.c +++ b/kernel/trace/trace_events.c @@ -183,6 +183,7 @@ static int trace_define_common_fields(void) __common_field(unsigned char, flags); __common_field(unsigned char, preempt_count); __common_field(int, pid); + __common_field(unsigned char, migrate_disable); return ret; } diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c index a0bf446bb0348..5b642b502b00f 100644 --- a/kernel/trace/trace_output.c +++ b/kernel/trace/trace_output.c @@ -497,6 +497,11 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry) else trace_seq_putc(s, '.'); + if (entry->migrate_disable) + trace_seq_printf(s, "%x", entry->migrate_disable); + else + trace_seq_putc(s, '.'); + return !trace_seq_has_overflowed(s); } -- 2.32.0 ^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: [PATCH] trace: Add migrate-disabled counter to tracing output. 2021-08-06 16:49 [PATCH] trace: Add migrate-disabled counter to tracing output Sebastian Andrzej Siewior @ 2021-08-06 17:51 ` Steven Rostedt 2021-08-06 18:10 ` Sebastian Andrzej Siewior 2021-08-10 13:26 ` [PATCH v2] " Sebastian Andrzej Siewior 0 siblings, 2 replies; 10+ messages in thread From: Steven Rostedt @ 2021-08-06 17:51 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On Fri, 6 Aug 2021 18:49:07 +0200 Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote: > From: Thomas Gleixner <tglx@linutronix.de> > > migrate_disable() forbids task migration to another CPU. It is available > since v5.11 and has already users such as highmem or BPF. It is useful > to observe this task state in tracing which already has other states > like the preemption counter. > > Add the migrate-disable counter to the trace entry so it shows up in the > trace. Due to the users mentioned above, it is already possible to > observe it: > > | bash-1108 [000] ...21 73.950578: rss_stat: mm_id=2213312838 curr=0 type=MM_ANONPAGES size=8192B > | bash-1108 [000] d..31 73.951222: irq_disable: caller=flush_tlb_mm_range+0x115/0x130 parent=ptep_clear_flush+0x42/0x50 > | bash-1108 [000] d..31 73.951222: tlb_flush: pages:1 reason:local mm shootdown (3) > > The last value is the migrate-disable counter. > > Signed-off-by: Thomas Gleixner <tglx@linutronix.de> > [bigeasy: patch description.] > Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> > --- > include/linux/trace_events.h | 2 ++ > kernel/trace/trace.c | 26 +++++++++++++++++++------- > kernel/trace/trace_events.c | 1 + > kernel/trace/trace_output.c | 5 +++++ > 4 files changed, 27 insertions(+), 7 deletions(-) > > diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h > index ad413b382a3ca..7c4280b4c6be7 100644 > --- a/include/linux/trace_events.h > +++ b/include/linux/trace_events.h > @@ -69,6 +69,7 @@ struct trace_entry { > unsigned char flags; > unsigned char preempt_count; > int pid; > + unsigned char migrate_disable; The only issue I have with this patch is this part. It extends the header of all events beyond 8 bytes, and actually adds another 4 or 8 bytes despite being just a char in size. That's because this is a header of a structure, which depending on the first field of an event, padding may be added to have 4 or 8 byte alignment. I'll be fine with merging this counter with either flags or preempt_count (neither needs all 8 bits). I can figure out how to update libtraceevent to handle this case. -- Steve > }; > > #define TRACE_EVENT_TYPE_MAX \ > @@ -157,6 +158,7 @@ static inline void tracing_generic_entry_update(struct trace_entry *entry, > unsigned int trace_ctx) ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH] trace: Add migrate-disabled counter to tracing output. 2021-08-06 17:51 ` Steven Rostedt @ 2021-08-06 18:10 ` Sebastian Andrzej Siewior 2021-08-10 13:26 ` [PATCH v2] " Sebastian Andrzej Siewior 1 sibling, 0 replies; 10+ messages in thread From: Sebastian Andrzej Siewior @ 2021-08-06 18:10 UTC (permalink / raw) To: Steven Rostedt; +Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On 2021-08-06 13:51:24 [-0400], Steven Rostedt wrote: > > diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h > > index ad413b382a3ca..7c4280b4c6be7 100644 > > --- a/include/linux/trace_events.h > > +++ b/include/linux/trace_events.h > > @@ -69,6 +69,7 @@ struct trace_entry { > > unsigned char flags; > > unsigned char preempt_count; > > int pid; > > + unsigned char migrate_disable; > > The only issue I have with this patch is this part. It extends the > header of all events beyond 8 bytes, and actually adds another 4 or 8 > bytes despite being just a char in size. That's because this is a > header of a structure, which depending on the first field of an event, > padding may be added to have 4 or 8 byte alignment. > > I'll be fine with merging this counter with either flags or > preempt_count (neither needs all 8 bits). I can figure out how to > update libtraceevent to handle this case. I was kind of expecting that. Let me try 4 bits for the preempt counter and 4 bits for the migrate counter. > -- Steve > Sebastian ^ permalink raw reply [flat|nested] 10+ messages in thread
* [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-08-06 17:51 ` Steven Rostedt 2021-08-06 18:10 ` Sebastian Andrzej Siewior @ 2021-08-10 13:26 ` Sebastian Andrzej Siewior 2021-09-02 7:16 ` Sebastian Andrzej Siewior 2021-09-03 23:42 ` Steven Rostedt 1 sibling, 2 replies; 10+ messages in thread From: Sebastian Andrzej Siewior @ 2021-08-10 13:26 UTC (permalink / raw) To: Steven Rostedt; +Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra From: Thomas Gleixner <tglx@linutronix.de> migrate_disable() forbids task migration to another CPU. It is available since v5.11 and has already users such as highmem or BPF. It is useful to observe this task state in tracing which already has other states like the preemption counter. Instead of adding the migrate disable counter as a new entry to struct trace_entry, which would extend the whole struct by four bytes, it is squashed into the preempt-disable counter. The lower four bits represent the preemption counter, the upper four bits represent the migrate disable counter. Both counter shouldn't exceed 15 but if they do, there is a safety net which caps the value at 15. Add the migrate-disable counter to the trace entry so it shows up in the trace. Due to the users mentioned above, it is already possible to observe it: | bash-1108 [000] ...21 73.950578: rss_stat: mm_id=2213312838 curr=0 type=MM_ANONPAGES size=8192B | bash-1108 [000] d..31 73.951222: irq_disable: caller=flush_tlb_mm_range+0x115/0x130 parent=ptep_clear_flush+0x42/0x50 | bash-1108 [000] d..31 73.951222: tlb_flush: pages:1 reason:local mm shootdown (3) The last value is the migrate-disable counter. Things that popped up: - trace_print_lat_context() does not print the migrate counter. Not sure if it should. It is used in "verbose" mode and uses 8 digits and I'm not sure ther is something processing the value. - trace_define_common_fields() now defines a different variable. This probably breaks things. No ide what to do in order to preserve the old behaviour. Since this is used as a filter it should be split somehow to be able to match both nibbles here. Signed-off-by: Thomas Gleixner <tglx@linutronix.de> [bigeasy: patch description.] Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> --- v1…v2: - use the upper nibble of the preemption counter for the migrate disable counter and the lower for the preemption counter. This avoids extending the struct by four bytes due to alignment / padding. include/linux/trace_events.h | 4 ++-- kernel/trace/trace.c | 26 +++++++++++++++++++------- kernel/trace/trace_events.c | 3 ++- kernel/trace/trace_output.c | 11 ++++++++--- 4 files changed, 31 insertions(+), 13 deletions(-) diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index ad413b382a3ca..92680a59740e4 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -67,7 +67,7 @@ void trace_event_printf(struct trace_iterator *iter, const char *fmt, ...); struct trace_entry { unsigned short type; unsigned char flags; - unsigned char preempt_count; + unsigned char preempt_mg_count; int pid; }; @@ -156,7 +156,7 @@ static inline void tracing_generic_entry_update(struct trace_entry *entry, unsigned short type, unsigned int trace_ctx) { - entry->preempt_count = trace_ctx & 0xff; + entry->preempt_mg_count = trace_ctx & 0xff; entry->pid = current->pid; entry->type = type; entry->flags = trace_ctx >> 16; diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index c59dd35a6da5c..ea9082fdcc69a 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -2603,6 +2603,15 @@ enum print_line_t trace_handle_return(struct trace_seq *s) } EXPORT_SYMBOL_GPL(trace_handle_return); +static unsigned short migration_disable_value(void) +{ +#if defined(CONFIG_SMP) + return current->migration_disabled; +#else + return 0; +#endif +} + unsigned int tracing_gen_ctx_irq_test(unsigned int irqs_status) { unsigned int trace_flags = irqs_status; @@ -2621,7 +2630,8 @@ unsigned int tracing_gen_ctx_irq_test(unsigned int irqs_status) trace_flags |= TRACE_FLAG_NEED_RESCHED; if (test_preempt_need_resched()) trace_flags |= TRACE_FLAG_PREEMPT_RESCHED; - return (trace_flags << 16) | (pc & 0xff); + return (trace_flags << 16) | (min_t(unsigned int, pc & 0xff, 0xf)) | + (min_t(unsigned int, migration_disable_value(), 0xf)) << 4; } struct ring_buffer_event * @@ -4177,9 +4187,10 @@ static void print_lat_help_header(struct seq_file *m) "# | / _----=> need-resched \n" "# || / _---=> hardirq/softirq \n" "# ||| / _--=> preempt-depth \n" - "# |||| / delay \n" - "# cmd pid ||||| time | caller \n" - "# \\ / ||||| \\ | / \n"); + "# |||| / _-=> migrate-disable \n" + "# ||||| / delay \n" + "# cmd pid |||||| time | caller \n" + "# \\ / |||||| \\ | / \n"); } static void print_event_info(struct array_buffer *buf, struct seq_file *m) @@ -4217,9 +4228,10 @@ static void print_func_help_header_irq(struct array_buffer *buf, struct seq_file seq_printf(m, "# %.*s / _----=> need-resched\n", prec, space); seq_printf(m, "# %.*s| / _---=> hardirq/softirq\n", prec, space); seq_printf(m, "# %.*s|| / _--=> preempt-depth\n", prec, space); - seq_printf(m, "# %.*s||| / delay\n", prec, space); - seq_printf(m, "# TASK-PID %.*s CPU# |||| TIMESTAMP FUNCTION\n", prec, " TGID "); - seq_printf(m, "# | | %.*s | |||| | |\n", prec, " | "); + seq_printf(m, "# %.*s||| / _-=> migrate-disable\n", prec, space); + seq_printf(m, "# %.*s|||| / delay\n", prec, space); + seq_printf(m, "# TASK-PID %.*s CPU# ||||| TIMESTAMP FUNCTION\n", prec, " TGID "); + seq_printf(m, "# | | %.*s | ||||| | |\n", prec, " | "); } void diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c index 80e96989770ed..5817d14e8095f 100644 --- a/kernel/trace/trace_events.c +++ b/kernel/trace/trace_events.c @@ -181,7 +181,8 @@ static int trace_define_common_fields(void) __common_field(unsigned short, type); __common_field(unsigned char, flags); - __common_field(unsigned char, preempt_count); + /* XXX */ + __common_field(unsigned char, preempt_mg_count); __common_field(int, pid); return ret; diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c index a0bf446bb0348..def0d8de2df6f 100644 --- a/kernel/trace/trace_output.c +++ b/kernel/trace/trace_output.c @@ -492,8 +492,13 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry) trace_seq_printf(s, "%c%c%c", irqs_off, need_resched, hardsoft_irq); - if (entry->preempt_count) - trace_seq_printf(s, "%x", entry->preempt_count); + if (entry->preempt_mg_count & 0xf) + trace_seq_printf(s, "%x", entry->preempt_mg_count & 0xf); + else + trace_seq_putc(s, '.'); + + if (entry->preempt_mg_count & 0xf0) + trace_seq_printf(s, "%x", entry->preempt_mg_count >> 4); else trace_seq_putc(s, '.'); @@ -656,7 +661,7 @@ int trace_print_lat_context(struct trace_iterator *iter) trace_seq_printf( s, "%16s %7d %3d %d %08x %08lx ", comm, entry->pid, iter->cpu, entry->flags, - entry->preempt_count, iter->idx); + entry->preempt_mg_count & 0xf, iter->idx); } else { lat_print_generic(s, entry, iter->cpu); } -- 2.32.0 ^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-08-10 13:26 ` [PATCH v2] " Sebastian Andrzej Siewior @ 2021-09-02 7:16 ` Sebastian Andrzej Siewior 2021-09-03 22:50 ` Steven Rostedt 2021-09-03 23:42 ` Steven Rostedt 1 sibling, 1 reply; 10+ messages in thread From: Sebastian Andrzej Siewior @ 2021-09-02 7:16 UTC (permalink / raw) To: Steven Rostedt; +Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On 2021-08-10 15:26:26 [+0200], To Steven Rostedt wrote: > From: Thomas Gleixner <tglx@linutronix.de> > > migrate_disable() forbids task migration to another CPU. It is available > since v5.11 and has already users such as highmem or BPF. It is useful > to observe this task state in tracing which already has other states > like the preemption counter. > > Instead of adding the migrate disable counter as a new entry to struct > trace_entry, which would extend the whole struct by four bytes, it is > squashed into the preempt-disable counter. The lower four bits represent > the preemption counter, the upper four bits represent the migrate > disable counter. Both counter shouldn't exceed 15 but if they do, there > is a safety net which caps the value at 15. > > Add the migrate-disable counter to the trace entry so it shows up in the > trace. Due to the users mentioned above, it is already possible to > observe it: > > | bash-1108 [000] ...21 73.950578: rss_stat: mm_id=2213312838 curr=0 type=MM_ANONPAGES size=8192B > | bash-1108 [000] d..31 73.951222: irq_disable: caller=flush_tlb_mm_range+0x115/0x130 parent=ptep_clear_flush+0x42/0x50 > | bash-1108 [000] d..31 73.951222: tlb_flush: pages:1 reason:local mm shootdown (3) > > The last value is the migrate-disable counter. > > Things that popped up: > - trace_print_lat_context() does not print the migrate counter. Not sure > if it should. It is used in "verbose" mode and uses 8 digits and I'm > not sure ther is something processing the value. > > - trace_define_common_fields() now defines a different variable. This > probably breaks things. No ide what to do in order to preserve the old > behaviour. Since this is used as a filter it should be split somehow > to be able to match both nibbles here. > > Signed-off-by: Thomas Gleixner <tglx@linutronix.de> > [bigeasy: patch description.] > Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> > --- > v1…v2: > - use the upper nibble of the preemption counter for the migrate > disable counter and the lower for the preemption counter. This > avoids extending the struct by four bytes due to alignment / > padding. Ping. Sebastian ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-09-02 7:16 ` Sebastian Andrzej Siewior @ 2021-09-03 22:50 ` Steven Rostedt 0 siblings, 0 replies; 10+ messages in thread From: Steven Rostedt @ 2021-09-03 22:50 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On Thu, 2 Sep 2021 09:16:50 +0200 Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote: > > Ping. Crap, this fell through the cracks. Let me pull it in and start testing it. We still have another week of the merge window, luckily. -- Steve ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-08-10 13:26 ` [PATCH v2] " Sebastian Andrzej Siewior 2021-09-02 7:16 ` Sebastian Andrzej Siewior @ 2021-09-03 23:42 ` Steven Rostedt 2021-09-06 8:13 ` Sebastian Andrzej Siewior 1 sibling, 1 reply; 10+ messages in thread From: Steven Rostedt @ 2021-09-03 23:42 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra BTW, When doing a v2, always create a new thread. Never send it as a reply to the previous patch. The reason I missed this is because replies to previous patches do not end up in my internal patchwork. And I only look at that for patches. Not my INBOX. On Tue, 10 Aug 2021 15:26:25 +0200 Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote: > --- a/kernel/trace/trace_events.c > +++ b/kernel/trace/trace_events.c > @@ -181,7 +181,8 @@ static int trace_define_common_fields(void) > > __common_field(unsigned short, type); > __common_field(unsigned char, flags); > - __common_field(unsigned char, preempt_count); > + /* XXX */ > + __common_field(unsigned char, preempt_mg_count); > __common_field(int, pid); > > return ret; I'm going to have to nuke this hunk of the patch, and update all the other locations that have preempt_mg_count in it. Because I just tested it, and this breaks user space. # trace-cmd record -e all sleep 1 # trace-cmd report -l sleep-1903 2...ffffffff 743.721748: lock_release: 0xffffffffb1a2f428 trace_types_lock sleep-1903 2...ffffffff 743.721749: lock_release: 0xffff89b981318430 sb_writers sleep-1903 2d..ffffffff 743.721749: irq_disable: caller=rcu_irq_enter_irqson+0x25 parent=0x0 sleep-1903 2d..ffffffff 743.721749: irq_enable: caller=rcu_irq_enter_irqson+0x2f parent=0x0 sleep-1903 2...ffffffff 743.721750: preempt_disable: caller=vfs_write+0x13a parent=vfs_write+0x13a sleep-1903 2d..ffffffff 743.721750: irq_disable: caller=rcu_irq_exit_irqson+0x25 parent=0x0 sleep-1903 2d..ffffffff 743.721750: irq_enable: caller=rcu_irq_exit_irqson+0x2f parent=0x0 sleep-1903 2d..ffffffff 743.721750: irq_disable: caller=rcu_irq_enter_irqson+0x25 parent=0x0 sleep-1903 2d..ffffffff 743.721750: irq_enable: caller=rcu_irq_enter_irqson+0x2f parent=0x0 sleep-1903 2...ffffffff 743.721750: preempt_enable: caller=vfs_write+0x15c parent=vfs_write+0x15c sleep-1903 2d..ffffffff 743.721751: irq_disable: caller=rcu_irq_exit_irqson+0x25 parent=0x0 sleep-1903 2d..ffffffff 743.721751: irq_enable: caller=rcu_irq_exit_irqson+0x2f parent=0x0 sleep-1903 2...ffffffff 743.721751: lock_release: 0xffff89b8a144e4f0 &f->f_pos_lock sleep-1903 2...ffffffff 743.721751: sys_exit: NR 1 = 1 sleep-1903 2...ffffffff 743.721751: sys_exit_write: 0x1 sleep-1903 2d..ffffffff 743.721752: irq_disable: caller=syscall_exit_to_user_mode+0xe parent=0x0 sleep-1903 2d..ffffffff 743.721752: irq_enable: caller=syscall_exit_to_user_mode+0x1b parent=0x0 Because to parse the preempt portion, libtraceevent searches for "common_preempt_count". When it's not found, -1 is used. As the migrate disable is an offset, we can at least filter that. And if and old libtraceevent is used, the preempt counts will be the combination of both, and although it may be a little confusing, at least, it can be figured out. I'm going to fold the below patch into this patch if that's OK with you? -- Steve diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index 5a679315fbed..0a0144580bbd 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -67,7 +67,7 @@ void trace_event_printf(struct trace_iterator *iter, const char *fmt, ...); struct trace_entry { unsigned short type; unsigned char flags; - unsigned char preempt_mg_count; + unsigned char preempt_count; int pid; }; @@ -156,7 +156,7 @@ static inline void tracing_generic_entry_update(struct trace_entry *entry, unsigned short type, unsigned int trace_ctx) { - entry->preempt_mg_count = trace_ctx & 0xff; + entry->preempt_count = trace_ctx & 0xff; entry->pid = current->pid; entry->type = type; entry->flags = trace_ctx >> 16; diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c index d3715e2f6707..830b3b9940f4 100644 --- a/kernel/trace/trace_events.c +++ b/kernel/trace/trace_events.c @@ -181,8 +181,8 @@ static int trace_define_common_fields(void) __common_field(unsigned short, type); __common_field(unsigned char, flags); - /* XXX */ - __common_field(unsigned char, preempt_mg_count); + /* Holds both preempt_count and migrate_disable */ + __common_field(unsigned char, preempt_count); __common_field(int, pid); return ret; diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c index def0d8de2df6..c2ca40e8595b 100644 --- a/kernel/trace/trace_output.c +++ b/kernel/trace/trace_output.c @@ -492,13 +492,13 @@ int trace_print_lat_fmt(struct trace_seq *s, struct trace_entry *entry) trace_seq_printf(s, "%c%c%c", irqs_off, need_resched, hardsoft_irq); - if (entry->preempt_mg_count & 0xf) - trace_seq_printf(s, "%x", entry->preempt_mg_count & 0xf); + if (entry->preempt_count & 0xf) + trace_seq_printf(s, "%x", entry->preempt_count & 0xf); else trace_seq_putc(s, '.'); - if (entry->preempt_mg_count & 0xf0) - trace_seq_printf(s, "%x", entry->preempt_mg_count >> 4); + if (entry->preempt_count & 0xf0) + trace_seq_printf(s, "%x", entry->preempt_count >> 4); else trace_seq_putc(s, '.'); @@ -661,7 +661,7 @@ int trace_print_lat_context(struct trace_iterator *iter) trace_seq_printf( s, "%16s %7d %3d %d %08x %08lx ", comm, entry->pid, iter->cpu, entry->flags, - entry->preempt_mg_count & 0xf, iter->idx); + entry->preempt_count & 0xf, iter->idx); } else { lat_print_generic(s, entry, iter->cpu); } ^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-09-03 23:42 ` Steven Rostedt @ 2021-09-06 8:13 ` Sebastian Andrzej Siewior 2021-09-07 15:21 ` Steven Rostedt 0 siblings, 1 reply; 10+ messages in thread From: Sebastian Andrzej Siewior @ 2021-09-06 8:13 UTC (permalink / raw) To: Steven Rostedt; +Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On 2021-09-03 19:42:16 [-0400], Steven Rostedt wrote: Hi Steven, > BTW, > > When doing a v2, always create a new thread. Never send it as a reply to > the previous patch. The reason I missed this is because replies to previous > patches do not end up in my internal patchwork. And I only look at that for > patches. Not my INBOX. oki. > > > --- a/kernel/trace/trace_events.c > > +++ b/kernel/trace/trace_events.c > > @@ -181,7 +181,8 @@ static int trace_define_common_fields(void) > > > > __common_field(unsigned short, type); > > __common_field(unsigned char, flags); > > - __common_field(unsigned char, preempt_count); > > + /* XXX */ > > + __common_field(unsigned char, preempt_mg_count); > > __common_field(int, pid); > > > > return ret; > > I'm going to have to nuke this hunk of the patch, and update all the other > locations that have preempt_mg_count in it. Because I just tested it, and > this breaks user space. I left that with that XXX on purpose so you can look and comment and say how to fix it. The problem I had with preempt_count was that only the lower nibble contains the preemption counter. So I thought you could easily came up with something how this can be split or taught to only expose the lower nibble. I didn't after a few attempts. My understanding is that this `preempt_count' is also used in the filter tracefs file so something like "preempt_count > 1" > filter would also match for migrate_count = 2, preempt_count = 1. You seem to be happy to filter in user space. Sebastian ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-09-06 8:13 ` Sebastian Andrzej Siewior @ 2021-09-07 15:21 ` Steven Rostedt 2021-09-07 15:24 ` Sebastian Andrzej Siewior 0 siblings, 1 reply; 10+ messages in thread From: Steven Rostedt @ 2021-09-07 15:21 UTC (permalink / raw) To: Sebastian Andrzej Siewior Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On Mon, 6 Sep 2021 10:13:43 +0200 Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote: > I left that with that XXX on purpose so you can look and comment and say > how to fix it. The problem I had with preempt_count was that only the > lower nibble contains the preemption counter. So I thought you could > easily came up with something how this can be split or taught to only > expose the lower nibble. I didn't after a few attempts. > My understanding is that this `preempt_count' is also used in the filter > tracefs file so something like "preempt_count > 1" > filter would also > match for migrate_count = 2, preempt_count = 1. You seem to be happy to > filter in user space. Right. It will break filtering, and I don't see a good way to handle that. That said, I'll update the code to handle comparing fields with a mask. I'll need to do this with the kernel as well. I'm fine with breaking the filtering on preempt_count over having it just fail to print it at all. -- Steve ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: [PATCH v2] trace: Add migrate-disabled counter to tracing output. 2021-09-07 15:21 ` Steven Rostedt @ 2021-09-07 15:24 ` Sebastian Andrzej Siewior 0 siblings, 0 replies; 10+ messages in thread From: Sebastian Andrzej Siewior @ 2021-09-07 15:24 UTC (permalink / raw) To: Steven Rostedt; +Cc: linux-kernel, Ingo Molnar, Thomas Gleixner, Peter Zijlstra On 2021-09-07 11:21:28 [-0400], Steven Rostedt wrote: > Right. It will break filtering, and I don't see a good way to handle that. > > That said, I'll update the code to handle comparing fields with a mask. > I'll need to do this with the kernel as well. > > I'm fine with breaking the filtering on preempt_count over having it just > fail to print it at all. This was my only concern and if it does not matter even better ;) Thank you. > -- Steve Sebastian ^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2021-09-07 15:24 UTC | newest] Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2021-08-06 16:49 [PATCH] trace: Add migrate-disabled counter to tracing output Sebastian Andrzej Siewior 2021-08-06 17:51 ` Steven Rostedt 2021-08-06 18:10 ` Sebastian Andrzej Siewior 2021-08-10 13:26 ` [PATCH v2] " Sebastian Andrzej Siewior 2021-09-02 7:16 ` Sebastian Andrzej Siewior 2021-09-03 22:50 ` Steven Rostedt 2021-09-03 23:42 ` Steven Rostedt 2021-09-06 8:13 ` Sebastian Andrzej Siewior 2021-09-07 15:21 ` Steven Rostedt 2021-09-07 15:24 ` Sebastian Andrzej Siewior
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).