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

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

[Pekka Enberg]

On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@gmail.com> 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.

                        Pekka

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

[Vegard Nossum]

On Tue, May 6, 2008 at 10:38 PM, Pekka Enberg <penberg@cs.helsinki.fi> wrote:
>
> On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@gmail.com> 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 :-)

c027eaf2 <acpi_ps_get_next_arg>:
c027eaf2:	55                   	push   %ebp
c027eaf3:	89 e5                	mov    %esp,%ebp
c027eaf5:	57                   	push   %edi
c027eaf6:	89 c7                	mov    %eax,%edi
c027eaf8:	56                   	push   %esi
c027eaf9:	89 ce                	mov    %ecx,%esi
c027eafb:	53                   	push   %ebx
c027eafc:	89 d3                	mov    %edx,%ebx
c027eafe:	8d 41 ff             	lea    -0x1(%ecx),%eax
c027eb01:	83 ec 10             	sub    $0x10,%esp
c027eb04:	83 f8 11             	cmp    $0x11,%eax
c027eb07:	0f 87 fb 01 00 00    	ja     c027ed08 <acpi_ps_get_next_arg+0x216>
c027eb0d:	ff 24 85 c4 f4 4d c0 	jmp    *-0x3fb20b3c(,%eax,4)
c027eb14:	b8 0a 00 00 00       	mov    $0xa,%eax
c027eb19:	e8 1a 15 00 00       	call   c0280038 <acpi_ps_alloc_op>
c027eb1e:	85 c0                	test   %eax,%eax
c027eb20:	89 45 e4             	mov    %eax,-0x1c(%ebp)
c027eb23:	0f 84 19 02 00 00    	je     c027ed42 <acpi_ps_get_next_arg+0x250>
c027eb29:	89 c1                	mov    %eax,%ecx
c027eb2b:	89 f2                	mov    %esi,%edx
c027eb2d:	89 d8                	mov    %ebx,%eax
c027eb2f:	e8 d8 fc ff ff       	call   c027e80c <acpi_ps_get_next_simple_arg>
c027eb34:	e9 fd 01 00 00       	jmp    c027ed36 <acpi_ps_get_next_arg+0x244>
c027eb39:	89 d0                	mov    %edx,%eax
c027eb3b:	e8 65 fc ff ff       	call   c027e7a5 <acpi_ps_get_next_package_end>
c027eb40:	89 43 10             	mov    %eax,0x10(%ebx)
c027eb43:	e9 e7 01 00 00       	jmp    c027ed2f <acpi_ps_get_next_arg+0x23d>
c027eb48:	8b 7a 04             	mov    0x4(%edx),%edi
c027eb4b:	3b 7a 10             	cmp    0x10(%edx),%edi
c027eb4e:	0f 83 db 01 00 00    	jae    c027ed2f <acpi_ps_get_next_arg+0x23d>
c027eb54:	c7 45 e4 00 00 00 00 	movl   $0x0,-0x1c(%ebp)
c027eb5b:	c7 45 e8 00 00 00 00 	movl   $0x0,-0x18(%ebp)
c027eb62:	8b 03                	mov    (%ebx),%eax
c027eb64:	89 45 f0             	mov    %eax,-0x10(%ebp)
c027eb67:	8a 07                	mov    (%edi),%al
c027eb69:	84 c0                	test   %al,%al
c027eb6b:	74 0c                	je     c027eb79 <acpi_ps_get_next_arg+0x87>
c027eb6d:	fe c8                	dec    %al
c027eb6f:	66 c7 45 ee 30 00    	movw   $0x30,-0x12(%ebp)
c027eb75:	75 1c                	jne    c027eb93 <acpi_ps_get_next_arg+0xa1>
c027eb77:	eb 0e                	jmp    c027eb87 <acpi_ps_get_next_arg+0x95>
c027eb79:	8d 47 01             	lea    0x1(%edi),%eax
c027eb7c:	89 43 04             	mov    %eax,0x4(%ebx)
c027eb7f:	66 c7 45 ee 31 00    	movw   $0x31,-0x12(%ebp)
c027eb85:	eb 0c                	jmp    c027eb93 <acpi_ps_get_next_arg+0xa1>
c027eb87:	8d 47 01             	lea    0x1(%edi),%eax
c027eb8a:	89 43 04             	mov    %eax,0x4(%ebx)
c027eb8d:	66 c7 45 ee 32 00    	movw   $0x32,-0x12(%ebp)
c027eb93:	0f b7 45 ee          	movzwl -0x12(%ebp),%eax
c027eb97:	e8 9c 14 00 00       	call   c0280038 <acpi_ps_alloc_op>
c027eb9c:	85 c0                	test   %eax,%eax
c027eb9e:	89 c6                	mov    %eax,%esi
c027eba0:	0f 84 9c 01 00 00    	je     c027ed42 <acpi_ps_get_next_arg+0x250>
c027eba6:	2b 7d f0             	sub    -0x10(%ebp),%edi
c027eba9:	89 78 08             	mov    %edi,0x8(%eax)
c027ebac:	66 83 7d ee 31       	cmpw   $0x31,-0x12(%ebp)
c027ebb1:	74 1e                	je     c027ebd1 <acpi_ps_get_next_arg+0xdf>
c027ebb3:	66 83 7d ee 32       	cmpw   $0x32,-0x12(%ebp)
c027ebb8:	74 23                	je     c027ebdd <acpi_ps_get_next_arg+0xeb>
c027ebba:	66 83 7d ee 30       	cmpw   $0x30,-0x12(%ebp)
c027ebbf:	75 47                	jne    c027ec08 <acpi_ps_get_next_arg+0x116>
c027ebc1:	8b 43 04             	mov    0x4(%ebx),%eax
c027ebc4:	8b 10                	mov    (%eax),%edx
c027ebc6:	89 f0                	mov    %esi,%eax
c027ebc8:	e8 0b 14 00 00       	call   c027ffd8 <acpi_ps_set_name>
c027ebcd:	83 43 04 04          	addl   $0x4,0x4(%ebx)
c027ebd1:	89 d8                	mov    %ebx,%eax
c027ebd3:	e8 74 fb ff ff       	call   c027e74c
<acpi_ps_get_next_package_length>
c027ebd8:	89 46 14             	mov    %eax,0x14(%esi)
c027ebdb:	eb 2b                	jmp    c027ec08 <acpi_ps_get_next_arg+0x116>
c027ebdd:	8b 43 04             	mov    0x4(%ebx),%eax
c027ebe0:	31 d2                	xor    %edx,%edx
c027ebe2:	0f b6 00             	movzbl (%eax),%eax
c027ebe5:	c7 46 18 00 00 00 00 	movl   $0x0,0x18(%esi)
c027ebec:	c1 e0 08             	shl    $0x8,%eax
c027ebef:	89 46 14             	mov    %eax,0x14(%esi)
c027ebf2:	8b 4b 04             	mov    0x4(%ebx),%ecx
c027ebf5:	8d 41 01             	lea    0x1(%ecx),%eax
c027ebf8:	89 43 04             	mov    %eax,0x4(%ebx)
c027ebfb:	0f b6 41 01          	movzbl 0x1(%ecx),%eax
c027ebff:	09 46 14             	or     %eax,0x14(%esi)
c027ec02:	09 56 18             	or     %edx,0x18(%esi)
c027ec05:	ff 43 04             	incl   0x4(%ebx)
c027ec08:	83 7d e8 00          	cmpl   $0x0,-0x18(%ebp)
c027ec0c:	75 05                	jne    c027ec13 <acpi_ps_get_next_arg+0x121>
c027ec0e:	89 75 e4             	mov    %esi,-0x1c(%ebp)
c027ec11:	eb 06                	jmp    c027ec19 <acpi_ps_get_next_arg+0x127>
c027ec13:	8b 55 e8             	mov    -0x18(%ebp),%edx
c027ec16:	89 72 0c             	mov    %esi,0xc(%edx)
c027ec19:	8b 7b 04             	mov    0x4(%ebx),%edi
c027ec1c:	8b 43 10             	mov    0x10(%ebx),%eax
c027ec1f:	89 75 e8             	mov    %esi,-0x18(%ebp)
c027ec22:	39 c7                	cmp    %eax,%edi
c027ec24:	0f 82 38 ff ff ff    	jb     c027eb62 <acpi_ps_get_next_arg+0x70>
c027ec2a:	eb 36                	jmp    c027ec62 <acpi_ps_get_next_arg+0x170>
c027ec2c:	8b 42 04             	mov    0x4(%edx),%eax
c027ec2f:	3b 42 10             	cmp    0x10(%edx),%eax
c027ec32:	0f 83 f7 00 00 00    	jae    c027ed2f <acpi_ps_get_next_arg+0x23d>
c027ec38:	b8 33 00 00 00       	mov    $0x33,%eax
c027ec3d:	e8 f6 13 00 00       	call   c0280038 <acpi_ps_alloc_op>
c027ec42:	85 c0                	test   %eax,%eax
c027ec44:	89 45 e4             	mov    %eax,-0x1c(%ebp)
c027ec47:	0f 84 f5 00 00 00    	je     c027ed42 <acpi_ps_get_next_arg+0x250>
c027ec4d:	8b 43 10             	mov    0x10(%ebx),%eax
c027ec50:	8b 55 e4             	mov    -0x1c(%ebp),%edx
c027ec53:	2b 43 04             	sub    0x4(%ebx),%eax
c027ec56:	89 42 14             	mov    %eax,0x14(%edx)
c027ec59:	8b 43 04             	mov    0x4(%ebx),%eax
c027ec5c:	89 42 24             	mov    %eax,0x24(%edx)
c027ec5f:	8b 43 10             	mov    0x10(%ebx),%eax
c027ec62:	89 43 04             	mov    %eax,0x4(%ebx)
c027ec65:	e9 cc 00 00 00       	jmp    c027ed36 <acpi_ps_get_next_arg+0x244>
c027ec6a:	89 d0                	mov    %edx,%eax
c027ec6c:	e8 f2 00 00 00       	call   c027ed63 <acpi_ps_peek_opcode>
c027ec71:	66 85 c0             	test   %ax,%ax
c027ec74:	74 19                	je     c027ec8f <acpi_ps_get_next_arg+0x19d>
c027ec76:	0f b7 f0             	movzwl %ax,%esi
c027ec79:	89 f0                	mov    %esi,%eax
c027ec7b:	e8 29 13 00 00       	call   c027ffa9 <acpi_ps_is_leading_char>
c027ec80:	84 c0                	test   %al,%al
c027ec82:	75 0b                	jne    c027ec8f <acpi_ps_get_next_arg+0x19d>
c027ec84:	89 f0                	mov    %esi,%eax
c027ec86:	e8 37 13 00 00       	call   c027ffc2 <acpi_ps_is_prefix_char>
c027ec8b:	84 c0                	test   %al,%al
c027ec8d:	74 5f                	je     c027ecee <acpi_ps_get_next_arg+0x1fc>
c027ec8f:	b8 2d 00 00 00       	mov    $0x2d,%eax
c027ec94:	e8 9f 13 00 00       	call   c0280038 <acpi_ps_alloc_op>
c027ec99:	85 c0                	test   %eax,%eax
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...

c027ecb0:	75 29                	jne    c027ecdb <acpi_ps_get_next_arg+0x1e9>
c027ecb2:	8b 4d e4             	mov    -0x1c(%ebp),%ecx
c027ecb5:	89 da                	mov    %ebx,%edx
c027ecb7:	89 f8                	mov    %edi,%eax
c027ecb9:	6a 01                	push   $0x1
c027ecbb:	e8 2f fc ff ff       	call   c027e8ef <acpi_ps_get_next_namepath>
c027ecc0:	5f                   	pop    %edi
c027ecc1:	89 c3                	mov    %eax,%ebx
c027ecc3:	8b 45 e4             	mov    -0x1c(%ebp),%eax
c027ecc6:	66 83 78 06 35       	cmpw   $0x35,0x6(%eax)
c027eccb:	75 6b                	jne    c027ed38 <acpi_ps_get_next_arg+0x246>
c027eccd:	e8 14 13 00 00       	call   c027ffe6 <acpi_ps_free_op>
c027ecd2:	c7 45 e4 00 00 00 00 	movl   $0x0,-0x1c(%ebp)
c027ecd9:	eb 5d                	jmp    c027ed38 <acpi_ps_get_next_arg+0x246>
c027ecdb:	8b 4d e4             	mov    -0x1c(%ebp),%ecx
c027ecde:	89 da                	mov    %ebx,%edx
c027ece0:	89 f8                	mov    %edi,%eax
c027ece2:	6a 00                	push   $0x0
c027ece4:	e8 06 fc ff ff       	call   c027e8ef <acpi_ps_get_next_namepath>
c027ece9:	5e                   	pop    %esi
c027ecea:	89 c3                	mov    %eax,%ebx
c027ecec:	eb 4a                	jmp    c027ed38 <acpi_ps_get_next_arg+0x246>
c027ecee:	c7 47 54 01 00 00 00 	movl   $0x1,0x54(%edi)
c027ecf5:	eb 38                	jmp    c027ed2f <acpi_ps_get_next_arg+0x23d>
c027ecf7:	8b 42 04             	mov    0x4(%edx),%eax
c027ecfa:	3b 42 10             	cmp    0x10(%edx),%eax
c027ecfd:	73 30                	jae    c027ed2f <acpi_ps_get_next_arg+0x23d>
c027ecff:	c7 47 54 ff ff ff ff 	movl   $0xffffffff,0x54(%edi)
c027ed06:	eb 27                	jmp    c027ed2f <acpi_ps_get_next_arg+0x23d>
c027ed08:	56                   	push   %esi
c027ed09:	bb 05 30 00 00       	mov    $0x3005,%ebx
c027ed0e:	68 ce 1a 5b c0       	push   $0xc05b1ace
c027ed13:	68 e8 02 00 00       	push   $0x2e8
c027ed18:	ff 35 0c f5 4d c0    	pushl  0xc04df50c
c027ed1e:	e8 b2 4d 00 00       	call   c0283ad5 <acpi_ut_error>
c027ed23:	c7 45 e4 00 00 00 00 	movl   $0x0,-0x1c(%ebp)
c027ed2a:	83 c4 10             	add    $0x10,%esp
c027ed2d:	eb 09                	jmp    c027ed38 <acpi_ps_get_next_arg+0x246>
c027ed2f:	c7 45 e4 00 00 00 00 	movl   $0x0,-0x1c(%ebp)
c027ed36:	31 db                	xor    %ebx,%ebx
c027ed38:	8b 45 08             	mov    0x8(%ebp),%eax
c027ed3b:	8b 55 e4             	mov    -0x1c(%ebp),%edx
c027ed3e:	89 10                	mov    %edx,(%eax)
c027ed40:	eb 05                	jmp    c027ed47 <acpi_ps_get_next_arg+0x255>
c027ed42:	bb 04 00 00 00       	mov    $0x4,%ebx
c027ed47:	8d 65 f4             	lea    -0xc(%ebp),%esp
c027ed4a:	89 d8                	mov    %ebx,%eax
c027ed4c:	5b                   	pop    %ebx
c027ed4d:	5e                   	pop    %esi
c027ed4e:	5f                   	pop    %edi
c027ed4f:	5d                   	pop    %ebp
c027ed50:	c3                   	ret
c027ed51:	90                   	nop
c027ed52:	90                   	nop
c027ed53:	90                   	nop

Thanks! :-)


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

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

[Pekka Enberg]

Vegard Nossum wrote:
> On Tue, May 6, 2008 at 10:38 PM, Pekka Enberg <penberg@cs.helsinki.fi> wrote:
>> On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@gmail.com> 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?

			Pekka

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@cs.helsinki.fi> wrote:
>
> Vegard Nossum wrote:
>
> > On Tue, May 6, 2008 at 10:38 PM, Pekka Enberg <penberg@cs.helsinki.fi>
> wrote:
> >
> > > On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@gmail.com>
> 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

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

[Lin Ming]

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@cs.helsinki.fi> wrote:
> >
> > Vegard Nossum wrote:
> >
> > > On Tue, May 6, 2008 at 10:38 PM, Pekka Enberg <penberg@cs.helsinki.fi>
> > wrote:
> > >
> > > > On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@gmail.com>
> > 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
> 

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

[Lin Ming]

Here comes a simple patch that fixes the warning in my machine.

Vegard, would you please help to test it in your machine?

Thanks,
Lin Ming

Signed-off-by: Lin Ming <ming.m.lin@intel.com>
---
diff --git a/drivers/acpi/parser/psargs.c b/drivers/acpi/parser/psargs.c
index f1e8bf6..ef55d24 100644
--- a/drivers/acpi/parser/psargs.c
+++ b/drivers/acpi/parser/psargs.c
@@ -268,7 +268,7 @@ acpi_ps_get_next_namepath(struct acpi_walk_state
*walk_state,
 	 */
 	if (ACPI_SUCCESS(status) &&
 	    possible_method_call && (node->type == ACPI_TYPE_METHOD)) {
-		if (walk_state->op->common.aml_opcode == AML_UNLOAD_OP) {
+		if (walk_state->op && walk_state->op->common.aml_opcode ==
AML_UNLOAD_OP) {
 			/*
 			 * acpi_ps_get_next_namestring has increased the AML pointer,
 			 * so we need to restore the saved AML pointer for method call.
@@ -691,7 +691,7 @@ acpi_ps_get_next_arg(struct acpi_walk_state
*walk_state,
 
 			/* To support super_name arg of Unload */
 
-			if (walk_state->op->common.aml_opcode == AML_UNLOAD_OP) {
+			if (walk_state->op && walk_state->op->common.aml_opcode ==
AML_UNLOAD_OP) {
 				status =
 				    acpi_ps_get_next_namepath(walk_state,
 							      parser_state, arg,

 

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@cs.helsinki.fi> wrote:
> >
> > Vegard Nossum wrote:
> >
> > > On Tue, May 6, 2008 at 10:38 PM, Pekka Enberg <penberg@cs.helsinki.fi>
> > wrote:
> > >
> > > > On Tue, May 6, 2008 at 7:09 PM, Vegard Nossum <vegard.nossum@gmail.com>
> > 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
> 

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

[Vegard Nossum]

Hello,

On Thu, May 8, 2008 at 7:35 AM, Lin Ming <ming.m.lin@intel.com> wrote:
> Here comes a simple patch that fixes the warning in my machine.
>
>  Vegard, would you please help to test it in your machine?
>

Thanks for the try, but unfortunately this does not solve the problem.

Please note that kmemcheck is an patch to the kernel; without it you
will never see the warning. You can pull it from
git://git.kernel.org/pub/scm/linux/kernel/git/vegard/kmemcheck.git current
though it is unlikely that it will help you more than looking at the
code (or the report) will do.

>  Thanks,
>  Lin Ming
>
>  Signed-off-by: Lin Ming <ming.m.lin@intel.com>
>  ---
>  diff --git a/drivers/acpi/parser/psargs.c b/drivers/acpi/parser/psargs.c
>  index f1e8bf6..ef55d24 100644
>  --- a/drivers/acpi/parser/psargs.c
>  +++ b/drivers/acpi/parser/psargs.c
>  @@ -268,7 +268,7 @@ acpi_ps_get_next_namepath(struct acpi_walk_state
>  *walk_state,

>          */
>         if (ACPI_SUCCESS(status) &&
>             possible_method_call && (node->type == ACPI_TYPE_METHOD)) {
>  -               if (walk_state->op->common.aml_opcode == AML_UNLOAD_OP) {
>  +               if (walk_state->op && walk_state->op->common.aml_opcode ==
>  AML_UNLOAD_OP) {
>                         /*
>                          * acpi_ps_get_next_namestring has increased the AML pointer,
>                          * so we need to restore the saved AML pointer for method call.

Also, noticing your change, I can see why it makes no difference:
Pekka already found that it is walk_state->op that has the value of
0xf7c12ec6 (e.g. the pointer being dereferenced), so the test will
still succeed.

On the other hand, I have discovered what seems to be a deficiency in
kmemcheck (i.e. it might be my fault entirely), so it is possible that
the warning is bogus. Will send an update shortly.


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

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

[Lin Ming]

On Thu, 2008-05-08 at 08:05 +0200, Vegard Nossum wrote:
> Hello,
> 
> On Thu, May 8, 2008 at 7:35 AM, Lin Ming <ming.m.lin@intel.com> wrote:
> > Here comes a simple patch that fixes the warning in my machine.
> >
> >  Vegard, would you please help to test it in your machine?
> >
> 
> Thanks for the try, but unfortunately this does not solve the problem.

It's strange.
In my machine, without this patch the warning shows up
With this patch applied the waring goes away

Would you please upload the acpidump file?

> 
> Please note that kmemcheck is an patch to the kernel; without it you
> will never see the warning. You can pull it from
> git://git.kernel.org/pub/scm/linux/kernel/git/vegard/kmemcheck.git current

Yes, I pulled the kmemcheck tree.

BTW, I like the kmemcheck patch, it's very useful :) Great work :)

Lin Ming

> though it is unlikely that it will help you more than looking at the
> code (or the report) will do.
> 
> >  Thanks,
> >  Lin Ming
> >
> >  Signed-off-by: Lin Ming <ming.m.lin@intel.com>
> >  ---
> >  diff --git a/drivers/acpi/parser/psargs.c b/drivers/acpi/parser/psargs.c
> >  index f1e8bf6..ef55d24 100644
> >  --- a/drivers/acpi/parser/psargs.c
> >  +++ b/drivers/acpi/parser/psargs.c
> >  @@ -268,7 +268,7 @@ acpi_ps_get_next_namepath(struct acpi_walk_state
> >  *walk_state,
> 
> >          */
> >         if (ACPI_SUCCESS(status) &&
> >             possible_method_call && (node->type == ACPI_TYPE_METHOD)) {
> >  -               if (walk_state->op->common.aml_opcode == AML_UNLOAD_OP) {
> >  +               if (walk_state->op && walk_state->op->common.aml_opcode ==
> >  AML_UNLOAD_OP) {
> >                         /*
> >                          * acpi_ps_get_next_namestring has increased the AML pointer,
> >                          * so we need to restore the saved AML pointer for method call.
> 
> Also, noticing your change, I can see why it makes no difference:
> Pekka already found that it is walk_state->op that has the value of
> 0xf7c12ec6 (e.g. the pointer being dereferenced), so the test will
> still succeed.
> 
> On the other hand, I have discovered what seems to be a deficiency in
> kmemcheck (i.e. it might be my fault entirely), so it is possible that
> the warning is bogus. Will send an update shortly.
> 
> 
> Vegard
> 

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

[Vegard Nossum]

(Reworked to bottom-post style)

On Thu, May 8, 2008 at 8:12 AM, Lin Ming <ming.m.lin@intel.com> wrote:
>  > though it is unlikely that it will help you more than looking at the
>  > code (or the report) will do.
>  >
>  > >  Thanks,
>  > >  Lin Ming
>  > >
>  > >  Signed-off-by: Lin Ming <ming.m.lin@intel.com>
>  > >  ---
>  > >  diff --git a/drivers/acpi/parser/psargs.c b/drivers/acpi/parser/psargs.c
>  > >  index f1e8bf6..ef55d24 100644
>  > >  --- a/drivers/acpi/parser/psargs.c
>  > >  +++ b/drivers/acpi/parser/psargs.c
>  > >  @@ -268,7 +268,7 @@ acpi_ps_get_next_namepath(struct acpi_walk_state
>  > >  *walk_state,
>  >
>  > >          */
>  > >         if (ACPI_SUCCESS(status) &&
>  > >             possible_method_call && (node->type == ACPI_TYPE_METHOD)) {
>  > >  -               if (walk_state->op->common.aml_opcode == AML_UNLOAD_OP) {
>  > >  +               if (walk_state->op && walk_state->op->common.aml_opcode ==
>  > >  AML_UNLOAD_OP) {
>  > >                         /*
>  > >                          * acpi_ps_get_next_namestring has increased the AML pointer,
>  > >                          * so we need to restore the saved AML pointer for method call.
>  >
>  > Also, noticing your change, I can see why it makes no difference:
>  > Pekka already found that it is walk_state->op that has the value of
>  > 0xf7c12ec6 (e.g. the pointer being dereferenced), so the test will
>  > still succeed.
>  >
>  > On the other hand, I have discovered what seems to be a deficiency in
>  > kmemcheck (i.e. it might be my fault entirely), so it is possible that
>  > the warning is bogus. Will send an update shortly.

Okay: The deficiency is that SLUB will use the first four bytes of
each allocation to store the so-called freepointer; this means that
these will always be marked "initialized" even though they might
belong to an allocation that has been freed. This should NOT affect
the genuineness of the warning, however note that an earlier error
might have passed unnoticed. In other words, it doesn't lead to false
positives.

>  On Thu, 2008-05-08 at 08:05 +0200, Vegard Nossum wrote:
>  > Hello,
>  >
>  > On Thu, May 8, 2008 at 7:35 AM, Lin Ming <ming.m.lin@intel.com> wrote:
>  > > Here comes a simple patch that fixes the warning in my machine.
>  > >
>  > >  Vegard, would you please help to test it in your machine?
>  > >
>  >
>  > Thanks for the try, but unfortunately this does not solve the problem.
>
>  It's strange.
>  In my machine, without this patch the warning shows up
>  With this patch applied the waring goes away

Ah. That is strange indeed.

>  Would you please upload the acpidump file?

Which file is this or how can I produce it? Please tell me the exact
parameters to pass to the command line.

>  > Please note that kmemcheck is an patch to the kernel; without it you
>  > will never see the warning. You can pull it from
>  > git://git.kernel.org/pub/scm/linux/kernel/git/vegard/kmemcheck.git current
>
>  Yes, I pulled the kmemcheck tree.
>
>  BTW, I like the kmemcheck patch, it's very useful :) Great work :)
>
>  Lin Ming

Ahh, great. You got it working! Thanks :-D


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

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

[Lin Ming]

On Thu, 2008-05-08 at 08:31 +0200, Vegard Nossum wrote:
> (Reworked to bottom-post style)
> 
> On Thu, May 8, 2008 at 8:12 AM, Lin Ming <ming.m.lin@intel.com> wrote:
> >  > though it is unlikely that it will help you more than looking at the
> >  > code (or the report) will do.
> >  >
> >  > >  Thanks,
> >  > >  Lin Ming
> >  > >
> >  > >  Signed-off-by: Lin Ming <ming.m.lin@intel.com>
> >  > >  ---
> >  > >  diff --git a/drivers/acpi/parser/psargs.c b/drivers/acpi/parser/psargs.c
> >  > >  index f1e8bf6..ef55d24 100644
> >  > >  --- a/drivers/acpi/parser/psargs.c
> >  > >  +++ b/drivers/acpi/parser/psargs.c
> >  > >  @@ -268,7 +268,7 @@ acpi_ps_get_next_namepath(struct acpi_walk_state
> >  > >  *walk_state,
> >  >
> >  > >          */
> >  > >         if (ACPI_SUCCESS(status) &&
> >  > >             possible_method_call && (node->type == ACPI_TYPE_METHOD)) {
> >  > >  -               if (walk_state->op->common.aml_opcode == AML_UNLOAD_OP) {
> >  > >  +               if (walk_state->op && walk_state->op->common.aml_opcode ==
> >  > >  AML_UNLOAD_OP) {
> >  > >                         /*
> >  > >                          * acpi_ps_get_next_namestring has increased the AML pointer,
> >  > >                          * so we need to restore the saved AML pointer for method call.
> >  >
> >  > Also, noticing your change, I can see why it makes no difference:
> >  > Pekka already found that it is walk_state->op that has the value of
> >  > 0xf7c12ec6 (e.g. the pointer being dereferenced), so the test will
> >  > still succeed.
> >  >
> >  > On the other hand, I have discovered what seems to be a deficiency in
> >  > kmemcheck (i.e. it might be my fault entirely), so it is possible that
> >  > the warning is bogus. Will send an update shortly.
> 
> Okay: The deficiency is that SLUB will use the first four bytes of
> each allocation to store the so-called freepointer; this means that
> these will always be marked "initialized" even though they might
> belong to an allocation that has been freed. This should NOT affect
> the genuineness of the warning, however note that an earlier error
> might have passed unnoticed. In other words, it doesn't lead to false
> positives.
> 
> >  On Thu, 2008-05-08 at 08:05 +0200, Vegard Nossum wrote:
> >  > Hello,
> >  >
> >  > On Thu, May 8, 2008 at 7:35 AM, Lin Ming <ming.m.lin@intel.com> wrote:
> >  > > Here comes a simple patch that fixes the warning in my machine.
> >  > >
> >  > >  Vegard, would you please help to test it in your machine?
> >  > >
> >  >
> >  > Thanks for the try, but unfortunately this does not solve the problem.
> >
> >  It's strange.
> >  In my machine, without this patch the warning shows up
> >  With this patch applied the waring goes away
> 
> Ah. That is strange indeed.
> 
> >  Would you please upload the acpidump file?
> 
> Which file is this or how can I produce it? Please tell me the exact
> parameters to pass to the command line.

Please download acpidump util from
http://kernel.org/pub/linux/kernel/people/lenb/acpi/utils/pmtools-20071116.tar.bz2

Run "acpidump > acpidump.out" as root

Then upload acpidump.out to somewhere I can access

Lin Ming

> 
> >  > Please note that kmemcheck is an patch to the kernel; without it you
> >  > will never see the warning. You can pull it from
> >  > git://git.kernel.org/pub/scm/linux/kernel/git/vegard/kmemcheck.git current
> >
> >  Yes, I pulled the kmemcheck tree.
> >
> >  BTW, I like the kmemcheck patch, it's very useful :) Great work :)
> >
> >  Lin Ming
> 
> Ahh, great. You got it working! Thanks :-D
> 
> 
> Vegard
> 

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

[Vegard Nossum]

On Thu, May 8, 2008 at 8:56 AM, Lin Ming <ming.m.lin@intel.com> wrote:
>  > >  On Thu, 2008-05-08 at 08:05 +0200, Vegard Nossum wrote:
>  > >  > Hello,
>  > >  >
>  > >  > On Thu, May 8, 2008 at 7:35 AM, Lin Ming <ming.m.lin@intel.com> wrote:
>  > >  > > Here comes a simple patch that fixes the warning in my machine.
>  > >  > >
>  > >  > >  Vegard, would you please help to test it in your machine?
>  > >  > >
>  > >  >
>  > >  > Thanks for the try, but unfortunately this does not solve the problem.
>  > >
>  > >  It's strange.
>  > >  In my machine, without this patch the warning shows up
>  > >  With this patch applied the waring goes away
>  >
>  > Ah. That is strange indeed.
>  >
>  > >  Would you please upload the acpidump file?
>  >
>  > Which file is this or how can I produce it? Please tell me the exact
>  > parameters to pass to the command line.
>
>  Please download acpidump util from
>  http://kernel.org/pub/linux/kernel/people/lenb/acpi/utils/pmtools-20071116.tar.bz2
>
>  Run "acpidump > acpidump.out" as root
>
>  Then upload acpidump.out to somewhere I can access
>
>  Lin Ming

You can find it here:
http://userweb.kernel.org/~vegard/bugs/20080508-acpi/

(When running acpidump I got some message, now gone from the screen
unfortunately, but it said something like 0B checksum failed? Hm,
well, it seemed to produce the file anyway.)

Hope this helps. Thanks!


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