Hi Peter,
I was seeing a early fault when running tip/master with VMI enabled on
VMware platform.
This early fault was in the vmi_patch code where we are applying
paravirt_alternatives. After some trials i noticed that this is
reproducible only with CONFIG_TRACING. With that disabled my VM boots
again.
I started a git bisect after that, and git pointed to this as the bad
commit
commit 6cc3c6e12bb039047974ad2e7e2d46d15a1b762f
trace_clock: fix preemption bug
I then reverted that commit from tip/master and the system did boot.
But I fail to understand how this simple patch would be causing things
to fail in VMI. Any ideas ?
Thanks,
Alok
On Fri, 2009-03-13 at 10:56 -0700, Alok Kataria wrote:
> Hi Peter,
>
> I was seeing a early fault when running tip/master with VMI enabled on
> VMware platform.
> This early fault was in the vmi_patch code where we are applying
> paravirt_alternatives. After some trials i noticed that this is
> reproducible only with CONFIG_TRACING. With that disabled my VM boots
> again.
>
> I started a git bisect after that, and git pointed to this as the bad
> commit
>
> commit 6cc3c6e12bb039047974ad2e7e2d46d15a1b762f
> trace_clock: fix preemption bug
>
> I then reverted that commit from tip/master and the system did boot.
> But I fail to understand how this simple patch would be causing things
> to fail in VMI. Any ideas ?
Looking at arch/x86/include/asm/paravirt.h (god I wish paravirt would go
away, not only does it screw over ctags, it also hurts my brain), it
appears its playing icky games with primitives like
raw_local_irq_disable():
static inline void raw_local_irq_disable(void)
{
asm volatile(paravirt_alt(PARAVIRT_CALL)
:
: paravirt_type(pv_irq_ops.irq_disable),
paravirt_clobber(CLBR_EAX)
: "memory", "eax", "cc");
}
So what was supposed to be a simple op, now gets expanded into god knows
what, and might lead to tracer recursion or something.
Maybe a simple notrace annotation somewhere in that paravirt code is all
it takes, who knows.
Steve, you've been known to work on virt stuff too, happen to have a
bright idea? :-)
Peter Zijlstra wrote:
> So what was supposed to be a simple op, now gets expanded into god knows
> what, and might lead to tracer recursion or something.
I don't think that's relevent in this case; Alok's report is not that
this code crashes, but that this changeset causes a crash somewhere in
the VMI/paravirt patching code. Very odd.
J
Alok Kataria wrote:
> Hi Peter,
>
> I was seeing a early fault when running tip/master with VMI enabled on
> VMware platform.
> This early fault was in the vmi_patch code where we are applying
> paravirt_alternatives. After some trials i noticed that this is
> reproducible only with CONFIG_TRACING. With that disabled my VM boots
> again.
>
> I started a git bisect after that, and git pointed to this as the bad
> commit
>
> commit 6cc3c6e12bb039047974ad2e7e2d46d15a1b762f
> trace_clock: fix preemption bug
>
> I then reverted that commit from tip/master and the system did boot.
> But I fail to understand how this simple patch would be causing things
> to fail in VMI. Any ideas ?
>
Nope. My first guess is that this is a misbisection, but the fact that
reverting helps tends to undermine that diagnosis.
What crash are you seeing? What kind of fault? At what instruction?
Doing what? It's a bit hard to tell what you're actually seeing.
Does reverting the text_poke() changes make a difference?
J
On Sun, 15 Mar 2009, Peter Zijlstra wrote:
>
> Looking at arch/x86/include/asm/paravirt.h (god I wish paravirt would go
> away, not only does it screw over ctags, it also hurts my brain), it
> appears its playing icky games with primitives like
> raw_local_irq_disable():
>
> static inline void raw_local_irq_disable(void)
> {
> asm volatile(paravirt_alt(PARAVIRT_CALL)
> :
> : paravirt_type(pv_irq_ops.irq_disable),
> paravirt_clobber(CLBR_EAX)
> : "memory", "eax", "cc");
> }
>
> So what was supposed to be a simple op, now gets expanded into god knows
> what, and might lead to tracer recursion or something.
It should only blow up if a guest is using tracing, and the code to call
the hypervisor is also being traced.
>
> Maybe a simple notrace annotation somewhere in that paravirt code is all
> it takes, who knows.
>
> Steve, you've been known to work on virt stuff too, happen to have a
> bright idea? :-)
I have noticed that some paravirt ops calls (like this
raw_local_irq_disable) does not get inlined. It sometimes gets made into a
function. This would cause raw_local_irq_disable to actually be traced!
One answer is to use "always_inline" or I can dig out a patch that makes
inline also include "notrace".
-- Steve
Steven Rostedt wrote:
> On Sun, 15 Mar 2009, Peter Zijlstra wrote:
>
>> Looking at arch/x86/include/asm/paravirt.h (god I wish paravirt would go
>> away, not only does it screw over ctags, it also hurts my brain), it
>> appears its playing icky games with primitives like
>> raw_local_irq_disable():
>>
>> static inline void raw_local_irq_disable(void)
>> {
>> asm volatile(paravirt_alt(PARAVIRT_CALL)
>> :
>> : paravirt_type(pv_irq_ops.irq_disable),
>> paravirt_clobber(CLBR_EAX)
>> : "memory", "eax", "cc");
>> }
>>
>> So what was supposed to be a simple op, now gets expanded into god knows
>> what, and might lead to tracer recursion or something.
>>
>
> It should only blow up if a guest is using tracing, and the code to call
> the hypervisor is also being traced.
>
>
>> Maybe a simple notrace annotation somewhere in that paravirt code is all
>> it takes, who knows.
>>
>> Steve, you've been known to work on virt stuff too, happen to have a
>> bright idea? :-)
>>
>
> I have noticed that some paravirt ops calls (like this
> raw_local_irq_disable) does not get inlined. It sometimes gets made into a
> function. This would cause raw_local_irq_disable to actually be traced!
>
> One answer is to use "always_inline" or I can dig out a patch that makes
> inline also include "notrace".
Yes, these should probably be always_inline and notrace (just in case
gcc gets it into its head that it might be a good idea to put mcount
calls into inlined functions).
J
On Sat, 2009-03-14 at 16:45 -0700, Jeremy Fitzhardinge wrote:
> Alok Kataria wrote:
> > Hi Peter,
> >
> > I was seeing a early fault when running tip/master with VMI enabled on
> > VMware platform.
> > This early fault was in the vmi_patch code where we are applying
> > paravirt_alternatives. After some trials i noticed that this is
> > reproducible only with CONFIG_TRACING. With that disabled my VM boots
> > again.
> >
> > I started a git bisect after that, and git pointed to this as the bad
> > commit
> >
> > commit 6cc3c6e12bb039047974ad2e7e2d46d15a1b762f
> > trace_clock: fix preemption bug
> >
> > I then reverted that commit from tip/master and the system did boot.
> > But I fail to understand how this simple patch would be causing things
> > to fail in VMI. Any ideas ?
> >
>
> Nope. My first guess is that this is a misbisection, but the fact that
> reverting helps tends to undermine that diagnosis.
>
> What crash are you seeing? What kind of fault? At what instruction?
It being a early fault, nothing is printed on the console the system
just stays stuck in this early_fault code in arch/x86/kernel/head_32.S
I don't understand why is this not printing anything at this early fault
though, the system just enters the hlt_loop and stays there.
> Doing what? It's a bit hard to tell what you're actually seeing.
I did some more debugging and I think i know what the problem is
The objdump for trace_clock_local looks like this
c1070c24 <trace_clock_local>:
c1070c24: 55 push %ebp
c1070c25: 89 e5 mov %esp,%ebp
c1070c27: 53 push %ebx
c1070c28: 83 ec 08 sub $0x8,%esp
c1070c2b: ff 15 5c 87 3d c1 call *0xc13d875c
c1070c31: ba 64 87 3d c1 mov $0xc13d8764,%edx
c1070c36: 89 45 f4 mov %eax,0xfffffff4(%ebp)
c1070c39: ff 12 call *(%edx) <<=====*
c1070c3b: e8 cd 68 f9 ff call c100750d <sched_clock>
c1070c40: 89 c1 mov %eax,%ecx
c1070c42: 8b 45 f4 mov 0xfffffff4(%ebp),%eax
c1070c45: ff 15 60 87 3d c1 call *0xc13d8760
Notice instruction on c1070c39 we have "call *(edx)",
edx was just loaded with the address for the paravirt call.
when we try to replace that to a call to vmi specific function, maybe we
hit a BUG_ON(len < 5) in vmi's patch_internal code, because now the
instruction length is less than 5.
Is there is a way to get GCC to not do such fancy tricks, and instead do
a direct "call 0xc13d8764" ?
Thanks,
Alok
>
> Does reverting the text_poke() changes make a difference?
>
> J
Alok Kataria wrote:
> On Sat, 2009-03-14 at 16:45 -0700, Jeremy Fitzhardinge wrote:
>
>> Alok Kataria wrote:
>>
>>> Hi Peter,
>>>
>>> I was seeing a early fault when running tip/master with VMI enabled on
>>> VMware platform.
>>> This early fault was in the vmi_patch code where we are applying
>>> paravirt_alternatives. After some trials i noticed that this is
>>> reproducible only with CONFIG_TRACING. With that disabled my VM boots
>>> again.
>>>
>>> I started a git bisect after that, and git pointed to this as the bad
>>> commit
>>>
>>> commit 6cc3c6e12bb039047974ad2e7e2d46d15a1b762f
>>> trace_clock: fix preemption bug
>>>
>>> I then reverted that commit from tip/master and the system did boot.
>>> But I fail to understand how this simple patch would be causing things
>>> to fail in VMI. Any ideas ?
>>>
>>>
>> Nope. My first guess is that this is a misbisection, but the fact that
>> reverting helps tends to undermine that diagnosis.
>>
>> What crash are you seeing? What kind of fault? At what instruction?
>>
>
> It being a early fault, nothing is printed on the console the system
> just stays stuck in this early_fault code in arch/x86/kernel/head_32.S
>
> I don't understand why is this not printing anything at this early fault
> though, the system just enters the hlt_loop and stays there.
>
It should drop something onto the vga console (and/or serial port?).
>> Doing what? It's a bit hard to tell what you're actually seeing.
>>
> I did some more debugging and I think i know what the problem is
> The objdump for trace_clock_local looks like this
>
> c1070c24 <trace_clock_local>:
> c1070c24: 55 push %ebp
> c1070c25: 89 e5 mov %esp,%ebp
> c1070c27: 53 push %ebx
> c1070c28: 83 ec 08 sub $0x8,%esp
> c1070c2b: ff 15 5c 87 3d c1 call *0xc13d875c
> c1070c31: ba 64 87 3d c1 mov $0xc13d8764,%edx
> c1070c36: 89 45 f4 mov %eax,0xfffffff4(%ebp)
> c1070c39: ff 12 call *(%edx) <<=====*
> c1070c3b: e8 cd 68 f9 ff call c100750d <sched_clock>
> c1070c40: 89 c1 mov %eax,%ecx
> c1070c42: 8b 45 f4 mov 0xfffffff4(%ebp),%eax
> c1070c45: ff 15 60 87 3d c1 call *0xc13d8760
>
> Notice instruction on c1070c39 we have "call *(edx)",
> edx was just loaded with the address for the paravirt call.
> when we try to replace that to a call to vmi specific function, maybe we
> hit a BUG_ON(len < 5) in vmi's patch_internal code, because now the
> instruction length is less than 5.
>
> Is there is a way to get GCC to not do such fancy tricks, and instead do
> a direct "call 0xc13d8764" ?
Well, indirect "call *0xc13d875c". But yes, its hard to see what gcc
thinks its getting out of doing the indirect call via %edx. We
definitely don't want gcc doing such things, even if it does make sense
(such as calling an op multiple times, and CSEing the pointer); given
that we generate all this in asm anyway, we could force it. Does this help?
diff --git a/arch/x86/include/asm/paravirt.h b/arch/x86/include/asm/paravirt.h
index d4fec1f..62dfc51 100644
--- a/arch/x86/include/asm/paravirt.h
+++ b/arch/x86/include/asm/paravirt.h
@@ -395,7 +395,7 @@ extern struct pv_lock_ops pv_lock_ops;
#define paravirt_type(op) \
[paravirt_typenum] "i" (PARAVIRT_PATCH(op)), \
- [paravirt_opptr] "m" (op)
+ [paravirt_opptr] "i" (&(op))
#define paravirt_clobber(clobber) \
[paravirt_clobber] "i" (clobber)
@@ -449,7 +449,7 @@ int paravirt_disable_iospace(void);
* offset into the paravirt_patch_template structure, and can therefore be
* freely converted back into a structure offset.
*/
-#define PARAVIRT_CALL "call *%[paravirt_opptr];"
+#define PARAVIRT_CALL "call *%c[paravirt_opptr];"
/*
* These macros are intended to wrap calls through one of the paravirt
J
On Mon, 2009-03-16 at 15:54 -0700, Jeremy Fitzhardinge wrote:
> > I don't understand why is this not printing anything at this early fault
> > though, the system just enters the hlt_loop and stays there.
> >
>
> It should drop something onto the vga console (and/or serial port?).
Surprisingly it doesn't, but anyways...
>
> >> Doing what? It's a bit hard to tell what you're actually seeing.
> >>
> > I did some more debugging and I think i know what the problem is
> > The objdump for trace_clock_local looks like this
> >
> > c1070c24 <trace_clock_local>:
> > c1070c24: 55 push %ebp
> > c1070c25: 89 e5 mov %esp,%ebp
> > c1070c27: 53 push %ebx
> > c1070c28: 83 ec 08 sub $0x8,%esp
> > c1070c2b: ff 15 5c 87 3d c1 call *0xc13d875c
> > c1070c31: ba 64 87 3d c1 mov $0xc13d8764,%edx
> > c1070c36: 89 45 f4 mov %eax,0xfffffff4(%ebp)
> > c1070c39: ff 12 call *(%edx) <<=====*
> > c1070c3b: e8 cd 68 f9 ff call c100750d <sched_clock>
> > c1070c40: 89 c1 mov %eax,%ecx
> > c1070c42: 8b 45 f4 mov 0xfffffff4(%ebp),%eax
> > c1070c45: ff 15 60 87 3d c1 call *0xc13d8760
> >
> > Notice instruction on c1070c39 we have "call *(edx)",
> > edx was just loaded with the address for the paravirt call.
> > when we try to replace that to a call to vmi specific function, maybe we
> > hit a BUG_ON(len < 5) in vmi's patch_internal code, because now the
> > instruction length is less than 5.
> >
> > Is there is a way to get GCC to not do such fancy tricks, and instead do
> > a direct "call 0xc13d8764" ?
> Well, indirect "call *0xc13d875c". But yes, its hard to see what gcc
> thinks its getting out of doing the indirect call via %edx. We
> definitely don't want gcc doing such things, even if it does make sense
> (such as calling an op multiple times, and CSEing the pointer); given
> that we generate all this in asm anyway, we could force it. Does this help?
Yes, This does the trick
The disassembly for trace_clock_local is now correct, and this boots
too.
c107105c <trace_clock_local>:
c107105c: 55 push %ebp
c107105d: 89 e5 mov %esp,%ebp
c107105f: 53 push %ebx
c1071060: 83 ec 08 sub $0x8,%esp
c1071063: ff 15 7c 07 3e c1 call *0xc13e077c
c1071069: 89 45 f4 mov %eax,0xfffffff4(%ebp)
c107106c: ff 15 84 07 3e c1 call *0xc13e0784
c1071072: e8 36 65 f9 ff call c10075ad <sched_clock>
c1071077: 89 c1 mov %eax,%ecx
c1071079: 8b 45 f4 mov 0xfffffff4(%ebp),%eax
c107107c: ff 15 80 07 3e c1 call *0xc13e0780
Thanks,
Alok
>
> diff --git a/arch/x86/include/asm/paravirt.h b/arch/x86/include/asm/paravirt.h
> index d4fec1f..62dfc51 100644
> --- a/arch/x86/include/asm/paravirt.h
> +++ b/arch/x86/include/asm/paravirt.h
> @@ -395,7 +395,7 @@ extern struct pv_lock_ops pv_lock_ops;
>
> #define paravirt_type(op) \
> [paravirt_typenum] "i" (PARAVIRT_PATCH(op)), \
> - [paravirt_opptr] "m" (op)
> + [paravirt_opptr] "i" (&(op))
> #define paravirt_clobber(clobber) \
> [paravirt_clobber] "i" (clobber)
>
> @@ -449,7 +449,7 @@ int paravirt_disable_iospace(void);
> * offset into the paravirt_patch_template structure, and can therefore be
> * freely converted back into a structure offset.
> */
> -#define PARAVIRT_CALL "call *%[paravirt_opptr];"
> +#define PARAVIRT_CALL "call *%c[paravirt_opptr];"
>
> /*
> * These macros are intended to wrap calls through one of the paravirt
>
>