Re: ACPI: kmemcheck: Caught 16-bit read from freed memory (f7c12ec6)

[Vegard Nossum]

Hi,

On Tue, May 6, 2008 at 10:54 PM, Pekka Enberg <penberg@xxxxxxxxxxxxxx> wrote:
>
> Vegard Nossum wrote:
>
> > On Tue, May 6, 2008 at 10:38 PM, Pekka Enberg <penberg@xxxxxxxxxxxxxx>
> wrote:
> >
> > > On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@xxxxxxxxx>
> wrote:
> > >  >  Running kmemcheck on top of v2.6.26-rc1 gives the following (never
> > >  >  before seen) warning:
> > >  >
> > >  >  Linux Plug and Play Support v0.97 (c) Adam Belay
> > >  >  pnp: PnP ACPI init
> > >  >  ACPI: bus type pnp registered
> > >  >  kmemcheck: Caught 16-bit read from freed memory (f7c12ec6)
> > >  >
> > >  >  Pid: 1, comm: swapper Not tainted (2.6.26-rc1-00010-g7966e04 #2)
> > >  >  EIP: 0060:[<c027ecaa>] EFLAGS: 00010286 CPU: 0
> > >  >  EIP is at acpi_ps_get_next_arg+0x1b8/0x262
> > >  >  EAX: f7c12ec0 EBX: f7d20428 ECX: f7ca1b00 EDX: 00000001
> > >  >  ESI: 00000049 EDI: f7d20400 EBP: f7c61e38 ESP: c06c9dc8
> > >  >   DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> > >  >  CR0: 8005003b CR2: f7c46456 CR3: 006ba000 CR4: 000006c0
> > >  >  DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
> > >  >  DR6: ffff4ff0 DR7: 00000400
> > >  >   [<c0119192>] kmemcheck_read+0xe2/0x140
> > >  >   [<c0119326>] kmemcheck_access+0x136/0x1a0
> > >  >   [<c04bd286>] do_page_fault+0x5e6/0x690
> > >  >   [<c04bb2da>] error_code+0x72/0x78
> > >  >   [<c027f991>] acpi_ps_parse_loop+0x4dd/0x7f8
> > >  >   [<c027ee36>] acpi_ps_parse_aml+0xb4/0x332
> > >  >   [<c02802c0>] acpi_ps_execute_method+0x13d/0x20d
> > >  >   [<c027c8a2>] acpi_ns_evaluate+0x10e/0x1b0
> > >  >   [<c0283210>] acpi_ut_evaluate_object+0x51/0x18d
> > >  >   [<c0283406>] acpi_ut_execute_STA+0x22/0x7b
> > >  >   [<c027c18b>] acpi_ns_get_device_callback+0x5a/0x121
> > >  >   [<c027e410>] acpi_ns_walk_namespace+0xf0/0x10c
> > >  >   [<c027c0b5>] acpi_get_devices+0x47/0x5d
> > >  >   [<c068db45>] pnpacpi_init+0x65/0xa0
> > >  >   [<c06735c7>] kernel_init+0x127/0x290
> > >  >   [<c0104cc7>] kernel_thread_helper+0x7/0x10
> > >  >   [<ffffffff>] 0xffffffff
> > >  >  pnp: PnP ACPI: found 17 devices
> > >  >  ACPI: ACPI bus type pnp unregistered
> > >  >
> > >  >  This faulting instruction comes from
> > >  >
> > >  >  $ addr2line -e vmlinux -i c027ecaa
> > >  >  drivers/acpi/parser/psargs.c:694
> > >
> > >  (That's some seriously hairy code in ACPI btw.)
> > >
> > >  Vegard, can you do disassembly for the faulting instruction? I *think*
> > >  it's the "walk_state->op" bit that is hanging to an object that was
> > >  already deleted in the strange loop in acpi_ps_parse_loop() but it
> > >  would be good to have some more data on this.
> > >
> >
> > Of course. This is in fact another image, but the EIP (and indeed
> > EAX...EDX) are exactly the same. I hope this doesn't get mangled too
> > much by gmail. It's a lot, though :-)
> >
>
>  [snip]
>
>
>
> > c027ec9b:       89 45 e4                mov    %eax,-0x1c(%ebp)
> > c027ec9e:       0f 84 9e 00 00 00       je     c027ed42
> <acpi_ps_get_next_arg+0x250>
> > c027eca4:       8b 87 d4 01 00 00       mov    0x1d4(%edi),%eax
> > c027ecaa:       66 81 78 06 2a 5b       cmpw   $0x5b2a,0x6(%eax)
> >
> >       ^--- EIP here
> >
> > Well, at least kmemcheck correctly identifies it as a 16-bit read...
> >
>
>  Aah, I didn't notice it was a 16-bit read. But yeah at offset 6 we have
> 16-bit aml_opcode:
>
>  #define ACPI_PARSE_COMMON \
>         union acpi_parse_object         *parent; \
>         u8                              descriptor_type; \
>         u8                              flags; \
>         u16                             aml_opcode; \
>
>  So walk_state->op probably points to an object that was already free'd.
> Len?

I turned on ACPI logging just in case you can use it for something.
The full log was a whopping 36M, so I grepped for the memory address
in question (actually, "f7c12ec." since the last digit is 0 for the
start of the object and 6 for the ->op). It turns up a few times; in
particular:

 psutils-0177 [F7C5C000] [00] ps_free_op            : Free retval op: f7c12ec0
 psutils-0177 [F7C5C000] [00] ps_free_op            : Free retval op: f7c12ec0

but you should keep in mind that the kmemcheck report will turn up
out-of-line, probably a long time after the actual error. (The
stack-trace and register dump is correct, though.)

I've uploaded the log to here:

http://userweb.kernel.org/~vegard/bugs/20080507-acpi/relevant.txt

The full log is also available at full.txt. I hope it can help.


Vegard

-- 
"The animistic metaphor of the bug that maliciously sneaked in while
the programmer was not looking is intellectually dishonest as it
disguises that the error is the programmer's own creation."
	-- E. W. Dijkstra, EWD1036
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/