最新消息:20210816 当前crifan.com域名已被污染,为防止失联,请关注(页面右下角的)公众号

The foggy crystal ball: Understanding Oopses

工作和技术 crifan 1619浏览 0评论
[ZT]<a target="_blank" href="https://bugzilla.novell.com/bugreporting-faq/oops-reading.txt"><font color="#ff0000" size="5">The foggy crystal ball: Understanding Oopses</font></a>
<font color="#0000ff"><strong>(What is oops ,and how to use the oops to do debug -&gt; the kernel panic )</strong></font>
In the introduction, we already covered how to capture an oops.  In this
document, we will look at the format of an oops in some detail, and
demonstrate what can be learned from that information.

1. Interpreting Oops messages
=============================

The following will assume that the oops includes symbolic names for
all addresses, either because the kernel already supports the kallsyms
feature, or because the oops was massages by syslogd or ksymooops
already.

Here is a typical oops from a SLES9 beta kernel:

    Unable to handle kernel NULL pointer dereference at virtual address 00000094
     printing eip:
    c02b47f6
    *pde = 00000000
    Oops: 0000 [#1]
    CPU:    0
    EIP:    0060:[<c02b47f6>]    Tainted: G  U
    EFLAGS: 00010202   (2.6.5-7.97-default) 
    EIP is at udp_rcv+0xf6/0x5e0
    eax: cfb53b80   ebx: df206844   ecx: 0e217d13   edx: 00000020
    esi: 00002088   edi: 00882088   ebp: 00000000   esp: c0399e88
    ds: 007b   es: 007b   ss: 0068
    Process swapper (pid: 0, threadinfo=c0398000 task=c033b100)
    Stack: e1047860 00000000 e10478a0 c0284f0e 00000000 4480b609 4180b609 df206844 
           cfb53b80 cfb53b80 c035e0a0 00000000 00000000 c0294982 00000000 00000001 
           00000002 c0285bca 00000000 cfb53b80 c03ffe88 cfb53b80 c856f030 d263f080 
    Call Trace:
     [<c0284f0e>] nf_iterate+0x5e/0xb0
     [<c0294982>] ip_local_deliver_finish+0x52/0x1c0
     [<c0285bca>] nf_hook_slow+0xea/0xf0
     [<c0294c5a>] ip_local_deliver+0x16a/0x220
     [<c0294930>] ip_local_deliver_finish+0x0/0x1c0
     [<c0294873>] ip_rcv+0x3c3/0x480
     [<c027cf40>] netif_receive_skb+0x210/0x220
     [<c02799f2>] alloc_skb+0x32/0xd0
     [<e104ce33>] e100_poll+0x2d3/0x650 [e100]
     [<c027bda2>] net_rx_action+0xa2/0xf0
     [<c01231e3>] __do_softirq+0x43/0x90
     [<c0123256>] do_softirq+0x26/0x30
     [<c010a8f5>] do_IRQ+0x125/0x1a0
     [<c0108d48>] common_interrupt+0x18/0x20
     [<c0106290>] default_idle+0x0/0x30
     [<c01062b3>] default_idle+0x23/0x30
     [<c0106dac>] cpu_idle+0x1c/0x40
     [<c039a629>] start_kernel+0x299/0x300

    Code: f7 85 94 00 00 00 00 00 00 30 0f 84 62 01 00 00 8b 4c 24 1c 

How do we interpret such an oops? Let's go through the message in some
detail before explaining all the fields in their entirety.

The very first line gives you a clue why the exception happened, in this
case the kernel tried to access an invalid address (00000094).

As it's a very small integer, this is less likely to be a corrupted pointer
but rather an offset (0x94) added to address 0. This happens if you have a 
NULL pointer to a struct, say "struct foo *mypointer", any your code tries
to access "mypointer->somevar" with struct member somevar at offset 0x94.

Next comes the instruction pointer (EIP on i386) as hex address; and a few
lines down the same address displayed relative to the closes symbol known
to the kernel.

These symbols deserve a little explanation.  In the example
above, the exception happened when executing the instruction at
"udp_rcv+0xf6/0x5e0". This indicates an offset of 0xf6 counting from the
start of function udp_rcv. The second hex number indicates what the kernel
thinks is the length of that function. In fact, it's the distance to the
next global symbol; there can actually be static functions that follow
udp_rcv which do not show up in the symbol table. However, these two
numbers can give you a rough indication of where the crash happened. In
this case, the problematic statement should be no more than a dozen
lines from the start of udp_rcv().

A few lines down there is the pid and name of the process that died.
In this case, it's the swapper (pid 0), which is not a regular process.
This indicates that we crashed inside an interrupt or a bottom half
handler.

Another important piece of information is the dump of all registers.
Here the kernel basically displays the content of all registers prior
to the execution of the faulting instruction. This can help location
the problem when looking at the disassembly dump. As we're not looking
at the disassembly (yet), we'll ignore these for now.

Following the process information, the oops includes a hexdump of the
top of the stack. Some of the words on the stack are return addresses,
so the kernel also tries to translate map these into symbols. The
algorithm used is rather simple-minded; the Suse kernel doesn't use
frame pointers, and it doesn't have any other debugging information
(such as dwarf) available either. Therefore, it uses a simple heuristic
to check whether a given value could be the address of a kernel function
or not, and if it thinks so, it will map it to the closes symbol. 

This will usually give you a close idea of the call chain, but you
should not treat this as 100% reliable. For instance, the stack may
contain left-overs from previous function calls that show up as weird
blips in the backtrace. Similar, if function pointers are passed around
as arguments on the stack, these will show up in the backtrace as well.

In the example above, the function names that stick out are
common_interrupt (confirming the fact that we're handling an interrupt),
ip_rcv (confirming that we're delivering an IP packet, and nf_hook_slow.
The latter is in the packet filtering code, and is never called unless
a packet filter has been installed. So we know that the kernel was
configured to do packet filtering.

The last line of the oops shows the instruction(s) that the
faulting location. Even without much knowledge of i386 assembler,
the "94 00 00 00" sticks out, which matches exactly the offset 0x94
we hypothesized above. And indeed, feeding the oops above to
ksymoops shows that the instruction is "testl  $0x30000000,0x94(%ebp)".

2. Looking at the disassembly
=============================

Now that we know the oops happened in udp_rcv, it may be time to look
at the disassembly (we could skip this step and look at the source code
directly, but for the sake of a didactic example, please bear with me :).

Probably the easiest way is to use gdb and the "disas" command. If the
offending function is in the kernel itself (as opposed to a loadable
module), you will need a copy of the uncompressed kernel image. The
Suse kernel RPMs all contain a gzipped copy as /boot/vmlinux.gz (SLES8)
or /boot/vmlinux-<kernelversions>.gz. Simply uncompress this image and
run gdb on it.

If the offending function is in a module, you can also use gdb on the
module object directly. Alternatively, you can use the objdump utility
to obtain a full text dump of the entire module, which is a little more
than you actually need, but on the other hand it allows you search
this dump more efficiently using grep etc.

Following through with our example, here's the section of code in
udp_rcv where the crash happens:

0xc02b47df <udp_rcv+226>:       push   %eax
0xc02b47e0 <udp_rcv+227>:       push   %edi
0xc02b47e1 <udp_rcv+228>:       push   %ebx
0xc02b47e2 <udp_rcv+229>:       call   0xc02b467d <udp_checksum_init>
0xc02b47e7 <udp_rcv+234>:       add    $0x14,%esp
0xc02b47ea <udp_rcv+237>:       test   %eax,%eax
0xc02b47ec <udp_rcv+239>:       js     0xc02b4746 <udp_rcv+73>
0xc02b47f2 <udp_rcv+245>:       mov    0x8(%esp,1),%ebp
0xc02b47f6 <udp_rcv+249>:       testl  $0x30000000,0x94(%ebp) <---- HERE
0xc02b47fd <udp_rcv+256>:       je     0xc02601e8 <udp_rcv+296>
0xc02b47ff <udp_rcv+258>:       mov    (%esp,1),%eax
0xc02b4802 <udp_rcv+261>:       push   %eax

What we can see here is that the offending instruction immediately
follows a function call to udp_checksum_init(). This is easily
located in udp_rcv:

    struct rtable *rt = (struct rtable*) skb->dst;

    ...
        if (udp_checksum_init(skb, uh, ulen, saddr, daddr) < 0)
                goto csum_error;
        if (rt->rt_flags & (RTCF_BROADCAST|RTCF_MULTICAST))
                return udp_v4_mcast_deliver(skb, uh, saddr, daddr);

The crash occurs in the second if() statement because the pointer "rt"
was NULL, which in turn was initialized from skb->dst at the top of
the function. This should never happen...

3. Conclusion
=============

So now we know where it crashed, and what the immediate cause for this
crash was. From here on, debugging is mostly about understanding the code,
and figuring out what triggers this unexpected condition.

In the case discussed above, the description of what happens is actually
not really straightforward, so if you're interested in the bug itself
(and the fix), please refer to SUSE bug #42902.

4. Detailed anatomy of an Oops
==============================

5. Special oops features
========================

[Describe version specific oops features, such as cvs timestamps here]

N. Authors
==========
Olaf Kirch    <[email protected]>

转载请注明:在路上 » The foggy crystal ball: Understanding Oopses

发表我的评论
取消评论

表情

Hi,您需要填写昵称和邮箱!

  • 昵称 (必填)
  • 邮箱 (必填)
  • 网址
79 queries in 0.185 seconds, using 22.13MB memory