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

From: Lin Ming
Date: Wed May 07 2008 - 21:43:35 EST


I'm looking at this issue.

Thanks for the info

Lin Ming

On Wed, 2008-05-07 at 21:21 +0200, Vegard Nossum wrote:
> 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
>

--
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/