slab corruption on AIO 2.6.0-test5-mm4

slab corruption on AIO 2.6.0-test5-mm4

[Daniel McNeil]

While testing AIO on 2.6.0-test5-mm4 using ext3 file system,
I hung my system.  Unfortunately, I did not have sysrq enabled.
I rebooted with sysrq and debug enabled.   I hit this slab corruption
message:

Slab corruption: start=cc45df20, expend=cc45dfef, problemat=cc45df58
Last user: [<c0193136>](__aio_put_req+0xa8/0x1b1)
Data: ********************************************************00 00 01
00 00 00
Next: 71 F0 2C .36 31 19 C0 00 00 00 00 00 00 00 00 00 01 10 00 00 02 20
00 00
slab error in check_poison_obj(): cache `kiocb': object was modified
after freegCall Trace:
 [<c014e1f9>] check_poison_obj+0x106/0x18f
 [<c0192c52>] __aio_get_req+0x27/0x180
 [<c0150439>] kmem_cache_alloc+0x192/0x1e4
 [<c0192c52>] __aio_get_req+0x27/0x180
 [<c01947cd>] io_submit_one+0xb7/0x2d3
 [<c0194ac6>] sys_io_submit+0xdd/0x143
 [<c03c40b3>] syscall_call+0x7/0xb

I am still testing and will send more email when I get more info.

Daniel

Re: slab corruption on AIO 2.6.0-test5-mm4

[Daniel McNeil]

I re-ran an aio test using O_DIRECT to copy a file to an already
allocated file.  The kernel is 2.6.0-test5-mm4 with
CONFIG_DEBUG_PAGEALLOC enabled.
             
# Files before test:
$ ls -l
-rw-rw-r--    1 daniel   daniel   88289280 Sep 26 11:18 ff2
-rw-------    1 daniel   daniel   88289280 Jun  9 16:54 glibc-2.3.2.tar

# Test program doing 8k O_DIRECT aio with only 1 outstanding i/o
# at a time.
$ time aiocp -b 8k -n 1 -f O_DIRECT glibc-2.3.2.tar ff2

#
# Kernel Message
                                                                     
Unable to handle kernel paging request at virtual address ddb1df60
 printing eip:
c0148440
*pde = 00076063
*pte = 1db1d000
Oops: 0002 [#1]
PREEMPT SMP DEBUG_PAGEALLOC
CPU:    0
EIP:    0060:[<c0148440>]    Not tainted VLI
EFLAGS: 00210287
EIP is at __generic_file_aio_write_nolock+0xa01/0xce2
eax: 00002000   ebx: 05433000   ecx: ddb1df60   edx: 00000000
esi: 00000000   edi: ccf0fe74   ebp: d2c4de54   esp: d2c4dd60
ds: 007b   es: 007b   ss: 0068
Process aiocp (pid: 1966, threadinfo=d2c4c000 task=dbf009b0)
Stack: 00000001 ddb1df28 d2c4de80 00000000 00000000 00000001 00000001 00000000
       d2d00f28 ccf11e74 d2c4debc 00000000 00000000 00000001 00000009 00002000
       00000000 df2f9df8 fffffff4 de852df8 ffffffff 00000000 c14a3c88 00002000
Call Trace:
 [<c012022c>] kernel_map_pages+0x28/0x5d
 [<c014f381>] cache_init_objs+0xe2/0x1d5
 [<c01489f9>] generic_file_aio_write+0x97/0x163
 [<c01aa04f>] ext3_file_write+0x3f/0xcc
 [<c0194844>] aio_pwrite+0x42/0xb3
 [<c01939f5>] aio_run_iocb+0xb2/0x20e
 [<c0192fbe>] __aio_get_req+0x27/0x180
 [<c0194802>] aio_pwrite+0x0/0xb3
 [<c0194c7c>] io_submit_one+0x1fa/0x2d3
 [<c0194e32>] sys_io_submit+0xdd/0x143
 [<c03c4423>] syscall_call+0x7/0xb
                                                                                
Code: ff ff 7c 18 7f 08 39 9d 48 ff ff ff 76 0e 8b 85 6c ff ff ff 85 c0
0f 84 c1 00 00 00 8b 85 48 ff ff ff 8b 95 4c ff ff ff 8b 4d 14 <89> 01
89 51 04 8b 85 68 ff ff ff 85 c0 78 22 8b 5d 84 f6 43 19
 <7>exit_aio:ioctx still alive: 2 1 0



Looking at the disassembly it looks like it blew up on
mm/filemap.c line 1848:

	*ppos = end;

generic_file_aio_write() calls __generic_file_aio_write_nolock() 
with these parameters:

ret = __generic_file_aio_write_nolock(iocb, &local_iov, 1,
                                                &iocb->ki_pos);

So it looks like the *ppos is writing to iocb->ki_pos, but the
iocb has somehow already been freed.  Well, that's my guess for
now.  I'm still looking at the code.

Daniel

Re: slab corruption on AIO 2.6.0-test5-mm4

[Suparna Bhattacharya]

On Fri, Sep 26, 2003 at 04:59:23PM -0700, Daniel McNeil wrote:
> I re-ran an aio test using O_DIRECT to copy a file to an already
> allocated file.  The kernel is 2.6.0-test5-mm4 with
> CONFIG_DEBUG_PAGEALLOC enabled.
>              
> # Files before test:
> $ ls -l
> -rw-rw-r--    1 daniel   daniel   88289280 Sep 26 11:18 ff2
> -rw-------    1 daniel   daniel   88289280 Jun  9 16:54 glibc-2.3.2.tar
> 
> # Test program doing 8k O_DIRECT aio with only 1 outstanding i/o
> # at a time.
> $ time aiocp -b 8k -n 1 -f O_DIRECT glibc-2.3.2.tar ff2
> 
> #
> # Kernel Message
>                                                                      
> Unable to handle kernel paging request at virtual address ddb1df60
>  printing eip:
> c0148440
> *pde = 00076063
> *pte = 1db1d000
> Oops: 0002 [#1]
> PREEMPT SMP DEBUG_PAGEALLOC
> CPU:    0
> EIP:    0060:[<c0148440>]    Not tainted VLI
> EFLAGS: 00210287
> EIP is at __generic_file_aio_write_nolock+0xa01/0xce2
> eax: 00002000   ebx: 05433000   ecx: ddb1df60   edx: 00000000
> esi: 00000000   edi: ccf0fe74   ebp: d2c4de54   esp: d2c4dd60
> ds: 007b   es: 007b   ss: 0068
> Process aiocp (pid: 1966, threadinfo=d2c4c000 task=dbf009b0)
> Stack: 00000001 ddb1df28 d2c4de80 00000000 00000000 00000001 00000001 00000000
>        d2d00f28 ccf11e74 d2c4debc 00000000 00000000 00000001 00000009 00002000
>        00000000 df2f9df8 fffffff4 de852df8 ffffffff 00000000 c14a3c88 00002000
> Call Trace:
>  [<c012022c>] kernel_map_pages+0x28/0x5d
>  [<c014f381>] cache_init_objs+0xe2/0x1d5
>  [<c01489f9>] generic_file_aio_write+0x97/0x163
>  [<c01aa04f>] ext3_file_write+0x3f/0xcc
>  [<c0194844>] aio_pwrite+0x42/0xb3
>  [<c01939f5>] aio_run_iocb+0xb2/0x20e
>  [<c0192fbe>] __aio_get_req+0x27/0x180
>  [<c0194802>] aio_pwrite+0x0/0xb3
>  [<c0194c7c>] io_submit_one+0x1fa/0x2d3
>  [<c0194e32>] sys_io_submit+0xdd/0x143
>  [<c03c4423>] syscall_call+0x7/0xb
>                                                                                 
> Code: ff ff 7c 18 7f 08 39 9d 48 ff ff ff 76 0e 8b 85 6c ff ff ff 85 c0
> 0f 84 c1 00 00 00 8b 85 48 ff ff ff 8b 95 4c ff ff ff 8b 4d 14 <89> 01
> 89 51 04 8b 85 68 ff ff ff 85 c0 78 22 8b 5d 84 f6 43 19
>  <7>exit_aio:ioctx still alive: 2 1 0
> 
> 
> 
> Looking at the disassembly it looks like it blew up on
> mm/filemap.c line 1848:
> 
> 	*ppos = end;
> 
> generic_file_aio_write() calls __generic_file_aio_write_nolock() 
> with these parameters:
> 
> ret = __generic_file_aio_write_nolock(iocb, &local_iov, 1,
>                                                 &iocb->ki_pos);
> 
> So it looks like the *ppos is writing to iocb->ki_pos, but the
> iocb has somehow already been freed.  Well, that's my guess for

If the i/o completes by the time we get to line 1848, this sounds
quite possible (aio_complete() would have been called and freed
the iocb in finished_one_bio). I wonder why this race didn't show 
up earlier, though ...

Regards
Suparna

> now.  I'm still looking at the code.
> 
> Daniel
> 
> 
> --
> To unsubscribe, send a message with 'unsubscribe linux-aio' in
> the body to majordomo@kvack.org.  For more info on Linux AIO,
> see: http://www.kvack.org/aio/
> Don't email: <a href=mailto:"aart@kvack.org">aart@kvack.org</a>

-- 
Suparna Bhattacharya (suparna@in.ibm.com)
Linux Technology Center
IBM Software Labs, India

[PATCH 2.6.0-test6-mm1] aio ref count in io_submit_one

[Daniel McNeil]

[-- Attachment #1: Type: text/plain, Size: 672 bytes --]

Andrew and Suparna,

Here is a patch to hold an extra reference count on the AIO request iocb
while it is being submitted and then drop it ref before returning.
This prevents the race I was seeing with AIO O_DIRECT tests on ext3
where the aio_complete() was freeing the iocb while it was still
be referenced by the AIO submit code path.  I've run this on my
2-proc box with CONFIG_DEBUG_PAGEALLOC on and I no longer hit
the oops.  The other option is to change the AIO code to never
reference the iocb after it has been submitted, but that seems more
error prone.  This patch is a very small change. I am surprised we have
not seen this race before. 

Thoughts?

Daniel



[-- Attachment #2: 2.6.0-test6-mm1.aio_ref_count.patch --]
[-- Type: text/plain, Size: 668 bytes --]

--- linux-2.6.0-test6-mm1/fs/aio.c	2003-09-30 14:47:51.000000000 -0700
+++ linux-2.6.0-test6-mm1.aio/fs/aio.c	2003-09-30 16:03:08.702783397 -0700
@@ -1490,7 +1490,14 @@ int io_submit_one(struct kioctx *ctx, st
 		goto out_put_req;
 
 	spin_lock_irq(&ctx->ctx_lock);
+	/*
+	 * Hold an extra reference while submitting the i/o.
+	 * This prevents races between the aio code path referencing the
+	 * req (after submitting it) and aio_complete() freeing the req.
+	 */
+	req->ki_users++;		/* grab extra reference */
 	ret = aio_run_iocb(req);
+	(void)__aio_put_req(ctx, req);	/* drop the extra reference */	
 	spin_unlock_irq(&ctx->ctx_lock);
 
 	if (-EIOCBRETRY == ret)

Re: [PATCH 2.6.0-test6-mm1] aio ref count in io_submit_one

[Suparna Bhattacharya]

On Tue, Sep 30, 2003 at 04:22:49PM -0700, Daniel McNeil wrote:
> Andrew and Suparna,
> 
> Here is a patch to hold an extra reference count on the AIO request iocb
> while it is being submitted and then drop it ref before returning.
> This prevents the race I was seeing with AIO O_DIRECT tests on ext3
> where the aio_complete() was freeing the iocb while it was still
> be referenced by the AIO submit code path.  I've run this on my
> 2-proc box with CONFIG_DEBUG_PAGEALLOC on and I no longer hit
> the oops.  The other option is to change the AIO code to never
> reference the iocb after it has been submitted, but that seems more
> error prone.  This patch is a very small change. I am surprised we have
> not seen this race before. 
> 
> Thoughts?
> 
> Daniel
> 
> 

> --- linux-2.6.0-test6-mm1/fs/aio.c	2003-09-30 14:47:51.000000000 -0700
> +++ linux-2.6.0-test6-mm1.aio/fs/aio.c	2003-09-30 16:03:08.702783397 -0700
> @@ -1490,7 +1490,14 @@ int io_submit_one(struct kioctx *ctx, st
>  		goto out_put_req;
>  
>  	spin_lock_irq(&ctx->ctx_lock);
> +	/*
> +	 * Hold an extra reference while submitting the i/o.
> +	 * This prevents races between the aio code path referencing the
> +	 * req (after submitting it) and aio_complete() freeing the req.
> +	 */
> +	req->ki_users++;		/* grab extra reference */
>  	ret = aio_run_iocb(req);
> +	(void)__aio_put_req(ctx, req);	/* drop the extra reference */	

I haven't looked very closely, but am just wondering why you ignore 
the return value of __aio_put_req here - are you sure there is no 
potential memory leakage (could be missing a put_ioctx) as a result ? 


>  	spin_unlock_irq(&ctx->ctx_lock);
>  
>  	if (-EIOCBRETRY == ret)

Although this isn't a problem with retry-based AIO (where we always
call aio_complete() from the calling routine, so should never see
the iocb going away underneath us), if we do add the ref count 
increment, we should probably try to do it for both the initial
submission and subsequent retries --- just in case we have code
(in future) that uses a combination of retries and aio completion
from interrupt context.

Regards
Suparna

-- 
Suparna Bhattacharya (suparna@in.ibm.com)
Linux Technology Center
IBM Software Labs, India

[PATCH 2.6.0-test6-mm1] aio ref count in io_submit_one updated

[Daniel McNeil]

[-- Attachment #1: Type: text/plain, Size: 666 bytes --]

On Wed, 2003-10-01 at 01:46, Suparna Bhattacharya wrote:

> I haven't looked very closely, but am just wondering why you ignore 
> the return value of __aio_put_req here - are you sure there is no 
> potential memory leakage (could be missing a put_ioctx) as a result ? 


You are right.  I didn't look closely enough.  I thought the only
difference between aio_put_req() and __aio_put_req() was the lock
already being help.  I missed the put_ioctx().  So here is the
updated patch.  This also runs on my 2-proc with CONFIG_DEBUG_PAGEALLOC
without oops'ing.

I'm still looking at the retry case and I will send out a patch for
that when I'm done.

Thanks,

Daniel



[-- Attachment #2: 2.6.0-test6-mm1.aio_ref_count.patch --]
[-- Type: text/plain, Size: 1096 bytes --]

--- linux-2.6.0-test6-mm1/fs/aio.c	2003-09-30 14:47:51.000000000 -0700
+++ linux-2.6.0-test6-mm1.aio/fs/aio.c	2003-10-01 13:42:25.091744710 -0700
@@ -1431,6 +1431,7 @@ int io_submit_one(struct kioctx *ctx, st
 	struct kiocb *req;
 	struct file *file;
 	ssize_t ret;
+	int need_putctx;
 
 	/* enforce forwards compatibility on users */
 	if (unlikely(iocb->aio_reserved1 || iocb->aio_reserved2 ||
@@ -1490,16 +1491,26 @@ int io_submit_one(struct kioctx *ctx, st
 		goto out_put_req;
 
 	spin_lock_irq(&ctx->ctx_lock);
+	/*
+	 * Hold an extra reference while submitting the i/o.
+	 * This prevents races between the aio code path referencing the
+	 * req (after submitting it) and aio_complete() freeing the req.
+	 */
+	req->ki_users++;			/* grab extra reference */
 	ret = aio_run_iocb(req);
+	need_putctx = __aio_put_req(ctx, req);	/* drop the extra reference */	
 	spin_unlock_irq(&ctx->ctx_lock);
 
 	if (-EIOCBRETRY == ret)
 		queue_work(aio_wq, &ctx->wq);
 
+	if (need_putctx)
+		put_ioctx(ctx);
+
 	return 0;
 
 out_put_req:
-	aio_put_req(req);
+	(void)aio_put_req(req);
 	return ret;
 }
 

PATCH 2.6.0-test6-mm2] aio ref count during retry

[Daniel McNeil]

[-- Attachment #1: Type: text/plain, Size: 1314 bytes --]

On Wed, 2003-10-01 at 01:46, Suparna Bhattacharya wrote:
> Although this isn't a problem with retry-based AIO (where we always
> call aio_complete() from the calling routine, so should never see
> the iocb going away underneath us), if we do add the ref count 
> increment, we should probably try to do it for both the initial
> submission and subsequent retries --- just in case we have code
> (in future) that uses a combination of retries and aio completion
> from interrupt context.
> 
> Regards
> Suparna

Andrew and Suparna,


Here is the patch for AIO retry to hold an extra ref count.
The patch is small, but I wanted to make sure it was safe.
I spent time looking over the retry code and this patch looks
ok to me.  It is potentially calling put_ioctx() while holding
ctx->ctx_lock, I do not think that will cause any problems.
This should never be the last reference on the ioctx anyway,
since the loop is checking list_empty(&ctx->run_list).  The
first ref is taken in sys_io_setup() and last removed in
io_destroy(). It also looks like holding ctx->ctx_lock prevents
any races between any retries and an io_destroy() which would
try to cancel all iocbs.

I've tested this on my 2-proc by coping a raw partitions and
copying ext3 files using using AIO and O_DIRECT, O_SYNC, and both.

Thoughts?

Daniel

[-- Attachment #2: 2.6.0-test6-mm2.aio_retry_ref_count.patch --]
[-- Type: text/plain, Size: 704 bytes --]

--- linux-2.6.0-test6-mm2/fs/aio.c	2003-10-03 10:45:39.000000000 -0700
+++ linux-2.6.0-test6-mm2.aio/fs/aio.c	2003-10-03 11:26:26.894495149 -0700
@@ -771,12 +771,20 @@ static void __aio_run_iocbs(struct kioct
 	struct kiocb *iocb;
 	ssize_t ret;
 	int count = 0;
+	int need_putctx;
 
 	while (!list_empty(&ctx->run_list)) {
 		iocb = list_entry(ctx->run_list.next, struct kiocb,
 			ki_run_list);
 		list_del(&iocb->ki_run_list);
+		/*
+		 * Hold an extra reference while retrying i/o.
+		 */
+		iocb->ki_users++;	/* grab extra reference */
 		ret = aio_run_iocb(iocb);
+		need_putctx = __aio_put_req(ctx, iocb);  /* drop extra ref */
+		if (need_putctx)
+			put_ioctx(ctx);
 		count++;
 	}
 	aio_run++;

Re: PATCH 2.6.0-test6-mm2] aio ref count during retry

[Andrew Morton]

Daniel McNeil <daniel@osdl.org> wrote:
>
> Here is the patch for AIO retry to hold an extra ref count.
> The patch is small, but I wanted to make sure it was safe.
> I spent time looking over the retry code and this patch looks
> ok to me.  It is potentially calling put_ioctx() while holding
> ctx->ctx_lock, I do not think that will cause any problems.
> This should never be the last reference on the ioctx anyway,
> since the loop is checking list_empty(&ctx->run_list).

So...  if the refcount is never zero in there, why are you changing it to
take an additional reference?

Re: PATCH 2.6.0-test6-mm2] aio ref count during retry

[Daniel McNeil]

On Fri, 2003-10-03 at 14:40, Andrew Morton wrote:
> Daniel McNeil <daniel@osdl.org> wrote:
> >
> > Here is the patch for AIO retry to hold an extra ref count.
> > The patch is small, but I wanted to make sure it was safe.
> > I spent time looking over the retry code and this patch looks
> > ok to me.  It is potentially calling put_ioctx() while holding
> > ctx->ctx_lock, I do not think that will cause any problems.
> > This should never be the last reference on the ioctx anyway,
> > since the loop is checking list_empty(&ctx->run_list).
> 
> So...  if the refcount is never zero in there, why are you changing it to
> take an additional reference?

The extra reference is on the iocb itself.  Each iocb has a reference
on the ioctx.  When dropping the extra reference using __aio_put_req(),
you have to check if it was the last reference and then drop that iocb's
reference on the ioctx by calling put_ioctx().  It is the ioctx's ref
count that is never zero here.

Having the extra ref on the iocb, guarantees that the iocb won't be
freed until the extra reference is dropped. In the initial submit
case, the lower level code has looking at the iocb after submitting
it (which was racy without the extra reference).  This patch just
added the extra reference for iocb during retries.

Daniel