Problem with GDB when debugging IRQ handlers

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

Hello, colleagues,

I've got into a problem when trying to debug irq handlers on PXA (in
qemu). backtrace is really strange from my POV (a target is just a qemu
running a bit modified 3.0-rc2 kernel):

arm-linux-gnueabi-gdb vmlinux
GNU gdb (GDB) 7.2-debian
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "--host=i486-linux-gnu --target=arm-linux-gnueabi".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from vmlinux...done.
(gdb) target localhost:1234
Undefined target command: "localhost:1234".  Try "help target".
(gdb) target remote:1234
break handle_Remote debugging using :1234
0xa0000000 in ?? ()
(gdb) break handle_level_irq
Breakpoint 1 at 0xc008811c: file kernel/irq/chip.c, line 329.
(gdb) cont
Continuing.

Breakpoint 1, handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
329		mask_ack_irq(desc);
(gdb) bt
#0  handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
#1  0xc0085f64 in generic_handle_irq_desc (irq=42) at include/linux/irqdesc.h:111
#2  generic_handle_irq (irq=42) at kernel/irq/irqdesc.c:304
#3  0xc0033060 in asm_do_IRQ (irq=42, regs=<value optimized out>) at arch/arm/kernel/irq.c:90
#4  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#5  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#6  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#7  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#8  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#9  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#10 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#11 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
#12 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202

... and so on it continues ad infinitum. Is it the expected behaviour?
Because I'm pretty much sure that this isn't a desired behaviour.

-- 
With best wishes
Dmitry

Problem with GDB when debugging IRQ handlers

[Russell King - ARM Linux]

On Mon, Jun 27, 2011 at 04:53:06PM +0400, Dmitry Eremin-Solenikov wrote:
> I've got into a problem when trying to debug irq handlers on PXA (in
> qemu). backtrace is really strange from my POV (a target is just a qemu
> running a bit modified 3.0-rc2 kernel):
...
> Breakpoint 1, handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
> 329		mask_ack_irq(desc);
> (gdb) bt
> #0  handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
> #1  0xc0085f64 in generic_handle_irq_desc (irq=42) at include/linux/irqdesc.h:111
> #2  generic_handle_irq (irq=42) at kernel/irq/irqdesc.c:304
> #3  0xc0033060 in asm_do_IRQ (irq=42, regs=<value optimized out>) at arch/arm/kernel/irq.c:90
> #4  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #5  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #6  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #7  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #8  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #9  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #10 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #11 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> #12 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> 
> ... and so on it continues ad infinitum. Is it the expected behaviour?
> Because I'm pretty much sure that this isn't a desired behaviour.

My guess is that gdb is trying to unwind using the unwind information.
However, I don't think we actually give the assembler the full information
to be able to unwind this.  I've no idea how to solve this as I'm no
expert at the debug info.

We _really_ _do_ want to unwind through this so that we can see the
parent kernel context information in backtraces - and the fact that
the kernel itself can unwind through these means we can't tell the
unwinder not to.

So, no idea.  I think you need someone who knows debug info to sort
this one out.

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

Hello,

On 27.06.2011 17:27, Russell King - ARM Linux wrote:
> On Mon, Jun 27, 2011 at 04:53:06PM +0400, Dmitry Eremin-Solenikov wrote:
>> I've got into a problem when trying to debug irq handlers on PXA (in
>> qemu). backtrace is really strange from my POV (a target is just a qemu
>> running a bit modified 3.0-rc2 kernel):
> ...
>> Breakpoint 1, handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
>> 329		mask_ack_irq(desc);
>> (gdb) bt
>> #0  handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
>> #1  0xc0085f64 in generic_handle_irq_desc (irq=42) at include/linux/irqdesc.h:111
>> #2  generic_handle_irq (irq=42) at kernel/irq/irqdesc.c:304
>> #3  0xc0033060 in asm_do_IRQ (irq=42, regs=<value optimized out>) at arch/arm/kernel/irq.c:90
>> #4  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #5  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #6  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #7  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #8  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #9  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #10 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #11 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>> #12 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>
>> ... and so on it continues ad infinitum. Is it the expected behaviour?
>> Because I'm pretty much sure that this isn't a desired behaviour.
>
> My guess is that gdb is trying to unwind using the unwind information.
> However, I don't think we actually give the assembler the full information
> to be able to unwind this.  I've no idea how to solve this as I'm no
> expert at the debug info.
>
> We _really_ _do_ want to unwind through this so that we can see the
> parent kernel context information in backtraces - and the fact that
> the kernel itself can unwind through these means we can't tell the
> unwinder not to.
>
> So, no idea.  I think you need someone who knows debug info to sort
> this one out.

Adding gdb ML to cc in the hope to get any assistance.

-- 
With best wishes
Dmitry

Problem with GDB when debugging IRQ handlers

[Hui Zhu]

If I remember is right, kernel didn't supply enough debug info in
entry-armv.S.  So GDB cannot got enough debug info, then got some
frame parse bug inside it.

I think add some cfi
code(http://sourceware.org/binutils/docs/as/CFI-directives.html) like
x86 entry did can handle this issue.

Thanks,
Hui

On Mon, Jun 27, 2011 at 22:04, Dmitry Eremin-Solenikov
<dbaryshkov@gmail.com> wrote:
> Hello,
>
> On 27.06.2011 17:27, Russell King - ARM Linux wrote:
>>
>> On Mon, Jun 27, 2011 at 04:53:06PM +0400, Dmitry Eremin-Solenikov wrote:
>>>
>>> I've got into a problem when trying to debug irq handlers on PXA (in
>>> qemu). backtrace is really strange from my POV (a target is just a qemu
>>> running a bit modified 3.0-rc2 kernel):
>>
>> ...
>>>
>>> Breakpoint 1, handle_level_irq (irq=42, desc=0xc3e06000) at
>>> kernel/irq/chip.c:329
>>> 329 ? ? ? ? ? ? mask_ack_irq(desc);
>>> (gdb) bt
>>> #0 ?handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
>>> #1 ?0xc0085f64 in generic_handle_irq_desc (irq=42) at
>>> include/linux/irqdesc.h:111
>>> #2 ?generic_handle_irq (irq=42) at kernel/irq/irqdesc.c:304
>>> #3 ?0xc0033060 in asm_do_IRQ (irq=42, regs=<value optimized out>) at
>>> arch/arm/kernel/irq.c:90
>>> #4 ?0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #5 ?0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #6 ?0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #7 ?0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #8 ?0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #9 ?0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #10 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #11 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #12 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>>
>>> ... and so on it continues ad infinitum. Is it the expected behaviour?
>>> Because I'm pretty much sure that this isn't a desired behaviour.
>>
>> My guess is that gdb is trying to unwind using the unwind information.
>> However, I don't think we actually give the assembler the full information
>> to be able to unwind this. ?I've no idea how to solve this as I'm no
>> expert at the debug info.
>>
>> We _really_ _do_ want to unwind through this so that we can see the
>> parent kernel context information in backtraces - and the fact that
>> the kernel itself can unwind through these means we can't tell the
>> unwinder not to.
>>
>> So, no idea. ?I think you need someone who knows debug info to sort
>> this one out.
>
> Adding gdb ML to cc in the hope to get any assistance.
>
> --
> With best wishes
> Dmitry
>
>

Problem with GDB when debugging IRQ handlers

[Yao Qi]

On 06/27/2011 10:04 PM, Dmitry Eremin-Solenikov wrote:
> Hello,
> 
> On 27.06.2011 17:27, Russell King - ARM Linux wrote:
>> On Mon, Jun 27, 2011 at 04:53:06PM +0400, Dmitry Eremin-Solenikov wrote:
>>> I've got into a problem when trying to debug irq handlers on PXA (in
>>> qemu). backtrace is really strange from my POV (a target is just a qemu
>>> running a bit modified 3.0-rc2 kernel):
>> ...
>>> Breakpoint 1, handle_level_irq (irq=42, desc=0xc3e06000) at
>>> kernel/irq/chip.c:329
>>> 329        mask_ack_irq(desc);
>>> (gdb) bt
>>> #0  handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
>>> #1  0xc0085f64 in generic_handle_irq_desc (irq=42) at
>>> include/linux/irqdesc.h:111
>>> #2  generic_handle_irq (irq=42) at kernel/irq/irqdesc.c:304
>>> #3  0xc0033060 in asm_do_IRQ (irq=42, regs=<value optimized out>) at
>>> arch/arm/kernel/irq.c:90
>>> #4  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #5  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #6  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #7  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #8  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #9  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #10 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #11 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>> #12 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
>>>
>>> ... and so on it continues ad infinitum. Is it the expected behaviour?
>>> Because I'm pretty much sure that this isn't a desired behaviour.
>>

Usually, if debugging information is not there, GDB will try to unwind
stacks by analyzing function's prologue.  It looks arm prologue analyzer
goes into an endless loop, because of (I guess) the irregular register
usage in low-level kernel asm code.

arm/gdb's prologue analyzer can handle common code, but I am afraid it
is unable to handle kernel-specific code, unless we make gdb
kernel-aware.  At least, we may teach gdb to stop at __irq_svc.

Please file a bug report against gdb, and post the disassembly of
__irq_svc in bug report.

>> We _really_ _do_ want to unwind through this so that we can see the
>> parent kernel context information in backtraces - and the fact that

I am not sure GDB is able to unwind stacks across processes (from child
to parent).

-- 
Yao (??)

Problem with GDB when debugging IRQ handlers

[Russell King - ARM Linux]

On Mon, Jun 27, 2011 at 10:58:59PM +0800, Yao Qi wrote:
> On 06/27/2011 10:04 PM, Dmitry Eremin-Solenikov wrote:
> > Hello,
> > 
> > On 27.06.2011 17:27, Russell King - ARM Linux wrote:
> >> We _really_ _do_ want to unwind through this so that we can see the
> >> parent kernel context information in backtraces - and the fact that
> 
> I am not sure GDB is able to unwind stacks across processes (from child
> to parent).

It's not about unwinding across processes.  It's still the same process.

Let me give you a recent example.  This may be using frame pointers rather
than the unwinder, but serves to illustrate what we - as kernel developers -
absolutely must have from the kernel:

Internal error: Oops: 17 [#1] PREEMPT
Modules linked in: uinput g_ether cryptomgr aead arc4 crypto_algapi rt2800usb rt2800lib rt2x00usb rt2x00lib mac80211 cfg80211 sg pcmciamtd mousedev snd_soc_wm8750 snd_soc_pxa2xx_i2s snd_soc_core ohci_hcd usbcore pxa27x_udc physmap snd_pcm_oss snd_pcm snd_timer snd_page_alloc snd_mixer_oss snd soundcore rfcomm pxaficp_ir ircomm_tty ircomm irda ipv6 hidp hid bluetooth rfkill crc16
CPU: 0    Not tainted  (3.0.0-rc4+ #5)
PC is at complete+0x28/0x7c
LR is at complete+0x28/0x7c
pc : [<c0036b6c>]    lr : [<c0036b6c>]    psr: 80000093
sp : c3897b68  ip : c3897b68  fp : c3897b84
r10: c4806000  r9 : c381f3e0  r8 : 0000000a
r7 : c30f0da8  r6 : 00000000  r5 : 00000000  r4 : a0000013
r3 : c3896000  r2 : 00000000  r1 : 00000103  r0 : 00000004
Flags: Nzcv  IRQs off  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
Control: 0000397f  Table: a080c000  DAC: 00000017
Process kswapd0 (pid: 270, stack limit = 0xc3896278)
[<c0036b6c>] (complete+0x28/0x7c) from [<c01e9b0c>] (spi_complete+0x10/0x14)
[<c01e9b0c>] (spi_complete+0x10/0x14) from [<c01eac2c>] (giveback+0x114/0x12c)
[<c01eac2c>] (giveback+0x114/0x12c) from [<c01eb60c>] (pump_transfers+0x13c/0x6f8)
[<c01eb60c>] (pump_transfers+0x13c/0x6f8) from [<c0044924>] (tasklet_action+0x90/0xf0)
[<c0044924>] (tasklet_action+0x90/0xf0) from [<c0044eb8>] (__do_softirq+0x98/0x138)
[<c0044eb8>] (__do_softirq+0x98/0x138) from [<c00453a0>] (irq_exit+0x4c/0xa8)
[<c00453a0>] (irq_exit+0x4c/0xa8) from [<c002406c>] (asm_do_IRQ+0x6c/0x8c)
[<c002406c>] (asm_do_IRQ+0x6c/0x8c) from [<c0024b84>] (__irq_svc+0x44/0xcc)
Exception stack(0xc3897c78 to 0xc3897cc0)
7c60:                                                       4022d320 4022e000
7c80: 08000075 00001000 c32273c0 c03ce1c0 c2b49b78 4022d000 c2b420b4 00000001
7ca0: 00000000 c3897cfc 00000000 c3897cc0 c00afc54 c002edd8 00000013 ffffffff
[<c0024b84>] (__irq_svc+0x44/0xcc) from [<c002edd8>] (xscale_flush_user_cache_range+0x18/0x3c)
[<c002edd8>] (xscale_flush_user_cache_range+0x18/0x3c) from [<c00affd8>] (try_to_unmap_file+0x98/0x4ec)
[<c00affd8>] (try_to_unmap_file+0x98/0x4ec) from [<c00b07ac>] (try_to_unmap+0x40/0x60)
[<c00b07ac>] (try_to_unmap+0x40/0x60) from [<c009b940>] (shrink_page_list+0x2a8/0x8cc)
[<c009b940>] (shrink_page_list+0x2a8/0x8cc) from [<c009c448>] (shrink_inactive_list+0x218/0x344)
[<c009c448>] (shrink_inactive_list+0x218/0x344) from [<c009c8f8>] (shrink_zone+0x384/0x4ac)
[<c009c8f8>] (shrink_zone+0x384/0x4ac) from [<c009ceb0>] (kswapd+0x490/0x7d0)
[<c009ceb0>] (kswapd+0x490/0x7d0) from [<c0059be0>] (kthread+0x90/0x98)
[<c0059be0>] (kthread+0x90/0x98) from [<c00258d8>] (kernel_thread_exit+0x0/0x8)
Code: e3843080 e121f003 e3a00001 ebfff96a (e5953000)

This shows that we've unwound from 'complete' to '__irq_svc'.  That
may not be the full story though - the problem may relate to where we
were when we were interrupted (or indeed took the data or prefetch
abort).  So the unwinding from __irq_svc right back to kthread is
just as important.

This is all the same process - kthread() created PID270 (kswapd0) which
is the same process which was present when the interrupt happened.

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

On 6/28/11, Russell King - ARM Linux <linux@arm.linux.org.uk> wrote:
> On Mon, Jun 27, 2011 at 10:58:59PM +0800, Yao Qi wrote:
>> On 06/27/2011 10:04 PM, Dmitry Eremin-Solenikov wrote:
>> > Hello,
>> >
>> > On 27.06.2011 17:27, Russell King - ARM Linux wrote:
>> >> We _really_ _do_ want to unwind through this so that we can see the
>> >> parent kernel context information in backtraces - and the fact that
>>
>> I am not sure GDB is able to unwind stacks across processes (from child
>> to parent).
>
> It's not about unwinding across processes.  It's still the same process.
>
> Let me give you a recent example.  This may be using frame pointers rather
> than the unwinder, but serves to illustrate what we - as kernel developers -
> absolutely must have from the kernel:
>
> Internal error: Oops: 17 [#1] PREEMPT
> Modules linked in: uinput g_ether cryptomgr aead arc4 crypto_algapi
> rt2800usb rt2800lib rt2x00usb rt2x00lib mac80211 cfg80211 sg pcmciamtd
> mousedev snd_soc_wm8750 snd_soc_pxa2xx_i2s snd_soc_core ohci_hcd usbcore
> pxa27x_udc physmap snd_pcm_oss snd_pcm snd_timer snd_page_alloc
> snd_mixer_oss snd soundcore rfcomm pxaficp_ir ircomm_tty ircomm irda ipv6
> hidp hid bluetooth rfkill crc16
> CPU: 0    Not tainted  (3.0.0-rc4+ #5)
> PC is at complete+0x28/0x7c
> LR is at complete+0x28/0x7c
> pc : [<c0036b6c>]    lr : [<c0036b6c>]    psr: 80000093
> sp : c3897b68  ip : c3897b68  fp : c3897b84
> r10: c4806000  r9 : c381f3e0  r8 : 0000000a
> r7 : c30f0da8  r6 : 00000000  r5 : 00000000  r4 : a0000013
> r3 : c3896000  r2 : 00000000  r1 : 00000103  r0 : 00000004
> Flags: Nzcv  IRQs off  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
> Control: 0000397f  Table: a080c000  DAC: 00000017
> Process kswapd0 (pid: 270, stack limit = 0xc3896278)
> [<c0036b6c>] (complete+0x28/0x7c) from [<c01e9b0c>] (spi_complete+0x10/0x14)
> [<c01e9b0c>] (spi_complete+0x10/0x14) from [<c01eac2c>]
> (giveback+0x114/0x12c)
> [<c01eac2c>] (giveback+0x114/0x12c) from [<c01eb60c>]
> (pump_transfers+0x13c/0x6f8)
> [<c01eb60c>] (pump_transfers+0x13c/0x6f8) from [<c0044924>]
> (tasklet_action+0x90/0xf0)
> [<c0044924>] (tasklet_action+0x90/0xf0) from [<c0044eb8>]
> (__do_softirq+0x98/0x138)
> [<c0044eb8>] (__do_softirq+0x98/0x138) from [<c00453a0>]
> (irq_exit+0x4c/0xa8)
> [<c00453a0>] (irq_exit+0x4c/0xa8) from [<c002406c>] (asm_do_IRQ+0x6c/0x8c)
> [<c002406c>] (asm_do_IRQ+0x6c/0x8c) from [<c0024b84>] (__irq_svc+0x44/0xcc)
> Exception stack(0xc3897c78 to 0xc3897cc0)
> 7c60:                                                       4022d320
> 4022e000
> 7c80: 08000075 00001000 c32273c0 c03ce1c0 c2b49b78 4022d000 c2b420b4
> 00000001
> 7ca0: 00000000 c3897cfc 00000000 c3897cc0 c00afc54 c002edd8 00000013
> ffffffff
> [<c0024b84>] (__irq_svc+0x44/0xcc) from [<c002edd8>]
> (xscale_flush_user_cache_range+0x18/0x3c)
> [<c002edd8>] (xscale_flush_user_cache_range+0x18/0x3c) from [<c00affd8>]
> (try_to_unmap_file+0x98/0x4ec)
> [<c00affd8>] (try_to_unmap_file+0x98/0x4ec) from [<c00b07ac>]
> (try_to_unmap+0x40/0x60)
> [<c00b07ac>] (try_to_unmap+0x40/0x60) from [<c009b940>]
> (shrink_page_list+0x2a8/0x8cc)
> [<c009b940>] (shrink_page_list+0x2a8/0x8cc) from [<c009c448>]
> (shrink_inactive_list+0x218/0x344)
> [<c009c448>] (shrink_inactive_list+0x218/0x344) from [<c009c8f8>]
> (shrink_zone+0x384/0x4ac)
> [<c009c8f8>] (shrink_zone+0x384/0x4ac) from [<c009ceb0>]
> (kswapd+0x490/0x7d0)
> [<c009ceb0>] (kswapd+0x490/0x7d0) from [<c0059be0>] (kthread+0x90/0x98)
> [<c0059be0>] (kthread+0x90/0x98) from [<c00258d8>]
> (kernel_thread_exit+0x0/0x8)
> Code: e3843080 e121f003 e3a00001 ebfff96a (e5953000)
>
> This shows that we've unwound from 'complete' to '__irq_svc'.  That
> may not be the full story though - the problem may relate to where we
> were when we were interrupted (or indeed took the data or prefetch
> abort).  So the unwinding from __irq_svc right back to kthread is
> just as important.

I did some checks. It seems, the problem isn't related to unwinder. At least
it looks like kernel has all necessary unwinding subops. It looks like the
problem is really related to the lack of necessary .cfi information. At least
when i added .cfi_startproc/.cfi_endproc annotations to entry-armv.S code,
gdb stopped decoding backtrace with the "previous frame identical to this frame"
error. Unfortunately I don't have enough knowledge to add .cfi annotations to
irq handlers.

For the reference I'm providing the patch in the attachment.

Russell, will you agree to merge at least this partial solution, so
that gdb chokes,
but doesn't go to indefinite recursion? If you'd agree, I'll submit it
with proper
headers and sign-off.

-- 
With best wishes
Dmitry
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ARM_CFI.patch
Type: text/x-patch
Size: 1980 bytes
Desc: not available
URL: <http://lists.infradead.org/pipermail/linux-arm-kernel/attachments/20110628/61c0ad0d/attachment.bin>

Problem with GDB when debugging IRQ handlers

[Russell King - ARM Linux]

On Tue, Jun 28, 2011 at 04:06:11PM +0400, Dmitry Eremin-Solenikov wrote:
> For the reference I'm providing the patch in the attachment.
> 
> Russell, will you agree to merge at least this partial solution, so
> that gdb chokes,
> but doesn't go to indefinite recursion? If you'd agree, I'll submit it
> with proper
> headers and sign-off.

It looks like it does the right thing, but I think we need someone who
knows how the debug info is supposed to work comment.

Adding Catalin to the thread to see whether Catalin has any comments;
Catalin added the original unwinder annotations.

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 04:06:11PM +0400, Dmitry Eremin-Solenikov wrote:
> On 6/28/11, Russell King - ARM Linux <linux@arm.linux.org.uk> wrote:
> I did some checks. It seems, the problem isn't related to unwinder. At least
> it looks like kernel has all necessary unwinding subops. It looks like the
> problem is really related to the lack of necessary .cfi information. At least
> when i added .cfi_startproc/.cfi_endproc annotations to entry-armv.S code,
> gdb stopped decoding backtrace with the "previous frame identical to this frame"
> error. Unfortunately I don't have enough knowledge to add .cfi annotations to
> irq handlers.

I think it may have stopped decoding because of some information it
reads from the stack doesn't look sane. But I wonder whether we could
get it looping again depending on the register values in the interrupted
context.

> diff --git a/arch/arm/kernel/entry-armv.S b/arch/arm/kernel/entry-armv.S
> index e8d8856..d77f9d7 100644
> --- a/arch/arm/kernel/entry-armv.S
> +++ b/arch/arm/kernel/entry-armv.S
> @@ -28,6 +28,7 @@
>  #include "entry-header.S"
>  #include <asm/entry-macro-multi.S>
>  
> +	.cfi_sections	.debug_frame
>  /*
>   * Interrupt handling.  Preserves r7, r8, r9
>   */
> @@ -113,6 +114,7 @@ ENDPROC(__und_invalid)
>  
>  	.macro	svc_entry, stack_hole=0
>   UNWIND(.fnstart		)
> +	.cfi_startproc
>   UNWIND(.save {r0 - pc}		)
>  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)

Could you add some directives like below in the svc_entry macro (after
"sub sp...", not sure if it matters) and check whether gdb behaves
better:

	.cfi_def_cfa_offset S_PC
	.cfi_offset 14, -4

Thanks.

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 03:20:45PM +0100, Catalin Marinas wrote:
> On Tue, Jun 28, 2011 at 04:06:11PM +0400, Dmitry Eremin-Solenikov wrote:
> > On 6/28/11, Russell King - ARM Linux <linux@arm.linux.org.uk> wrote:
> > I did some checks. It seems, the problem isn't related to unwinder. At least
> > it looks like kernel has all necessary unwinding subops. It looks like the
> > problem is really related to the lack of necessary .cfi information. At least
> > when i added .cfi_startproc/.cfi_endproc annotations to entry-armv.S code,
> > gdb stopped decoding backtrace with the "previous frame identical to this frame"
> > error. Unfortunately I don't have enough knowledge to add .cfi annotations to
> > irq handlers.
> 
> I think it may have stopped decoding because of some information it
> reads from the stack doesn't look sane. But I wonder whether we could
> get it looping again depending on the register values in the interrupted
> context.
> 
> > diff --git a/arch/arm/kernel/entry-armv.S b/arch/arm/kernel/entry-armv.S
> > index e8d8856..d77f9d7 100644
> > --- a/arch/arm/kernel/entry-armv.S
> > +++ b/arch/arm/kernel/entry-armv.S
> > @@ -28,6 +28,7 @@
> >  #include "entry-header.S"
> >  #include <asm/entry-macro-multi.S>
> >  
> > +	.cfi_sections	.debug_frame
> >  /*
> >   * Interrupt handling.  Preserves r7, r8, r9
> >   */
> > @@ -113,6 +114,7 @@ ENDPROC(__und_invalid)
> >  
> >  	.macro	svc_entry, stack_hole=0
> >   UNWIND(.fnstart		)
> > +	.cfi_startproc
> >   UNWIND(.save {r0 - pc}		)
> >  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
> 
> Could you add some directives like below in the svc_entry macro (after
> "sub sp...", not sure if it matters) and check whether gdb behaves
> better:
> 
> 	.cfi_def_cfa_offset S_PC
> 	.cfi_offset 14, -4

Actually since the return address is in S_PC (which maybe gdb assumes it
would be the saved LR), this is probably not be correct. After SVC
entry, we have he following structure on the stack:

	ORIG_r0
	CPSR
		<--- assuming this is the Call Frame Address (SP+S_PC+4)
	PC	<--- CFA - 4
	LR	<--- don't care
	SP	<--- CFA - 12
	...


So we tell gdb about this with something like below (untested):

	.cfi_def_cfa_offset S_PC + 4
	.cfi_offset 14, -4
	.cfi_offset 13, -12

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Russell King - ARM Linux]

On Tue, Jun 28, 2011 at 03:30:14PM +0100, Catalin Marinas wrote:
> Actually since the return address is in S_PC (which maybe gdb assumes it
> would be the saved LR), this is probably not be correct. After SVC
> entry, we have he following structure on the stack:
> 
> 	ORIG_r0
> 	CPSR
> 		<--- assuming this is the Call Frame Address (SP+S_PC+4)
> 	PC	<--- CFA - 4
> 	LR	<--- don't care
> 	SP	<--- CFA - 12
> 	...

If I'm reading this correctly, it's not correct.

parent SP -->	parent context stack
		[possible empty word]
		ORIG_r0
		parent context CPSR
		parent context PC
		parent context LR
		parent context SP
		...
new SP -->	R0

That empty word may or may not be present if the parent SP is aligned to
a 64-bit boundary.

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 03:37:59PM +0100, Russell King - ARM Linux wrote:
> On Tue, Jun 28, 2011 at 03:30:14PM +0100, Catalin Marinas wrote:
> > Actually since the return address is in S_PC (which maybe gdb assumes it
> > would be the saved LR), this is probably not be correct. After SVC
> > entry, we have he following structure on the stack:
> > 
> > 	ORIG_r0
> > 	CPSR
> > 		<--- assuming this is the Call Frame Address (SP+S_PC+4)
> > 	PC	<--- CFA - 4
> > 	LR	<--- don't care
> > 	SP	<--- CFA - 12
> > 	...
> 
> If I'm reading this correctly, it's not correct.
> 
> parent SP -->	parent context stack
> 		[possible empty word]
> 		ORIG_r0
> 		parent context CPSR
> 		parent context PC
> 		parent context LR
> 		parent context SP
> 		...
> new SP -->	R0
> 
> That empty word may or may not be present if the parent SP is aligned to
> a 64-bit boundary.

But it shouldn't matter if we tell gdb that the previous SP (parent) is
stored in the current stack at CFA - 12. It calculates CFA by adding
S_PC+4 to the current SP, in which case the possible empty word doesn't
matter.

But please note that I don't have any gdb experience, so we need someone
else to confirm.

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
> On Tue, Jun 28, 2011 at 03:20:45PM +0100, Catalin Marinas wrote:
>> On Tue, Jun 28, 2011 at 04:06:11PM +0400, Dmitry Eremin-Solenikov wrote:
>> > On 6/28/11, Russell King - ARM Linux <linux@arm.linux.org.uk> wrote:
>> > I did some checks. It seems, the problem isn't related to unwinder. At
>> > least
>> > it looks like kernel has all necessary unwinding subops. It looks like
>> > the
>> > problem is really related to the lack of necessary .cfi information. At
>> > least
>> > when i added .cfi_startproc/.cfi_endproc annotations to entry-armv.S
>> > code,
>> > gdb stopped decoding backtrace with the "previous frame identical to
>> > this frame"
>> > error. Unfortunately I don't have enough knowledge to add .cfi
>> > annotations to
>> > irq handlers.
>>
>> I think it may have stopped decoding because of some information it
>> reads from the stack doesn't look sane. But I wonder whether we could
>> get it looping again depending on the register values in the interrupted
>> context.
>>
>> > diff --git a/arch/arm/kernel/entry-armv.S b/arch/arm/kernel/entry-armv.S
>> > index e8d8856..d77f9d7 100644
>> > --- a/arch/arm/kernel/entry-armv.S
>> > +++ b/arch/arm/kernel/entry-armv.S
>> > @@ -28,6 +28,7 @@
>> >  #include "entry-header.S"
>> >  #include <asm/entry-macro-multi.S>
>> >
>> > +	.cfi_sections	.debug_frame
>> >  /*
>> >   * Interrupt handling.  Preserves r7, r8, r9
>> >   */
>> > @@ -113,6 +114,7 @@ ENDPROC(__und_invalid)
>> >
>> >  	.macro	svc_entry, stack_hole=0
>> >   UNWIND(.fnstart		)
>> > +	.cfi_startproc
>> >   UNWIND(.save {r0 - pc}		)
>> >  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
>>
>> Could you add some directives like below in the svc_entry macro (after
>> "sub sp...", not sure if it matters) and check whether gdb behaves
>> better:
>>
>> 	.cfi_def_cfa_offset S_PC
>> 	.cfi_offset 14, -4
>
> Actually since the return address is in S_PC (which maybe gdb assumes it
> would be the saved LR), this is probably not be correct. After SVC
> entry, we have he following structure on the stack:
>
> 	ORIG_r0
> 	CPSR
> 		<--- assuming this is the Call Frame Address (SP+S_PC+4)
> 	PC	<--- CFA - 4
> 	LR	<--- don't care
> 	SP	<--- CFA - 12
> 	...
>
>
> So we tell gdb about this with something like below (untested):
>
> 	.cfi_def_cfa_offset S_PC + 4
> 	.cfi_offset 14, -4
> 	.cfi_offset 13, -12

This brings "unknown CFA rule" gdb exception, but it seems I got your idea.

-- 
With best wishes
Dmitry

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

On 6/28/11, Dmitry Eremin-Solenikov <dbaryshkov@gmail.com> wrote:
> On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
>> On Tue, Jun 28, 2011 at 03:20:45PM +0100, Catalin Marinas wrote:
>>> On Tue, Jun 28, 2011 at 04:06:11PM +0400, Dmitry Eremin-Solenikov wrote:
>>> > On 6/28/11, Russell King - ARM Linux <linux@arm.linux.org.uk> wrote:
>>> > I did some checks. It seems, the problem isn't related to unwinder. At
>>> > least
>>> > it looks like kernel has all necessary unwinding subops. It looks like
>>> > the
>>> > problem is really related to the lack of necessary .cfi information.
>>> > At
>>> > least
>>> > when i added .cfi_startproc/.cfi_endproc annotations to entry-armv.S
>>> > code,
>>> > gdb stopped decoding backtrace with the "previous frame identical to
>>> > this frame"
>>> > error. Unfortunately I don't have enough knowledge to add .cfi
>>> > annotations to
>>> > irq handlers.
>>>
>>> I think it may have stopped decoding because of some information it
>>> reads from the stack doesn't look sane. But I wonder whether we could
>>> get it looping again depending on the register values in the interrupted
>>> context.
>>>
>>> > diff --git a/arch/arm/kernel/entry-armv.S
>>> > b/arch/arm/kernel/entry-armv.S
>>> > index e8d8856..d77f9d7 100644
>>> > --- a/arch/arm/kernel/entry-armv.S
>>> > +++ b/arch/arm/kernel/entry-armv.S
>>> > @@ -28,6 +28,7 @@
>>> >  #include "entry-header.S"
>>> >  #include <asm/entry-macro-multi.S>
>>> >
>>> > +	.cfi_sections	.debug_frame
>>> >  /*
>>> >   * Interrupt handling.  Preserves r7, r8, r9
>>> >   */
>>> > @@ -113,6 +114,7 @@ ENDPROC(__und_invalid)
>>> >
>>> >  	.macro	svc_entry, stack_hole=0
>>> >   UNWIND(.fnstart		)
>>> > +	.cfi_startproc
>>> >   UNWIND(.save {r0 - pc}		)
>>> >  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
>>>
>>> Could you add some directives like below in the svc_entry macro (after
>>> "sub sp...", not sure if it matters) and check whether gdb behaves
>>> better:
>>>
>>> 	.cfi_def_cfa_offset S_PC
>>> 	.cfi_offset 14, -4
>>
>> Actually since the return address is in S_PC (which maybe gdb assumes it
>> would be the saved LR), this is probably not be correct. After SVC
>> entry, we have he following structure on the stack:
>>
>> 	ORIG_r0
>> 	CPSR
>> 		<--- assuming this is the Call Frame Address (SP+S_PC+4)
>> 	PC	<--- CFA - 4
>> 	LR	<--- don't care
>> 	SP	<--- CFA - 12
>> 	...
>>
>>
>> So we tell gdb about this with something like below (untested):
>>
>> 	.cfi_def_cfa_offset S_PC + 4
>> 	.cfi_offset 14, -4
>> 	.cfi_offset 13, -12
>
> This brings "unknown CFA rule" gdb exception, but it seems I got your idea.

No, this seems to work, it was my fault. I got more or less reasonable
backtrace now.

-- 
With best wishes
Dmitry

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 03:54:11PM +0100, Dmitry Eremin-Solenikov wrote:
> On 6/28/11, Dmitry Eremin-Solenikov <dbaryshkov@gmail.com> wrote:
> > On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
> >> Actually since the return address is in S_PC (which maybe gdb assumes it
> >> would be the saved LR), this is probably not be correct. After SVC
> >> entry, we have he following structure on the stack:
> >>
> >> 	ORIG_r0
> >> 	CPSR
> >> 		<--- assuming this is the Call Frame Address (SP+S_PC+4)
> >> 	PC	<--- CFA - 4
> >> 	LR	<--- don't care
> >> 	SP	<--- CFA - 12
> >> 	...
> >>
> >>
> >> So we tell gdb about this with something like below (untested):
> >>
> >> 	.cfi_def_cfa_offset S_PC + 4
> >> 	.cfi_offset 14, -4
> >> 	.cfi_offset 13, -12
> >
> > This brings "unknown CFA rule" gdb exception, but it seems I got your idea.
> 
> No, this seems to work, it was my fault. I got more or less reasonable
> backtrace now.

Does gdb manage to get into the parent stack frame?

BTW, are you compiling with FRAME_POINTER enabled? In this case you
would need to set some offset for the FP register (11). If you don't
mind missing the first part in the parent context, maybe something like
below:

	.cfi_def_cfa_offset S_PC
	.cfi_offset 14, -4
	.cfi_offset 13, -8
	.cfi_offset 11, -16

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
> On Tue, Jun 28, 2011 at 03:54:11PM +0100, Dmitry Eremin-Solenikov wrote:
>> On 6/28/11, Dmitry Eremin-Solenikov <dbaryshkov@gmail.com> wrote:
>> > On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
>> >> Actually since the return address is in S_PC (which maybe gdb assumes
>> >> it
>> >> would be the saved LR), this is probably not be correct. After SVC
>> >> entry, we have he following structure on the stack:
>> >>
>> >> 	ORIG_r0
>> >> 	CPSR
>> >> 		<--- assuming this is the Call Frame Address (SP+S_PC+4)
>> >> 	PC	<--- CFA - 4
>> >> 	LR	<--- don't care
>> >> 	SP	<--- CFA - 12
>> >> 	...
>> >>
>> >>
>> >> So we tell gdb about this with something like below (untested):
>> >>
>> >> 	.cfi_def_cfa_offset S_PC + 4
>> >> 	.cfi_offset 14, -4
>> >> 	.cfi_offset 13, -12
>> >
>> > This brings "unknown CFA rule" gdb exception, but it seems I got your
>> > idea.
>>
>> No, this seems to work, it was my fault. I got more or less reasonable
>> backtrace now.
>
> Does gdb manage to get into the parent stack frame?
>
> BTW, are you compiling with FRAME_POINTER enabled? In this case you
> would need to set some offset for the FP register (11). If you don't
> mind missing the first part in the parent context, maybe something like
> below:
>
> 	.cfi_def_cfa_offset S_PC
> 	.cfi_offset 14, -4
> 	.cfi_offset 13, -8
> 	.cfi_offset 11, -16

No, this seems wrong. Previous version was better. Here is a part of gdb log
generated using the attached patch:

Breakpoint 2, pxamci_start_cmd (host=0xc3bfd680, cmd=0xc3e7bed8,
cmdat=2112) at /run/shm/zigbee-kernel/drivers/mmc/host/pxamci.c:256
256		WARN_ON(host->cmd != NULL);
#0  pxamci_start_cmd (host=0xc3bfd680, cmd=0xc3e7bed8, cmdat=2112) at
/run/shm/zigbee-kernel/drivers/mmc/host/pxamci.c:256
#1  0xc0248870 in mmc_start_request (host=0xc3bfd400, mrq=0xc3e7beb0)
at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:196
#2  0xc02488bc in mmc_wait_for_req (host=0xc3bfd400, mrq=0xc3e7beb0)
at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:220
#3  0xc0248930 in mmc_wait_for_cmd (host=0xc3bfd400, cmd=0xc3e7bed8,
retries=0) at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:249
#4  0xc024ef48 in mmc_io_rw_direct_host (host=0xc3bfd400, write=<value
optimized out>, fn=<value optimized out>, addr=<value optimized out>,
in=<value optimized out>, out=0xc3e7bf3f  <incomplete sequence \330>)
at /run/shm/zigbee-kernel/drivers/mmc/core/sdio_ops.c:89
#5  0xc024efd4 in sdio_reset (host=0xc3bfd400) at
/run/shm/zigbee-kernel/drivers/mmc/core/sdio_ops.c:191
#6  0xc0249974 in mmc_rescan_try_freq (host=0xc3bfd400, freq=<value
optimized out>) at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:1548
#7  0xc0249b60 in mmc_rescan (work=0xc3bfd618) at
/run/shm/zigbee-kernel/drivers/mmc/core/core.c:1609
#8  0xc00638b0 in process_one_work (worker=0xc3e63580,
work=0xc3bfd618) at /run/shm/zigbee-kernel/kernel/workqueue.c:1868
#9  0xc0063e2c in worker_thread (__worker=<value optimized out>) at
/run/shm/zigbee-kernel/kernel/workqueue.c:1979
#10 0xc00675dc in kthread (_create=0xc3e41ef0) at
/run/shm/zigbee-kernel/kernel/kthread.c:96
#11 0xc0033810 in kernel_thread_helper ()
#12 0xc0033810 in kernel_thread_helper ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Breakpoint 1, pxamci_irq (irq=39, devid=0xc3bfd680) at
/run/shm/zigbee-kernel/drivers/mmc/host/pxamci.c:397
397		testtt();
#0  pxamci_irq (irq=39, devid=0xc3bfd680) at
/run/shm/zigbee-kernel/drivers/mmc/host/pxamci.c:397
#1  0xc0084fa4 in handle_irq_event_percpu (desc=0xc3e05ea0,
action=0xc399f1c0) at /run/shm/zigbee-kernel/kernel/irq/handle.c:126
#2  0xc0085128 in handle_irq_event (desc=0xc3e05ea0) at
/run/shm/zigbee-kernel/kernel/irq/handle.c:182
#3  0xc00871d0 in handle_level_irq (irq=<value optimized out>,
desc=0xc3e05ea0) at /run/shm/zigbee-kernel/kernel/irq/chip.c:345
#4  0xc0084f64 in generic_handle_irq_desc (irq=39) at
/run/shm/zigbee-kernel/include/linux/irqdesc.h:111
#5  generic_handle_irq (irq=39) at
/run/shm/zigbee-kernel/kernel/irq/irqdesc.c:304
#6  0xc0032060 in asm_do_IRQ (irq=39, regs=<value optimized out>) at
/run/shm/zigbee-kernel/arch/arm/kernel/irq.c:90
#7  0xc0032b50 in __irq_svc () at
/run/shm/zigbee-kernel/arch/arm/kernel/entry-armv.S:222
#8  0xc0253bc4 in arch_local_irq_restore (host=0xc3bfd680,
cmd=0xc3e7bed8, cmdat=2113) at
/run/shm/zigbee-kernel/arch/arm/include/asm/irqflags.h:142
#9  spin_unlock_irqrestore (host=0xc3bfd680, cmd=0xc3e7bed8,
cmdat=2113) at /run/shm/zigbee-kernel/include/linux/spinlock.h:340
#10 pxamci_enable_irq (host=0xc3bfd680, cmd=0xc3e7bed8, cmdat=2113) at
/run/shm/zigbee-kernel/drivers/mmc/host/pxamci.c:160
#11 pxamci_start_cmd (host=0xc3bfd680, cmd=0xc3e7bed8, cmdat=2113) at
/run/shm/zigbee-kernel/drivers/mmc/host/pxamci.c:285
#12 0xc0248870 in mmc_start_request (host=0xc3bfd400, mrq=0xc3e7beb0)
at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:196
#13 0xc02488bc in mmc_wait_for_req (host=0xc3bfd400, mrq=0xc3e7beb0)
at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:220
#14 0xc0248930 in mmc_wait_for_cmd (host=0xc3bfd400, cmd=0xc3e7bed8,
retries=0) at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:249
#15 0xc024ef48 in mmc_io_rw_direct_host (host=0xc3bfd400, write=<value
optimized out>, fn=<value optimized out>, addr=<value optimized out>,
in=<value optimized out>, out=0xc3e7bf3f  <incomplete sequence \330>)
at /run/shm/zigbee-kernel/drivers/mmc/core/sdio_ops.c:89
#16 0xc024efd4 in sdio_reset (host=0xc3bfd400) at
/run/shm/zigbee-kernel/drivers/mmc/core/sdio_ops.c:191
#17 0xc0249974 in mmc_rescan_try_freq (host=0xc3bfd400, freq=<value
optimized out>) at /run/shm/zigbee-kernel/drivers/mmc/core/core.c:1548
#18 0xc0249b60 in mmc_rescan (work=0xc3bfd618) at
/run/shm/zigbee-kernel/drivers/mmc/core/core.c:1609
#19 0xc00638b0 in process_one_work (worker=0xc3e63580,
work=0xc3bfd618) at /run/shm/zigbee-kernel/kernel/workqueue.c:1868
#20 0xc0063e2c in worker_thread (__worker=<value optimized out>) at
/run/shm/zigbee-kernel/kernel/workqueue.c:1979
#21 0xc00675dc in kthread (_create=0xc3e41ef0) at
/run/shm/zigbee-kernel/kernel/kthread.c:96
#22 0xc0033810 in kernel_thread_helper ()
#23 0xc0033810 in kernel_thread_helper ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Colleagues, does this look suitable for you?

-- 
With best wishes
Dmitry
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ARM_CFI.patch
Type: text/x-patch
Size: 2492 bytes
Desc: not available
URL: <http://lists.infradead.org/pipermail/linux-arm-kernel/attachments/20110628/316f4c3f/attachment.bin>

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 04:45:52PM +0100, Dmitry Eremin-Solenikov wrote:
> Here is a part of gdb log generated using the attached patch:
[...]
> #11 0xc0033810 in kernel_thread_helper ()
> #12 0xc0033810 in kernel_thread_helper ()
> Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Maybe you can add something similar to the kernel_thread_helper in
arch/arm/kernel/process.c? I'm not sure whether there is something like
.cantunwind (as for the kernel unwinding information).

> diff --git a/arch/arm/kernel/entry-armv.S b/arch/arm/kernel/entry-armv.S
> index e8d8856..44daf40 100644
> --- a/arch/arm/kernel/entry-armv.S
> +++ b/arch/arm/kernel/entry-armv.S
> @@ -28,6 +28,7 @@
>  #include "entry-header.S"
>  #include <asm/entry-macro-multi.S>
>  
> +	.cfi_sections	.debug_frame
>  /*
>   * Interrupt handling.  Preserves r7, r8, r9
>   */
> @@ -113,6 +114,7 @@ ENDPROC(__und_invalid)
>  
>  	.macro	svc_entry, stack_hole=0
>   UNWIND(.fnstart		)
> +	.cfi_startproc
>   UNWIND(.save {r0 - pc}		)
>  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
>  #ifdef CONFIG_THUMB2_KERNEL
> @@ -146,6 +148,24 @@ ENDPROC(__und_invalid)
>  	@  r4 - orig_r0 (see pt_regs definition in ptrace.h)
>  	@
>  	stmia	r5, {r0 - r4}
> +	.cfi_def_cfa_offset S_PC + 4
> +	.cfi_offset 14, -4
> +#define	CFI_REG_OFF(r) .cfi_offset r, (r - 16) * 4
> +	CFI_REG_OFF(13)
> +	CFI_REG_OFF(12)
> +	CFI_REG_OFF(11)
> +	CFI_REG_OFF(10)
> +	CFI_REG_OFF(9)
> +	CFI_REG_OFF(8)
> +	CFI_REG_OFF(7)
> +	CFI_REG_OFF(6)
> +	CFI_REG_OFF(5)
> +	CFI_REG_OFF(4)
> +	CFI_REG_OFF(3)
> +	CFI_REG_OFF(2)
> +	CFI_REG_OFF(1)
> +	CFI_REG_OFF(0)
> +#undef CFI_REG_OFF
>  	.endm

Do we need all the registers in here for gdb stack unwinding? In general
we would only need LR, SP and FP.

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
> On Tue, Jun 28, 2011 at 04:45:52PM +0100, Dmitry Eremin-Solenikov wrote:
>> Here is a part of gdb log generated using the attached patch:
> [...]
>> #11 0xc0033810 in kernel_thread_helper ()
>> #12 0xc0033810 in kernel_thread_helper ()
>> Backtrace stopped: previous frame identical to this frame (corrupt stack?)
>
> Maybe you can add something similar to the kernel_thread_helper in
> arch/arm/kernel/process.c? I'm not sure whether there is something like
> .cantunwind (as for the kernel unwinding information).
>
>> diff --git a/arch/arm/kernel/entry-armv.S b/arch/arm/kernel/entry-armv.S
>> index e8d8856..44daf40 100644
>> --- a/arch/arm/kernel/entry-armv.S
>> +++ b/arch/arm/kernel/entry-armv.S
>> @@ -28,6 +28,7 @@
>>  #include "entry-header.S"
>>  #include <asm/entry-macro-multi.S>
>>
>> +	.cfi_sections	.debug_frame
>>  /*
>>   * Interrupt handling.  Preserves r7, r8, r9
>>   */
>> @@ -113,6 +114,7 @@ ENDPROC(__und_invalid)
>>
>>  	.macro	svc_entry, stack_hole=0
>>   UNWIND(.fnstart		)
>> +	.cfi_startproc
>>   UNWIND(.save {r0 - pc}		)
>>  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
>>  #ifdef CONFIG_THUMB2_KERNEL
>> @@ -146,6 +148,24 @@ ENDPROC(__und_invalid)
>>  	@  r4 - orig_r0 (see pt_regs definition in ptrace.h)
>>  	@
>>  	stmia	r5, {r0 - r4}
>> +	.cfi_def_cfa_offset S_PC + 4
>> +	.cfi_offset 14, -4
>> +#define	CFI_REG_OFF(r) .cfi_offset r, (r - 16) * 4
>> +	CFI_REG_OFF(13)
>> +	CFI_REG_OFF(12)
>> +	CFI_REG_OFF(11)
>> +	CFI_REG_OFF(10)
>> +	CFI_REG_OFF(9)
>> +	CFI_REG_OFF(8)
>> +	CFI_REG_OFF(7)
>> +	CFI_REG_OFF(6)
>> +	CFI_REG_OFF(5)
>> +	CFI_REG_OFF(4)
>> +	CFI_REG_OFF(3)
>> +	CFI_REG_OFF(2)
>> +	CFI_REG_OFF(1)
>> +	CFI_REG_OFF(0)
>> +#undef CFI_REG_OFF
>>  	.endm
>
> Do we need all the registers in here for gdb stack unwinding? In general
> we would only need LR, SP and FP.

CFI info isn't only related to stack unwinding. IIUC (I'll have to run
more experiments)
these instrutions will help me to get correct variables/arguments
values in the before-exception stack frames.

>
> --
> Catalin
>
>


-- 
With best wishes
Dmitry

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 11:26:28PM +0100, Dmitry Eremin-Solenikov wrote:
> On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
> > On Tue, Jun 28, 2011 at 04:45:52PM +0100, Dmitry Eremin-Solenikov wrote:
> >>  	.macro	svc_entry, stack_hole=0
> >>   UNWIND(.fnstart		)
> >> +	.cfi_startproc
> >>   UNWIND(.save {r0 - pc}		)
> >>  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
> >>  #ifdef CONFIG_THUMB2_KERNEL
> >> @@ -146,6 +148,24 @@ ENDPROC(__und_invalid)
> >>  	@  r4 - orig_r0 (see pt_regs definition in ptrace.h)
> >>  	@
> >>  	stmia	r5, {r0 - r4}
> >> +	.cfi_def_cfa_offset S_PC + 4
> >> +	.cfi_offset 14, -4
> >> +#define	CFI_REG_OFF(r) .cfi_offset r, (r - 16) * 4
> >> +	CFI_REG_OFF(13)
> >> +	CFI_REG_OFF(12)
> >> +	CFI_REG_OFF(11)
> >> +	CFI_REG_OFF(10)
> >> +	CFI_REG_OFF(9)
> >> +	CFI_REG_OFF(8)
> >> +	CFI_REG_OFF(7)
> >> +	CFI_REG_OFF(6)
> >> +	CFI_REG_OFF(5)
> >> +	CFI_REG_OFF(4)
> >> +	CFI_REG_OFF(3)
> >> +	CFI_REG_OFF(2)
> >> +	CFI_REG_OFF(1)
> >> +	CFI_REG_OFF(0)
> >> +#undef CFI_REG_OFF
> >>  	.endm
> >
> > Do we need all the registers in here for gdb stack unwinding? In general
> > we would only need LR, SP and FP.
> 
> CFI info isn't only related to stack unwinding. IIUC (I'll have to run
> more experiments) these instrutions will help me to get correct
> variables/arguments values in the before-exception stack frames.

OK, in this case we may need to add some annotations. You could actually
generate a .s file from and existing C one (including -g) and see what
.cfi directives it generates.

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Dmitry Eremin-Solenikov]

On 6/29/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
> On Tue, Jun 28, 2011 at 11:26:28PM +0100, Dmitry Eremin-Solenikov wrote:
>> On 6/28/11, Catalin Marinas <catalin.marinas@arm.com> wrote:
>> > On Tue, Jun 28, 2011 at 04:45:52PM +0100, Dmitry Eremin-Solenikov wrote:
>> >>  	.macro	svc_entry, stack_hole=0
>> >>   UNWIND(.fnstart		)
>> >> +	.cfi_startproc
>> >>   UNWIND(.save {r0 - pc}		)
>> >>  	sub	sp, sp, #(S_FRAME_SIZE + \stack_hole - 4)
>> >>  #ifdef CONFIG_THUMB2_KERNEL
>> >> @@ -146,6 +148,24 @@ ENDPROC(__und_invalid)
>> >>  	@  r4 - orig_r0 (see pt_regs definition in ptrace.h)
>> >>  	@
>> >>  	stmia	r5, {r0 - r4}
>> >> +	.cfi_def_cfa_offset S_PC + 4
>> >> +	.cfi_offset 14, -4
>> >> +#define	CFI_REG_OFF(r) .cfi_offset r, (r - 16) * 4
>> >> +	CFI_REG_OFF(13)
>> >> +	CFI_REG_OFF(12)
>> >> +	CFI_REG_OFF(11)
>> >> +	CFI_REG_OFF(10)
>> >> +	CFI_REG_OFF(9)
>> >> +	CFI_REG_OFF(8)
>> >> +	CFI_REG_OFF(7)
>> >> +	CFI_REG_OFF(6)
>> >> +	CFI_REG_OFF(5)
>> >> +	CFI_REG_OFF(4)
>> >> +	CFI_REG_OFF(3)
>> >> +	CFI_REG_OFF(2)
>> >> +	CFI_REG_OFF(1)
>> >> +	CFI_REG_OFF(0)
>> >> +#undef CFI_REG_OFF
>> >>  	.endm
>> >
>> > Do we need all the registers in here for gdb stack unwinding? In general
>> > we would only need LR, SP and FP.
>>
>> CFI info isn't only related to stack unwinding. IIUC (I'll have to run
>> more experiments) these instrutions will help me to get correct
>> variables/arguments values in the before-exception stack frames.
>
> OK, in this case we may need to add some annotations. You could actually
> generate a .s file from and existing C one (including -g) and see what
> .cfi directives it generates.

Yes, that actually gave me some ideas. Unfortunately entry*.S files are
a bit ... uncommon, so there are nearly no 1-1 cases. BTW: It seems x86
has .cfi annotations connected to most if not all assembler commands.
I think this is a bit too much, but you got the idea.

-- 
With best wishes
Dmitry

Problem with GDB when debugging IRQ handlers

[Hui Zhu]

If this kernel didn't open FRAME_POINTER, what will happen?

On Tue, Jun 28, 2011 at 18:39, Russell King - ARM Linux
<linux@arm.linux.org.uk> wrote:
> On Mon, Jun 27, 2011 at 10:58:59PM +0800, Yao Qi wrote:
>> On 06/27/2011 10:04 PM, Dmitry Eremin-Solenikov wrote:
>> > Hello,
>> >
>> > On 27.06.2011 17:27, Russell King - ARM Linux wrote:
>> >> We _really_ _do_ want to unwind through this so that we can see the
>> >> parent kernel context information in backtraces - and the fact that
>>
>> I am not sure GDB is able to unwind stacks across processes (from child
>> to parent).
>
> It's not about unwinding across processes. ?It's still the same process.
>
> Let me give you a recent example. ?This may be using frame pointers rather
> than the unwinder, but serves to illustrate what we - as kernel developers -
> absolutely must have from the kernel:
>
> Internal error: Oops: 17 [#1] PREEMPT
> Modules linked in: uinput g_ether cryptomgr aead arc4 crypto_algapi rt2800usb rt2800lib rt2x00usb rt2x00lib mac80211 cfg80211 sg pcmciamtd mousedev snd_soc_wm8750 snd_soc_pxa2xx_i2s snd_soc_core ohci_hcd usbcore pxa27x_udc physmap snd_pcm_oss snd_pcm snd_timer snd_page_alloc snd_mixer_oss snd soundcore rfcomm pxaficp_ir ircomm_tty ircomm irda ipv6 hidp hid bluetooth rfkill crc16
> CPU: 0 ? ?Not tainted ?(3.0.0-rc4+ #5)
> PC is at complete+0x28/0x7c
> LR is at complete+0x28/0x7c
> pc : [<c0036b6c>] ? ?lr : [<c0036b6c>] ? ?psr: 80000093
> sp : c3897b68 ?ip : c3897b68 ?fp : c3897b84
> r10: c4806000 ?r9 : c381f3e0 ?r8 : 0000000a
> r7 : c30f0da8 ?r6 : 00000000 ?r5 : 00000000 ?r4 : a0000013
> r3 : c3896000 ?r2 : 00000000 ?r1 : 00000103 ?r0 : 00000004
> Flags: Nzcv ?IRQs off ?FIQs on ?Mode SVC_32 ?ISA ARM ?Segment kernel
> Control: 0000397f ?Table: a080c000 ?DAC: 00000017
> Process kswapd0 (pid: 270, stack limit = 0xc3896278)
> [<c0036b6c>] (complete+0x28/0x7c) from [<c01e9b0c>] (spi_complete+0x10/0x14)
> [<c01e9b0c>] (spi_complete+0x10/0x14) from [<c01eac2c>] (giveback+0x114/0x12c)
> [<c01eac2c>] (giveback+0x114/0x12c) from [<c01eb60c>] (pump_transfers+0x13c/0x6f8)
> [<c01eb60c>] (pump_transfers+0x13c/0x6f8) from [<c0044924>] (tasklet_action+0x90/0xf0)
> [<c0044924>] (tasklet_action+0x90/0xf0) from [<c0044eb8>] (__do_softirq+0x98/0x138)
> [<c0044eb8>] (__do_softirq+0x98/0x138) from [<c00453a0>] (irq_exit+0x4c/0xa8)
> [<c00453a0>] (irq_exit+0x4c/0xa8) from [<c002406c>] (asm_do_IRQ+0x6c/0x8c)
> [<c002406c>] (asm_do_IRQ+0x6c/0x8c) from [<c0024b84>] (__irq_svc+0x44/0xcc)
> Exception stack(0xc3897c78 to 0xc3897cc0)
> 7c60: ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? 4022d320 4022e000
> 7c80: 08000075 00001000 c32273c0 c03ce1c0 c2b49b78 4022d000 c2b420b4 00000001
> 7ca0: 00000000 c3897cfc 00000000 c3897cc0 c00afc54 c002edd8 00000013 ffffffff
> [<c0024b84>] (__irq_svc+0x44/0xcc) from [<c002edd8>] (xscale_flush_user_cache_range+0x18/0x3c)
> [<c002edd8>] (xscale_flush_user_cache_range+0x18/0x3c) from [<c00affd8>] (try_to_unmap_file+0x98/0x4ec)
> [<c00affd8>] (try_to_unmap_file+0x98/0x4ec) from [<c00b07ac>] (try_to_unmap+0x40/0x60)
> [<c00b07ac>] (try_to_unmap+0x40/0x60) from [<c009b940>] (shrink_page_list+0x2a8/0x8cc)
> [<c009b940>] (shrink_page_list+0x2a8/0x8cc) from [<c009c448>] (shrink_inactive_list+0x218/0x344)
> [<c009c448>] (shrink_inactive_list+0x218/0x344) from [<c009c8f8>] (shrink_zone+0x384/0x4ac)
> [<c009c8f8>] (shrink_zone+0x384/0x4ac) from [<c009ceb0>] (kswapd+0x490/0x7d0)
> [<c009ceb0>] (kswapd+0x490/0x7d0) from [<c0059be0>] (kthread+0x90/0x98)
> [<c0059be0>] (kthread+0x90/0x98) from [<c00258d8>] (kernel_thread_exit+0x0/0x8)
> Code: e3843080 e121f003 e3a00001 ebfff96a (e5953000)
>
> This shows that we've unwound from 'complete' to '__irq_svc'. ?That
> may not be the full story though - the problem may relate to where we
> were when we were interrupted (or indeed took the data or prefetch
> abort). ?So the unwinding from __irq_svc right back to kthread is
> just as important.
>
> This is all the same process - kthread() created PID270 (kswapd0) which
> is the same process which was present when the interrupt happened.
>

Problem with GDB when debugging IRQ handlers

[Russell King - ARM Linux]

On Tue, Jun 28, 2011 at 08:06:27PM +0800, Hui Zhu wrote:
> If this kernel didn't open FRAME_POINTER, what will happen?

I can't answer that question directly, as I don't use a toolchain new
enough to generate proper unwind information.

However, I haven't seen any problems being reported on the list with
bad/broken backtraces from the kernel, so my _assumption_ is that the
kernel is fine with its own debug info.

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Tue, Jun 28, 2011 at 01:09:28PM +0100, Russell King - ARM Linux wrote:
> On Tue, Jun 28, 2011 at 08:06:27PM +0800, Hui Zhu wrote:
> > If this kernel didn't open FRAME_POINTER, what will happen?
> 
> I can't answer that question directly, as I don't use a toolchain new
> enough to generate proper unwind information.
> 
> However, I haven't seen any problems being reported on the list with
> bad/broken backtraces from the kernel, so my _assumption_ is that the
> kernel is fine with its own debug info.

I tested this when contributing the unwinding support and it was ok. The
reason is that the svc_entry macro in entry-armv.S adds some annotations
line .fnstart and .save that generate the correct unwinding bytecodes
(but as I said, that's different from the dwarf information which
probably needs different annotations).

-- 
Catalin

Problem with GDB when debugging IRQ handlers

[Catalin Marinas]

On Mon, Jun 27, 2011 at 02:27:35PM +0100, Russell King - ARM Linux wrote:
> On Mon, Jun 27, 2011 at 04:53:06PM +0400, Dmitry Eremin-Solenikov wrote:
> > I've got into a problem when trying to debug irq handlers on PXA (in
> > qemu). backtrace is really strange from my POV (a target is just a qemu
> > running a bit modified 3.0-rc2 kernel):
> ...
> > Breakpoint 1, handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
> > 329		mask_ack_irq(desc);
> > (gdb) bt
> > #0  handle_level_irq (irq=42, desc=0xc3e06000) at kernel/irq/chip.c:329
> > #1  0xc0085f64 in generic_handle_irq_desc (irq=42) at include/linux/irqdesc.h:111
> > #2  generic_handle_irq (irq=42) at kernel/irq/irqdesc.c:304
> > #3  0xc0033060 in asm_do_IRQ (irq=42, regs=<value optimized out>) at arch/arm/kernel/irq.c:90
> > #4  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #5  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #6  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #7  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #8  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #9  0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #10 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #11 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > #12 0xc0033b50 in __irq_svc () at arch/arm/kernel/entry-armv.S:202
> > 
> > ... and so on it continues ad infinitum. Is it the expected behaviour?
> > Because I'm pretty much sure that this isn't a desired behaviour.
> 
> My guess is that gdb is trying to unwind using the unwind information.
> However, I don't think we actually give the assembler the full information
> to be able to unwind this.  I've no idea how to solve this as I'm no
> expert at the debug info.

I don't think gdb is using the unwind information that we get in the
kernel (that's actually the information used for C++ exceptions). Gdb is
in general using the dwarf information in the vmlinux file (which we
don't get in the final Image file).

-- 
Catalin