Oops tracing

rrlangly · 06-30-2011, 09:37 AM

I'm trying to find the problem in a kernel module I'm writing. I've listed the output from running "decodecode < oops.txt", and below that is the Oops output from my kernel module.

I don't know assembly, but I'm guessing from the 'decodecode' output that movl line says I'm writing in a null value. So, how do I now find what line of code this is in my kernel module?

Any help much appreciated.

Code:

$ /usr/src/linux/scripts/decodecode < ./oops.txt 

Jun 30 01:24:52 gecko kernel: [ 255.147010] Code: fe 60 81 48 8b bd 50 ff ff ff e8 3f f7 fd ff 48 8b 85 50 ff ff ff 48 81 c4 c8 00 00 00 5b c9 c3 90 90 90 55 48 8d 47 08 48 89 e5 <c7> 07 00 00 00 00 48 89 47 08 48 89 47 10 c9 c3 55 48 89 e5 41
All code
========
   0:   fe                      (bad)  
   1:   60                      (bad)  
   2:   81 48 8b bd 50 ff ff    orl    $0xffff50bd,-0x75(%rax)
   9:   ff e8                   ljmpq  *<internal disassembler error>
   b:   3f                      (bad)  
   c:   f7 fd                   idiv   %ebp
   e:   ff 48 8b                decl   -0x75(%rax)
  11:   85 50 ff                test   %edx,-0x1(%rax)
  14:   ff                      (bad)  
  15:   ff 48 81                decl   -0x7f(%rax)
  18:   c4 c8 00 00             (bad)(bad) 
  1c:   00 5b c9                add    %bl,-0x37(%rbx)
  1f:   c3                      retq   
  20:   90                      nop
  21:   90                      nop
  22:   90                      nop
  23:   55                      push   %rbp
  24:   48 8d 47 08             lea    0x8(%rdi),%rax
  28:   48 89 e5                mov    %rsp,%rbp
  2b:*  c7 07 00 00 00 00       movl   $0x0,(%rdi)     <-- trapping instruction
  31:   48 89 47 08             mov    %rax,0x8(%rdi)
  35:   48 89 47 10             mov    %rax,0x10(%rdi)
  39:   c9                      leaveq 
  3a:   c3                      retq   
  3b:   55                      push   %rbp
  3c:   48 89 e5                mov    %rsp,%rbp
  3f:   41                      rex.B

Code starting with the faulting instruction
===========================================
   0:   c7 07 00 00 00 00       movl   $0x0,(%rdi)
   6:   48 89 47 08             mov    %rax,0x8(%rdi)
   a:   48 89 47 10             mov    %rax,0x10(%rdi)
   e:   c9                      leaveq 
   f:   c3                      retq   
  10:   55                      push   %rbp
  11:   48 89 e5                mov    %rsp,%rbp
  14:   41                      rex.B

Looks like decodecode has shown me where the offending instruction is. But now, how to match this to the source?

Code:

Jun 30 01:24:52 gecko kernel: [  255.146217] BUG: unable to handle kernel pag
ing request at ffffffff8141a734
Jun 30 01:24:52 gecko kernel: [  255.147010] IP: [<ffffffff810811b4>] __init_
waitqueue_head+0x8/0x18
Jun 30 01:24:52 gecko kernel: [  255.147010] PGD 1a0b067 PUD 1a0f063 PMD 1400
1e1
Jun 30 01:24:52 gecko kernel: [  255.147010] Oops: 0003 [#1] SMP
Jun 30 01:24:52 gecko kernel: [  255.147010] last sysfs file: /sys/devices/vi
rtio-pci/virtio1/block/vda/dev
Jun 30 01:24:52 gecko kernel: [  255.147010] CPU 0
Jun 30 01:24:52 gecko kernel: [  255.147010] Modules linked in: tst1 tst2
Jun 30 01:24:52 gecko kernel: [  255.147010]
Jun 30 01:24:52 gecko kernel: [  255.147010] Pid: 1655, comm: tstlisten Not tain
ted 2.6.36-gentoo-r5 #8 /Bochs
Jun 30 01:24:52 gecko kernel: [  255.147010] RIP: 0010:[<ffffffff810811b4>]  
[<ffffffff810811b4>] __init_waitqueue_head+0x8/0x18
Jun 30 01:24:52 gecko kernel: [  255.147010] RSP: 0018:ffff88001edebd78  EFLA
GS: 00010282
Jun 30 01:24:52 gecko kernel: [  255.147010] RAX: ffffffff8141a73c RBX: ffff88001c41a000 RCX: ffffffff814194be
Jun 30 01:24:52 gecko kernel: [  255.147010] RDX: ffffffff8141a734 RSI: ffffffff81c48740 RDI: ffffffff8141a734
Jun 30 01:24:52 gecko kernel: [  255.147010] RBP: ffff88001edebd78 R08: ffff880001e10390 R09: 0000000000000000
Jun 30 01:24:52 gecko kernel: [  255.147010] R10: 0000000000000005 R11: dead000000200200 R12: ffff88001f951400
Jun 30 01:24:52 gecko kernel: [  255.147010] R13: ffffffff8141a734 R14: 0000000000000040 R15: 0000000000000000
Jun 30 01:24:52 gecko kernel: [  255.147010] FS:  00007f02582a2700(0000) GS:ffff880001e00000(0000) knlGS:0000000000000000
Jun 30 01:24:52 gecko kernel: [  255.147010] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jun 30 01:24:52 gecko kernel: [  255.147010] CR2: ffffffff8141a734 CR3: 000000001efe4000 CR4: 00000000000006f0
Jun 30 01:24:52 gecko kernel: [  255.147010] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jun 30 01:24:52 gecko kernel: [  255.147010] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jun 30 01:24:52 gecko kernel: [  255.147010] Process tstlisten (pid: 1655, threadinfo ffff88001edea000, task ffff88001ec43410)
Jun 30 01:24:52 gecko kernel: [  255.147010] Stack:
Jun 30 01:24:52 gecko kernel: [  255.147010]  ffff88001edebda8 ffffffff81419553 ffff88001f951400 ffff88001f951400
Jun 30 01:24:52 gecko kernel: [  255.147010] <0> 0000000000000001 0000000000000001 ffff88001edebdc8 ffffffff8111f294
Jun 30 01:24:52 gecko kernel: [  255.147010] <0> ffff88001f951400 ffffffff81c32e50 ffff88001edebdf8 ffffffff8111f311
Jun 30 01:24:52 gecko kernel: [  255.147010] Call Trace:
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff81419553>] sock_alloc_inode+0xb1/0xf2
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff8111f294>] alloc_inode+0x18/0x76
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff8111f311>] new_inode+0x1f/0xb3
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffffa00001d1>] ? T.757+0xe/0x10 [tst1]
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff81416ff6>] sock_alloc+0x14/0x58
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff81417655>] __sock_create+0x97/0x1a3
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffffa00003fd>] ? mod_create+0x22a/0x3c1 [tst1]
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff814177ad>] sock_create+0x2b/0x2d
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffffa0000473>] mod_create+0x2a0/0x3c1 [tst1]
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff814176df>] __sock_create+0x121/0x1a3
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff814177ad>] sock_create+0x2b/0x2d
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff81417968>] sys_socket+0x26/0x57
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff81555425>] ? page_fault+0x25/0x30
Jun 30 01:24:52 gecko kernel: [  255.147010]  [<ffffffff8102ba42>] system_call_fastpath+0x16/0x1b
Jun 30 01:24:52 gecko kernel: [  255.147010] Code: fe 60 81 48 8b bd 50 ff ff ff e8 3f f7 fd ff 48 8b 85 50 ff ff ff 48 81 c4 c8 00 00 00 5b c9 c3 90 90 90 55 48 8d 47 08 48 89 e5 <c7> 07 00 00 00 00 48 89 47 08 48 89 47 10 c9 c3 55 48 89 e5 41
Jun 30 01:24:52 gecko kernel: [  255.147010] RIP  [<ffffffff810811b4>] __init_waitqueue_head+0x8/0x18
Jun 30 01:24:52 gecko kernel: [  255.147010]  RSP <ffff88001edebd78>
Jun 30 01:24:52 gecko kernel: [  255.147010] CR2: ffffffff8141a734
Jun 30 01:24:52 gecko kernel: [  255.147010] ---[ end trace 0da814b5844c54b3 ]---

nini09 · 06-30-2011, 02:16 PM

I don't think your decodecode tool work correctly because so many bad instruction.

bsat · 07-01-2011, 12:19 AM

from the oops message it looks like a problem in the __init_waitqueue_head, make sure you have initialized everything that you have used in the function.

rrlangly · 07-01-2011, 06:07 PM

Quote:

Originally Posted by bsat

from the oops message it looks like a problem in the __init_waitqueue_head, make sure you have initialized everything that you have used in the function.

I guess that's what's got me a bit confused. I don't have __init_waitqueue_head anywhere's in my code. I do call sock_create() (and I see that in the stacktrace), and everything in my function is initialized.