ftrace fixes

ftrace fixes

[Sven Schnelle]

Hi Steve,

here are a few other patches i made to fix some ftrace and ftrace test
problems i've seen on s390.

Regards
Sven

[PATCH 1/3] selftests/ftrace: fix glob selftest

[Sven Schnelle]

test.d/ftrace/func-filter-glob.tc is failing on s390 because it has
ARCH_INLINE_SPIN_LOCK and friends set to 'y'. So the usual
__raw_spin_lock symbol isn't in the ftrace function list. Change
'*aw*lock' to '*time*ns' which would hopefully match some of the
ktime_() functions on all platforms.

Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
---
 .../testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc  | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
index 27a54a17da65..a5d61667cd56 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
@@ -30,7 +30,7 @@ ftrace_filter_check '*schedule*' '^.*schedule.*$'
 ftrace_filter_check 'schedule*' '^schedule.*$'
 
 # filter by *mid*end
-ftrace_filter_check '*aw*lock' '.*aw.*lock$'
+ftrace_filter_check '*time*ns' '.*time.*ns$'
 
 # filter by start*mid*
 ftrace_filter_check 'mutex*try*' '^mutex.*try.*'
-- 
2.17.1

[PATCH 2/3] samples/trace_printk: wait for IRQ work to finish

[Sven Schnelle]

trace_printk schedules work via irq_work_queue(), but doesn't
wait until it was processed. The kprobe_module.tc testcase does:

:;: "Load module again, which means the event1 should be recorded";:
modprobe trace-printk
grep "event1:" trace

so the grep which checks the trace file might run before the irq work
was processed. Fix this by adding a irq_work_sync().

Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
---
 samples/trace_printk/trace-printk.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/samples/trace_printk/trace-printk.c b/samples/trace_printk/trace-printk.c
index 7affc3b50b61..cfc159580263 100644
--- a/samples/trace_printk/trace-printk.c
+++ b/samples/trace_printk/trace-printk.c
@@ -36,6 +36,7 @@ static int __init trace_printk_init(void)
 
 	/* Kick off printing in irq context */
 	irq_work_queue(&irqwork);
+	irq_work_sync(&irqwork);
 
 	trace_printk("This is a %s that will use trace_bprintk()\n",
 		     "static string");
-- 
2.17.1

[PATCH 3/3] ftrace: fix endianness bug in histogram trigger

[Sven Schnelle]

At least on PA-RISC and s390 synthetic histogram triggers are failing
selftests because trace_event_raw_event_synth() always writes a 64 bit
values, but the reader expects a field->size sized value. On little endian
machines this doesn't hurt, but on big endian this makes the reader always
read zero values.

Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
---
 kernel/trace/trace_events_hist.c | 21 ++++++++++++++++++++-
 1 file changed, 20 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index f49d1a36d3ae..f62de5f43e79 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -911,7 +911,26 @@ static notrace void trace_event_raw_event_synth(void *__data,
 			strscpy(str_field, str_val, STR_VAR_LEN_MAX);
 			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
 		} else {
-			entry->fields[n_u64] = var_ref_vals[var_ref_idx + i];
+			struct synth_field *field = event->fields[i];
+			u64 val = var_ref_vals[var_ref_idx + i];
+
+			switch (field->size) {
+			case 1:
+				*(u8 *)&entry->fields[n_u64] = (u8)val;
+				break;
+
+			case 2:
+				*(u16 *)&entry->fields[n_u64] = (u16)val;
+				break;
+
+			case 4:
+				*(u32 *)&entry->fields[n_u64] = (u32)val;
+				break;
+
+			default:
+				entry->fields[n_u64] = val;
+				break;
+			}
 			n_u64++;
 		}
 	}
-- 
2.17.1

Re: [PATCH 3/3] ftrace: fix endianness bug in histogram trigger

[Steven Rostedt]

On Wed, 18 Dec 2019 08:44:27 +0100
Sven Schnelle <svens@linux.ibm.com> wrote:

> At least on PA-RISC and s390 synthetic histogram triggers are failing
> selftests because trace_event_raw_event_synth() always writes a 64 bit
> values, but the reader expects a field->size sized value. On little endian
> machines this doesn't hurt, but on big endian this makes the reader always
> read zero values.

Does this fix make the other one obsolete?

  https://lore.kernel.org/r/20191211110959.2baeb70f@gandalf.local.home

-- Steve

> 
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> ---
>  kernel/trace/trace_events_hist.c | 21 ++++++++++++++++++++-
>  1 file changed, 20 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
> index f49d1a36d3ae..f62de5f43e79 100644
> --- a/kernel/trace/trace_events_hist.c
> +++ b/kernel/trace/trace_events_hist.c
> @@ -911,7 +911,26 @@ static notrace void trace_event_raw_event_synth(void *__data,
>  			strscpy(str_field, str_val, STR_VAR_LEN_MAX);
>  			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
>  		} else {
> -			entry->fields[n_u64] = var_ref_vals[var_ref_idx + i];
> +			struct synth_field *field = event->fields[i];
> +			u64 val = var_ref_vals[var_ref_idx + i];
> +
> +			switch (field->size) {
> +			case 1:
> +				*(u8 *)&entry->fields[n_u64] = (u8)val;
> +				break;
> +
> +			case 2:
> +				*(u16 *)&entry->fields[n_u64] = (u16)val;
> +				break;
> +
> +			case 4:
> +				*(u32 *)&entry->fields[n_u64] = (u32)val;
> +				break;
> +
> +			default:
> +				entry->fields[n_u64] = val;
> +				break;
> +			}
>  			n_u64++;
>  		}
>  	}

Re: [PATCH 3/3] ftrace: fix endianness bug in histogram trigger

[Sven Schnelle]

Hi Steve,

On Wed, Dec 18, 2019 at 10:24:23AM -0500, Steven Rostedt wrote:
> On Wed, 18 Dec 2019 08:44:27 +0100
> Sven Schnelle <svens@linux.ibm.com> wrote:
> 
> > At least on PA-RISC and s390 synthetic histogram triggers are failing
> > selftests because trace_event_raw_event_synth() always writes a 64 bit
> > values, but the reader expects a field->size sized value. On little endian
> > machines this doesn't hurt, but on big endian this makes the reader always
> > read zero values.
> 
> Does this fix make the other one obsolete?
> 
>   https://lore.kernel.org/r/20191211110959.2baeb70f@gandalf.local.home

No, that's a completely different issue, so we need both.

Regards
Sven

Re: [PATCH 1/3] selftests/ftrace: fix glob selftest

[Steven Rostedt]

On Wed, 18 Dec 2019 08:44:25 +0100
Sven Schnelle <svens@linux.ibm.com> wrote:

> test.d/ftrace/func-filter-glob.tc is failing on s390 because it has
> ARCH_INLINE_SPIN_LOCK and friends set to 'y'. So the usual
> __raw_spin_lock symbol isn't in the ftrace function list. Change
> '*aw*lock' to '*time*ns' which would hopefully match some of the
> ktime_() functions on all platforms.

This requires an ack from Masami, and this patch can go through Shuah's
tree.

Also, any patches for the Linux kernel should be Cc'd to lkml. The
linux-trace-devel is mostly for tracing tools, not kernel patches.

-- Steve

> 
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> ---
>  .../testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc  | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
> index 27a54a17da65..a5d61667cd56 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
> @@ -30,7 +30,7 @@ ftrace_filter_check '*schedule*' '^.*schedule.*$'
>  ftrace_filter_check 'schedule*' '^schedule.*$'
>  
>  # filter by *mid*end
> -ftrace_filter_check '*aw*lock' '.*aw.*lock$'
> +ftrace_filter_check '*time*ns' '.*time.*ns$'
>  
>  # filter by start*mid*
>  ftrace_filter_check 'mutex*try*' '^mutex.*try.*'

Re: [PATCH 3/3] ftrace: fix endianness bug in histogram trigger

[Steven Rostedt]

On Wed, 18 Dec 2019 08:44:27 +0100
Sven Schnelle <svens@linux.ibm.com> wrote:

> At least on PA-RISC and s390 synthetic histogram triggers are failing
> selftests because trace_event_raw_event_synth() always writes a 64 bit
> values, but the reader expects a field->size sized value. On little endian
> machines this doesn't hurt, but on big endian this makes the reader always
> read zero values.

Tom,

Does this patch look fine to you?

Also, it was only sent to linux-trace-devel. You can see the original
patch here:

  https://lore.kernel.org/linux-trace-devel/20191218074427.96184-4-svens@linux.ibm.com/

-- Steve


> 
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> ---
>  kernel/trace/trace_events_hist.c | 21 ++++++++++++++++++++-
>  1 file changed, 20 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
> index f49d1a36d3ae..f62de5f43e79 100644
> --- a/kernel/trace/trace_events_hist.c
> +++ b/kernel/trace/trace_events_hist.c
> @@ -911,7 +911,26 @@ static notrace void trace_event_raw_event_synth(void *__data,
>  			strscpy(str_field, str_val, STR_VAR_LEN_MAX);
>  			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
>  		} else {
> -			entry->fields[n_u64] = var_ref_vals[var_ref_idx + i];
> +			struct synth_field *field = event->fields[i];
> +			u64 val = var_ref_vals[var_ref_idx + i];
> +
> +			switch (field->size) {
> +			case 1:
> +				*(u8 *)&entry->fields[n_u64] = (u8)val;
> +				break;
> +
> +			case 2:
> +				*(u16 *)&entry->fields[n_u64] = (u16)val;
> +				break;
> +
> +			case 4:
> +				*(u32 *)&entry->fields[n_u64] = (u32)val;
> +				break;
> +
> +			default:
> +				entry->fields[n_u64] = val;
> +				break;
> +			}
>  			n_u64++;
>  		}
>  	}

Re: [PATCH 1/3] selftests/ftrace: fix glob selftest

[Masami Hiramatsu]

On Thu, 19 Dec 2019 18:31:51 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed, 18 Dec 2019 08:44:25 +0100
> Sven Schnelle <svens@linux.ibm.com> wrote:
> 
> > test.d/ftrace/func-filter-glob.tc is failing on s390 because it has
> > ARCH_INLINE_SPIN_LOCK and friends set to 'y'. So the usual
> > __raw_spin_lock symbol isn't in the ftrace function list. Change
> > '*aw*lock' to '*time*ns' which would hopefully match some of the
> > ktime_() functions on all platforms.
> 
> This requires an ack from Masami, and this patch can go through Shuah's
> tree.
> 
> Also, any patches for the Linux kernel should be Cc'd to lkml. The
> linux-trace-devel is mostly for tracing tools, not kernel patches.

Thanks Steve to CC to me.
BTW, are there any reason why we use different symbols for different
glob patterns?
I mean we can use 'schedul*', '*chedule' and '*sch*ule' as test
glob patterns.

Thank you,

> 
> -- Steve
> 
> > 
> > Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> > ---
> >  .../testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc  | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> > 
> > diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
> > index 27a54a17da65..a5d61667cd56 100644
> > --- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
> > +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
> > @@ -30,7 +30,7 @@ ftrace_filter_check '*schedule*' '^.*schedule.*$'
> >  ftrace_filter_check 'schedule*' '^schedule.*$'
> >  
> >  # filter by *mid*end
> > -ftrace_filter_check '*aw*lock' '.*aw.*lock$'
> > +ftrace_filter_check '*time*ns' '.*time.*ns$'
> >  
> >  # filter by start*mid*
> >  ftrace_filter_check 'mutex*try*' '^mutex.*try.*'
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH 1/3] selftests/ftrace: fix glob selftest

[Sven Schnelle]

Hi,

On Fri, Dec 20, 2019 at 04:27:46PM +0900, Masami Hiramatsu wrote:
> On Thu, 19 Dec 2019 18:31:51 -0500
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > On Wed, 18 Dec 2019 08:44:25 +0100
> > Sven Schnelle <svens@linux.ibm.com> wrote:
> > 
> > > test.d/ftrace/func-filter-glob.tc is failing on s390 because it has
> > > ARCH_INLINE_SPIN_LOCK and friends set to 'y'. So the usual
> > > __raw_spin_lock symbol isn't in the ftrace function list. Change
> > > '*aw*lock' to '*time*ns' which would hopefully match some of the
> > > ktime_() functions on all platforms.
> > 
> > This requires an ack from Masami, and this patch can go through Shuah's
> > tree.
> > 
> > Also, any patches for the Linux kernel should be Cc'd to lkml. The
> > linux-trace-devel is mostly for tracing tools, not kernel patches.
> 
> Thanks Steve to CC to me.
> BTW, are there any reason why we use different symbols for different
> glob patterns?
> I mean we can use 'schedul*', '*chedule' and '*sch*ule' as test
> glob patterns.

Don't know, but i don't see a reason why we should have different patterns. If
there's an agreement that we prefer a common pattern i can update the patch and
resend.

Regards
Sven

Re: [PATCH 3/3] ftrace: fix endianness bug in histogram trigger

[Tom Zanussi]

Hi Steve,

On Thu, 2019-12-19 at 18:33 -0500, Steven Rostedt wrote:
> On Wed, 18 Dec 2019 08:44:27 +0100
> Sven Schnelle <svens@linux.ibm.com> wrote:
> 
> > At least on PA-RISC and s390 synthetic histogram triggers are
> > failing
> > selftests because trace_event_raw_event_synth() always writes a 64
> > bit
> > values, but the reader expects a field->size sized value. On little
> > endian
> > machines this doesn't hurt, but on big endian this makes the reader
> > always
> > read zero values.
> 
> Tom,
> 
> Does this patch look fine to you?

Yeah, it looks fine to me.

Acked-by: Tom Zanussi <tom.zanussi@linux.intel.com>

> 
> Also, it was only sent to linux-trace-devel. You can see the original
> patch here:
> 
>   https://lore.kernel.org/linux-trace-devel/20191218074427.96184-4-sv
> ens@linux.ibm.com/
> 
> -- Steve
> 
> 
> > 
> > Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> > ---
> >  kernel/trace/trace_events_hist.c | 21 ++++++++++++++++++++-
> >  1 file changed, 20 insertions(+), 1 deletion(-)
> > 
> > diff --git a/kernel/trace/trace_events_hist.c
> > b/kernel/trace/trace_events_hist.c
> > index f49d1a36d3ae..f62de5f43e79 100644
> > --- a/kernel/trace/trace_events_hist.c
> > +++ b/kernel/trace/trace_events_hist.c
> > @@ -911,7 +911,26 @@ static notrace void
> > trace_event_raw_event_synth(void *__data,
> >  			strscpy(str_field, str_val,
> > STR_VAR_LEN_MAX);
> >  			n_u64 += STR_VAR_LEN_MAX / sizeof(u64);
> >  		} else {
> > -			entry->fields[n_u64] =
> > var_ref_vals[var_ref_idx + i];
> > +			struct synth_field *field = event-
> > >fields[i];
> > +			u64 val = var_ref_vals[var_ref_idx + i];
> > +
> > +			switch (field->size) {
> > +			case 1:
> > +				*(u8 *)&entry->fields[n_u64] =
> > (u8)val;
> > +				break;
> > +
> > +			case 2:
> > +				*(u16 *)&entry->fields[n_u64] =
> > (u16)val;
> > +				break;
> > +
> > +			case 4:
> > +				*(u32 *)&entry->fields[n_u64] =
> > (u32)val;
> > +				break;
> > +
> > +			default:
> > +				entry->fields[n_u64] = val;
> > +				break;
> > +			}
> >  			n_u64++;
> >  		}
> >  	}
> 
> 

Re: [PATCH 1/3] selftests/ftrace: fix glob selftest

[Steven Rostedt]

On Fri, 20 Dec 2019 08:32:40 +0100
Sven Schnelle <svens@linux.ibm.com> wrote:


> > Thanks Steve to CC to me.
> > BTW, are there any reason why we use different symbols for different
> > glob patterns?
> > I mean we can use 'schedul*', '*chedule' and '*sch*ule' as test
> > glob patterns.  
> 
> Don't know, but i don't see a reason why we should have different patterns. If
> there's an agreement that we prefer a common pattern i can update the patch and
> resend.


I think I liked trying other functions just to make sure that it was
working to add a bit of churn to the mix (for the unlikely case that
schedule has some fluke case).

We could just switch it all to use schedule, or we can change "aw" to
"spin".

-- Steve