[ltt-dev] LTTng 2.0 on ARM

[ltt-dev] LTTng 2.0 on ARM

[Rabin Vincent]

On Tue, Sep 13, 2011 at 21:20, Mathieu Desnoyers
<compudj@krystal.dyndns.org> wrote:
> * Avik Sil (avik.sil at linaro.org) wrote:
>> On Tuesday 13 September 2011 12:35 AM, Mathieu Desnoyers wrote:
>> > * Avik Sil (avik.sil at linaro.org) wrote:
>> >> [ 1139.173522] vmalloc_sync_all_sym: c00a1d14
>> >> [ 1139.180877] Internal error: Oops - undefined instruction: 0 [#1]
>> >> PREEMPT SMP
>> >> [ 1139.191284] Modules linked in: lttng_ftrace(+)
>> >> [ 1139.198974] CPU: 1 ? ?Not tainted ?(3.0.0-1004-linaro-omap #6)
>> >> [ 1139.208099] PC is at vmalloc_sync_all+0x0/0x8
>> >> [ 1139.215667] LR is at init_module+0x1c/0x28 [lttng_ftrace]
>> >> [ 1139.224304] pc : [<c00a1d14>] ? ?lr : [<bf800211>] ? ?psr: 60000113
>> >> [ 1139.224304] sp : ebb11f50 ?ip : 00000000 ?fp : 00000000
>> >> [ 1139.242401] r10: 00000000 ?r9 : 00000000 ?r8 : c06a2f00
>> >> [ 1139.250793] r7 : bf8001f5 ?r6 : 00000000 ?r5 : 00182008 ?r4 : c00a1d14
>> >> [ 1139.260559] r3 : 271aed1f ?r2 : ebb11f44 ?r1 : bf8003a6 ?r0 : 00000034
>> >> [ 1139.270233] Flags: nZCv ?IRQs on ?FIQs on ?Mode SVC_32 ?ISA ARM
[...]
>> Disassembly of section .text:
>>
>> c00a1d14 <vmalloc_sync_all>:
>> c00a1d14: ? ? b500 ? ? ? ? ? ?push ? ?{lr}
>> c00a1d16: ? ? f76a fa9d ? ? ? bl ? ? ?c000c254 <__gnu_mcount_nc>
>> c00a1d1a: ? ? 4770 ? ? ? ? ? ?bx ? ? ?lr
>>
[...]
>> >
>> > We have to keep in mind that this could also be a ftrace function tracer
>> > bug, in which case the surrounding of 0xc00a1d14 from the vmlinux image
>> > will not match the instructions in memory. Can you dump the hex content
>> > around 0xc00a1d14 just before the vmalloc_sync_all gets called and
>> > compare with the disassembly ?
>>
>> The hex content dump shows:
>>
>> [ ?150.810119] c00a1d14: b500 f85d eb04 4770
>>
>> So it seems your guess is right, the content of vmlinux image
>> surrounding 0xc00a1d14 is not matching the instruction in memory. By
>> grepping objdump I found that instruction 'f85d eb04' translates to
>> "ldr.w ? ? ? ?lr, [sp], #4".
>
> I'm adding the ARM function tracer developers in CC. Maybe they can
> enlighten us.

ftrace has indeed overwritten the instructions here, but it's done it
correctly.  The problem here is that you're trying to execute a Thumb-2
function in ARM mode.  This is unrelated to ftrace, I've reproduced it
here with a Thumb-2 kernel without ftrace enabled with just this code:

static int __init late(void)
{
	void (*v)(void);

	v = (void *) kallsyms_lookup_name("vmalloc_sync_all");
	printk("%s addr %p\n", __func__, v);
	
	v();

	return 0;
}
late_initcall(late);

which leads to this:

  late addr c010ed7c
  Internal error: Oops - undefined instruction: 0 [#1] PREEMPT SMP
  CPU: 0    Not tainted  (3.1.0-rc2+ #339)
  PC is at late+0x4/0x28
  LR is at late+0x17/0x28
  pc : [<c010ed80>]    lr : [<c010ed93>]    psr: 40000013
  sp : c782dfb0  ip : 00000000  fp : 00000000
  r10: 00000000  r9 : 00000000  r8 : 00000000
  r7 : 00000033  r6 : 00000000  r5 : c010ed7d  r4 : c010ed7c
  r3 : c010ed7c  r2 : c782dfa4  r1 : c00f0963  r0 : 00000025
  Flags: nZcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
  Control: 50c53c7d  Table: 0000406a  DAC: 00000015
  Process swapper (pid: 1, stack limit = 0xc782c2f0)
  Stack: (0xc782dfb0 to 0xc782e000)
  dfa0:                                     c011ab7c c010b66b 00000000 00000000
  dfc0: 0000007f c01295ac c000ca81 c011ab7c c011ab94 c000ca81 00000033 00000000
  dfe0: 00000000 c010b765 00000000 00000000 c010b701 c000ca81 00000000 00000000
  [<c010ed80>] (late+0x4/0x28) from [<c010b66b>] (do_one_initcall+0x63/0xf8)
  [<c010b66b>] (do_one_initcall+0x63/0xf8) from [<c010b765>]
(kernel_init+0x65/0xd8)
  [<c010b765>] (kernel_init+0x65/0xd8) from [<c000ca81>]
(kernel_thread_exit+0x1/0x6)
  Code: c0125e20 c01307ac 47702000 4806b510 (f81ef727)

The problem is that the addresses returned by kallsyms_lookup_name()
does not have the zero bit, which is what is expected for Thumb
functions because the BLX instruction which is used to call them uses
this bit to determines which mode to switch into.  Since it's cleared,
you switch to ARM mode and attempt to execute Thumb-2 code, with obvious
results.

A cursory look at the parties involved shows that nm doesn't show the
zero bit (even though it's set in the vmlinux symbol table), and
scripts/kallsyms builds the table by parsing nm's output.

Adding linux-arm-kernel.

[ltt-dev] LTTng 2.0 on ARM

[Dave Martin]

On Tue, Sep 13, 2011 at 11:14:47PM +0530, Rabin Vincent wrote:
> On Tue, Sep 13, 2011 at 21:20, Mathieu Desnoyers
> <compudj@krystal.dyndns.org> wrote:
> > * Avik Sil (avik.sil at linaro.org) wrote:
> >> On Tuesday 13 September 2011 12:35 AM, Mathieu Desnoyers wrote:
> >> > * Avik Sil (avik.sil at linaro.org) wrote:
> >> >> [ 1139.173522] vmalloc_sync_all_sym: c00a1d14
> >> >> [ 1139.180877] Internal error: Oops - undefined instruction: 0 [#1]
> >> >> PREEMPT SMP
> >> >> [ 1139.191284] Modules linked in: lttng_ftrace(+)
> >> >> [ 1139.198974] CPU: 1 ? ?Not tainted ?(3.0.0-1004-linaro-omap #6)
> >> >> [ 1139.208099] PC is at vmalloc_sync_all+0x0/0x8
> >> >> [ 1139.215667] LR is at init_module+0x1c/0x28 [lttng_ftrace]
> >> >> [ 1139.224304] pc : [<c00a1d14>] ? ?lr : [<bf800211>] ? ?psr: 60000113
> >> >> [ 1139.224304] sp : ebb11f50 ?ip : 00000000 ?fp : 00000000
> >> >> [ 1139.242401] r10: 00000000 ?r9 : 00000000 ?r8 : c06a2f00
> >> >> [ 1139.250793] r7 : bf8001f5 ?r6 : 00000000 ?r5 : 00182008 ?r4 : c00a1d14
> >> >> [ 1139.260559] r3 : 271aed1f ?r2 : ebb11f44 ?r1 : bf8003a6 ?r0 : 00000034
> >> >> [ 1139.270233] Flags: nZCv ?IRQs on ?FIQs on ?Mode SVC_32 ?ISA ARM
> [...]
> >> Disassembly of section .text:
> >>
> >> c00a1d14 <vmalloc_sync_all>:
> >> c00a1d14: ? ? b500 ? ? ? ? ? ?push ? ?{lr}
> >> c00a1d16: ? ? f76a fa9d ? ? ? bl ? ? ?c000c254 <__gnu_mcount_nc>
> >> c00a1d1a: ? ? 4770 ? ? ? ? ? ?bx ? ? ?lr
> >>
> [...]
> >> >
> >> > We have to keep in mind that this could also be a ftrace function tracer
> >> > bug, in which case the surrounding of 0xc00a1d14 from the vmlinux image
> >> > will not match the instructions in memory. Can you dump the hex content
> >> > around 0xc00a1d14 just before the vmalloc_sync_all gets called and
> >> > compare with the disassembly ?
> >>
> >> The hex content dump shows:
> >>
> >> [ ?150.810119] c00a1d14: b500 f85d eb04 4770
> >>
> >> So it seems your guess is right, the content of vmlinux image
> >> surrounding 0xc00a1d14 is not matching the instruction in memory. By
> >> grepping objdump I found that instruction 'f85d eb04' translates to
> >> "ldr.w ? ? ? ?lr, [sp], #4".
> >
> > I'm adding the ARM function tracer developers in CC. Maybe they can
> > enlighten us.
> 
> ftrace has indeed overwritten the instructions here, but it's done it
> correctly.  The problem here is that you're trying to execute a Thumb-2
> function in ARM mode.  This is unrelated to ftrace, I've reproduced it
> here with a Thumb-2 kernel without ftrace enabled with just this code:
> 
> static int __init late(void)
> {
> 	void (*v)(void);
> 
> 	v = (void *) kallsyms_lookup_name("vmalloc_sync_all");
> 	printk("%s addr %p\n", __func__, v);
> 	
> 	v();
> 
> 	return 0;
> }
> late_initcall(late);
> 
> which leads to this:
> 
>   late addr c010ed7c
>   Internal error: Oops - undefined instruction: 0 [#1] PREEMPT SMP
>   CPU: 0    Not tainted  (3.1.0-rc2+ #339)
>   PC is at late+0x4/0x28
>   LR is at late+0x17/0x28
>   pc : [<c010ed80>]    lr : [<c010ed93>]    psr: 40000013
>   sp : c782dfb0  ip : 00000000  fp : 00000000
>   r10: 00000000  r9 : 00000000  r8 : 00000000
>   r7 : 00000033  r6 : 00000000  r5 : c010ed7d  r4 : c010ed7c
>   r3 : c010ed7c  r2 : c782dfa4  r1 : c00f0963  r0 : 00000025
>   Flags: nZcv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
>   Control: 50c53c7d  Table: 0000406a  DAC: 00000015
>   Process swapper (pid: 1, stack limit = 0xc782c2f0)
>   Stack: (0xc782dfb0 to 0xc782e000)
>   dfa0:                                     c011ab7c c010b66b 00000000 00000000
>   dfc0: 0000007f c01295ac c000ca81 c011ab7c c011ab94 c000ca81 00000033 00000000
>   dfe0: 00000000 c010b765 00000000 00000000 c010b701 c000ca81 00000000 00000000
>   [<c010ed80>] (late+0x4/0x28) from [<c010b66b>] (do_one_initcall+0x63/0xf8)
>   [<c010b66b>] (do_one_initcall+0x63/0xf8) from [<c010b765>]
> (kernel_init+0x65/0xd8)
>   [<c010b765>] (kernel_init+0x65/0xd8) from [<c000ca81>]
> (kernel_thread_exit+0x1/0x6)
>   Code: c0125e20 c01307ac 47702000 4806b510 (f81ef727)
> 
> The problem is that the addresses returned by kallsyms_lookup_name()
> does not have the zero bit, which is what is expected for Thumb
> functions because the BLX instruction which is used to call them uses
> this bit to determines which mode to switch into.  Since it's cleared,
> you switch to ARM mode and attempt to execute Thumb-2 code, with obvious
> results.
> 
> A cursory look at the parties involved shows that nm doesn't show the
> zero bit (even though it's set in the vmlinux symbol table), and
> scripts/kallsyms builds the table by parsing nm's output.

It's not quite as simple as saying "the output of nm is wrong" though...

When getting the address of a function, there are actually two
separate answers:

 a) the pointer which can be used to call the function

 b) the address of the start of the function body

On many arches these they are identical, but on some they are different.
On ARM, they are identical for ARM code but different for Thumb code
(because the Thumb bit must be set in case (a) but not in case (b))

It may be worth looking at what is done in the kernel for ia64 and ppc64.
I believe that (a) and (b) are quite different for these because
functions are called through descriptors.  Don't quote me on that though:
I'm mostly ignorant about these arches.

For the Thumb-2 kernel case, we can probably hack around this: there
are various places in the kernel where we just force-set the Thumb bit
in addresses without really knowing what the target code is.  We get
away with this because the kernel is (very nearly) 100% Thumb code
for a Thumb-2 kernel.

However, if the kernel already has a correct approach for solving this
problem, we should probably be using it.

Cheers
---Dave

[ltt-dev] LTTng 2.0 on ARM

[Jon Medhurst (Tixy)]

On Wed, 2011-09-14 at 11:09 +0100, Dave Martin wrote:
> On Tue, Sep 13, 2011 at 11:14:47PM +0530, Rabin Vincent wrote:
[...]
> > The problem is that the addresses returned by kallsyms_lookup_name()
> > does not have the zero bit, which is what is expected for Thumb
> > functions because the BLX instruction which is used to call them uses
> > this bit to determines which mode to switch into.  Since it's cleared,
> > you switch to ARM mode and attempt to execute Thumb-2 code, with obvious
> > results.
> > 
> > A cursory look at the parties involved shows that nm doesn't show the
> > zero bit (even though it's set in the vmlinux symbol table), and
> > scripts/kallsyms builds the table by parsing nm's output.
> 
> It's not quite as simple as saying "the output of nm is wrong" though...
> 
> When getting the address of a function, there are actually two
> separate answers:
> 
>  a) the pointer which can be used to call the function
> 
>  b) the address of the start of the function body
> 
> On many arches these they are identical, but on some they are different.
> On ARM, they are identical for ARM code but different for Thumb code
> (because the Thumb bit must be set in case (a) but not in case (b))
> 
> It may be worth looking at what is done in the kernel for ia64 and ppc64.
> I believe that (a) and (b) are quite different for these because
> functions are called through descriptors.  Don't quote me on that though:
> I'm mostly ignorant about these arches.
> 
> For the Thumb-2 kernel case, we can probably hack around this: there
> are various places in the kernel where we just force-set the Thumb bit
> in addresses without really knowing what the target code is.  We get
> away with this because the kernel is (very nearly) 100% Thumb code
> for a Thumb-2 kernel.
> 
> However, if the kernel already has a correct approach for solving this
> problem, we should probably be using it.

This is the same issue I found recently with kprobes [1]. There is also
an inconsistency as function symbols in loadable module do have bit zero
set, but if the module is built-in then bit zero is clear. 

-- 
Tixy

[1] http://www.spinics.net/lists/arm-kernel/msg138283.html

[ltt-dev] LTTng 2.0 on ARM

[Dave Martin]

On Wed, Sep 14, 2011 at 05:27:08PM +0100, Jon Medhurst (Tixy) wrote:
> On Wed, 2011-09-14 at 11:09 +0100, Dave Martin wrote:
> > On Tue, Sep 13, 2011 at 11:14:47PM +0530, Rabin Vincent wrote:
> [...]
> > > The problem is that the addresses returned by kallsyms_lookup_name()
> > > does not have the zero bit, which is what is expected for Thumb
> > > functions because the BLX instruction which is used to call them uses
> > > this bit to determines which mode to switch into.  Since it's cleared,
> > > you switch to ARM mode and attempt to execute Thumb-2 code, with obvious
> > > results.
> > > 
> > > A cursory look at the parties involved shows that nm doesn't show the
> > > zero bit (even though it's set in the vmlinux symbol table), and
> > > scripts/kallsyms builds the table by parsing nm's output.
> > 
> > It's not quite as simple as saying "the output of nm is wrong" though...
> > 
> > When getting the address of a function, there are actually two
> > separate answers:
> > 
> >  a) the pointer which can be used to call the function
> > 
> >  b) the address of the start of the function body
> > 
> > On many arches these they are identical, but on some they are different.
> > On ARM, they are identical for ARM code but different for Thumb code
> > (because the Thumb bit must be set in case (a) but not in case (b))
> > 
> > It may be worth looking at what is done in the kernel for ia64 and ppc64.
> > I believe that (a) and (b) are quite different for these because
> > functions are called through descriptors.  Don't quote me on that though:
> > I'm mostly ignorant about these arches.
> > 
> > For the Thumb-2 kernel case, we can probably hack around this: there
> > are various places in the kernel where we just force-set the Thumb bit
> > in addresses without really knowing what the target code is.  We get
> > away with this because the kernel is (very nearly) 100% Thumb code
> > for a Thumb-2 kernel.
> > 
> > However, if the kernel already has a correct approach for solving this
> > problem, we should probably be using it.
> 
> This is the same issue I found recently with kprobes [1]. There is also
> an inconsistency as function symbols in loadable module do have bit zero
> set, but if the module is built-in then bit zero is clear. 

Does that mean that some different infrastructure is used to get the module
symbols compared with kallsyms?  That feels nasty -- they should at least
be consistent...

---Dave

[ltt-dev] LTTng 2.0 on ARM

[Jon Medhurst (Tixy)]

On Fri, 2011-09-16 at 17:25 +0100, Dave Martin wrote:
> On Wed, Sep 14, 2011 at 05:27:08PM +0100, Jon Medhurst (Tixy) wrote:
> > This is the same issue I found recently with kprobes [1]. There is also
> > an inconsistency as function symbols in loadable module do have bit zero
> > set, but if the module is built-in then bit zero is clear. 
> 
> Does that mean that some different infrastructure is used to get the module
> symbols compared with kallsyms?

Yes, there's different infrastructure to handle symbols in loadable
modules compared to those in the kernel binary. I mentioned this in [1],
or in your Linaro inbox on 29th Aug ;-)

>   That feels nasty -- they should at least
> be consistent...

I agree, getting them consistent would solve half the problem.

-- 
Tixy


[1] http://www.spinics.net/lists/arm-kernel/msg138283.html