Peter,
I noticed that you pulled in Seiji's patches into tip. Last night I was
running my test suite on them, and this morning they showed the
following compile bug. I found the fix and attached it below. I pushed
it into my tree that's based on your x86/trace branch, for your
convenience.
My testing also triggered another bug, but I'm not sure it's related to
these patches or something that already existed. I'm currently
investigating it now.
-- Steve
Please pull the latest tip/x86/trace tree, which can be found at:
git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
tip/x86/trace
Head SHA1: 83ab85140bc1492f92de263a1c30ea04a0f465f7
Steven Rostedt (Red Hat) (1):
trace,x86: Move creation of irq tracepoints from apic.c to irq.c
----
arch/x86/kernel/Makefile | 2 ++
arch/x86/kernel/apic/Makefile | 1 -
arch/x86/kernel/apic/apic.c | 4 +---
arch/x86/kernel/irq.c | 2 ++
4 files changed, 5 insertions(+), 4 deletions(-)
---------------------------
commit 83ab85140bc1492f92de263a1c30ea04a0f465f7
Author: Steven Rostedt (Red Hat) <[email protected]>
Date: Fri Jun 21 10:29:05 2013 -0400
trace,x86: Move creation of irq tracepoints from apic.c to irq.c
Compiling without CONFIG_X86_LOCAL_APIC set, apic.c will not be
compiled, and the irq tracepoints will not be created via the
CREATE_TRACE_POINTS macro. When CONFIG_X86_LOCAL_APIC is not set,
we get the following build error:
LD init/built-in.o
arch/x86/built-in.o: In function `trace_x86_platform_ipi_entry':
linux-test.git/arch/x86/include/asm/trace/irq_vectors.h:66: undefined reference to `__tracepoint_x86_platform_ipi_entry'
arch/x86/built-in.o: In function `trace_x86_platform_ipi_exit':
linux-test.git/arch/x86/include/asm/trace/irq_vectors.h:66: undefined reference to `__tracepoint_x86_platform_ipi_exit'
arch/x86/built-in.o: In function `trace_irq_work_entry':
linux-test.git/arch/x86/include/asm/trace/irq_vectors.h:72: undefined reference to `__tracepoint_irq_work_entry'
arch/x86/built-in.o: In function `trace_irq_work_exit':
linux-test.git/arch/x86/include/asm/trace/irq_vectors.h:72: undefined reference to `__tracepoint_irq_work_exit'
arch/x86/built-in.o:(__jump_table+0x8): undefined reference to `__tracepoint_x86_platform_ipi_entry'
arch/x86/built-in.o:(__jump_table+0x14): undefined reference to `__tracepoint_x86_platform_ipi_exit'
arch/x86/built-in.o:(__jump_table+0x20): undefined reference to `__tracepoint_irq_work_entry'
arch/x86/built-in.o:(__jump_table+0x2c): undefined reference to `__tracepoint_irq_work_exit'
make[1]: *** [vmlinux] Error 1
make: *** [sub-make] Error 2
As irq.c is always compiled for x86, it is a more appropriate location
to create the irq tracepoints.
Cc: Seiji Aguchi <[email protected]>
Signed-off-by: Steven Rostedt <[email protected]>
diff --git a/arch/x86/kernel/Makefile b/arch/x86/kernel/Makefile
index 74b3891a..44e763f 100644
--- a/arch/x86/kernel/Makefile
+++ b/arch/x86/kernel/Makefile
@@ -16,6 +16,8 @@ CFLAGS_REMOVE_ftrace.o = -pg
CFLAGS_REMOVE_early_printk.o = -pg
endif
+CFLAGS_irq.o := -I$(src)/../include/asm/trace
+
obj-y := process_$(BITS).o signal.o entry_$(BITS).o
obj-y += traps.o irq.o irq_$(BITS).o dumpstack_$(BITS).o
obj-y += time.o ioport.o ldt.o dumpstack.o nmi.o
diff --git a/arch/x86/kernel/apic/Makefile b/arch/x86/kernel/apic/Makefile
index 5274c3a..0ae0323 100644
--- a/arch/x86/kernel/apic/Makefile
+++ b/arch/x86/kernel/apic/Makefile
@@ -2,7 +2,6 @@
# Makefile for local APIC drivers and for the IO-APIC code
#
-CFLAGS_apic.o := -I$(src)/../../include/asm/trace
obj-$(CONFIG_X86_LOCAL_APIC) += apic.o apic_noop.o ipi.o
obj-y += hw_nmi.o
diff --git a/arch/x86/kernel/apic/apic.c b/arch/x86/kernel/apic/apic.c
index 61ced40..961676c 100644
--- a/arch/x86/kernel/apic/apic.c
+++ b/arch/x86/kernel/apic/apic.c
@@ -35,6 +35,7 @@
#include <linux/smp.h>
#include <linux/mm.h>
+#include <asm/trace/irq_vectors.h>
#include <asm/irq_remapping.h>
#include <asm/perf_event.h>
#include <asm/x86_init.h>
@@ -55,9 +56,6 @@
#include <asm/tsc.h>
#include <asm/hypervisor.h>
-#define CREATE_TRACE_POINTS
-#include <asm/trace/irq_vectors.h>
-
unsigned int num_processors;
unsigned disabled_cpus __cpuinitdata;
diff --git a/arch/x86/kernel/irq.c b/arch/x86/kernel/irq.c
index 06af119..3a8185c 100644
--- a/arch/x86/kernel/irq.c
+++ b/arch/x86/kernel/irq.c
@@ -17,6 +17,8 @@
#include <asm/idle.h>
#include <asm/mce.h>
#include <asm/hw_irq.h>
+
+#define CREATE_TRACE_POINTS
#include <asm/trace/irq_vectors.h>
atomic_t irq_err_count;
On 06/21/2013 10:31 AM, Steven Rostedt wrote:
>
> Peter,
>
> I noticed that you pulled in Seiji's patches into tip. Last night I was
> running my test suite on them, and this morning they showed the
> following compile bug. I found the fix and attached it below. I pushed
> it into my tree that's based on your x86/trace branch, for your
> convenience.
>
> My testing also triggered another bug, but I'm not sure it's related to
> these patches or something that already existed. I'm currently
> investigating it now.
>
> -- Steve
>
>
> Please pull the latest tip/x86/trace tree, which can be found at:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> tip/x86/trace
>
> Head SHA1: 83ab85140bc1492f92de263a1c30ea04a0f465f7
>
Thanks, pulled!
-hpa
On Fri, 2013-06-21 at 13:31 -0400, Steven Rostedt wrote:
> My testing also triggered another bug, but I'm not sure it's related to
> these patches or something that already existed. I'm currently
> investigating it now.
I haven't been able to reproduce it.
Here's the bug I hit while running function tracer on hackbench:
------------[ cut here ]------------
WARNING: at /work/autotest/nobackup/linux-test.git/kernel/fork.c:1196 copy_process+0x2c3/0x1398()
DEBUG_LOCKS_WARN_ON(!p->hardirqs_enabled)^M
Modules linked in:
CPU: 1 PID: 4570 Comm: gdm-simple-gree Not tainted 3.10.0-rc3-test+ #5
Hardware name: /DG965MQ, BIOS MQ96510J.86A.0372.2006.0605.1717 06/05/2006
ffffffff81d2a7a5 ffff88006ed13d50 ffffffff8192822b ffff88006ed13d90
ffffffff81035f25 ffff8800721c6000 ffff88006ed13da0 0000000001200011
0000000000000000 ffff88006ed5e000 ffff8800721c6000 ffff88006ed13df0
Call Trace:
[<ffffffff8192822b>] dump_stack+0x19/0x1b
[<ffffffff81035f25>] warn_slowpath_common+0x67/0x80
[<ffffffff81035fe1>] warn_slowpath_fmt+0x46/0x48
[<ffffffff812bfc5d>] ? __raw_spin_lock_init+0x31/0x52
[<ffffffff810341f7>] copy_process+0x2c3/0x1398^M
[<ffffffff8103539d>] do_fork+0xa8/0x260
[<ffffffff810ca7b1>] ? trace_preempt_on+0x2a/0x2f
[<ffffffff812afb3e>] ? trace_hardirqs_on_thunk+0x3a/0x3f
[<ffffffff81937fe7>] ? sysret_check+0x1b/0x56
[<ffffffff81937fe7>] ? sysret_check+0x1b/0x56
[<ffffffff810355cf>] SyS_clone+0x16/0x18
[<ffffffff81938369>] stub_clone+0x69/0x90
[<ffffffff81937fc2>] ? system_call_fastpath+0x16/0x1b
---[ end trace 8b157a9d20ca1aa2 ]---
Does that look familiar?
I can send the .config if needed.
-- Steve
On 06/21/2013 02:09 PM, Steven Rostedt wrote:
> Call Trace:
> [<ffffffff8103539d>] do_fork+0xa8/0x260
> [<ffffffff810ca7b1>] ? trace_preempt_on+0x2a/0x2f
> [<ffffffff812afb3e>] ? trace_hardirqs_on_thunk+0x3a/0x3f
This bit of the call chain seems a little odd, no?
-hpa
On Fri, 2013-06-21 at 17:09 -0400, Steven Rostedt wrote:
> On Fri, 2013-06-21 at 13:31 -0400, Steven Rostedt wrote:
>
> > My testing also triggered another bug, but I'm not sure it's related to
> > these patches or something that already existed. I'm currently
> > investigating it now.
>
>
> I haven't been able to reproduce it.
Correction, I am able to reproduce it. The trick is I need to kick off
the test as soon as I get a login prompt, as the gui is still coming up
(this time the crash happened on pulseaudio). The test suite runs the
test when it detects the login. I was trying to reproduce it manually,
which was well after login was set up.
I'll try to make sure I can reproduce it consistently, or at least in a
short number of tries. And then remove all the patches and see if I can
still trigger it.
-- Steve
On Fri, 2013-06-21 at 14:13 -0700, H. Peter Anvin wrote:
> On 06/21/2013 02:09 PM, Steven Rostedt wrote:
> > Call Trace:
> > [<ffffffff8103539d>] do_fork+0xa8/0x260
> > [<ffffffff810ca7b1>] ? trace_preempt_on+0x2a/0x2f
> > [<ffffffff812afb3e>] ? trace_hardirqs_on_thunk+0x3a/0x3f
>
> This bit of the call chain seems a little odd, no?
Doesn't the "?" mean its just in the stack but not part of the call
frame that was used. CONFIG_FRAME_POINTER is set in the config.
With lockdep and preempt tracing enabled, why would this seem strange?
-- Steve
On 06/21/2013 02:28 PM, Steven Rostedt wrote:
> On Fri, 2013-06-21 at 14:13 -0700, H. Peter Anvin wrote:
>> On 06/21/2013 02:09 PM, Steven Rostedt wrote:
>>> Call Trace:
>>> [<ffffffff8103539d>] do_fork+0xa8/0x260
>>> [<ffffffff810ca7b1>] ? trace_preempt_on+0x2a/0x2f
>>> [<ffffffff812afb3e>] ? trace_hardirqs_on_thunk+0x3a/0x3f
>>
>> This bit of the call chain seems a little odd, no?
>
> Doesn't the "?" mean its just in the stack but not part of the call
> frame that was used. CONFIG_FRAME_POINTER is set in the config.
>
> With lockdep and preempt tracing enabled, why would this seem strange?
>
I didn't think trace_hardirqs_on_thunk called trace_preempt_on but maybe
I misread the code.
-hpa
On Fri, 2013-06-21 at 17:26 -0400, Steven Rostedt wrote:
> On Fri, 2013-06-21 at 17:09 -0400, Steven Rostedt wrote:
> > On Fri, 2013-06-21 at 13:31 -0400, Steven Rostedt wrote:
> >
> > > My testing also triggered another bug, but I'm not sure it's related to
> > > these patches or something that already existed. I'm currently
> > > investigating it now.
> >
> >
> > I haven't been able to reproduce it.
>
> Correction, I am able to reproduce it. The trick is I need to kick off
> the test as soon as I+
+/*
+ * the load_current_idt() is called with interrupt disabled by
local_irq_save()
+ * to avoid races. That way the IDT will always be set back to the
expected
+ * descriptor.
+ */
+static inline void load_current_idt(void)
+{
+ unsigned long flags;
+
+ local_irq_save(flags);
+ if (is_debug_idt_enabled())
+ load_debug_idt();
+ else
+ load_idt((const struct desc_ptr *)&idt_descr);
+ local_irq_restore(flags);
+}
> get a login prompt, as the gui is still coming up
> (this time the crash happened on pulseaudio). The test suite runs the
> test when it detects the login. I was trying to reproduce it manually,
> which was well after login was set up.
>
> I'll try to make sure I can reproduce it consistently, or at least in a
> short number of tries. And then remove all the patches and see if I can
> still trigger it.
OK, I can easily reproduce it when applying this commit:
629f4f9d59a27d8e58aa612e886e6a9a63ea7aeb
"x86: Rename variables for debugging"
Which doesn't just rename a variable but changes the way we update the
IDT for debugging.
After removing this commit, I can not reproduce the dump. I'm thinking
that the IDT switch did something that caused this to happen. Could be,
as lockdep (which is what is having issues here) is where things are
going wrong.
Oh, I think the issue is with this...
+
+/*
+ * the load_current_idt() is called with interrupt disabled by local_irq_save()
+ * to avoid races. That way the IDT will always be set back to the expected
+ * descriptor.
+ */
+static inline void load_current_idt(void)
+{
+ unsigned long flags;
+
+ local_irq_save(flags);
+ if (is_debug_idt_enabled())
+ load_debug_idt();
+ else
+ load_idt((const struct desc_ptr *)&idt_descr);
+ local_irq_restore(flags);
+}
It's not safe to call local_irq_save() here. From entry_64.S:
.macro TRACE_IRQS_OFF_DEBUG
call debug_stack_set_zero
TRACE_IRQS_OFF
call debug_stack_reset
.endm
We must change the idt before we can trace irqs being disabled. The
local_irq_save() here is going to be traced by lockdep. Why do we need
to disable interrupts? It's pretty pointless since this same code can be
called by NMIs.
-- Steve
> +static inline void load_current_idt(void)
> +{
> + unsigned long flags;
> +
> + local_irq_save(flags);
> + if (is_debug_idt_enabled())
> + load_debug_idt();
> + else
> + load_idt((const struct desc_ptr *)&idt_descr);
> + local_irq_restore(flags);
> +}
>
> It's not safe to call local_irq_save() here. From entry_64.S:
>
> .macro TRACE_IRQS_OFF_DEBUG
> call debug_stack_set_zero
> TRACE_IRQS_OFF
> call debug_stack_reset
> .endm
>
> We must change the idt before we can trace irqs being disabled. The
> local_irq_save() here is going to be traced by lockdep. Why do we need
> to disable interrupts? It's pretty pointless since this same code can be
> called by NMIs.
OK, I agree to remove the local_irq_save().
I thought it is safe to disable interrupt to avoid potential races,
because the load_current_id() is a common function and someone else may use it near future.
Per Intel's Software Developer's manual, there is a case which we should disable interrupts
to switch IDT in IA-32e Mode.
But I think it is corner case.
<snip>
9.8.5.2 IA-32e Mode Interrupts and Exceptions
Software must not allow exceptions or interrupts to occur between the time IA-32e mode is activated and the
update of the interrupt-descriptor-table register (IDTR) that establishes references to a 64-bit interrupt-descriptor
table (IDT). This is because the IDT remains in legacy form immediately after IA-32e mode is activated.
If an interrupt or exception occurs prior to updating the IDTR, a legacy 32-bit interrupt gate will be referenced and
interpreted as a 64-bit interrupt gate with unpredictable results. External interrupts can be disabled by using the
CLI instruction.
Non-maskable interrupts (NMI) must be disabled using external hardware.
<snip>
Seiji
????{.n?+???????+%?????ݶ??w??{.n?+????{??G?????{ay? ʇڙ?,j??f???h?????????z_??(?階?ݢj"???m??????G????????????&???~???iO???z??v?^?m???? ????????I?
On Sat, 2013-06-22 at 17:42 +0000, Seiji Aguchi wrote:
> > +static inline void load_current_idt(void)
> > +{
> > + unsigned long flags;
> > +
> > + local_irq_save(flags);
> > + if (is_debug_idt_enabled())
> > + load_debug_idt();
> > + else
> > + load_idt((const struct desc_ptr *)&idt_descr);
> > + local_irq_restore(flags);
> > +}
> >
> > It's not safe to call local_irq_save() here. From entry_64.S:
> >
> > .macro TRACE_IRQS_OFF_DEBUG
> > call debug_stack_set_zero
> > TRACE_IRQS_OFF
> > call debug_stack_reset
> > .endm
> >
> > We must change the idt before we can trace irqs being disabled. The
> > local_irq_save() here is going to be traced by lockdep. Why do we need
> > to disable interrupts? It's pretty pointless since this same code can be
> > called by NMIs.
>
> OK, I agree to remove the local_irq_save().
>
> I thought it is safe to disable interrupt to avoid potential races,
> because the load_current_id() is a common function and someone else may use it near future.
It should not be that common of a function. Not many should use it.
I'm testing a patch now and should post it in a few hours.
-- Steve
* H. Peter Anvin <[email protected]> wrote:
> On 06/21/2013 10:31 AM, Steven Rostedt wrote:
> >
> > Peter,
> >
> > I noticed that you pulled in Seiji's patches into tip. Last night I was
> > running my test suite on them, and this morning they showed the
> > following compile bug. I found the fix and attached it below. I pushed
> > it into my tree that's based on your x86/trace branch, for your
> > convenience.
> >
> > My testing also triggered another bug, but I'm not sure it's related to
> > these patches or something that already existed. I'm currently
> > investigating it now.
> >
> > -- Steve
> >
> >
> > Please pull the latest tip/x86/trace tree, which can be found at:
> >
> > git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> > tip/x86/trace
> >
> > Head SHA1: 83ab85140bc1492f92de263a1c30ea04a0f465f7
> >
>
> Thanks, pulled!
It's still broken for some configs:
arch/x86/built-in.o: In function `trace_threshold_interrupt':
(.entry.text+0x1226): undefined reference to `smp_trace_threshold_interrupt'
arch/x86/built-in.o: In function `trace_thermal_interrupt':
(.entry.text+0x1306): undefined reference to `smp_trace_thermal_interrupt'
config attached.
Thanks,
Ingo
* Ingo Molnar <[email protected]> wrote:
>
> * H. Peter Anvin <[email protected]> wrote:
>
> > On 06/21/2013 10:31 AM, Steven Rostedt wrote:
> > >
> > > Peter,
> > >
> > > I noticed that you pulled in Seiji's patches into tip. Last night I was
> > > running my test suite on them, and this morning they showed the
> > > following compile bug. I found the fix and attached it below. I pushed
> > > it into my tree that's based on your x86/trace branch, for your
> > > convenience.
> > >
> > > My testing also triggered another bug, but I'm not sure it's related to
> > > these patches or something that already existed. I'm currently
> > > investigating it now.
> > >
> > > -- Steve
> > >
> > >
> > > Please pull the latest tip/x86/trace tree, which can be found at:
> > >
> > > git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> > > tip/x86/trace
> > >
> > > Head SHA1: 83ab85140bc1492f92de263a1c30ea04a0f465f7
> > >
> >
> > Thanks, pulled!
>
> It's still broken for some configs:
>
> arch/x86/built-in.o: In function `trace_threshold_interrupt':
> (.entry.text+0x1226): undefined reference to `smp_trace_threshold_interrupt'
> arch/x86/built-in.o: In function `trace_thermal_interrupt':
> (.entry.text+0x1306): undefined reference to `smp_trace_thermal_interrupt'
>
> config attached.
I've applied the fix from Seiji Aguchi and I'm testing the updated
tip:x86/trace branch now.
Thanks,
Ingo