All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
@ 2017-03-16 13:56 Josh Poimboeuf
  2017-03-16 14:41 ` Steven Rostedt
  2017-03-21 20:44 ` Paul Menzel
  0 siblings, 2 replies; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-16 13:56 UTC (permalink / raw)
  To: Rafael J . Wysocki, Len Brown
  Cc: linux-acpi, linux-kernel, Steven Rostedt, Ingo Molnar, Paul Menzel

Paul Menzel reported a warning:

  WARNING: CPU: 0 PID: 774 at /build/linux-ROBWaj/linux-4.9.13/kernel/trace/trace_functions_graph.c:233 ftrace_return_to_handler+0x1aa/0x1e0
  Bad frame pointer: expected f6919d98, received f6919db0
    from func acpi_pm_device_sleep_wake return to c43b6f9d

The warning means that function graph tracing is broken for the
acpi_pm_device_sleep_wake() function.  That's because the acpi Makefile
unconditionally sets the '-Os' gcc flag to optimize for size.  That's an
issue because mcount-based function graph tracing is incompatible with
'-Os' on x86, thanks to the following gcc bug:

  https://gcc.gnu.org/bugzilla/show_bug.cgi?id=42109

I have another patch pending which will ensure that mcount-based
function graph tracing is never used with CONFIG_CC_OPTIMIZE_FOR_SIZE on
x86.

But this patch is needed in addition to that one because the ACPI
Makefile overrides that config option for no apparent reason.  It has
had this flag since the beginning of git history, and there's no related
comment, so I don't know why it's there.  As far as I can tell, there's
no reason for it to be there.  The appropriate behavior is for it to
honor CONFIG_CC_OPTIMIZE_FOR_{SIZE,PERFORMANCE} like the rest of the
kernel.

Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 drivers/acpi/Makefile | 1 -
 1 file changed, 1 deletion(-)

diff --git a/drivers/acpi/Makefile b/drivers/acpi/Makefile
index a391bbc..d94f92f 100644
--- a/drivers/acpi/Makefile
+++ b/drivers/acpi/Makefile
@@ -2,7 +2,6 @@
 # Makefile for the Linux ACPI interpreter
 #
 
-ccflags-y			:= -Os
 ccflags-$(CONFIG_ACPI_DEBUG)	+= -DACPI_DEBUG_OUTPUT
 
 #
-- 
2.7.4


^ permalink raw reply related	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-16 13:56 [PATCH] acpi: fix incompatibility with mcount-based function graph tracing Josh Poimboeuf
@ 2017-03-16 14:41 ` Steven Rostedt
  2017-03-21 20:44 ` Paul Menzel
  1 sibling, 0 replies; 30+ messages in thread
From: Steven Rostedt @ 2017-03-16 14:41 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Rafael J . Wysocki, Len Brown, linux-acpi, linux-kernel,
	Ingo Molnar, Paul Menzel

On Thu, 16 Mar 2017 08:56:28 -0500
Josh Poimboeuf <jpoimboe@redhat.com> wrote:

> Paul Menzel reported a warning:
> 
>   WARNING: CPU: 0 PID: 774 at /build/linux-ROBWaj/linux-4.9.13/kernel/trace/trace_functions_graph.c:233 ftrace_return_to_handler+0x1aa/0x1e0
>   Bad frame pointer: expected f6919d98, received f6919db0
>     from func acpi_pm_device_sleep_wake return to c43b6f9d
> 
> The warning means that function graph tracing is broken for the
> acpi_pm_device_sleep_wake() function.  That's because the acpi Makefile
> unconditionally sets the '-Os' gcc flag to optimize for size.  That's an
> issue because mcount-based function graph tracing is incompatible with
> '-Os' on x86, thanks to the following gcc bug:
> 
>   https://gcc.gnu.org/bugzilla/show_bug.cgi?id=42109
> 
> I have another patch pending which will ensure that mcount-based
> function graph tracing is never used with CONFIG_CC_OPTIMIZE_FOR_SIZE on
> x86.
> 
> But this patch is needed in addition to that one because the ACPI
> Makefile overrides that config option for no apparent reason.  It has
> had this flag since the beginning of git history, and there's no related
> comment, so I don't know why it's there.  As far as I can tell, there's
> no reason for it to be there.  The appropriate behavior is for it to
> honor CONFIG_CC_OPTIMIZE_FOR_{SIZE,PERFORMANCE} like the rest of the
> kernel.
> 
> Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
> Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
> ---
>  drivers/acpi/Makefile | 1 -
>  1 file changed, 1 deletion(-)
> 
> diff --git a/drivers/acpi/Makefile b/drivers/acpi/Makefile
> index a391bbc..d94f92f 100644
> --- a/drivers/acpi/Makefile
> +++ b/drivers/acpi/Makefile
> @@ -2,7 +2,6 @@
>  # Makefile for the Linux ACPI interpreter
>  #
>  
> -ccflags-y			:= -Os

Unless somebody can come up with a real reason to have this,

Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

-- Steve

>  ccflags-$(CONFIG_ACPI_DEBUG)	+= -DACPI_DEBUG_OUTPUT
>  
>  #

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-16 13:56 [PATCH] acpi: fix incompatibility with mcount-based function graph tracing Josh Poimboeuf
  2017-03-16 14:41 ` Steven Rostedt
@ 2017-03-21 20:44 ` Paul Menzel
  2017-03-22  0:04   ` Paul Menzel
  2017-03-24 18:12   ` Josh Poimboeuf
  1 sibling, 2 replies; 30+ messages in thread
From: Paul Menzel @ 2017-03-21 20:44 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Rafael J . Wysocki, Len Brown, linux-acpi, linux-kernel,
	Steven Rostedt, Ingo Molnar

Dear Josh,


On 2017-03-16 14:56, Josh Poimboeuf wrote:
> Paul Menzel reported a warning:
> 
>   WARNING: CPU: 0 PID: 774 at
> /build/linux-ROBWaj/linux-4.9.13/kernel/trace/trace_functions_graph.c:233
> ftrace_return_to_handler+0x1aa/0x1e0
>   Bad frame pointer: expected f6919d98, received f6919db0
>     from func acpi_pm_device_sleep_wake return to c43b6f9d
> 
> The warning means that function graph tracing is broken for the
> acpi_pm_device_sleep_wake() function.  That's because the acpi Makefile
> unconditionally sets the '-Os' gcc flag to optimize for size.  That's 
> an
> issue because mcount-based function graph tracing is incompatible with
> '-Os' on x86, thanks to the following gcc bug:
> 
>   https://gcc.gnu.org/bugzilla/show_bug.cgi?id=42109
> 
> I have another patch pending which will ensure that mcount-based
> function graph tracing is never used with CONFIG_CC_OPTIMIZE_FOR_SIZE 
> on
> x86.
> 
> But this patch is needed in addition to that one because the ACPI
> Makefile overrides that config option for no apparent reason.  It has
> had this flag since the beginning of git history, and there's no 
> related
> comment, so I don't know why it's there.  As far as I can tell, there's
> no reason for it to be there.  The appropriate behavior is for it to
> honor CONFIG_CC_OPTIMIZE_FOR_{SIZE,PERFORMANCE} like the rest of the
> kernel.
> 
> Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
> Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
> ---
>  drivers/acpi/Makefile | 1 -
>  1 file changed, 1 deletion(-)
> 
> diff --git a/drivers/acpi/Makefile b/drivers/acpi/Makefile
> index a391bbc..d94f92f 100644
> --- a/drivers/acpi/Makefile
> +++ b/drivers/acpi/Makefile
> @@ -2,7 +2,6 @@
>  # Makefile for the Linux ACPI interpreter
>  #
> 
> -ccflags-y			:= -Os
>  ccflags-$(CONFIG_ACPI_DEBUG)	+= -DACPI_DEBUG_OUTPUT
> 
>  #

I checked out Linux 4.9.16, applied your patch on top, and copied the 
Debian 4.9 Linux kernel configuration, did `make menuconfig`, disabled 
building debugging symbols, and executed `ARCH=i386 make -j40 deb-pkg`.

I installed that package on the Lenovo X60, and the result with tracing 
enabled has improved. The system suspends without a crash. 
Unfortunately, instead of resuming when pressing the power button, it 
starts from scratch. Suspend and resume without tracing enabled works 
though.

I’ll try to collect logs, but I don’t know, if there will be any, if the 
system just resets.

Maybe, this can be reproduced in QEMU?


Kind regards,

Paul

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-21 20:44 ` Paul Menzel
@ 2017-03-22  0:04   ` Paul Menzel
  2017-03-24 18:12   ` Josh Poimboeuf
  1 sibling, 0 replies; 30+ messages in thread
From: Paul Menzel @ 2017-03-22  0:04 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Rafael J . Wysocki, Len Brown, linux-acpi, linux-kernel,
	Steven Rostedt, Ingo Molnar

Dear Josh,


On 2017-03-21 21:44, Paul Menzel wrote:

> On 2017-03-16 14:56, Josh Poimboeuf wrote:
>> Paul Menzel reported a warning:
>> 
>>   WARNING: CPU: 0 PID: 774 at
>> /build/linux-ROBWaj/linux-4.9.13/kernel/trace/trace_functions_graph.c:233
>> ftrace_return_to_handler+0x1aa/0x1e0
>>   Bad frame pointer: expected f6919d98, received f6919db0
>>     from func acpi_pm_device_sleep_wake return to c43b6f9d
>> 
>> The warning means that function graph tracing is broken for the
>> acpi_pm_device_sleep_wake() function.  That's because the acpi 
>> Makefile
>> unconditionally sets the '-Os' gcc flag to optimize for size.  That's 
>> an
>> issue because mcount-based function graph tracing is incompatible with
>> '-Os' on x86, thanks to the following gcc bug:
>> 
>>   https://gcc.gnu.org/bugzilla/show_bug.cgi?id=42109
>> 
>> I have another patch pending which will ensure that mcount-based
>> function graph tracing is never used with CONFIG_CC_OPTIMIZE_FOR_SIZE 
>> on
>> x86.
>> 
>> But this patch is needed in addition to that one because the ACPI
>> Makefile overrides that config option for no apparent reason.  It has
>> had this flag since the beginning of git history, and there's no 
>> related
>> comment, so I don't know why it's there.  As far as I can tell, 
>> there's
>> no reason for it to be there.  The appropriate behavior is for it to
>> honor CONFIG_CC_OPTIMIZE_FOR_{SIZE,PERFORMANCE} like the rest of the
>> kernel.
>> 
>> Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
>> Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
>> ---
>>  drivers/acpi/Makefile | 1 -
>>  1 file changed, 1 deletion(-)
>> 
>> diff --git a/drivers/acpi/Makefile b/drivers/acpi/Makefile
>> index a391bbc..d94f92f 100644
>> --- a/drivers/acpi/Makefile
>> +++ b/drivers/acpi/Makefile
>> @@ -2,7 +2,6 @@
>>  # Makefile for the Linux ACPI interpreter
>>  #
>> 
>> -ccflags-y			:= -Os
>>  ccflags-$(CONFIG_ACPI_DEBUG)	+= -DACPI_DEBUG_OUTPUT
>> 
>>  #
> 
> I checked out Linux 4.9.16, applied your patch on top, and copied the
> Debian 4.9 Linux kernel configuration, did `make menuconfig`, disabled
> building debugging symbols, and executed `ARCH=i386 make -j40
> deb-pkg`.
> 
> I installed that package on the Lenovo X60, and the result with
> tracing enabled has improved. The system suspends without a crash.
> Unfortunately, instead of resuming when pressing the power button, it
> starts from scratch. Suspend and resume without tracing enabled works
> though.
> 
> I’ll try to collect logs, but I don’t know, if there will be any, if
> the system just resets.

The system is able to resume with `no_console_suspend` passed to Linux 
on its command line.

```
$ more /proc/cmdline
BOOT_IMAGE=/vmlinuz-4.9.16 
root=UUID=0198e82a-32df-4f18-bec0-3e08802b084d ro noisapnp 
pcie_aspm=force pcie_aspm.policy=powersave nmi_watchdog=0 iomem=relaxed 
console=t
tyS1,115200 console=tty0 no_console_suspend
```

Please tell me, what you need from my side.

> Maybe, this can be reproduced in QEMU?


Kind regards,

Paul

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-21 20:44 ` Paul Menzel
  2017-03-22  0:04   ` Paul Menzel
@ 2017-03-24 18:12   ` Josh Poimboeuf
  2017-03-24 18:41     ` Steven Rostedt
  1 sibling, 1 reply; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-24 18:12 UTC (permalink / raw)
  To: Paul Menzel
  Cc: Rafael J . Wysocki, Len Brown, linux-acpi, linux-kernel,
	Steven Rostedt, Ingo Molnar

On Tue, Mar 21, 2017 at 09:44:03PM +0100, Paul Menzel wrote:
> I checked out Linux 4.9.16, applied your patch on top, and copied the Debian
> 4.9 Linux kernel configuration, did `make menuconfig`, disabled building
> debugging symbols, and executed `ARCH=i386 make -j40 deb-pkg`.
> 
> I installed that package on the Lenovo X60, and the result with tracing
> enabled has improved. The system suspends without a crash. Unfortunately,
> instead of resuming when pressing the power button, it starts from scratch.
> Suspend and resume without tracing enabled works though.
> 
> I’ll try to collect logs, but I don’t know, if there will be any, if the
> system just resets.
> 
> Maybe, this can be reproduced in QEMU?

So I was able to recreate this issue in qemu, and after some hours of
debugging I managed to figure it out.

It's rebooting during the resume because of a triple fault in
prepare_ftrace_return().

acpi wakeup for secondary cpu
  startup_32_smp()
    load_ucode_ap()
      prepare_ftrace_return()
        ftrace_graph_is_dead()
	  dereferences virtual address (kill_ftrace_graph) in real mode <-- BOOM

I tried fixing it by changing load_ucode_ap() to notrace, but that
function calls some other functions which also have mcount hooks, which
call other functions, etc.

Instead I was able to "fix" it by ignoring ftrace calls in real mode:

-----
index 8f3d9cf..5c0d0c6 100644
--- a/arch/x86/kernel/ftrace.c
+++ b/arch/x86/kernel/ftrace.c
@@ -983,6 +983,9 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
 	unsigned long return_hooker = (unsigned long)
 				&return_to_handler;
 
+	if (__builtin_return_address(0) < TASK_SIZE_MAX)
+		return;
+
 	if (unlikely(ftrace_graph_is_dead()))
 		return;
---------------

I'm not sure what the best fix should really be.  A few ideas off the
top of my head:

- A real mode check similar to the above (except it should probably be
  more precise)

- Make tracing_graph_pause a percpu variable so that it can be read from
  prepare_ftrace_return()

- pause_graph_tracing() from ftrace_suspend_notifier_call()

Steven, thoughts?

-- 
Josh

^ permalink raw reply related	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-24 18:12   ` Josh Poimboeuf
@ 2017-03-24 18:41     ` Steven Rostedt
  2017-03-25 13:20       ` Rafael J. Wysocki
  0 siblings, 1 reply; 30+ messages in thread
From: Steven Rostedt @ 2017-03-24 18:41 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Paul Menzel, Rafael J . Wysocki, Len Brown, linux-acpi,
	linux-kernel, Ingo Molnar

On Fri, 24 Mar 2017 13:12:54 -0500
Josh Poimboeuf <jpoimboe@redhat.com> wrote:


> Instead I was able to "fix" it by ignoring ftrace calls in real mode:
> 
> -----
> index 8f3d9cf..5c0d0c6 100644
> --- a/arch/x86/kernel/ftrace.c
> +++ b/arch/x86/kernel/ftrace.c
> @@ -983,6 +983,9 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
>  	unsigned long return_hooker = (unsigned long)
>  				&return_to_handler;
>  
> +	if (__builtin_return_address(0) < TASK_SIZE_MAX)
> +		return;
> +
>  	if (unlikely(ftrace_graph_is_dead()))
>  		return;
> ---------------
> 
> I'm not sure what the best fix should really be.  A few ideas off the
> top of my head:
> 
> - A real mode check similar to the above (except it should probably be
>   more precise)

The real mode check hack may be good enough for now. Make sure that
it's commented well.

-- Steve

> 
> - Make tracing_graph_pause a percpu variable so that it can be read from
>   prepare_ftrace_return()
> 
> - pause_graph_tracing() from ftrace_suspend_notifier_call()
> 
> Steven, thoughts?
> 


^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-24 18:41     ` Steven Rostedt
@ 2017-03-25 13:20       ` Rafael J. Wysocki
  2017-03-27 14:08         ` Josh Poimboeuf
  0 siblings, 1 reply; 30+ messages in thread
From: Rafael J. Wysocki @ 2017-03-25 13:20 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Josh Poimboeuf, Paul Menzel, Len Brown, linux-acpi, linux-kernel,
	Ingo Molnar

On Friday, March 24, 2017 02:41:14 PM Steven Rostedt wrote:
> On Fri, 24 Mar 2017 13:12:54 -0500
> Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> 
> 
> > Instead I was able to "fix" it by ignoring ftrace calls in real mode:
> > 
> > -----
> > index 8f3d9cf..5c0d0c6 100644
> > --- a/arch/x86/kernel/ftrace.c
> > +++ b/arch/x86/kernel/ftrace.c
> > @@ -983,6 +983,9 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
> >  	unsigned long return_hooker = (unsigned long)
> >  				&return_to_handler;
> >  
> > +	if (__builtin_return_address(0) < TASK_SIZE_MAX)
> > +		return;
> > +
> >  	if (unlikely(ftrace_graph_is_dead()))
> >  		return;
> > ---------------
> > 
> > I'm not sure what the best fix should really be.  A few ideas off the
> > top of my head:
> > 
> > - A real mode check similar to the above (except it should probably be
> >   more precise)
> 
> The real mode check hack may be good enough for now. Make sure that
> it's commented well.

Agreed.

Thanks,
Rafael


^ permalink raw reply	[flat|nested] 30+ messages in thread

* [PATCH] trace: Make trace_hwlat timestamp y2038 safe
@ 2017-03-26 20:57 Deepa Dinamani
  2017-03-27  9:25 ` kbuild test robot
  2017-03-27 10:04 ` kbuild test robot
  0 siblings, 2 replies; 30+ messages in thread
From: Deepa Dinamani @ 2017-03-26 20:57 UTC (permalink / raw)
  To: rostedt, mingo, linux-kernel; +Cc: arnd, y2038

struct timespec is not y2038 safe on 32 bit machines
and needs to be replaced by struct timespec64
in order to represent times beyond year 2038 on such
machines.

Fix all the timestamp representation in struct trace_hwlat
and all the corresponding implementations.

Signed-off-by: Deepa Dinamani <deepa.kernel@gmail.com>
---
 kernel/trace/trace_entries.h | 6 +++---
 kernel/trace/trace_hwlat.c   | 4 ++--
 kernel/trace/trace_output.c  | 5 ++---
 3 files changed, 7 insertions(+), 8 deletions(-)

diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index c203ac4..adcdbbe 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -348,14 +348,14 @@ FTRACE_ENTRY(hwlat, hwlat_entry,
 		__field(	u64,			duration	)
 		__field(	u64,			outer_duration	)
 		__field(	u64,			nmi_total_ts	)
-		__field_struct( struct timespec,	timestamp	)
-		__field_desc(	long,	timestamp,	tv_sec		)
+		__field_struct( struct timespec64,	timestamp	)
+		__field_desc(	s64,	timestamp,	tv_sec		)
 		__field_desc(	long,	timestamp,	tv_nsec		)
 		__field(	unsigned int,		nmi_count	)
 		__field(	unsigned int,		seqnum		)
 	),
 
-	F_printk("cnt:%u\tts:%010lu.%010lu\tinner:%llu\touter:%llunmi-ts:%llu\tnmi-count:%u\n",
+	F_printk("cnt:%u\tts:%010llu.%010lu\tinner:%llu\touter:%llunmi-ts:%llu\tnmi-count:%u\n",
 		 __entry->seqnum,
 		 __entry->tv_sec,
 		 __entry->tv_nsec,
diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
index 21ea6ae..2257ff1 100644
--- a/kernel/trace/trace_hwlat.c
+++ b/kernel/trace/trace_hwlat.c
@@ -83,7 +83,7 @@ struct hwlat_sample {
 	u64		duration;	/* delta */
 	u64		outer_duration;	/* delta (outer loop) */
 	u64		nmi_total_ts;	/* Total time spent in NMIs */
-	struct timespec	timestamp;	/* wall time */
+	struct timespec64	timestamp;	/* wall time */
 	int		nmi_count;	/* # NMIs during this sample */
 };
 
@@ -250,7 +250,7 @@ static int get_sample(void)
 		s.seqnum = hwlat_data.count;
 		s.duration = sample;
 		s.outer_duration = outer_sample;
-		s.timestamp = CURRENT_TIME;
+		ktime_get_real_ts64(&s.timestamp);
 		s.nmi_total_ts = nmi_total_ts;
 		s.nmi_count = nmi_count;
 		trace_hwlat_sample(&s);
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 02a4aeb..bf7c757 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -4,7 +4,6 @@
  * Copyright (C) 2008 Red Hat Inc, Steven Rostedt <srostedt@redhat.com>
  *
  */
-
 #include <linux/module.h>
 #include <linux/mutex.h>
 #include <linux/ftrace.h>
@@ -1161,7 +1160,7 @@ trace_hwlat_print(struct trace_iterator *iter, int flags,
 
 	trace_assign_type(field, entry);
 
-	trace_seq_printf(s, "#%-5u inner/outer(us): %4llu/%-5llu ts:%ld.%09ld",
+	trace_seq_printf(s, "#%-5u inner/outer(us): %4llu/%-5llu ts:%lld.%09ld",
 			 field->seqnum,
 			 field->duration,
 			 field->outer_duration,
@@ -1195,7 +1194,7 @@ trace_hwlat_raw(struct trace_iterator *iter, int flags,
 
 	trace_assign_type(field, iter->ent);
 
-	trace_seq_printf(s, "%llu %lld %ld %09ld %u\n",
+	trace_seq_printf(s, "%llu %lld %lld %09ld %u\n",
 			 field->duration,
 			 field->outer_duration,
 			 field->timestamp.tv_sec,
-- 
2.7.4

^ permalink raw reply related	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-26 20:57 [PATCH] trace: Make trace_hwlat timestamp y2038 safe Deepa Dinamani
@ 2017-03-27  9:25 ` kbuild test robot
  2017-03-27  9:55   ` Arnd Bergmann
  2017-03-27 10:04 ` kbuild test robot
  1 sibling, 1 reply; 30+ messages in thread
From: kbuild test robot @ 2017-03-27  9:25 UTC (permalink / raw)
  To: Deepa Dinamani; +Cc: kbuild-all, rostedt, mingo, linux-kernel, arnd, y2038

[-- Attachment #1: Type: text/plain, Size: 9465 bytes --]

Hi Deepa,

[auto build test WARNING on tip/perf/core]
[also build test WARNING on v4.11-rc4 next-20170327]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Deepa-Dinamani/trace-Make-trace_hwlat-timestamp-y2038-safe/20170327-150010
config: x86_64-randconfig-n0-03271517 (attached as .config)
compiler: gcc-4.8 (Debian 4.8.4-1) 4.8.4
reproduce:
        # save the attached .config to linux build tree
        make ARCH=x86_64 

All warnings (new ones prefixed by >>):

   kernel/trace/trace_output.c: In function 'trace_hwlat_print':
>> kernel/trace/trace_output.c:1168:5: warning: format '%lld' expects argument of type 'long long int', but argument 6 has type '__kernel_time_t' [-Wformat=]
        field->timestamp.tv_nsec);
        ^
   kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
   kernel/trace/trace_output.c:1202:5: warning: format '%lld' expects argument of type 'long long int', but argument 5 has type '__kernel_time_t' [-Wformat=]
        field->seqnum);
        ^
   Cyclomatic Complexity 5 include/linux/compiler.h:__read_once_size
   Cyclomatic Complexity 5 include/linux/compiler.h:__write_once_size
   Cyclomatic Complexity 1 arch/x86/include/asm/bitops.h:__ffs
   Cyclomatic Complexity 1 include/linux/list.h:INIT_LIST_HEAD
   Cyclomatic Complexity 2 include/linux/list.h:__list_add
   Cyclomatic Complexity 1 include/linux/list.h:list_add_tail
   Cyclomatic Complexity 1 include/linux/list.h:__list_del
   Cyclomatic Complexity 2 include/linux/list.h:__list_del_entry
   Cyclomatic Complexity 1 include/linux/list.h:list_del
   Cyclomatic Complexity 1 include/linux/list.h:list_empty
   Cyclomatic Complexity 2 include/linux/list.h:__hlist_del
   Cyclomatic Complexity 1 include/linux/list.h:hlist_del
   Cyclomatic Complexity 2 include/linux/list.h:hlist_add_head
   Cyclomatic Complexity 1 include/linux/rcupdate.h:rcu_lock_acquire
   Cyclomatic Complexity 1 include/linux/rcupdate.h:rcu_lock_release
   Cyclomatic Complexity 4 include/linux/rcupdate.h:rcu_read_lock
   Cyclomatic Complexity 4 include/linux/rcupdate.h:rcu_read_unlock
   Cyclomatic Complexity 1 include/linux/seq_buf.h:seq_buf_clear
   Cyclomatic Complexity 1 include/linux/seq_buf.h:seq_buf_init
   Cyclomatic Complexity 1 include/linux/seq_buf.h:seq_buf_has_overflowed
   Cyclomatic Complexity 1 include/linux/seq_buf.h:seq_buf_used
   Cyclomatic Complexity 1 include/linux/trace_seq.h:trace_seq_init
   Cyclomatic Complexity 1 include/linux/trace_seq.h:trace_seq_buffer_ptr
   Cyclomatic Complexity 3 include/linux/trace_seq.h:trace_seq_has_overflowed
   Cyclomatic Complexity 2 include/linux/trace_events.h:trace_handle_return
   Cyclomatic Complexity 3 include/linux/trace_events.h:trace_event_name
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:kretprobed
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:task_state_char
   Cyclomatic Complexity 5 kernel/trace/trace_output.c:trace_search_list
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_nop_print
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_hwlat_raw
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_print_raw
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_bprint_raw
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_bputs_raw
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_ctxwake_raw
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_wake_raw
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_ctx_raw
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_fn_raw
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_raw_data
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_hwlat_print
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_output_raw
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:seq_print_sym_offset
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:seq_print_sym_short
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_ctxwake_print
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_wake_print
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_ctx_print
   Cyclomatic Complexity 9 kernel/trace/trace_output.c:seq_print_user_ip
   Cyclomatic Complexity 9 kernel/trace/trace_output.c:trace_user_stack_print
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_ctxwake_bin
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_fn_bin
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_ctxwake_hex
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_wake_hex
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_ctx_hex
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_fn_hex
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_print_bputs_msg_only
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_print_bprintk_msg_only
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_print_printk_msg_only
   Cyclomatic Complexity 7 kernel/trace/trace_output.c:trace_print_flags_seq
   Cyclomatic Complexity 4 kernel/trace/trace_output.c:trace_print_symbols_seq
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_print_bitmask_seq
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_print_hex_seq
   Cyclomatic Complexity 6 kernel/trace/trace_output.c:trace_print_array_seq
   Cyclomatic Complexity 5 kernel/trace/trace_output.c:trace_raw_output_prep
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_output_call
   Cyclomatic Complexity 4 kernel/trace/trace_output.c:seq_print_ip_sym
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_print_print
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_bprint_print
   Cyclomatic Complexity 2 kernel/trace/trace_output.c:trace_bputs_print
   Cyclomatic Complexity 6 kernel/trace/trace_output.c:trace_stack_print
   Cyclomatic Complexity 4 kernel/trace/trace_output.c:trace_fn_trace
   Cyclomatic Complexity 12 kernel/trace/trace_output.c:trace_print_lat_fmt
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:lat_print_generic
   Cyclomatic Complexity 4 kernel/trace/trace_output.c:trace_find_mark
   Cyclomatic Complexity 5 kernel/trace/trace_output.c:lat_print_timestamp
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_print_context
   Cyclomatic Complexity 3 kernel/trace/trace_output.c:trace_print_lat_context
   Cyclomatic Complexity 5 kernel/trace/trace_output.c:ftrace_find_event
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_event_read_lock
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:trace_event_read_unlock
   Cyclomatic Complexity 17 kernel/trace/trace_output.c:register_trace_event
   Cyclomatic Complexity 6 kernel/trace/trace_output.c:init_events
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:__unregister_trace_event
   Cyclomatic Complexity 1 kernel/trace/trace_output.c:unregister_trace_event

vim +1168 kernel/trace/trace_output.c

e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1152) /* TRACE_HWLAT */
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1153) static enum print_line_t
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1154) trace_hwlat_print(struct trace_iterator *iter, int flags,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1155) 		  struct trace_event *event)
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1156) {
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1157) 	struct trace_entry *entry = iter->ent;
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1158) 	struct trace_seq *s = &iter->seq;
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1159) 	struct hwlat_entry *field;
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1160) 
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1161) 	trace_assign_type(field, entry);
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1162) 
df001907 Deepa Dinamani           2017-03-26  1163  	trace_seq_printf(s, "#%-5u inner/outer(us): %4llu/%-5llu ts:%lld.%09ld",
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1164) 			 field->seqnum,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1165) 			 field->duration,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1166) 			 field->outer_duration,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1167) 			 field->timestamp.tv_sec,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23 @1168) 			 field->timestamp.tv_nsec);
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1169) 
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1170) 	if (field->nmi_count) {
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1171) 		/*
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1172) 		 * The generic sched_clock() is not NMI safe, thus
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1173) 		 * we only record the count and not the time.
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1174) 		 */
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1175) 		if (!IS_ENABLED(CONFIG_GENERIC_SCHED_CLOCK))
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1176) 			trace_seq_printf(s, " nmi-total:%llu",

:::::: The code at line 1168 was first introduced by commit
:::::: e7c15cd8a113335cf7154f027c9c8da1a92238ee tracing: Added hardware latency tracer

:::::: TO: Steven Rostedt (Red Hat) <rostedt@goodmis.org>
:::::: CC: Steven Rostedt <rostedt@goodmis.org>

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation

[-- Attachment #2: .config.gz --]
[-- Type: application/gzip, Size: 19852 bytes --]

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27  9:25 ` kbuild test robot
@ 2017-03-27  9:55   ` Arnd Bergmann
  2017-03-27 14:28     ` Steven Rostedt
  0 siblings, 1 reply; 30+ messages in thread
From: Arnd Bergmann @ 2017-03-27  9:55 UTC (permalink / raw)
  To: kbuild test robot
  Cc: Deepa Dinamani, kbuild-all, Steven Rostedt, Ingo Molnar,
	Linux Kernel Mailing List, y2038 Mailman List

On Mon, Mar 27, 2017 at 11:25 AM, kbuild test robot <lkp@intel.com> wrote:
> Hi Deepa,
>
> [auto build test WARNING on tip/perf/core]
> [also build test WARNING on v4.11-rc4 next-20170327]
> [if your patch is applied to the wrong git tree, please drop us a note to help improve the system]
>
> url:    https://github.com/0day-ci/linux/commits/Deepa-Dinamani/trace-Make-trace_hwlat-timestamp-y2038-safe/20170327-150010
> config: x86_64-randconfig-n0-03271517 (attached as .config)
> compiler: gcc-4.8 (Debian 4.8.4-1) 4.8.4
> reproduce:
>         # save the attached .config to linux build tree
>         make ARCH=x86_64
>
> All warnings (new ones prefixed by >>):
>
>    kernel/trace/trace_output.c: In function 'trace_hwlat_print':
>>> kernel/trace/trace_output.c:1168:5: warning: format '%lld' expects argument of type 'long long int', but argument 6 has type '__kernel_time_t' [-Wformat=]
>         field->timestamp.tv_nsec);

This happens on 64-bit architectures because 'struct timespec64' is defined to
be equal to 'struct timespec', which has a 'long' tv_sec rather than
'long long'.

A cast to 's64' is probably the best workaround.

>    kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
>    kernel/trace/trace_output.c:1202:5: warning: format '%lld' expects argument of type 'long long int', but argument 5 has type '__kernel_time_t' [-Wformat=]
>         field->seqnum);

Same here.


      Arnd

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-26 20:57 [PATCH] trace: Make trace_hwlat timestamp y2038 safe Deepa Dinamani
  2017-03-27  9:25 ` kbuild test robot
@ 2017-03-27 10:04 ` kbuild test robot
  1 sibling, 0 replies; 30+ messages in thread
From: kbuild test robot @ 2017-03-27 10:04 UTC (permalink / raw)
  To: Deepa Dinamani; +Cc: kbuild-all, rostedt, mingo, linux-kernel, arnd, y2038

[-- Attachment #1: Type: text/plain, Size: 3416 bytes --]

Hi Deepa,

[auto build test WARNING on tip/perf/core]
[also build test WARNING on v4.11-rc4 next-20170327]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url:    https://github.com/0day-ci/linux/commits/Deepa-Dinamani/trace-Make-trace_hwlat-timestamp-y2038-safe/20170327-150010
config: x86_64-randconfig-s2-03271627 (attached as .config)
compiler: gcc-4.4 (Debian 4.4.7-8) 4.4.7
reproduce:
        # save the attached .config to linux build tree
        make ARCH=x86_64 

All warnings (new ones prefixed by >>):

   kernel/trace/trace_output.c: In function 'trace_hwlat_print':
>> kernel/trace/trace_output.c:1168: warning: format '%lld' expects type 'long long int', but argument 6 has type '__kernel_time_t'
   kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
   kernel/trace/trace_output.c:1202: warning: format '%lld' expects type 'long long int', but argument 5 has type '__kernel_time_t'

vim +1168 kernel/trace/trace_output.c

e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1152) /* TRACE_HWLAT */
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1153) static enum print_line_t
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1154) trace_hwlat_print(struct trace_iterator *iter, int flags,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1155) 		  struct trace_event *event)
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1156) {
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1157) 	struct trace_entry *entry = iter->ent;
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1158) 	struct trace_seq *s = &iter->seq;
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1159) 	struct hwlat_entry *field;
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1160) 
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1161) 	trace_assign_type(field, entry);
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1162) 
df001907 Deepa Dinamani           2017-03-26  1163  	trace_seq_printf(s, "#%-5u inner/outer(us): %4llu/%-5llu ts:%lld.%09ld",
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1164) 			 field->seqnum,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1165) 			 field->duration,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1166) 			 field->outer_duration,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1167) 			 field->timestamp.tv_sec,
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23 @1168) 			 field->timestamp.tv_nsec);
e7c15cd8 Steven Rostedt (Red Hat  2016-06-23  1169) 
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1170) 	if (field->nmi_count) {
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1171) 		/*
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1172) 		 * The generic sched_clock() is not NMI safe, thus
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1173) 		 * we only record the count and not the time.
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1174) 		 */
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1175) 		if (!IS_ENABLED(CONFIG_GENERIC_SCHED_CLOCK))
7b2c8625 Steven Rostedt (Red Hat  2016-08-04  1176) 			trace_seq_printf(s, " nmi-total:%llu",

:::::: The code at line 1168 was first introduced by commit
:::::: e7c15cd8a113335cf7154f027c9c8da1a92238ee tracing: Added hardware latency tracer

:::::: TO: Steven Rostedt (Red Hat) <rostedt@goodmis.org>
:::::: CC: Steven Rostedt <rostedt@goodmis.org>

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all                   Intel Corporation

[-- Attachment #2: .config.gz --]
[-- Type: application/gzip, Size: 24241 bytes --]

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-25 13:20       ` Rafael J. Wysocki
@ 2017-03-27 14:08         ` Josh Poimboeuf
  2017-03-27 14:54           ` [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram Josh Poimboeuf
  2017-03-27 16:59           ` [PATCH] acpi: fix incompatibility with mcount-based function graph tracing Rafael J. Wysocki
  0 siblings, 2 replies; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-27 14:08 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Steven Rostedt, Paul Menzel, Len Brown, linux-acpi, linux-kernel,
	Ingo Molnar

On Sat, Mar 25, 2017 at 02:20:11PM +0100, Rafael J. Wysocki wrote:
> On Friday, March 24, 2017 02:41:14 PM Steven Rostedt wrote:
> > On Fri, 24 Mar 2017 13:12:54 -0500
> > Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > 
> > 
> > > Instead I was able to "fix" it by ignoring ftrace calls in real mode:
> > > 
> > > -----
> > > index 8f3d9cf..5c0d0c6 100644
> > > --- a/arch/x86/kernel/ftrace.c
> > > +++ b/arch/x86/kernel/ftrace.c
> > > @@ -983,6 +983,9 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
> > >  	unsigned long return_hooker = (unsigned long)
> > >  				&return_to_handler;
> > >  
> > > +	if (__builtin_return_address(0) < TASK_SIZE_MAX)
> > > +		return;
> > > +
> > >  	if (unlikely(ftrace_graph_is_dead()))
> > >  		return;
> > > ---------------
> > > 
> > > I'm not sure what the best fix should really be.  A few ideas off the
> > > top of my head:
> > > 
> > > - A real mode check similar to the above (except it should probably be
> > >   more precise)
> > 
> > The real mode check hack may be good enough for now. Make sure that
> > it's commented well.
> 
> Agreed.

Just to clarify, there are two bugs related to function graph tracing
and suspend/resume.  The original patch in this thread (which removes
'-Os' from the acpi Makefile) is still needed.

-- 
Josh

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27  9:55   ` Arnd Bergmann
@ 2017-03-27 14:28     ` Steven Rostedt
  2017-03-27 14:53       ` Arnd Bergmann
  0 siblings, 1 reply; 30+ messages in thread
From: Steven Rostedt @ 2017-03-27 14:28 UTC (permalink / raw)
  To: Arnd Bergmann
  Cc: kbuild test robot, Deepa Dinamani, kbuild-all, Ingo Molnar,
	Linux Kernel Mailing List, y2038 Mailman List

On Mon, 27 Mar 2017 11:55:52 +0200
Arnd Bergmann <arnd@arndb.de> wrote:

> On Mon, Mar 27, 2017 at 11:25 AM, kbuild test robot <lkp@intel.com> wrote:
> > Hi Deepa,
> >
> > [auto build test WARNING on tip/perf/core]
> > [also build test WARNING on v4.11-rc4 next-20170327]
> > [if your patch is applied to the wrong git tree, please drop us a note to help improve the system]
> >
> > url:    https://github.com/0day-ci/linux/commits/Deepa-Dinamani/trace-Make-trace_hwlat-timestamp-y2038-safe/20170327-150010
> > config: x86_64-randconfig-n0-03271517 (attached as .config)
> > compiler: gcc-4.8 (Debian 4.8.4-1) 4.8.4
> > reproduce:
> >         # save the attached .config to linux build tree
> >         make ARCH=x86_64
> >
> > All warnings (new ones prefixed by >>):
> >
> >    kernel/trace/trace_output.c: In function 'trace_hwlat_print':  
> >>> kernel/trace/trace_output.c:1168:5: warning: format '%lld' expects argument of type 'long long int', but argument 6 has type '__kernel_time_t' [-Wformat=]  
> >         field->timestamp.tv_nsec);  
> 
> This happens on 64-bit architectures because 'struct timespec64' is defined to
> be equal to 'struct timespec', which has a 'long' tv_sec rather than
> 'long long'.
> 
> A cast to 's64' is probably the best workaround.
> 
> >    kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
> >    kernel/trace/trace_output.c:1202:5: warning: format '%lld' expects argument of type 'long long int', but argument 5 has type '__kernel_time_t' [-Wformat=]
> >         field->seqnum);  
> 
> Same here.
> 

Actually, I believe that "%zd" will work. It's made to work with size_t
which is long long on 32 and long on 64.

-- Steve

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27 14:28     ` Steven Rostedt
@ 2017-03-27 14:53       ` Arnd Bergmann
  2017-03-27 15:30         ` Steven Rostedt
  2017-03-27 21:02         ` Deepa Dinamani
  0 siblings, 2 replies; 30+ messages in thread
From: Arnd Bergmann @ 2017-03-27 14:53 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: kbuild test robot, Deepa Dinamani, kbuild-all, Ingo Molnar,
	Linux Kernel Mailing List, y2038 Mailman List

On Mon, Mar 27, 2017 at 4:28 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Mon, 27 Mar 2017 11:55:52 +0200
> Arnd Bergmann <arnd@arndb.de> wrote:
>
>> On Mon, Mar 27, 2017 at 11:25 AM, kbuild test robot <lkp@intel.com> wrote:
>> > Hi Deepa,
>> >
>> > [auto build test WARNING on tip/perf/core]
>> > [also build test WARNING on v4.11-rc4 next-20170327]
>> > [if your patch is applied to the wrong git tree, please drop us a note to help improve the system]
>> >
>> > url:    https://github.com/0day-ci/linux/commits/Deepa-Dinamani/trace-Make-trace_hwlat-timestamp-y2038-safe/20170327-150010
>> > config: x86_64-randconfig-n0-03271517 (attached as .config)
>> > compiler: gcc-4.8 (Debian 4.8.4-1) 4.8.4
>> > reproduce:
>> >         # save the attached .config to linux build tree
>> >         make ARCH=x86_64
>> >
>> > All warnings (new ones prefixed by >>):
>> >
>> >    kernel/trace/trace_output.c: In function 'trace_hwlat_print':
>> >>> kernel/trace/trace_output.c:1168:5: warning: format '%lld' expects argument of type 'long long int', but argument 6 has type '__kernel_time_t' [-Wformat=]
>> >         field->timestamp.tv_nsec);
>>
>> This happens on 64-bit architectures because 'struct timespec64' is defined to
>> be equal to 'struct timespec', which has a 'long' tv_sec rather than
>> 'long long'.
>>
>> A cast to 's64' is probably the best workaround.
>>
>> >    kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
>> >    kernel/trace/trace_output.c:1202:5: warning: format '%lld' expects argument of type 'long long int', but argument 5 has type '__kernel_time_t' [-Wformat=]
>> >         field->seqnum);
>>
>> Same here.
>>
>
> Actually, I believe that "%zd" will work. It's made to work with size_t
> which is long long on 32 and long on 64.

size_t is always 'long', not 'long long'. We have %pad for dma_addr_t
which may be 'long' or 'long long', but it is configuration dependent
which one it is on 32-bit.

We could probably introduce a %pts format string for timespec64
and have that pretty-printed.

         Arnd

^ permalink raw reply	[flat|nested] 30+ messages in thread

* [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-27 14:08         ` Josh Poimboeuf
@ 2017-03-27 14:54           ` Josh Poimboeuf
  2017-03-27 15:01             ` Paul Menzel
  2017-03-27 16:59           ` [PATCH] acpi: fix incompatibility with mcount-based function graph tracing Rafael J. Wysocki
  1 sibling, 1 reply; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-27 14:54 UTC (permalink / raw)
  To: Steven Rostedt, Ingo Molnar
  Cc: Paul Menzel, Len Brown, linux-acpi, linux-kernel, x86,
	Borislav Petkov, Rafael J. Wysocki

On x86-32, with CONFIG_FIRMWARE and multiple CPUs, if you enable
function graph tracing and then suspend to RAM, it will triple fault and
reboot when it resumes.

The first fault happens when booting a secondary CPU:

startup_32_smp()
  load_ucode_ap()
    prepare_ftrace_return()
      ftrace_graph_is_dead()
        (accesses 'kill_ftrace_graph')

The early head_32.S code calls into load_ucode_ap(), which has an an
ftrace hook, so it calls prepare_ftrace_return(), which calls
ftrace_graph_is_dead(), which tries to access the global
'kill_ftrace_graph' variable with a virtual address, causing a fault
because the CPU is still in real mode.

The fix is to add a check in prepare_ftrace_return() to make sure it's
running in protected mode before continuing.  The check makes sure the
stack pointer is a virtual kernel address.  It's a bit of a hack, but
it's not very intrusive and it works well enough.

For reference, here are a few other ways this could have potentially
been fixed:

- Move startup_32_smp()'s call to load_ucode_ap() down to *after* paging
  is enabled.  (No idea what that would break.)

- Track down load_ucode_ap()'s entire callee tree and mark all the
  functions 'notrace'.  (Probably not realistic.)

- Pause graph tracing in ftrace_suspend_notifier_call() or bringup_cpu()
  or __cpu_up(), and ensure that the pause facility can be queried from
  real mode.

Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 arch/x86/kernel/ftrace.c | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/arch/x86/kernel/ftrace.c b/arch/x86/kernel/ftrace.c
index 8f3d9cf..1c5c4e2 100644
--- a/arch/x86/kernel/ftrace.c
+++ b/arch/x86/kernel/ftrace.c
@@ -983,6 +983,17 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
 	unsigned long return_hooker = (unsigned long)
 				&return_to_handler;
 
+	/*
+	 * When resuming from suspend-to-ram, this function can be indirectly
+	 * called from early CPU startup code while the CPU is in real mode,
+	 * which would fail miserably.  Make sure the stack pointer is a
+	 * virtual address.
+	 *
+	 * This check isn't as accurate as virt_addr_valid(), but it should be
+	 * good enough for this purpose, and it's fast.
+	 */
+	if (unlikely((long)__builtin_frame_address(0) >= 0)) return;
+
 	if (unlikely(ftrace_graph_is_dead()))
 		return;
 
-- 
2.7.4


^ permalink raw reply related	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-27 14:54           ` [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram Josh Poimboeuf
@ 2017-03-27 15:01             ` Paul Menzel
  2017-03-27 15:20               ` [PATCH v2] " Josh Poimboeuf
                                 ` (2 more replies)
  0 siblings, 3 replies; 30+ messages in thread
From: Paul Menzel @ 2017-03-27 15:01 UTC (permalink / raw)
  To: Josh Poimboeuf, Steven Rostedt, Ingo Molnar
  Cc: Len Brown, linux-acpi, linux-kernel, x86, Borislav Petkov,
	Rafael J. Wysocki

Dear Josh,


On 03/27/17 16:54, Josh Poimboeuf wrote:
> On x86-32, with CONFIG_FIRMWARE and multiple CPUs, if you enable
> function graph tracing and then suspend to RAM, it will triple fault and
> reboot when it resumes.
>
> The first fault happens when booting a secondary CPU:
>
> startup_32_smp()
>   load_ucode_ap()
>     prepare_ftrace_return()
>       ftrace_graph_is_dead()
>         (accesses 'kill_ftrace_graph')
>
> The early head_32.S code calls into load_ucode_ap(), which has an an
> ftrace hook, so it calls prepare_ftrace_return(), which calls
> ftrace_graph_is_dead(), which tries to access the global
> 'kill_ftrace_graph' variable with a virtual address, causing a fault
> because the CPU is still in real mode.
>
> The fix is to add a check in prepare_ftrace_return() to make sure it's
> running in protected mode before continuing.  The check makes sure the
> stack pointer is a virtual kernel address.  It's a bit of a hack, but
> it's not very intrusive and it works well enough.
>
> For reference, here are a few other ways this could have potentially
> been fixed:
>
> - Move startup_32_smp()'s call to load_ucode_ap() down to *after* paging
>   is enabled.  (No idea what that would break.)
>
> - Track down load_ucode_ap()'s entire callee tree and mark all the
>   functions 'notrace'.  (Probably not realistic.)
>
> - Pause graph tracing in ftrace_suspend_notifier_call() or bringup_cpu()
>   or __cpu_up(), and ensure that the pause facility can be queried from
>   real mode.
>
> Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
> Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
> ---
>  arch/x86/kernel/ftrace.c | 11 +++++++++++
>  1 file changed, 11 insertions(+)

Thank you for debugging this. It’s great that you were able to reproduce 
this in QEMU. Hopefully, that’ll make for an easy test case. ;-)

> diff --git a/arch/x86/kernel/ftrace.c b/arch/x86/kernel/ftrace.c
> index 8f3d9cf..1c5c4e2 100644
> --- a/arch/x86/kernel/ftrace.c
> +++ b/arch/x86/kernel/ftrace.c
> @@ -983,6 +983,17 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
>  	unsigned long return_hooker = (unsigned long)
>  				&return_to_handler;
>
> +	/*
> +	 * When resuming from suspend-to-ram, this function can be indirectly
> +	 * called from early CPU startup code while the CPU is in real mode,
> +	 * which would fail miserably.  Make sure the stack pointer is a
> +	 * virtual address.
> +	 *
> +	 * This check isn't as accurate as virt_addr_valid(), but it should be
> +	 * good enough for this purpose, and it's fast.
> +	 */
> +	if (unlikely((long)__builtin_frame_address(0) >= 0)) return;

The coding style requires the `return;` to be on a separate line.

> +
>  	if (unlikely(ftrace_graph_is_dead()))
>  		return;

I’ll test your change this evening.


Kind regards,

Paul

^ permalink raw reply	[flat|nested] 30+ messages in thread

* [PATCH v2] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-27 15:01             ` Paul Menzel
@ 2017-03-27 15:20               ` Josh Poimboeuf
  2017-03-27 15:24               ` [PATCH] " Steven Rostedt
  2017-03-28  9:51               ` Paul Menzel
  2 siblings, 0 replies; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-27 15:20 UTC (permalink / raw)
  To: Paul Menzel
  Cc: Steven Rostedt, Ingo Molnar, Len Brown, linux-acpi, linux-kernel,
	x86, Borislav Petkov, Rafael J. Wysocki

On x86-32, with CONFIG_FIRMWARE and multiple CPUs, if you enable
function graph tracing and then suspend to RAM, it will triple fault and
reboot when it resumes.

The first fault happens when booting a secondary CPU:

startup_32_smp()
  load_ucode_ap()
    prepare_ftrace_return()
      ftrace_graph_is_dead()
        (accesses 'kill_ftrace_graph')

The early head_32.S code calls into load_ucode_ap(), which has an an
ftrace hook, so it calls prepare_ftrace_return(), which calls
ftrace_graph_is_dead(), which tries to access the global
'kill_ftrace_graph' variable with a virtual address, causing a fault
because the CPU is still in real mode.

The fix is to add a check in prepare_ftrace_return() to make sure it's
running in protected mode before continuing.  The check makes sure the
stack pointer is a virtual kernel address.  It's a bit of a hack, but
it's not very intrusive and it works well enough.

For reference, here are a few other (more difficult) ways this could
have potentially been fixed:

- Move startup_32_smp()'s call to load_ucode_ap() down to *after* paging
  is enabled.  (No idea what that would break.)

- Track down load_ucode_ap()'s entire callee tree and mark all the
  functions 'notrace'.  (Probably not realistic.)

- Pause graph tracing in ftrace_suspend_notifier_call() or bringup_cpu()
  or __cpu_up(), and ensure that the pause facility can be queried from
  real mode.

Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
v2:
- put return statement on its own line

 arch/x86/kernel/ftrace.c | 12 ++++++++++++
 1 file changed, 12 insertions(+)

diff --git a/arch/x86/kernel/ftrace.c b/arch/x86/kernel/ftrace.c
index 8f3d9cf..5b71535 100644
--- a/arch/x86/kernel/ftrace.c
+++ b/arch/x86/kernel/ftrace.c
@@ -983,6 +983,18 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
 	unsigned long return_hooker = (unsigned long)
 				&return_to_handler;
 
+	/*
+	 * When resuming from suspend-to-ram, this function can be indirectly
+	 * called from early CPU startup code while the CPU is in real mode,
+	 * which would fail miserably.  Make sure the stack pointer is a
+	 * virtual address.
+	 *
+	 * This check isn't as accurate as virt_addr_valid(), but it should be
+	 * good enough for this purpose, and it's fast.
+	 */
+	if (unlikely((long)__builtin_frame_address(0) >= 0))
+		return;
+
 	if (unlikely(ftrace_graph_is_dead()))
 		return;
 
-- 
2.7.4


^ permalink raw reply related	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-27 15:01             ` Paul Menzel
  2017-03-27 15:20               ` [PATCH v2] " Josh Poimboeuf
@ 2017-03-27 15:24               ` Steven Rostedt
  2017-03-28  9:51               ` Paul Menzel
  2 siblings, 0 replies; 30+ messages in thread
From: Steven Rostedt @ 2017-03-27 15:24 UTC (permalink / raw)
  To: Paul Menzel
  Cc: Josh Poimboeuf, Ingo Molnar, Len Brown, linux-acpi, linux-kernel,
	x86, Borislav Petkov, Rafael J. Wysocki

On Mon, 27 Mar 2017 17:01:53 +0200
Paul Menzel <pmenzel@molgen.mpg.de> wrote:

> > +	/*
> > +	 * When resuming from suspend-to-ram, this function can be indirectly
> > +	 * called from early CPU startup code while the CPU is in real mode,
> > +	 * which would fail miserably.  Make sure the stack pointer is a
> > +	 * virtual address.
> > +	 *
> > +	 * This check isn't as accurate as virt_addr_valid(), but it should be
> > +	 * good enough for this purpose, and it's fast.
> > +	 */
> > +	if (unlikely((long)__builtin_frame_address(0) >= 0)) return;  
> 
> The coding style requires the `return;` to be on a separate line.

Correct, and new versions of a patch should always start a new thread
(unless it's a single update of a patch in a long patch series).
Otherwise they get ignored. (hint hint)

-- Steve



> 
> > +
> >  	if (unlikely(ftrace_graph_is_dead()))
> >  		return;  
> 

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27 14:53       ` Arnd Bergmann
@ 2017-03-27 15:30         ` Steven Rostedt
  2017-03-27 15:35           ` Arnd Bergmann
  2017-03-27 21:02         ` Deepa Dinamani
  1 sibling, 1 reply; 30+ messages in thread
From: Steven Rostedt @ 2017-03-27 15:30 UTC (permalink / raw)
  To: Arnd Bergmann
  Cc: Paul Menzel, Len Brown, linux-acpi, linux-kernel, x86,
	Borislav Petkov, Rafael J. Wysocki

On Mon, 27 Mar 2017 16:53:09 +0200
Arnd Bergmann <arnd@arndb.de> wrote:


> > Actually, I believe that "%zd" will work. It's made to work with size_t
> > which is long long on 32 and long on 64.  
> 
> size_t is always 'long', not 'long long'. We have %pad for dma_addr_t
> which may be 'long' or 'long long', but it is configuration dependent
> which one it is on 32-bit.

Ah your right. It was that it was defined as "int" on 32 and "long" on
64, and that caused problems with warnings when using "%d" when it was
defined as long.

> 
> We could probably introduce a %pts format string for timespec64
> and have that pretty-printed.

Hmm, probably don't want a %p as that suggests its a pointer, which it
should not be. Unless we pass in the address of the number.

-- Steve

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27 15:30         ` Steven Rostedt
@ 2017-03-27 15:35           ` Arnd Bergmann
  2017-03-27 16:11             ` Steven Rostedt
  0 siblings, 1 reply; 30+ messages in thread
From: Arnd Bergmann @ 2017-03-27 15:35 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Paul Menzel, Len Brown, ACPI Devel Maling List,
	Linux Kernel Mailing List, the arch/x86 maintainers,
	Borislav Petkov, Rafael J. Wysocki

On Mon, Mar 27, 2017 at 5:30 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Mon, 27 Mar 2017 16:53:09 +0200
>> We could probably introduce a %pts format string for timespec64
>> and have that pretty-printed.
>
> Hmm, probably don't want a %p as that suggests its a pointer, which it
> should not be. Unless we pass in the address of the number.

The special format strings that the kernel defines all start with %p and
require passing by reference so we don't get a warning from gcc. We can't
just make up new format strings otherwise, but we can create new meaning
for special pointers as we do for struct resource and others.

       Arnd

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27 15:35           ` Arnd Bergmann
@ 2017-03-27 16:11             ` Steven Rostedt
  0 siblings, 0 replies; 30+ messages in thread
From: Steven Rostedt @ 2017-03-27 16:11 UTC (permalink / raw)
  To: Arnd Bergmann
  Cc: Paul Menzel, Len Brown, ACPI Devel Maling List,
	Linux Kernel Mailing List, the arch/x86 maintainers,
	Borislav Petkov, Rafael J. Wysocki

On Mon, 27 Mar 2017 17:35:13 +0200
Arnd Bergmann <arnd@arndb.de> wrote:

> On Mon, Mar 27, 2017 at 5:30 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
> > On Mon, 27 Mar 2017 16:53:09 +0200  
> >> We could probably introduce a %pts format string for timespec64
> >> and have that pretty-printed.  
> >
> > Hmm, probably don't want a %p as that suggests its a pointer, which it
> > should not be. Unless we pass in the address of the number.  
> 
> The special format strings that the kernel defines all start with %p and
> require passing by reference so we don't get a warning from gcc. We can't
> just make up new format strings otherwise, but we can create new meaning
> for special pointers as we do for struct resource and others.
> 

That's fine, but we need to be careful when it comes to tracing.
Passing in the address of a structure in the ring buffer may be fine,
but we need to make sure that an address pointing to something other
than the ring buffer is forbidden.

I'll need to update libtraceevent to handle such cases too.

-- Steve

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] acpi: fix incompatibility with mcount-based function graph tracing
  2017-03-27 14:08         ` Josh Poimboeuf
  2017-03-27 14:54           ` [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram Josh Poimboeuf
@ 2017-03-27 16:59           ` Rafael J. Wysocki
  1 sibling, 0 replies; 30+ messages in thread
From: Rafael J. Wysocki @ 2017-03-27 16:59 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Steven Rostedt, Paul Menzel, Len Brown, linux-acpi, linux-kernel,
	Ingo Molnar

On Monday, March 27, 2017 09:08:43 AM Josh Poimboeuf wrote:
> On Sat, Mar 25, 2017 at 02:20:11PM +0100, Rafael J. Wysocki wrote:
> > On Friday, March 24, 2017 02:41:14 PM Steven Rostedt wrote:
> > > On Fri, 24 Mar 2017 13:12:54 -0500
> > > Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > > 
> > > 
> > > > Instead I was able to "fix" it by ignoring ftrace calls in real mode:
> > > > 
> > > > -----
> > > > index 8f3d9cf..5c0d0c6 100644
> > > > --- a/arch/x86/kernel/ftrace.c
> > > > +++ b/arch/x86/kernel/ftrace.c
> > > > @@ -983,6 +983,9 @@ void prepare_ftrace_return(unsigned long self_addr, unsigned long *parent,
> > > >  	unsigned long return_hooker = (unsigned long)
> > > >  				&return_to_handler;
> > > >  
> > > > +	if (__builtin_return_address(0) < TASK_SIZE_MAX)
> > > > +		return;
> > > > +
> > > >  	if (unlikely(ftrace_graph_is_dead()))
> > > >  		return;
> > > > ---------------
> > > > 
> > > > I'm not sure what the best fix should really be.  A few ideas off the
> > > > top of my head:
> > > > 
> > > > - A real mode check similar to the above (except it should probably be
> > > >   more precise)
> > > 
> > > The real mode check hack may be good enough for now. Make sure that
> > > it's commented well.
> > 
> > Agreed.
> 
> Just to clarify, there are two bugs related to function graph tracing
> and suspend/resume.  The original patch in this thread (which removes
> '-Os' from the acpi Makefile) is still needed.

OK

Thanks,
Rafael


^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27 14:53       ` Arnd Bergmann
  2017-03-27 15:30         ` Steven Rostedt
@ 2017-03-27 21:02         ` Deepa Dinamani
  2017-03-28  7:26           ` Arnd Bergmann
  1 sibling, 1 reply; 30+ messages in thread
From: Deepa Dinamani @ 2017-03-27 21:02 UTC (permalink / raw)
  To: Arnd Bergmann
  Cc: Steven Rostedt, kbuild test robot, kbuild-all, Ingo Molnar,
	Linux Kernel Mailing List, y2038 Mailman List

>>> >
>>> >    kernel/trace/trace_output.c: In function 'trace_hwlat_print':
>>> >>> kernel/trace/trace_output.c:1168:5: warning: format '%lld' expects argument of type 'long long int', but argument 6 has type '__kernel_time_t' [-Wformat=]
>>> >         field->timestamp.tv_nsec);
>>>
>>> This happens on 64-bit architectures because 'struct timespec64' is defined to
>>> be equal to 'struct timespec', which has a 'long' tv_sec rather than
>>> 'long long'.
>>>
>>> A cast to 's64' is probably the best workaround.

We have been using long long cast to print timespec64 tv_sec.

I'm not sure what format specifier we would use if we cast to s64.
printk-formats suggests %lld or %llx.
Meaning a cast to long long.

>>>
>>> >    kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
>>> >    kernel/trace/trace_output.c:1202:5: warning: format '%lld' expects argument of type 'long long int', but argument 5 has type '__kernel_time_t' [-Wformat=]
>>> >         field->seqnum);
>>>
>>> Same here.
>>>
>>
>> Actually, I believe that "%zd" will work. It's made to work with size_t
>> which is long long on 32 and long on 64.
>
> size_t is always 'long', not 'long long'. We have %pad for dma_addr_t
> which may be 'long' or 'long long', but it is configuration dependent
> which one it is on 32-bit.
>
> We could probably introduce a %pts format string for timespec64
> and have that pretty-printed.

dma_addr_t can be u64 or u32 based on architecture be it 32 bit or 64 bit.
But, timespec64 tv_sec is always s64. This is the opposite problem
from dma_addr_t that it is 64 bits regardless of architecture.
So, wouldn't it be easier to use long long cast for tv_sec and then
print tv_nsec as long?

-Deepa

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] trace: Make trace_hwlat timestamp y2038 safe
  2017-03-27 21:02         ` Deepa Dinamani
@ 2017-03-28  7:26           ` Arnd Bergmann
  0 siblings, 0 replies; 30+ messages in thread
From: Arnd Bergmann @ 2017-03-28  7:26 UTC (permalink / raw)
  To: Deepa Dinamani
  Cc: Steven Rostedt, kbuild test robot, kbuild-all, Ingo Molnar,
	Linux Kernel Mailing List, y2038 Mailman List

On Mon, Mar 27, 2017 at 11:02 PM, Deepa Dinamani <deepa.kernel@gmail.com> wrote:
>>>> >
>>>> >    kernel/trace/trace_output.c: In function 'trace_hwlat_print':
>>>> >>> kernel/trace/trace_output.c:1168:5: warning: format '%lld' expects argument of type 'long long int', but argument 6 has type '__kernel_time_t' [-Wformat=]
>>>> >         field->timestamp.tv_nsec);
>>>>
>>>> This happens on 64-bit architectures because 'struct timespec64' is defined to
>>>> be equal to 'struct timespec', which has a 'long' tv_sec rather than
>>>> 'long long'.
>>>>
>>>> A cast to 's64' is probably the best workaround.
>
> We have been using long long cast to print timespec64 tv_sec.
>
> I'm not sure what format specifier we would use if we cast to s64.
> printk-formats suggests %lld or %llx.
> Meaning a cast to long long.

Right, s64 is alway 'long long'. Out of the two, the former feels
more natural as we normally count seconds in decimal.

>>>>
>>>> >    kernel/trace/trace_output.c: In function 'trace_hwlat_raw':
>>>> >    kernel/trace/trace_output.c:1202:5: warning: format '%lld' expects argument of type 'long long int', but argument 5 has type '__kernel_time_t' [-Wformat=]
>>>> >         field->seqnum);
>>>>
>>>> Same here.
>>>>
>>>
>>> Actually, I believe that "%zd" will work. It's made to work with size_t
>>> which is long long on 32 and long on 64.
>>
>> size_t is always 'long', not 'long long'. We have %pad for dma_addr_t
>> which may be 'long' or 'long long', but it is configuration dependent
>> which one it is on 32-bit.
>>
>> We could probably introduce a %pts format string for timespec64
>> and have that pretty-printed.
>
> dma_addr_t can be u64 or u32 based on architecture be it 32 bit or 64 bit.
> But, timespec64 tv_sec is always s64. This is the opposite problem
> from dma_addr_t that it is 64 bits regardless of architecture.
> So, wouldn't it be easier to use long long cast for tv_sec and then
> print tv_nsec as long?

The cast is clearly easier for this one instance, and that's what we should
do here.

Generally speaking I think it would be nice to have have a way to print
a timespec64 and I thought it would also address this instance but as
Steve pointed out, we can't print objects by reference in trace output
without duplicating the logic there, so let's not go there now.

      Arnd

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-27 15:01             ` Paul Menzel
  2017-03-27 15:20               ` [PATCH v2] " Josh Poimboeuf
  2017-03-27 15:24               ` [PATCH] " Steven Rostedt
@ 2017-03-28  9:51               ` Paul Menzel
  2017-03-28 15:39                 ` Steven Rostedt
  2 siblings, 1 reply; 30+ messages in thread
From: Paul Menzel @ 2017-03-28  9:51 UTC (permalink / raw)
  To: Josh Poimboeuf, Steven Rostedt, Ingo Molnar
  Cc: Len Brown, linux-acpi, linux-kernel, x86, Borislav Petkov,
	Rafael J. Wysocki

Dear Josh,


On 03/27/17 17:01, Paul Menzel wrote:

> On 03/27/17 16:54, Josh Poimboeuf wrote:
>> On x86-32, with CONFIG_FIRMWARE and multiple CPUs, if you enable
>> function graph tracing and then suspend to RAM, it will triple fault and
>> reboot when it resumes.
>>
>> The first fault happens when booting a secondary CPU:
>>
>> startup_32_smp()
>>   load_ucode_ap()
>>     prepare_ftrace_return()
>>       ftrace_graph_is_dead()
>>         (accesses 'kill_ftrace_graph')
>>
>> The early head_32.S code calls into load_ucode_ap(), which has an an
>> ftrace hook, so it calls prepare_ftrace_return(), which calls
>> ftrace_graph_is_dead(), which tries to access the global
>> 'kill_ftrace_graph' variable with a virtual address, causing a fault
>> because the CPU is still in real mode.
>>
>> The fix is to add a check in prepare_ftrace_return() to make sure it's
>> running in protected mode before continuing.  The check makes sure the
>> stack pointer is a virtual kernel address.  It's a bit of a hack, but
>> it's not very intrusive and it works well enough.
>>
>> For reference, here are a few other ways this could have potentially
>> been fixed:
>>
>> - Move startup_32_smp()'s call to load_ucode_ap() down to *after* paging
>>   is enabled.  (No idea what that would break.)
>>
>> - Track down load_ucode_ap()'s entire callee tree and mark all the
>>   functions 'notrace'.  (Probably not realistic.)
>>
>> - Pause graph tracing in ftrace_suspend_notifier_call() or bringup_cpu()
>>   or __cpu_up(), and ensure that the pause facility can be queried from
>>   real mode.
>>
>> Reported-by: Paul Menzel <pmenzel@molgen.mpg.de>
>> Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
>> ---
>>  arch/x86/kernel/ftrace.c | 11 +++++++++++
>>  1 file changed, 11 insertions(+)
>
> Thank you for debugging this. It’s great that you were able to reproduce
> this in QEMU. Hopefully, that’ll make for an easy test case. ;-)
>
>> diff --git a/arch/x86/kernel/ftrace.c b/arch/x86/kernel/ftrace.c
>> index 8f3d9cf..1c5c4e2 100644
>> --- a/arch/x86/kernel/ftrace.c
>> +++ b/arch/x86/kernel/ftrace.c
>> @@ -983,6 +983,17 @@ void prepare_ftrace_return(unsigned long
>> self_addr, unsigned long *parent,
>>      unsigned long return_hooker = (unsigned long)
>>                  &return_to_handler;
>>
>> +    /*
>> +     * When resuming from suspend-to-ram, this function can be
>> indirectly
>> +     * called from early CPU startup code while the CPU is in real mode,
>> +     * which would fail miserably.  Make sure the stack pointer is a
>> +     * virtual address.
>> +     *
>> +     * This check isn't as accurate as virt_addr_valid(), but it
>> should be
>> +     * good enough for this purpose, and it's fast.
>> +     */
>> +    if (unlikely((long)__builtin_frame_address(0) >= 0)) return;
>
> The coding style requires the `return;` to be on a separate line.
>
>> +
>>      if (unlikely(ftrace_graph_is_dead()))
>>          return;
>
> I’ll test your change this evening.

With both patches applied `./analyze_suspend.py -config 
suspend-callgraph.cfg -filter i915` succeeds on a Lenovo X60t, so 
suspend and resume work perfectly, when tracing is enabled.

Tested-by: Paul Menzel <pmenzel@molgen.mpg.de>

It’d be awesome, if you could tag both patches for inclusion into the 
stable Linux Kernel series.


Kind regards,

Paul

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-28  9:51               ` Paul Menzel
@ 2017-03-28 15:39                 ` Steven Rostedt
  2017-03-28 15:55                   ` Josh Poimboeuf
  0 siblings, 1 reply; 30+ messages in thread
From: Steven Rostedt @ 2017-03-28 15:39 UTC (permalink / raw)
  To: Paul Menzel
  Cc: Josh Poimboeuf, Ingo Molnar, Len Brown, linux-acpi, linux-kernel,
	x86, Borislav Petkov, Rafael J. Wysocki

On Tue, 28 Mar 2017 11:51:45 +0200
Paul Menzel <pmenzel@molgen.mpg.de> wrote:

> With both patches applied `./analyze_suspend.py -config 
> suspend-callgraph.cfg -filter i915` succeeds on a Lenovo X60t, so 
> suspend and resume work perfectly, when tracing is enabled.
> 
> Tested-by: Paul Menzel <pmenzel@molgen.mpg.de>
> 
> It’d be awesome, if you could tag both patches for inclusion into the 
> stable Linux Kernel series.

As long as they are not dependent on my patch series, I'm fine with
these going to stable.

-- Steve

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-28 15:39                 ` Steven Rostedt
@ 2017-03-28 15:55                   ` Josh Poimboeuf
  2017-03-28 21:12                     ` Rafael J. Wysocki
  0 siblings, 1 reply; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-28 15:55 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Paul Menzel, Ingo Molnar, Len Brown, linux-acpi, linux-kernel,
	x86, Borislav Petkov, Rafael J. Wysocki

On Tue, Mar 28, 2017 at 11:39:41AM -0400, Steven Rostedt wrote:
> On Tue, 28 Mar 2017 11:51:45 +0200
> Paul Menzel <pmenzel@molgen.mpg.de> wrote:
> 
> > With both patches applied `./analyze_suspend.py -config 
> > suspend-callgraph.cfg -filter i915` succeeds on a Lenovo X60t, so 
> > suspend and resume work perfectly, when tracing is enabled.
> > 
> > Tested-by: Paul Menzel <pmenzel@molgen.mpg.de>
> > 
> > It’d be awesome, if you could tag both patches for inclusion into the 
> > stable Linux Kernel series.
> 
> As long as they are not dependent on my patch series, I'm fine with
> these going to stable.

Stable sounds fine to me too.  Both patches are independent of your
x86-32 fentry patch set.

-- 
Josh

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-28 15:55                   ` Josh Poimboeuf
@ 2017-03-28 21:12                     ` Rafael J. Wysocki
  2017-03-28 21:42                       ` Josh Poimboeuf
  0 siblings, 1 reply; 30+ messages in thread
From: Rafael J. Wysocki @ 2017-03-28 21:12 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Steven Rostedt, Paul Menzel, Ingo Molnar, Len Brown, linux-acpi,
	linux-kernel, x86, Borislav Petkov

On Tuesday, March 28, 2017 10:55:46 AM Josh Poimboeuf wrote:
> On Tue, Mar 28, 2017 at 11:39:41AM -0400, Steven Rostedt wrote:
> > On Tue, 28 Mar 2017 11:51:45 +0200
> > Paul Menzel <pmenzel@molgen.mpg.de> wrote:
> > 
> > > With both patches applied `./analyze_suspend.py -config 
> > > suspend-callgraph.cfg -filter i915` succeeds on a Lenovo X60t, so 
> > > suspend and resume work perfectly, when tracing is enabled.
> > > 
> > > Tested-by: Paul Menzel <pmenzel@molgen.mpg.de>
> > > 
> > > It’d be awesome, if you could tag both patches for inclusion into the 
> > > stable Linux Kernel series.
> > 
> > As long as they are not dependent on my patch series, I'm fine with
> > these going to stable.
> 
> Stable sounds fine to me too.  Both patches are independent of your
> x86-32 fentry patch set.

Does https://patchwork.kernel.org/patch/9628301/ need to go into any particular
-stable series or just all of them?

Or should a Fixes: tag be added to it?

Thanks,
Rafael


^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-28 21:12                     ` Rafael J. Wysocki
@ 2017-03-28 21:42                       ` Josh Poimboeuf
  2017-03-28 21:47                         ` Rafael J. Wysocki
  0 siblings, 1 reply; 30+ messages in thread
From: Josh Poimboeuf @ 2017-03-28 21:42 UTC (permalink / raw)
  To: Rafael J. Wysocki
  Cc: Steven Rostedt, Paul Menzel, Ingo Molnar, Len Brown, linux-acpi,
	linux-kernel, x86, Borislav Petkov

On Tue, Mar 28, 2017 at 11:12:42PM +0200, Rafael J. Wysocki wrote:
> On Tuesday, March 28, 2017 10:55:46 AM Josh Poimboeuf wrote:
> > On Tue, Mar 28, 2017 at 11:39:41AM -0400, Steven Rostedt wrote:
> > > On Tue, 28 Mar 2017 11:51:45 +0200
> > > Paul Menzel <pmenzel@molgen.mpg.de> wrote:
> > > 
> > > > With both patches applied `./analyze_suspend.py -config 
> > > > suspend-callgraph.cfg -filter i915` succeeds on a Lenovo X60t, so 
> > > > suspend and resume work perfectly, when tracing is enabled.
> > > > 
> > > > Tested-by: Paul Menzel <pmenzel@molgen.mpg.de>
> > > > 
> > > > It’d be awesome, if you could tag both patches for inclusion into the 
> > > > stable Linux Kernel series.
> > > 
> > > As long as they are not dependent on my patch series, I'm fine with
> > > these going to stable.
> > 
> > Stable sounds fine to me too.  Both patches are independent of your
> > x86-32 fentry patch set.
> 
> Does https://patchwork.kernel.org/patch/9628301/ need to go into any particular
> -stable series or just all of them?
> 
> Or should a Fixes: tag be added to it?

As far as I can tell this issue has been around since the function_graph
tracer was introduced in 2008:

  15e6cb3673ea ("tracing: add a tracer to catch execution time of kernel functions")

(Though only for gcc >= 4.4.)

Not sure if it's overkill to specify 'Fixes' for an 8+ year old bug?  I
guess it can't hurt anything.

I think it can go in all of the stable branches.

-- 
Josh

^ permalink raw reply	[flat|nested] 30+ messages in thread

* Re: [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram
  2017-03-28 21:42                       ` Josh Poimboeuf
@ 2017-03-28 21:47                         ` Rafael J. Wysocki
  0 siblings, 0 replies; 30+ messages in thread
From: Rafael J. Wysocki @ 2017-03-28 21:47 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Steven Rostedt, Paul Menzel, Ingo Molnar, Len Brown, linux-acpi,
	linux-kernel, x86, Borislav Petkov

On Tuesday, March 28, 2017 04:42:18 PM Josh Poimboeuf wrote:
> On Tue, Mar 28, 2017 at 11:12:42PM +0200, Rafael J. Wysocki wrote:
> > On Tuesday, March 28, 2017 10:55:46 AM Josh Poimboeuf wrote:
> > > On Tue, Mar 28, 2017 at 11:39:41AM -0400, Steven Rostedt wrote:
> > > > On Tue, 28 Mar 2017 11:51:45 +0200
> > > > Paul Menzel <pmenzel@molgen.mpg.de> wrote:
> > > > 
> > > > > With both patches applied `./analyze_suspend.py -config 
> > > > > suspend-callgraph.cfg -filter i915` succeeds on a Lenovo X60t, so 
> > > > > suspend and resume work perfectly, when tracing is enabled.
> > > > > 
> > > > > Tested-by: Paul Menzel <pmenzel@molgen.mpg.de>
> > > > > 
> > > > > It’d be awesome, if you could tag both patches for inclusion into the 
> > > > > stable Linux Kernel series.
> > > > 
> > > > As long as they are not dependent on my patch series, I'm fine with
> > > > these going to stable.
> > > 
> > > Stable sounds fine to me too.  Both patches are independent of your
> > > x86-32 fentry patch set.
> > 
> > Does https://patchwork.kernel.org/patch/9628301/ need to go into any particular
> > -stable series or just all of them?
> > 
> > Or should a Fixes: tag be added to it?
> 
> As far as I can tell this issue has been around since the function_graph
> tracer was introduced in 2008:
> 
>   15e6cb3673ea ("tracing: add a tracer to catch execution time of kernel functions")
> 
> (Though only for gcc >= 4.4.)
> 
> Not sure if it's overkill to specify 'Fixes' for an 8+ year old bug?  I
> guess it can't hurt anything.
> 
> I think it can go in all of the stable branches.

OK, thanks!

^ permalink raw reply	[flat|nested] 30+ messages in thread

end of thread, other threads:[~2017-03-28 21:47 UTC | newest]

Thread overview: 30+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-03-16 13:56 [PATCH] acpi: fix incompatibility with mcount-based function graph tracing Josh Poimboeuf
2017-03-16 14:41 ` Steven Rostedt
2017-03-21 20:44 ` Paul Menzel
2017-03-22  0:04   ` Paul Menzel
2017-03-24 18:12   ` Josh Poimboeuf
2017-03-24 18:41     ` Steven Rostedt
2017-03-25 13:20       ` Rafael J. Wysocki
2017-03-27 14:08         ` Josh Poimboeuf
2017-03-27 14:54           ` [PATCH] ftrace/x86: fix x86-32 triple fault with graph tracing and suspend-to-ram Josh Poimboeuf
2017-03-27 15:01             ` Paul Menzel
2017-03-27 15:20               ` [PATCH v2] " Josh Poimboeuf
2017-03-27 15:24               ` [PATCH] " Steven Rostedt
2017-03-28  9:51               ` Paul Menzel
2017-03-28 15:39                 ` Steven Rostedt
2017-03-28 15:55                   ` Josh Poimboeuf
2017-03-28 21:12                     ` Rafael J. Wysocki
2017-03-28 21:42                       ` Josh Poimboeuf
2017-03-28 21:47                         ` Rafael J. Wysocki
2017-03-27 16:59           ` [PATCH] acpi: fix incompatibility with mcount-based function graph tracing Rafael J. Wysocki
2017-03-26 20:57 [PATCH] trace: Make trace_hwlat timestamp y2038 safe Deepa Dinamani
2017-03-27  9:25 ` kbuild test robot
2017-03-27  9:55   ` Arnd Bergmann
2017-03-27 14:28     ` Steven Rostedt
2017-03-27 14:53       ` Arnd Bergmann
2017-03-27 15:30         ` Steven Rostedt
2017-03-27 15:35           ` Arnd Bergmann
2017-03-27 16:11             ` Steven Rostedt
2017-03-27 21:02         ` Deepa Dinamani
2017-03-28  7:26           ` Arnd Bergmann
2017-03-27 10:04 ` kbuild test robot

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.